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 1C733106C4 for ; Fri, 12 Apr 2013 21:52:33 +0000 (UTC) Received: (qmail 40346 invoked by uid 500); 12 Apr 2013 21:52:31 -0000 Delivered-To: apmail-lucene-dev-archive@lucene.apache.org Received: (qmail 40287 invoked by uid 500); 12 Apr 2013 21:52:31 -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 40279 invoked by uid 99); 12 Apr 2013 21:52:31 -0000 Received: from athena.apache.org (HELO athena.apache.org) (140.211.11.136) by apache.org (qpsmtpd/0.29) with ESMTP; Fri, 12 Apr 2013 21:52:31 +0000 X-ASF-Spam-Status: No, hits=-2000.0 required=5.0 tests=ALL_TRUSTED,NORMAL_HTTP_TO_IP,WEIRD_PORT X-Spam-Check-By: apache.org Received: from [140.211.11.8] (HELO aegis.apache.org) (140.211.11.8) by apache.org (qpsmtpd/0.29) with ESMTP; Fri, 12 Apr 2013 21:52:22 +0000 Received: from aegis.apache.org (localhost [127.0.0.1]) by aegis.apache.org (Postfix) with ESMTP id A566DC0071 for ; Fri, 12 Apr 2013 21:52:01 +0000 (UTC) Date: Fri, 12 Apr 2013 21:51:40 +0000 (UTC) From: Apache Jenkins Server To: dev@lucene.apache.org Message-ID: <878264999.2051.1365803521658.JavaMail.hudson@aegis> In-Reply-To: <2077375999.1970.1365775452230.JavaMail.hudson@aegis> References: <2077375999.1970.1365775452230.JavaMail.hudson@aegis> Subject: [JENKINS] Lucene-Solr-Tests-4.x-java7 - Build # 1141 - Still Failing MIME-Version: 1.0 Content-Type: multipart/mixed; boundary="----=_Part_2050_1883127452.1365803500665" X-Jenkins-Job: Lucene-Solr-Tests-4.x-java7 X-Jenkins-Result: FAILURE X-Virus-Checked: Checked by ClamAV on apache.org ------=_Part_2050_1883127452.1365803500665 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: quoted-printable Build: https://builds.apache.org/job/Lucene-Solr-Tests-4.x-java7/1141/ 2 tests failed. REGRESSION: org.apache.solr.cloud.ShardSplitTest.testDistribSearch Error Message: Wrong doc count on shard1_1 expected:<50> but was:<49> Stack Trace: java.lang.AssertionError: Wrong doc count on shard1_1 expected:<50> but was= :<49> =09at __randomizedtesting.SeedInfo.seed([D24BF1F9741286A1:53AD7FE1034DE69D]= :0) =09at org.junit.Assert.fail(Assert.java:93) =09at org.junit.Assert.failNotEquals(Assert.java:647) =09at org.junit.Assert.assertEquals(Assert.java:128) =09at org.junit.Assert.assertEquals(Assert.java:472) =09at org.apache.solr.cloud.ShardSplitTest.doTest(ShardSplitTest.java:220) =09at org.apache.solr.BaseDistributedSearchTestCase.testDistribSearch(BaseD= istributedSearchTestCase.java:806) =09at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method) =09at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.= java:57) =09at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAcces= sorImpl.java:43) =09at java.lang.reflect.Method.invoke(Method.java:601) =09at com.carrotsearch.randomizedtesting.RandomizedRunner.invoke(Randomized= Runner.java:1559) =09at com.carrotsearch.randomizedtesting.RandomizedRunner.access$600(Random= izedRunner.java:79) =09at com.carrotsearch.randomizedtesting.RandomizedRunner$6.evaluate(Random= izedRunner.java:737) =09at com.carrotsearch.randomizedtesting.RandomizedRunner$7.evaluate(Random= izedRunner.java:773) =09at com.carrotsearch.randomizedtesting.RandomizedRunner$8.evaluate(Random= izedRunner.java:787) =09at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$= 1.evaluate(SystemPropertiesRestoreRule.java:53) =09at org.apache.lucene.util.TestRuleSetupTeardownChained$1.evaluate(TestRu= leSetupTeardownChained.java:50) =09at org.apache.lucene.util.TestRuleFieldCacheSanity$1.evaluate(TestRuleFi= eldCacheSanity.java:51) =09at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBef= oreAfterRule.java:46) =09at com.carrotsearch.randomizedtesting.rules.SystemPropertiesInvariantRul= e$1.evaluate(SystemPropertiesInvariantRule.java:55) =09at org.apache.lucene.util.TestRuleThreadAndTestName$1.evaluate(TestRuleT= hreadAndTestName.java:49) =09at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(Test= RuleIgnoreAfterMaxFailures.java:70) =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:358) =09at com.carrotsearch.randomizedtesting.ThreadLeakControl.forkTimeoutingTa= sk(ThreadLeakControl.java:782) =09at com.carrotsearch.randomizedtesting.ThreadLeakControl$3.evaluate(Threa= dLeakControl.java:442) =09at com.carrotsearch.randomizedtesting.RandomizedRunner.runSingleTest(Ran= domizedRunner.java:746) =09at com.carrotsearch.randomizedtesting.RandomizedRunner$3.evaluate(Random= izedRunner.java:648) =09at com.carrotsearch.randomizedtesting.RandomizedRunner$4.evaluate(Random= izedRunner.java:682) =09at com.carrotsearch.randomizedtesting.RandomizedRunner$5.evaluate(Random= izedRunner.java:693) =09at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(St= atementAdapter.java:36) =09at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$= 1.evaluate(SystemPropertiesRestoreRule.java:53) =09at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBef= oreAfterRule.java:46) =09at org.apache.lucene.util.TestRuleStoreClassName$1.evaluate(TestRuleStor= eClassName.java:42) =09at com.carrotsearch.randomizedtesting.rules.SystemPropertiesInvariantRul= e$1.evaluate(SystemPropertiesInvariantRule.java:55) =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 org.apache.lucene.util.TestRuleAssertionsRequired$1.evaluate(TestRule= AssertionsRequired.java:43) =09at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFai= lure.java:48) =09at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(Test= RuleIgnoreAfterMaxFailures.java:70) =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:358) =09at java.lang.Thread.run(Thread.java:722) REGRESSION: org.apache.solr.cloud.SyncSliceTest.testDistribSearch Error Message: shard1 is not consistent. Got 305 from http://127.0.0.1:38575/ihjbc/pg/col= lection1lastClient and got 5 from http://127.0.0.1:38580/ihjbc/pg/collectio= n1 Stack Trace: java.lang.AssertionError: shard1 is not consistent. Got 305 from http://12= 7.0.0.1:38575/ihjbc/pg/collection1lastClient and got 5 from http://127.0.0.= 1:38580/ihjbc/pg/collection1 =09at __randomizedtesting.SeedInfo.seed([D24BF1F9741286A1:53AD7FE1034DE69D]= :0) =09at org.junit.Assert.fail(Assert.java:93) =09at org.apache.solr.cloud.AbstractFullDistribZkTestBase.checkShardConsist= ency(AbstractFullDistribZkTestBase.java:963) =09at org.apache.solr.cloud.SyncSliceTest.doTest(SyncSliceTest.java:238) =09at org.apache.solr.BaseDistributedSearchTestCase.testDistribSearch(BaseD= istributedSearchTestCase.java:806) =09at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method) =09at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.= java:57) =09at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAcces= sorImpl.java:43) =09at java.lang.reflect.Method.invoke(Method.java:601) =09at com.carrotsearch.randomizedtesting.RandomizedRunner.invoke(Randomized= Runner.java:1559) =09at com.carrotsearch.randomizedtesting.RandomizedRunner.access$600(Random= izedRunner.java:79) =09at com.carrotsearch.randomizedtesting.RandomizedRunner$6.evaluate(Random= izedRunner.java:737) =09at com.carrotsearch.randomizedtesting.RandomizedRunner$7.evaluate(Random= izedRunner.java:773) =09at com.carrotsearch.randomizedtesting.RandomizedRunner$8.evaluate(Random= izedRunner.java:787) =09at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$= 1.evaluate(SystemPropertiesRestoreRule.java:53) =09at org.apache.lucene.util.TestRuleSetupTeardownChained$1.evaluate(TestRu= leSetupTeardownChained.java:50) =09at org.apache.lucene.util.TestRuleFieldCacheSanity$1.evaluate(TestRuleFi= eldCacheSanity.java:51) =09at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBef= oreAfterRule.java:46) =09at com.carrotsearch.randomizedtesting.rules.SystemPropertiesInvariantRul= e$1.evaluate(SystemPropertiesInvariantRule.java:55) =09at org.apache.lucene.util.TestRuleThreadAndTestName$1.evaluate(TestRuleT= hreadAndTestName.java:49) =09at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(Test= RuleIgnoreAfterMaxFailures.java:70) =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:358) =09at com.carrotsearch.randomizedtesting.ThreadLeakControl.forkTimeoutingTa= sk(ThreadLeakControl.java:782) =09at com.carrotsearch.randomizedtesting.ThreadLeakControl$3.evaluate(Threa= dLeakControl.java:442) =09at com.carrotsearch.randomizedtesting.RandomizedRunner.runSingleTest(Ran= domizedRunner.java:746) =09at com.carrotsearch.randomizedtesting.RandomizedRunner$3.evaluate(Random= izedRunner.java:648) =09at com.carrotsearch.randomizedtesting.RandomizedRunner$4.evaluate(Random= izedRunner.java:682) =09at com.carrotsearch.randomizedtesting.RandomizedRunner$5.evaluate(Random= izedRunner.java:693) =09at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(St= atementAdapter.java:36) =09at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$= 1.evaluate(SystemPropertiesRestoreRule.java:53) =09at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBef= oreAfterRule.java:46) =09at org.apache.lucene.util.TestRuleStoreClassName$1.evaluate(TestRuleStor= eClassName.java:42) =09at com.carrotsearch.randomizedtesting.rules.SystemPropertiesInvariantRul= e$1.evaluate(SystemPropertiesInvariantRule.java:55) =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 org.apache.lucene.util.TestRuleAssertionsRequired$1.evaluate(TestRule= AssertionsRequired.java:43) =09at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFai= lure.java:48) =09at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(Test= RuleIgnoreAfterMaxFailures.java:70) =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:358) =09at java.lang.Thread.run(Thread.java:722) Build Log: [...truncated 9176 lines...] [junit4:junit4] Suite: org.apache.solr.cloud.ShardSplitTest [junit4:junit4] 1> INFO - 2013-04-12 21:28:46.497; org.apache.solr.BaseD= istributedSearchTestCase; Setting hostContext system property: / [junit4:junit4] 1> INFO - 2013-04-12 21:28:46.502; org.apache.solr.SolrT= estCaseJ4; ###Starting testDistribSearch [junit4:junit4] 1> INFO - 2013-04-12 21:28:46.503; org.apache.solr.cloud= .ZkTestServer; STARTING ZK TEST SERVER [junit4:junit4] 1> client port:0.0.0.0/0.0.0.0:0 [junit4:junit4] 1> INFO - 2013-04-12 21:28:46.503; org.apache.solr.cloud= .ZkTestServer$ZKServerMain; Starting server [junit4:junit4] 1> INFO - 2013-04-12 21:28:46.604; org.apache.solr.cloud= .ZkTestServer; start zk server on port:47561 [junit4:junit4] 1> INFO - 2013-04-12 21:28:46.605; org.apache.solr.commo= n.cloud.ConnectionManager; Waiting for client to connect to ZooKeeper [junit4:junit4] 1> INFO - 2013-04-12 21:28:46.610; org.apache.solr.commo= n.cloud.ConnectionManager; Watcher org.apache.solr.common.cloud.ConnectionM= anager@6d51a97a name:ZooKeeperConnection Watcher:127.0.0.1:47561 got event = WatchedEvent state:SyncConnected type:None path:null path:null type:None [junit4:junit4] 1> INFO - 2013-04-12 21:28:46.610; org.apache.solr.commo= n.cloud.ConnectionManager; Client is connected to ZooKeeper [junit4:junit4] 1> INFO - 2013-04-12 21:28:46.611; org.apache.solr.commo= n.cloud.SolrZkClient; makePath: /solr [junit4:junit4] 1> INFO - 2013-04-12 21:28:46.621; org.apache.solr.commo= n.cloud.ConnectionManager; Waiting for client to connect to ZooKeeper [junit4:junit4] 1> INFO - 2013-04-12 21:28:46.623; org.apache.solr.commo= n.cloud.ConnectionManager; Watcher org.apache.solr.common.cloud.ConnectionM= anager@5363ab71 name:ZooKeeperConnection Watcher:127.0.0.1:47561/solr got e= vent WatchedEvent state:SyncConnected type:None path:null path:null type:No= ne [junit4:junit4] 1> INFO - 2013-04-12 21:28:46.624; org.apache.solr.commo= n.cloud.ConnectionManager; Client is connected to ZooKeeper [junit4:junit4] 1> INFO - 2013-04-12 21:28:46.624; org.apache.solr.commo= n.cloud.SolrZkClient; makePath: /collections/collection1 [junit4:junit4] 1> INFO - 2013-04-12 21:28:46.628; org.apache.solr.commo= n.cloud.SolrZkClient; makePath: /collections/collection1/shards [junit4:junit4] 1> INFO - 2013-04-12 21:28:46.637; org.apache.solr.commo= n.cloud.SolrZkClient; makePath: /collections/control_collection [junit4:junit4] 1> INFO - 2013-04-12 21:28:46.640; org.apache.solr.commo= n.cloud.SolrZkClient; makePath: /collections/control_collection/shards [junit4:junit4] 1> INFO - 2013-04-12 21:28:46.644; org.apache.solr.cloud= .AbstractZkTestCase; put /usr/home/hudson/hudson-slave/workspace/Lucene-Sol= r-Tests-4.x-java7/solr/build/solr-core/test-files/solr/collection1/conf/sol= rconfig-tlog.xml to /configs/conf1/solrconfig.xml [junit4:junit4] 1> INFO - 2013-04-12 21:28:46.644; org.apache.solr.commo= n.cloud.SolrZkClient; makePath: /configs/conf1/solrconfig.xml [junit4:junit4] 1> INFO - 2013-04-12 21:28:46.659; org.apache.solr.cloud= .AbstractZkTestCase; put /usr/home/hudson/hudson-slave/workspace/Lucene-Sol= r-Tests-4.x-java7/solr/build/solr-core/test-files/solr/collection1/conf/sch= ema.xml to /configs/conf1/schema.xml [junit4:junit4] 1> INFO - 2013-04-12 21:28:46.660; org.apache.solr.commo= n.cloud.SolrZkClient; makePath: /configs/conf1/schema.xml [junit4:junit4] 1> INFO - 2013-04-12 21:28:46.778; org.apache.solr.cloud= .AbstractZkTestCase; put /usr/home/hudson/hudson-slave/workspace/Lucene-Sol= r-Tests-4.x-java7/solr/build/solr-core/test-files/solr/collection1/conf/sto= pwords.txt to /configs/conf1/stopwords.txt [junit4:junit4] 1> INFO - 2013-04-12 21:28:46.779; org.apache.solr.commo= n.cloud.SolrZkClient; makePath: /configs/conf1/stopwords.txt [junit4:junit4] 1> INFO - 2013-04-12 21:28:46.782; org.apache.solr.cloud= .AbstractZkTestCase; put /usr/home/hudson/hudson-slave/workspace/Lucene-Sol= r-Tests-4.x-java7/solr/build/solr-core/test-files/solr/collection1/conf/pro= twords.txt to /configs/conf1/protwords.txt [junit4:junit4] 1> INFO - 2013-04-12 21:28:46.783; org.apache.solr.commo= n.cloud.SolrZkClient; makePath: /configs/conf1/protwords.txt [junit4:junit4] 1> INFO - 2013-04-12 21:28:46.793; org.apache.solr.cloud= .AbstractZkTestCase; put /usr/home/hudson/hudson-slave/workspace/Lucene-Sol= r-Tests-4.x-java7/solr/build/solr-core/test-files/solr/collection1/conf/cur= rency.xml to /configs/conf1/currency.xml [junit4:junit4] 1> INFO - 2013-04-12 21:28:46.793; org.apache.solr.commo= n.cloud.SolrZkClient; makePath: /configs/conf1/currency.xml [junit4:junit4] 1> INFO - 2013-04-12 21:28:46.797; org.apache.solr.cloud= .AbstractZkTestCase; put /usr/home/hudson/hudson-slave/workspace/Lucene-Sol= r-Tests-4.x-java7/solr/build/solr-core/test-files/solr/collection1/conf/ope= n-exchange-rates.json to /configs/conf1/open-exchange-rates.json [junit4:junit4] 1> INFO - 2013-04-12 21:28:46.797; org.apache.solr.commo= n.cloud.SolrZkClient; makePath: /configs/conf1/open-exchange-rates.json [junit4:junit4] 1> INFO - 2013-04-12 21:28:46.800; org.apache.solr.cloud= .AbstractZkTestCase; put /usr/home/hudson/hudson-slave/workspace/Lucene-Sol= r-Tests-4.x-java7/solr/build/solr-core/test-files/solr/collection1/conf/map= ping-ISOLatin1Accent.txt to /configs/conf1/mapping-ISOLatin1Accent.txt [junit4:junit4] 1> INFO - 2013-04-12 21:28:46.801; org.apache.solr.commo= n.cloud.SolrZkClient; makePath: /configs/conf1/mapping-ISOLatin1Accent.txt [junit4:junit4] 1> INFO - 2013-04-12 21:28:46.804; org.apache.solr.cloud= .AbstractZkTestCase; put /usr/home/hudson/hudson-slave/workspace/Lucene-Sol= r-Tests-4.x-java7/solr/build/solr-core/test-files/solr/collection1/conf/old= _synonyms.txt to /configs/conf1/old_synonyms.txt [junit4:junit4] 1> INFO - 2013-04-12 21:28:46.805; org.apache.solr.commo= n.cloud.SolrZkClient; makePath: /configs/conf1/old_synonyms.txt [junit4:junit4] 1> INFO - 2013-04-12 21:28:46.808; org.apache.solr.cloud= .AbstractZkTestCase; put /usr/home/hudson/hudson-slave/workspace/Lucene-Sol= r-Tests-4.x-java7/solr/build/solr-core/test-files/solr/collection1/conf/syn= onyms.txt to /configs/conf1/synonyms.txt [junit4:junit4] 1> INFO - 2013-04-12 21:28:46.808; org.apache.solr.commo= n.cloud.SolrZkClient; makePath: /configs/conf1/synonyms.txt [junit4:junit4] 1> INFO - 2013-04-12 21:28:46.957; org.eclipse.jetty.ser= ver.Server; jetty-8.1.8.v20121106 [junit4:junit4] 1> INFO - 2013-04-12 21:28:46.962; org.eclipse.jetty.ser= ver.AbstractConnector; Started SocketConnector@127.0.0.1:47083 [junit4:junit4] 1> INFO - 2013-04-12 21:28:46.963; org.apache.solr.servl= et.SolrDispatchFilter; SolrDispatchFilter.init() [junit4:junit4] 1> INFO - 2013-04-12 21:28:46.963; org.apache.solr.core.= SolrResourceLoader; JNDI not configured for solr (NoInitialContextEx) [junit4:junit4] 1> INFO - 2013-04-12 21:28:46.964; org.apache.solr.core.= SolrResourceLoader; using system property solr.solr.home: /usr/home/hudson/= hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build/solr-core/tes= t/J1/./org.apache.solr.cloud.ShardSplitTest-controljetty-1365802126818 [junit4:junit4] 1> INFO - 2013-04-12 21:28:46.964; org.apache.solr.core.= CoreContainer$Initializer; looking for solr config file: /usr/home/hudson/h= udson-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build/solr-core/test= /J1/./org.apache.solr.cloud.ShardSplitTest-controljetty-1365802126818/solr.= xml [junit4:junit4] 1> INFO - 2013-04-12 21:28:46.964; org.apache.solr.core.= CoreContainer; New CoreContainer 1260364539 [junit4:junit4] 1> INFO - 2013-04-12 21:28:46.965; org.apache.solr.core.= CoreContainer; Loading CoreContainer using Solr Home: '/usr/home/hudson/hud= son-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build/solr-core/test/J= 1/./org.apache.solr.cloud.ShardSplitTest-controljetty-1365802126818/' [junit4:junit4] 1> INFO - 2013-04-12 21:28:46.965; org.apache.solr.core.= SolrResourceLoader; new SolrResourceLoader for directory: '/usr/home/hudson= /hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build/solr-core/te= st/J1/./org.apache.solr.cloud.ShardSplitTest-controljetty-1365802126818/' [junit4:junit4] 1> INFO - 2013-04-12 21:28:47.010; org.apache.solr.handl= er.component.HttpShardHandlerFactory; Setting socketTimeout to: 120000 [junit4:junit4] 1> INFO - 2013-04-12 21:28:47.011; org.apache.solr.handl= er.component.HttpShardHandlerFactory; Setting urlScheme to: http:// [junit4:junit4] 1> INFO - 2013-04-12 21:28:47.011; org.apache.solr.handl= er.component.HttpShardHandlerFactory; Setting connTimeout to: 15000 [junit4:junit4] 1> INFO - 2013-04-12 21:28:47.012; org.apache.solr.handl= er.component.HttpShardHandlerFactory; Setting maxConnectionsPerHost to: 20 [junit4:junit4] 1> INFO - 2013-04-12 21:28:47.012; org.apache.solr.handl= er.component.HttpShardHandlerFactory; Setting corePoolSize to: 0 [junit4:junit4] 1> INFO - 2013-04-12 21:28:47.013; org.apache.solr.handl= er.component.HttpShardHandlerFactory; Setting maximumPoolSize to: 214748364= 7 [junit4:junit4] 1> INFO - 2013-04-12 21:28:47.013; org.apache.solr.handl= er.component.HttpShardHandlerFactory; Setting maxThreadIdleTime to: 5 [junit4:junit4] 1> INFO - 2013-04-12 21:28:47.013; org.apache.solr.handl= er.component.HttpShardHandlerFactory; Setting sizeOfQueue to: -1 [junit4:junit4] 1> INFO - 2013-04-12 21:28:47.014; org.apache.solr.handl= er.component.HttpShardHandlerFactory; Setting fairnessPolicy to: false [junit4:junit4] 1> INFO - 2013-04-12 21:28:47.014; org.apache.solr.clien= t.solrj.impl.HttpClientUtil; Creating new http client, config:maxConnection= sPerHost=3D20&maxConnections=3D10000&socketTimeout=3D120000&connTimeout=3D1= 5000&retry=3Dfalse [junit4:junit4] 1> INFO - 2013-04-12 21:28:47.030; org.apache.solr.core.= CoreContainer; Registering Log Listener [junit4:junit4] 1> INFO - 2013-04-12 21:28:47.043; org.apache.solr.core.= CoreContainer; Zookeeper client=3D127.0.0.1:47561/solr [junit4:junit4] 1> INFO - 2013-04-12 21:28:47.044; org.apache.solr.cloud= .ZkController; zkHost includes chroot [junit4:junit4] 1> INFO - 2013-04-12 21:28:47.045; org.apache.solr.commo= n.cloud.ConnectionManager; Waiting for client to connect to ZooKeeper [junit4:junit4] 1> INFO - 2013-04-12 21:28:47.048; org.apache.solr.commo= n.cloud.ConnectionManager; Watcher org.apache.solr.common.cloud.ConnectionM= anager@6fbb38de name:ZooKeeperConnection Watcher:127.0.0.1:47561 got event = WatchedEvent state:SyncConnected type:None path:null path:null type:None [junit4:junit4] 1> INFO - 2013-04-12 21:28:47.048; org.apache.solr.commo= n.cloud.ConnectionManager; Client is connected to ZooKeeper [junit4:junit4] 1> INFO - 2013-04-12 21:28:47.059; org.apache.solr.clien= t.solrj.impl.HttpClientUtil; Creating new http client, config:maxConnection= s=3D500&maxConnectionsPerHost=3D16&socketTimeout=3D120000&connTimeout=3D150= 00 [junit4:junit4] 1> INFO - 2013-04-12 21:28:47.069; org.apache.solr.commo= n.cloud.ConnectionManager; Waiting for client to connect to ZooKeeper [junit4:junit4] 1> INFO - 2013-04-12 21:28:47.071; org.apache.solr.commo= n.cloud.ConnectionManager; Watcher org.apache.solr.common.cloud.ConnectionM= anager@15199970 name:ZooKeeperConnection Watcher:127.0.0.1:47561/solr got e= vent WatchedEvent state:SyncConnected type:None path:null path:null type:No= ne [junit4:junit4] 1> INFO - 2013-04-12 21:28:47.071; org.apache.solr.commo= n.cloud.ConnectionManager; Client is connected to ZooKeeper [junit4:junit4] 1> INFO - 2013-04-12 21:28:47.078; org.apache.solr.commo= n.cloud.SolrZkClient; makePath: /overseer/queue [junit4:junit4] 1> INFO - 2013-04-12 21:28:47.083; org.apache.solr.commo= n.cloud.SolrZkClient; makePath: /overseer/collection-queue-work [junit4:junit4] 1> INFO - 2013-04-12 21:28:47.093; org.apache.solr.commo= n.cloud.SolrZkClient; makePath: /live_nodes [junit4:junit4] 1> INFO - 2013-04-12 21:28:47.095; org.apache.solr.cloud= .ZkController; Register node as live in ZooKeeper:/live_nodes/127.0.0.1:470= 83_ [junit4:junit4] 1> INFO - 2013-04-12 21:28:47.097; org.apache.solr.commo= n.cloud.SolrZkClient; makePath: /live_nodes/127.0.0.1:47083_ [junit4:junit4] 1> INFO - 2013-04-12 21:28:47.107; org.apache.solr.commo= n.cloud.SolrZkClient; makePath: /overseer_elect/election [junit4:junit4] 1> INFO - 2013-04-12 21:28:47.119; org.apache.solr.commo= n.cloud.SolrZkClient; makePath: /overseer_elect/leader [junit4:junit4] 1> INFO - 2013-04-12 21:28:47.128; org.apache.solr.cloud= .Overseer; Overseer (id=3D89509208162762755-127.0.0.1:47083_-n_0000000000) = starting [junit4:junit4] 1> INFO - 2013-04-12 21:28:47.138; org.apache.solr.commo= n.cloud.SolrZkClient; makePath: /overseer/queue-work [junit4:junit4] 1> INFO - 2013-04-12 21:28:47.150; org.apache.solr.cloud= .OverseerCollectionProcessor; Process current queue of collection creations [junit4:junit4] 1> INFO - 2013-04-12 21:28:47.150; org.apache.solr.commo= n.cloud.SolrZkClient; makePath: /clusterstate.json [junit4:junit4] 1> INFO - 2013-04-12 21:28:47.153; org.apache.solr.commo= n.cloud.SolrZkClient; makePath: /aliases.json [junit4:junit4] 1> INFO - 2013-04-12 21:28:47.155; org.apache.solr.commo= n.cloud.ZkStateReader; Updating cluster state from ZooKeeper...=20 [junit4:junit4] 1> INFO - 2013-04-12 21:28:47.157; org.apache.solr.cloud= .Overseer$ClusterStateUpdater; Starting to work on the main queue [junit4:junit4] 1> INFO - 2013-04-12 21:28:47.161; org.apache.solr.core.= CoreContainer; Creating SolrCore 'collection1' using instanceDir: /usr/home= /hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build/solr-= core/test/J1/./org.apache.solr.cloud.ShardSplitTest-controljetty-1365802126= 818/collection1 [junit4:junit4] 1> INFO - 2013-04-12 21:28:47.161; org.apache.solr.cloud= .ZkController; Check for collection zkNode:control_collection [junit4:junit4] 1> INFO - 2013-04-12 21:28:47.162; org.apache.solr.cloud= .ZkController; Collection zkNode exists [junit4:junit4] 1> INFO - 2013-04-12 21:28:47.162; org.apache.solr.cloud= .ZkController; Load collection config from:/collections/control_collection [junit4:junit4] 1> INFO - 2013-04-12 21:28:47.163; org.apache.solr.core.= SolrResourceLoader; new SolrResourceLoader for directory: '/usr/home/hudson= /hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build/solr-core/te= st/J1/./org.apache.solr.cloud.ShardSplitTest-controljetty-1365802126818/col= lection1/' [junit4:junit4] 1> INFO - 2013-04-12 21:28:47.165; org.apache.solr.core.= SolrResourceLoader; Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lu= cene-Solr-Tests-4.x-java7/solr/build/solr-core/test/J1/org.apache.solr.clou= d.ShardSplitTest-controljetty-1365802126818/collection1/lib/README' to clas= sloader [junit4:junit4] 1> INFO - 2013-04-12 21:28:47.165; org.apache.solr.core.= SolrResourceLoader; Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lu= cene-Solr-Tests-4.x-java7/solr/build/solr-core/test/J1/org.apache.solr.clou= d.ShardSplitTest-controljetty-1365802126818/collection1/lib/classes/' to cl= assloader [junit4:junit4] 1> INFO - 2013-04-12 21:28:47.216; org.apache.solr.core.= SolrConfig; Using Lucene MatchVersion: LUCENE_43 [junit4:junit4] 1> INFO - 2013-04-12 21:28:47.277; org.apache.solr.core.= SolrConfig; Loaded SolrConfig: solrconfig.xml [junit4:junit4] 1> INFO - 2013-04-12 21:28:47.379; org.apache.solr.schem= a.IndexSchema; Reading Solr Schema from schema.xml [junit4:junit4] 1> INFO - 2013-04-12 21:28:47.386; org.apache.solr.schem= a.IndexSchema; Schema name=3Dtest [junit4:junit4] 1> INFO - 2013-04-12 21:28:48.044; org.apache.solr.schem= a.OpenExchangeRatesOrgProvider; Initialized with rates=3Dopen-exchange-rate= s.json, refreshInterval=3D1440. [junit4:junit4] 1> INFO - 2013-04-12 21:28:48.058; org.apache.solr.schem= a.IndexSchema; default search field in schema is text [junit4:junit4] 1> INFO - 2013-04-12 21:28:48.062; org.apache.solr.schem= a.IndexSchema; unique key field: id [junit4:junit4] 1> INFO - 2013-04-12 21:28:48.082; org.apache.solr.schem= a.FileExchangeRateProvider; Reloading exchange rates from file currency.xml [junit4:junit4] 1> INFO - 2013-04-12 21:28:48.087; org.apache.solr.schem= a.FileExchangeRateProvider; Reloading exchange rates from file currency.xml [junit4:junit4] 1> INFO - 2013-04-12 21:28:48.092; org.apache.solr.schem= a.OpenExchangeRatesOrgProvider; Reloading exchange rates from open-exchange= -rates.json [junit4:junit4] 1> WARN - 2013-04-12 21:28:48.094; org.apache.solr.schem= a.OpenExchangeRatesOrgProvider$OpenExchangeRates; Unknown key IMPORTANT NOT= E [junit4:junit4] 1> WARN - 2013-04-12 21:28:48.094; org.apache.solr.schem= a.OpenExchangeRatesOrgProvider$OpenExchangeRates; Expected key, got STRING [junit4:junit4] 1> INFO - 2013-04-12 21:28:48.094; org.apache.solr.schem= a.OpenExchangeRatesOrgProvider; Reloading exchange rates from open-exchange= -rates.json [junit4:junit4] 1> WARN - 2013-04-12 21:28:48.096; org.apache.solr.schem= a.OpenExchangeRatesOrgProvider$OpenExchangeRates; Unknown key IMPORTANT NOT= E [junit4:junit4] 1> WARN - 2013-04-12 21:28:48.096; org.apache.solr.schem= a.OpenExchangeRatesOrgProvider$OpenExchangeRates; Expected key, got STRING [junit4:junit4] 1> INFO - 2013-04-12 21:28:48.096; org.apache.solr.core.= SolrCore; org.apache.solr.core.MockDirectoryFactory [junit4:junit4] 1> INFO - 2013-04-12 21:28:48.097; org.apache.solr.core.= SolrCore; [collection1] Opening new SolrCore at /usr/home/hudson/hudson-sla= ve/workspace/Lucene-Solr-Tests-4.x-java7/solr/build/solr-core/test/J1/./org= .apache.solr.cloud.ShardSplitTest-controljetty-1365802126818/collection1/, = dataDir=3D./org.apache.solr.cloud.ShardSplitTest-1365802126502/control/data= / [junit4:junit4] 1> INFO - 2013-04-12 21:28:48.097; org.apache.solr.core.= JmxMonitoredMap; JMX monitoring is enabled. Adding Solr mbeans to JMX Serve= r: com.sun.jmx.mbeanserver.JmxMBeanServer@71880832 [junit4:junit4] 1> INFO - 2013-04-12 21:28:48.098; org.apache.solr.core.= SolrCore; org.apache.solr.core.MockDirectoryFactory [junit4:junit4] 1> INFO - 2013-04-12 21:28:48.099; org.apache.solr.core.= CachingDirectoryFactory; return new directory for ./org.apache.solr.cloud.S= hardSplitTest-1365802126502/control/data [junit4:junit4] 1> INFO - 2013-04-12 21:28:48.099; org.apache.solr.core.= SolrCore; New index directory detected: old=3Dnull new=3D./org.apache.solr.= cloud.ShardSplitTest-1365802126502/control/data/index/ [junit4:junit4] 1> WARN - 2013-04-12 21:28:48.099; org.apache.solr.core.= SolrCore; [collection1] Solr index directory './org.apache.solr.cloud.Shard= SplitTest-1365802126502/control/data/index' doesn't exist. Creating new ind= ex... [junit4:junit4] 1> INFO - 2013-04-12 21:28:48.100; org.apache.solr.core.= CachingDirectoryFactory; return new directory for ./org.apache.solr.cloud.S= hardSplitTest-1365802126502/control/data/index [junit4:junit4] 1> INFO - 2013-04-12 21:28:48.104; org.apache.solr.core.= SolrDeletionPolicy; SolrDeletionPolicy.onCommit: commits:num=3D1 [junit4:junit4] 1> =09commit{dir=3DMockDirWrapper(org.apache.lucene.store= .RAMDirectory@42e5f0e7 lockFactory=3Dorg.apache.lucene.store.NativeFSLockFa= ctory@3a71db91),segFN=3Dsegments_1,generation=3D1,filenames=3D[segments_1] [junit4:junit4] 1> INFO - 2013-04-12 21:28:48.105; org.apache.solr.core.= SolrDeletionPolicy; newest commit =3D 1[segments_1] [junit4:junit4] 1> INFO - 2013-04-12 21:28:48.108; org.apache.solr.updat= e.processor.UpdateRequestProcessorChain; inserting DistributedUpdateProcess= orFactory into updateRequestProcessorChain "dedupe" [junit4:junit4] 1> INFO - 2013-04-12 21:28:48.108; org.apache.solr.updat= e.processor.UpdateRequestProcessorChain; inserting DistributedUpdateProcess= orFactory into updateRequestProcessorChain "stored_sig" [junit4:junit4] 1> INFO - 2013-04-12 21:28:48.109; org.apache.solr.updat= e.processor.UpdateRequestProcessorChain; inserting DistributedUpdateProcess= orFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit= " [junit4:junit4] 1> INFO - 2013-04-12 21:28:48.109; org.apache.solr.core.= RequestHandlers; created standard: solr.StandardRequestHandler [junit4:junit4] 1> INFO - 2013-04-12 21:28:48.110; org.apache.solr.core.= RequestHandlers; created /get: solr.RealTimeGetHandler [junit4:junit4] 1> INFO - 2013-04-12 21:28:48.110; org.apache.solr.core.= RequestHandlers; adding lazy requestHandler: solr.ReplicationHandler [junit4:junit4] 1> INFO - 2013-04-12 21:28:48.111; org.apache.solr.core.= RequestHandlers; created /replication: solr.ReplicationHandler [junit4:junit4] 1> INFO - 2013-04-12 21:28:48.111; org.apache.solr.core.= RequestHandlers; created /update: solr.UpdateRequestHandler [junit4:junit4] 1> INFO - 2013-04-12 21:28:48.112; org.apache.solr.core.= RequestHandlers; created /admin/: org.apache.solr.handler.admin.AdminHandle= rs [junit4:junit4] 1> INFO - 2013-04-12 21:28:48.125; org.apache.solr.handl= er.loader.XMLLoader; xsltCacheLifetimeSeconds=3D60 [junit4:junit4] 1> INFO - 2013-04-12 21:28:48.131; org.apache.solr.searc= h.SolrIndexSearcher; Opening Searcher@6d7e937e main [junit4:junit4] 1> INFO - 2013-04-12 21:28:48.131; org.apache.solr.updat= e.UpdateHandler; Clearing tlog files, tlogDir=3D./org.apache.solr.cloud.Sha= rdSplitTest-1365802126502/control/data/tlog [junit4:junit4] 1> INFO - 2013-04-12 21:28:48.132; org.apache.solr.updat= e.CommitTracker; Hard AutoCommit: disabled [junit4:junit4] 1> INFO - 2013-04-12 21:28:48.133; org.apache.solr.updat= e.CommitTracker; Soft AutoCommit: disabled [junit4:junit4] 1> INFO - 2013-04-12 21:28:48.136; org.apache.solr.core.= SolrCore; [collection1] Registered new searcher Searcher@6d7e937e main{Stan= dardDirectoryReader(segments_1:1)} [junit4:junit4] 1> INFO - 2013-04-12 21:28:48.139; org.apache.solr.cloud= .ZkController; publishing core=3Dcollection1 state=3Ddown [junit4:junit4] 1> INFO - 2013-04-12 21:28:48.139; org.apache.solr.cloud= .ZkController; numShards not found on descriptor - reading it from system p= roperty [junit4:junit4] 1> INFO - 2013-04-12 21:28:48.662; org.apache.solr.commo= n.cloud.ZkStateReader; Updating cloud state from ZooKeeper...=20 [junit4:junit4] 1> INFO - 2013-04-12 21:28:48.663; org.apache.solr.cloud= .Overseer$ClusterStateUpdater; Update state numShards=3D1 message=3D{ [junit4:junit4] 1> "operation":"state", [junit4:junit4] 1> "core_node_name":null, [junit4:junit4] 1> "numShards":"1", [junit4:junit4] 1> "shard":null, [junit4:junit4] 1> "roles":null, [junit4:junit4] 1> "state":"down", [junit4:junit4] 1> "shard_state":"active", [junit4:junit4] 1> "core":"collection1", [junit4:junit4] 1> "collection":"control_collection", [junit4:junit4] 1> "shard_range":null, [junit4:junit4] 1> "node_name":"127.0.0.1:47083_", [junit4:junit4] 1> "base_url":"http://127.0.0.1:47083"} [junit4:junit4] 1> INFO - 2013-04-12 21:28:48.663; org.apache.solr.cloud= .Overseer$ClusterStateUpdater; Create collection control_collection with nu= mShards 1 [junit4:junit4] 1> INFO - 2013-04-12 21:28:48.664; org.apache.solr.cloud= .Overseer$ClusterStateUpdater; Assigning new node to shard=3Dshard1 [junit4:junit4] 1> INFO - 2013-04-12 21:28:48.688; org.apache.solr.commo= n.cloud.ZkStateReader$2; A cluster state change: WatchedEvent state:SyncCon= nected type:NodeDataChanged path:/clusterstate.json, has occurred - updatin= g... (live nodes size: 1) [junit4:junit4] 1> INFO - 2013-04-12 21:28:49.142; org.apache.solr.core.= CoreContainer; registering core: collection1 [junit4:junit4] 1> INFO - 2013-04-12 21:28:49.142; org.apache.solr.cloud= .ZkController; Register replica - core:collection1 address:http://127.0.0.1= :47083 collection:control_collection shard:shard1 [junit4:junit4] 1> INFO - 2013-04-12 21:28:49.143; org.apache.solr.commo= n.cloud.SolrZkClient; makePath: /collections/control_collection/leader_elec= t/shard1/election [junit4:junit4] 1> INFO - 2013-04-12 21:28:49.170; org.apache.solr.cloud= .ShardLeaderElectionContext; Running the leader process. [junit4:junit4] 1> INFO - 2013-04-12 21:28:49.180; org.apache.solr.cloud= .ShardLeaderElectionContext; Enough replicas found to continue. [junit4:junit4] 1> INFO - 2013-04-12 21:28:49.180; org.apache.solr.cloud= .ShardLeaderElectionContext; I may be the new leader - try and sync [junit4:junit4] 1> INFO - 2013-04-12 21:28:49.180; org.apache.solr.cloud= .SyncStrategy; Sync replicas to http://127.0.0.1:47083/collection1/ [junit4:junit4] 1> INFO - 2013-04-12 21:28:49.181; org.apache.solr.cloud= .SyncStrategy; Sync Success - now sync replicas to me [junit4:junit4] 1> INFO - 2013-04-12 21:28:49.181; org.apache.solr.cloud= .SyncStrategy; http://127.0.0.1:47083/collection1/ has no replicas [junit4:junit4] 1> INFO - 2013-04-12 21:28:49.181; org.apache.solr.cloud= .ShardLeaderElectionContext; I am the new leader: http://127.0.0.1:47083/co= llection1/ [junit4:junit4] 1> INFO - 2013-04-12 21:28:49.182; org.apache.solr.commo= n.cloud.SolrZkClient; makePath: /collections/control_collection/leaders/sha= rd1 [junit4:junit4] 1> INFO - 2013-04-12 21:28:50.194; org.apache.solr.commo= n.cloud.ZkStateReader; Updating cloud state from ZooKeeper...=20 [junit4:junit4] 1> INFO - 2013-04-12 21:28:50.218; org.apache.solr.commo= n.cloud.ZkStateReader$2; A cluster state change: WatchedEvent state:SyncCon= nected type:NodeDataChanged path:/clusterstate.json, has occurred - updatin= g... (live nodes size: 1) [junit4:junit4] 1> INFO - 2013-04-12 21:28:50.260; org.apache.solr.cloud= .ZkController; We are http://127.0.0.1:47083/collection1/ and leader is htt= p://127.0.0.1:47083/collection1/ [junit4:junit4] 1> INFO - 2013-04-12 21:28:50.260; org.apache.solr.cloud= .ZkController; No LogReplay needed for core=3Dcollection1 baseURL=3Dhttp://= 127.0.0.1:47083 [junit4:junit4] 1> INFO - 2013-04-12 21:28:50.260; org.apache.solr.cloud= .ZkController; I am the leader, no recovery necessary [junit4:junit4] 1> INFO - 2013-04-12 21:28:50.261; org.apache.solr.cloud= .ZkController; publishing core=3Dcollection1 state=3Dactive [junit4:junit4] 1> INFO - 2013-04-12 21:28:50.261; org.apache.solr.cloud= .ZkController; numShards not found on descriptor - reading it from system p= roperty [junit4:junit4] 1> INFO - 2013-04-12 21:28:50.263; org.apache.solr.commo= n.cloud.ZkStateReader; Updating cloud state from ZooKeeper...=20 [junit4:junit4] 1> INFO - 2013-04-12 21:28:50.265; org.apache.solr.servl= et.SolrDispatchFilter; user.dir=3D/usr/home/hudson/hudson-slave/workspace/L= ucene-Solr-Tests-4.x-java7/solr/build/solr-core/test/J1 [junit4:junit4] 1> INFO - 2013-04-12 21:28:50.265; org.apache.solr.servl= et.SolrDispatchFilter; SolrDispatchFilter.init() done [junit4:junit4] 1> INFO - 2013-04-12 21:28:50.266; org.apache.solr.clien= t.solrj.impl.HttpClientUtil; Creating new http client, config:maxConnection= s=3D128&maxConnectionsPerHost=3D32&followRedirects=3Dfalse [junit4:junit4] 1> INFO - 2013-04-12 21:28:50.281; org.apache.solr.clien= t.solrj.impl.HttpClientUtil; Creating new http client, config: [junit4:junit4] 1> INFO - 2013-04-12 21:28:50.283; org.apache.solr.commo= n.cloud.ConnectionManager; Waiting for client to connect to ZooKeeper [junit4:junit4] 1> INFO - 2013-04-12 21:28:50.286; org.apache.solr.commo= n.cloud.ConnectionManager; Watcher org.apache.solr.common.cloud.ConnectionM= anager@26dc12bc name:ZooKeeperConnection Watcher:127.0.0.1:47561/solr got e= vent WatchedEvent state:SyncConnected type:None path:null path:null type:No= ne [junit4:junit4] 1> INFO - 2013-04-12 21:28:50.286; org.apache.solr.commo= n.cloud.ConnectionManager; Client is connected to ZooKeeper [junit4:junit4] 1> INFO - 2013-04-12 21:28:50.288; org.apache.solr.commo= n.cloud.ZkStateReader; Updating cluster state from ZooKeeper...=20 [junit4:junit4] 1> INFO - 2013-04-12 21:28:50.291; org.apache.solr.cloud= .ChaosMonkey; monkey: init - expire sessions:true cause connection loss:tru= e [junit4:junit4] 1> INFO - 2013-04-12 21:28:50.518; org.eclipse.jetty.ser= ver.Server; jetty-8.1.8.v20121106 [junit4:junit4] 1> INFO - 2013-04-12 21:28:50.521; org.eclipse.jetty.ser= ver.AbstractConnector; Started SocketConnector@127.0.0.1:29782 [junit4:junit4] 1> INFO - 2013-04-12 21:28:50.522; org.apache.solr.servl= et.SolrDispatchFilter; SolrDispatchFilter.init() [junit4:junit4] 1> INFO - 2013-04-12 21:28:50.523; org.apache.solr.core.= SolrResourceLoader; JNDI not configured for solr (NoInitialContextEx) [junit4:junit4] 1> INFO - 2013-04-12 21:28:50.523; org.apache.solr.core.= SolrResourceLoader; using system property solr.solr.home: /usr/home/hudson/= hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build/solr-core/tes= t/J1/./org.apache.solr.cloud.ShardSplitTest-jetty1-1365802130291 [junit4:junit4] 1> INFO - 2013-04-12 21:28:50.524; org.apache.solr.core.= CoreContainer$Initializer; looking for solr config file: /usr/home/hudson/h= udson-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build/solr-core/test= /J1/./org.apache.solr.cloud.ShardSplitTest-jetty1-1365802130291/solr.xml [junit4:junit4] 1> INFO - 2013-04-12 21:28:50.525; org.apache.solr.core.= CoreContainer; New CoreContainer 162607559 [junit4:junit4] 1> INFO - 2013-04-12 21:28:50.525; org.apache.solr.core.= CoreContainer; Loading CoreContainer using Solr Home: '/usr/home/hudson/hud= son-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build/solr-core/test/J= 1/./org.apache.solr.cloud.ShardSplitTest-jetty1-1365802130291/' [junit4:junit4] 1> INFO - 2013-04-12 21:28:50.526; org.apache.solr.core.= SolrResourceLoader; new SolrResourceLoader for directory: '/usr/home/hudson= /hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build/solr-core/te= st/J1/./org.apache.solr.cloud.ShardSplitTest-jetty1-1365802130291/' [junit4:junit4] 1> INFO - 2013-04-12 21:28:50.593; org.apache.solr.handl= er.component.HttpShardHandlerFactory; Setting socketTimeout to: 120000 [junit4:junit4] 1> INFO - 2013-04-12 21:28:50.594; org.apache.solr.handl= er.component.HttpShardHandlerFactory; Setting urlScheme to: http:// [junit4:junit4] 1> INFO - 2013-04-12 21:28:50.594; org.apache.solr.handl= er.component.HttpShardHandlerFactory; Setting connTimeout to: 15000 [junit4:junit4] 1> INFO - 2013-04-12 21:28:50.595; org.apache.solr.handl= er.component.HttpShardHandlerFactory; Setting maxConnectionsPerHost to: 20 [junit4:junit4] 1> INFO - 2013-04-12 21:28:50.595; org.apache.solr.handl= er.component.HttpShardHandlerFactory; Setting corePoolSize to: 0 [junit4:junit4] 1> INFO - 2013-04-12 21:28:50.596; org.apache.solr.handl= er.component.HttpShardHandlerFactory; Setting maximumPoolSize to: 214748364= 7 [junit4:junit4] 1> INFO - 2013-04-12 21:28:50.596; org.apache.solr.handl= er.component.HttpShardHandlerFactory; Setting maxThreadIdleTime to: 5 [junit4:junit4] 1> INFO - 2013-04-12 21:28:50.597; org.apache.solr.handl= er.component.HttpShardHandlerFactory; Setting sizeOfQueue to: -1 [junit4:junit4] 1> INFO - 2013-04-12 21:28:50.597; org.apache.solr.handl= er.component.HttpShardHandlerFactory; Setting fairnessPolicy to: false [junit4:junit4] 1> INFO - 2013-04-12 21:28:50.598; org.apache.solr.clien= t.solrj.impl.HttpClientUtil; Creating new http client, config:maxConnection= sPerHost=3D20&maxConnections=3D10000&socketTimeout=3D120000&connTimeout=3D1= 5000&retry=3Dfalse [junit4:junit4] 1> INFO - 2013-04-12 21:28:50.620; org.apache.solr.core.= CoreContainer; Registering Log Listener [junit4:junit4] 1> INFO - 2013-04-12 21:28:50.639; org.apache.solr.core.= CoreContainer; Zookeeper client=3D127.0.0.1:47561/solr [junit4:junit4] 1> INFO - 2013-04-12 21:28:50.640; org.apache.solr.cloud= .ZkController; zkHost includes chroot [junit4:junit4] 1> INFO - 2013-04-12 21:28:50.641; org.apache.solr.commo= n.cloud.ConnectionManager; Waiting for client to connect to ZooKeeper [junit4:junit4] 1> INFO - 2013-04-12 21:28:50.645; org.apache.solr.commo= n.cloud.ConnectionManager; Watcher org.apache.solr.common.cloud.ConnectionM= anager@1b299dea name:ZooKeeperConnection Watcher:127.0.0.1:47561 got event = WatchedEvent state:SyncConnected type:None path:null path:null type:None [junit4:junit4] 1> INFO - 2013-04-12 21:28:50.645; org.apache.solr.commo= n.cloud.ConnectionManager; Client is connected to ZooKeeper [junit4:junit4] 1> INFO - 2013-04-12 21:28:50.659; org.apache.solr.clien= t.solrj.impl.HttpClientUtil; Creating new http client, config:maxConnection= s=3D500&maxConnectionsPerHost=3D16&socketTimeout=3D120000&connTimeout=3D150= 00 [junit4:junit4] 1> INFO - 2013-04-12 21:28:50.671; org.apache.solr.commo= n.cloud.ConnectionManager; Waiting for client to connect to ZooKeeper [junit4:junit4] 1> INFO - 2013-04-12 21:28:50.674; org.apache.solr.commo= n.cloud.ConnectionManager; Watcher org.apache.solr.common.cloud.ConnectionM= anager@3a3d66f0 name:ZooKeeperConnection Watcher:127.0.0.1:47561/solr got e= vent WatchedEvent state:SyncConnected type:None path:null path:null type:No= ne [junit4:junit4] 1> INFO - 2013-04-12 21:28:50.674; org.apache.solr.commo= n.cloud.ConnectionManager; Client is connected to ZooKeeper [junit4:junit4] 1> INFO - 2013-04-12 21:28:50.685; org.apache.solr.commo= n.cloud.ZkStateReader; Updating cluster state from ZooKeeper...=20 [junit4:junit4] 1> INFO - 2013-04-12 21:28:51.689; org.apache.solr.cloud= .ZkController; Register node as live in ZooKeeper:/live_nodes/127.0.0.1:297= 82_ [junit4:junit4] 1> INFO - 2013-04-12 21:28:51.691; org.apache.solr.commo= n.cloud.SolrZkClient; makePath: /live_nodes/127.0.0.1:29782_ [junit4:junit4] 1> INFO - 2013-04-12 21:28:51.695; org.apache.solr.commo= n.cloud.ZkStateReader$3; Updating live nodes... (2) [junit4:junit4] 1> INFO - 2013-04-12 21:28:51.695; org.apache.solr.commo= n.cloud.ZkStateReader$3; Updating live nodes... (2) [junit4:junit4] 1> INFO - 2013-04-12 21:28:51.695; org.apache.solr.commo= n.cloud.ZkStateReader$2; A cluster state change: WatchedEvent state:SyncCon= nected type:NodeChildrenChanged path:/live_nodes, has occurred - updating..= . (live nodes size: 2) [junit4:junit4] 1> INFO - 2013-04-12 21:28:51.695; org.apache.solr.commo= n.cloud.ZkStateReader$3; Updating live nodes... (2) [junit4:junit4] 1> INFO - 2013-04-12 21:28:51.714; org.apache.solr.core.= CoreContainer; Creating SolrCore 'collection1' using instanceDir: /usr/home= /hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build/solr-= core/test/J1/./org.apache.solr.cloud.ShardSplitTest-jetty1-1365802130291/co= llection1 [junit4:junit4] 1> INFO - 2013-04-12 21:28:51.714; org.apache.solr.cloud= .ZkController; Check for collection zkNode:collection1 [junit4:junit4] 1> INFO - 2013-04-12 21:28:51.715; org.apache.solr.cloud= .ZkController; Collection zkNode exists [junit4:junit4] 1> INFO - 2013-04-12 21:28:51.715; org.apache.solr.cloud= .ZkController; Load collection config from:/collections/collection1 [junit4:junit4] 1> INFO - 2013-04-12 21:28:51.717; org.apache.solr.core.= SolrResourceLoader; new SolrResourceLoader for directory: '/usr/home/hudson= /hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build/solr-core/te= st/J1/./org.apache.solr.cloud.ShardSplitTest-jetty1-1365802130291/collectio= n1/' [junit4:junit4] 1> INFO - 2013-04-12 21:28:51.718; org.apache.solr.core.= SolrResourceLoader; Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lu= cene-Solr-Tests-4.x-java7/solr/build/solr-core/test/J1/org.apache.solr.clou= d.ShardSplitTest-jetty1-1365802130291/collection1/lib/README' to classloade= r [junit4:junit4] 1> INFO - 2013-04-12 21:28:51.719; org.apache.solr.core.= SolrResourceLoader; Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lu= cene-Solr-Tests-4.x-java7/solr/build/solr-core/test/J1/org.apache.solr.clou= d.ShardSplitTest-jetty1-1365802130291/collection1/lib/classes/' to classloa= der [junit4:junit4] 1> INFO - 2013-04-12 21:28:51.733; org.apache.solr.commo= n.cloud.ZkStateReader; Updating cloud state from ZooKeeper...=20 [junit4:junit4] 1> INFO - 2013-04-12 21:28:51.734; org.apache.solr.cloud= .Overseer$ClusterStateUpdater; Update state numShards=3D1 message=3D{ [junit4:junit4] 1> "operation":"state", [junit4:junit4] 1> "core_node_name":"127.0.0.1:47083__collection1", [junit4:junit4] 1> "numShards":"1", [junit4:junit4] 1> "shard":"shard1", [junit4:junit4] 1> "roles":null, [junit4:junit4] 1> "state":"active", [junit4:junit4] 1> "shard_state":"active", [junit4:junit4] 1> "core":"collection1", [junit4:junit4] 1> "collection":"control_collection", [junit4:junit4] 1> "shard_range":null, [junit4:junit4] 1> "node_name":"127.0.0.1:47083_", [junit4:junit4] 1> "base_url":"http://127.0.0.1:47083"} [junit4:junit4] 1> INFO - 2013-04-12 21:28:51.773; org.apache.solr.core.= SolrConfig; Using Lucene MatchVersion: LUCENE_43 [junit4:junit4] 1> INFO - 2013-04-12 21:28:51.834; org.apache.solr.core.= SolrConfig; Loaded SolrConfig: solrconfig.xml [junit4:junit4] 1> INFO - 2013-04-12 21:28:51.837; org.apache.solr.commo= n.cloud.ZkStateReader$2; A cluster state change: WatchedEvent state:SyncCon= nected type:NodeDataChanged path:/clusterstate.json, has occurred - updatin= g... (live nodes size: 2) [junit4:junit4] 1> INFO - 2013-04-12 21:28:51.837; org.apache.solr.commo= n.cloud.ZkStateReader$2; A cluster state change: WatchedEvent state:SyncCon= nected type:NodeDataChanged path:/clusterstate.json, has occurred - updatin= g... (live nodes size: 2) [junit4:junit4] 1> INFO - 2013-04-12 21:28:51.837; org.apache.solr.commo= n.cloud.ZkStateReader$2; A cluster state change: WatchedEvent state:SyncCon= nected type:NodeDataChanged path:/clusterstate.json, has occurred - updatin= g... (live nodes size: 2) [junit4:junit4] 1> INFO - 2013-04-12 21:28:51.837; org.apache.solr.schem= a.IndexSchema; Reading Solr Schema from schema.xml [junit4:junit4] 1> INFO - 2013-04-12 21:28:51.845; org.apache.solr.schem= a.IndexSchema; Schema name=3Dtest [junit4:junit4] 1> INFO - 2013-04-12 21:28:52.505; org.apache.solr.schem= a.OpenExchangeRatesOrgProvider; Initialized with rates=3Dopen-exchange-rate= s.json, refreshInterval=3D1440. [junit4:junit4] 1> INFO - 2013-04-12 21:28:52.518; org.apache.solr.schem= a.IndexSchema; default search field in schema is text [junit4:junit4] 1> INFO - 2013-04-12 21:28:52.522; org.apache.solr.schem= a.IndexSchema; unique key field: id [junit4:junit4] 1> INFO - 2013-04-12 21:28:52.541; org.apache.solr.schem= a.FileExchangeRateProvider; Reloading exchange rates from file currency.xml [junit4:junit4] 1> INFO - 2013-04-12 21:28:52.557; org.apache.solr.schem= a.FileExchangeRateProvider; Reloading exchange rates from file currency.xml [junit4:junit4] 1> INFO - 2013-04-12 21:28:52.562; org.apache.solr.schem= a.OpenExchangeRatesOrgProvider; Reloading exchange rates from open-exchange= -rates.json [junit4:junit4] 1> WARN - 2013-04-12 21:28:52.564; org.apache.solr.schem= a.OpenExchangeRatesOrgProvider$OpenExchangeRates; Unknown key IMPORTANT NOT= E [junit4:junit4] 1> WARN - 2013-04-12 21:28:52.564; org.apache.solr.schem= a.OpenExchangeRatesOrgProvider$OpenExchangeRates; Expected key, got STRING [junit4:junit4] 1> INFO - 2013-04-12 21:28:52.565; org.apache.solr.schem= a.OpenExchangeRatesOrgProvider; Reloading exchange rates from open-exchange= -rates.json [junit4:junit4] 1> WARN - 2013-04-12 21:28:52.566; org.apache.solr.schem= a.OpenExchangeRatesOrgProvider$OpenExchangeRates; Unknown key IMPORTANT NOT= E [junit4:junit4] 1> WARN - 2013-04-12 21:28:52.566; org.apache.solr.schem= a.OpenExchangeRatesOrgProvider$OpenExchangeRates; Expected key, got STRING [junit4:junit4] 1> INFO - 2013-04-12 21:28:52.567; org.apache.solr.core.= SolrCore; org.apache.solr.core.MockDirectoryFactory [junit4:junit4] 1> INFO - 2013-04-12 21:28:52.567; org.apache.solr.core.= SolrCore; [collection1] Opening new SolrCore at /usr/home/hudson/hudson-sla= ve/workspace/Lucene-Solr-Tests-4.x-java7/solr/build/solr-core/test/J1/./org= .apache.solr.cloud.ShardSplitTest-jetty1-1365802130291/collection1/, dataDi= r=3D./org.apache.solr.cloud.ShardSplitTest-1365802126502/jetty1/ [junit4:junit4] 1> INFO - 2013-04-12 21:28:52.567; org.apache.solr.core.= JmxMonitoredMap; JMX monitoring is enabled. Adding Solr mbeans to JMX Serve= r: com.sun.jmx.mbeanserver.JmxMBeanServer@71880832 [junit4:junit4] 1> INFO - 2013-04-12 21:28:52.568; org.apache.solr.core.= SolrCore; org.apache.solr.core.MockDirectoryFactory [junit4:junit4] 1> INFO - 2013-04-12 21:28:52.569; org.apache.solr.core.= CachingDirectoryFactory; return new directory for ./org.apache.solr.cloud.S= hardSplitTest-1365802126502/jetty1 [junit4:junit4] 1> INFO - 2013-04-12 21:28:52.569; org.apache.solr.core.= SolrCore; New index directory detected: old=3Dnull new=3D./org.apache.solr.= cloud.ShardSplitTest-1365802126502/jetty1/index/ [junit4:junit4] 1> WARN - 2013-04-12 21:28:52.570; org.apache.solr.core.= SolrCore; [collection1] Solr index directory './org.apache.solr.cloud.Shard= SplitTest-1365802126502/jetty1/index' doesn't exist. Creating new index... [junit4:junit4] 1> INFO - 2013-04-12 21:28:52.570; org.apache.solr.core.= CachingDirectoryFactory; return new directory for ./org.apache.solr.cloud.S= hardSplitTest-1365802126502/jetty1/index [junit4:junit4] 1> INFO - 2013-04-12 21:28:52.574; org.apache.solr.core.= SolrDeletionPolicy; SolrDeletionPolicy.onCommit: commits:num=3D1 [junit4:junit4] 1> =09commit{dir=3DMockDirWrapper(org.apache.lucene.store= .RAMDirectory@471c053d lockFactory=3Dorg.apache.lucene.store.NativeFSLockFa= ctory@6e9b7ab8),segFN=3Dsegments_1,generation=3D1,filenames=3D[segments_1] [junit4:junit4] 1> INFO - 2013-04-12 21:28:52.574; org.apache.solr.core.= SolrDeletionPolicy; newest commit =3D 1[segments_1] [junit4:junit4] 1> INFO - 2013-04-12 21:28:52.577; org.apache.solr.updat= e.processor.UpdateRequestProcessorChain; inserting DistributedUpdateProcess= orFactory into updateRequestProcessorChain "dedupe" [junit4:junit4] 1> INFO - 2013-04-12 21:28:52.578; org.apache.solr.updat= e.processor.UpdateRequestProcessorChain; inserting DistributedUpdateProcess= orFactory into updateRequestProcessorChain "stored_sig" [junit4:junit4] 1> INFO - 2013-04-12 21:28:52.578; org.apache.solr.updat= e.processor.UpdateRequestProcessorChain; inserting DistributedUpdateProcess= orFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit= " [junit4:junit4] 1> INFO - 2013-04-12 21:28:52.579; org.apache.solr.core.= RequestHandlers; created standard: solr.StandardRequestHandler [junit4:junit4] 1> INFO - 2013-04-12 21:28:52.580; org.apache.solr.core.= RequestHandlers; created /get: solr.RealTimeGetHandler [junit4:junit4] 1> INFO - 2013-04-12 21:28:52.580; org.apache.solr.core.= RequestHandlers; adding lazy requestHandler: solr.ReplicationHandler [junit4:junit4] 1> INFO - 2013-04-12 21:28:52.581; org.apache.solr.core.= RequestHandlers; created /replication: solr.ReplicationHandler [junit4:junit4] 1> INFO - 2013-04-12 21:28:52.581; org.apache.solr.core.= RequestHandlers; created /update: solr.UpdateRequestHandler [junit4:junit4] 1> INFO - 2013-04-12 21:28:52.582; org.apache.solr.core.= RequestHandlers; created /admin/: org.apache.solr.handler.admin.AdminHandle= rs [junit4:junit4] 1> INFO - 2013-04-12 21:28:52.595; org.apache.solr.handl= er.loader.XMLLoader; xsltCacheLifetimeSeconds=3D60 [junit4:junit4] 1> INFO - 2013-04-12 21:28:52.601; org.apache.solr.searc= h.SolrIndexSearcher; Opening Searcher@2746e92a main [junit4:junit4] 1> INFO - 2013-04-12 21:28:52.602; org.apache.solr.updat= e.UpdateHandler; Clearing tlog files, tlogDir=3D./org.apache.solr.cloud.Sha= rdSplitTest-1365802126502/jetty1/tlog [junit4:junit4] 1> INFO - 2013-04-12 21:28:52.603; org.apache.solr.updat= e.CommitTracker; Hard AutoCommit: disabled [junit4:junit4] 1> INFO - 2013-04-12 21:28:52.603; org.apache.solr.updat= e.CommitTracker; Soft AutoCommit: disabled [junit4:junit4] 1> INFO - 2013-04-12 21:28:52.608; org.apache.solr.core.= SolrCore; [collection1] Registered new searcher Searcher@2746e92a main{Stan= dardDirectoryReader(segments_1:1)} [junit4:junit4] 1> INFO - 2013-04-12 21:28:52.611; org.apache.solr.cloud= .ZkController; publishing core=3Dcollection1 state=3Ddown [junit4:junit4] 1> INFO - 2013-04-12 21:28:52.611; org.apache.solr.cloud= .ZkController; numShards not found on descriptor - reading it from system p= roperty [junit4:junit4] 1> INFO - 2013-04-12 21:28:53.342; org.apache.solr.commo= n.cloud.ZkStateReader; Updating cloud state from ZooKeeper...=20 [junit4:junit4] 1> INFO - 2013-04-12 21:28:53.343; org.apache.solr.cloud= .Overseer$ClusterStateUpdater; Update state numShards=3D2 message=3D{ [junit4:junit4] 1> "operation":"state", [junit4:junit4] 1> "core_node_name":null, [junit4:junit4] 1> "numShards":"2", [junit4:junit4] 1> "shard":null, [junit4:junit4] 1> "roles":null, [junit4:junit4] 1> "state":"down", [junit4:junit4] 1> "shard_state":"active", [junit4:junit4] 1> "core":"collection1", [junit4:junit4] 1> "collection":"collection1", [junit4:junit4] 1> "shard_range":null, [junit4:junit4] 1> "node_name":"127.0.0.1:29782_", [junit4:junit4] 1> "base_url":"http://127.0.0.1:29782"} [junit4:junit4] 1> INFO - 2013-04-12 21:28:53.343; org.apache.solr.cloud= .Overseer$ClusterStateUpdater; Create collection collection1 with numShards= 2 [junit4:junit4] 1> INFO - 2013-04-12 21:28:53.344; org.apache.solr.cloud= .Overseer$ClusterStateUpdater; Assigning new node to shard=3Dshard1 [junit4:junit4] 1> INFO - 2013-04-12 21:28:53.349; org.apache.solr.commo= n.cloud.ZkStateReader$2; A cluster state change: WatchedEvent state:SyncCon= nected type:NodeDataChanged path:/clusterstate.json, has occurred - updatin= g... (live nodes size: 2) [junit4:junit4] 1> INFO - 2013-04-12 21:28:53.349; org.apache.solr.commo= n.cloud.ZkStateReader$2; A cluster state change: WatchedEvent state:SyncCon= nected type:NodeDataChanged path:/clusterstate.json, has occurred - updatin= g... (live nodes size: 2) [junit4:junit4] 1> INFO - 2013-04-12 21:28:53.349; org.apache.solr.commo= n.cloud.ZkStateReader$2; A cluster state change: WatchedEvent state:SyncCon= nected type:NodeDataChanged path:/clusterstate.json, has occurred - updatin= g... (live nodes size: 2) [junit4:junit4] 1> INFO - 2013-04-12 21:28:53.614; org.apache.solr.core.= CoreContainer; registering core: collection1 [junit4:junit4] 1> INFO - 2013-04-12 21:28:53.614; org.apache.solr.cloud= .ZkController; Register replica - core:collection1 address:http://127.0.0.1= :29782 collection:collection1 shard:shard1 [junit4:junit4] 1> INFO - 2013-04-12 21:28:53.615; org.apache.solr.commo= n.cloud.SolrZkClient; makePath: /collections/collection1/leader_elect/shard= 1/election [junit4:junit4] 1> INFO - 2013-04-12 21:28:53.641; org.apache.solr.cloud= .ShardLeaderElectionContext; Running the leader process. [junit4:junit4] 1> INFO - 2013-04-12 21:28:53.654; org.apache.solr.cloud= .ShardLeaderElectionContext; Enough replicas found to continue. [junit4:junit4] 1> INFO - 2013-04-12 21:28:53.655; org.apache.solr.cloud= .ShardLeaderElectionContext; I may be the new leader - try and sync [junit4:junit4] 1> INFO - 2013-04-12 21:28:53.655; org.apache.solr.cloud= .SyncStrategy; Sync replicas to http://127.0.0.1:29782/collection1/ [junit4:junit4] 1> INFO - 2013-04-12 21:28:53.655; org.apache.solr.cloud= .SyncStrategy; Sync Success - now sync replicas to me [junit4:junit4] 1> INFO - 2013-04-12 21:28:53.656; org.apache.solr.cloud= .SyncStrategy; http://127.0.0.1:29782/collection1/ has no replicas [junit4:junit4] 1> INFO - 2013-04-12 21:28:53.656; org.apache.solr.cloud= .ShardLeaderElectionContext; I am the new leader: http://127.0.0.1:29782/co= llection1/ [junit4:junit4] 1> INFO - 2013-04-12 21:28:53.656; org.apache.solr.commo= n.cloud.SolrZkClient; makePath: /collections/collection1/leaders/shard1 [junit4:junit4] 1> INFO - 2013-04-12 21:28:54.911; org.apache.solr.commo= n.cloud.ZkStateReader; Updating cloud state from ZooKeeper...=20 [junit4:junit4] 1> INFO - 2013-04-12 21:28:54.938; org.apache.solr.commo= n.cloud.ZkStateReader$2; A cluster state change: WatchedEvent state:SyncCon= nected type:NodeDataChanged path:/clusterstate.json, has occurred - updatin= g... (live nodes size: 2) [junit4:junit4] 1> INFO - 2013-04-12 21:28:54.938; org.apache.solr.commo= n.cloud.ZkStateReader$2; A cluster state change: WatchedEvent state:SyncCon= nected type:NodeDataChanged path:/clusterstate.json, has occurred - updatin= g... (live nodes size: 2) [junit4:junit4] 1> INFO - 2013-04-12 21:28:54.938; org.apache.solr.commo= n.cloud.ZkStateReader$2; A cluster state change: WatchedEvent state:SyncCon= nected type:NodeDataChanged path:/clusterstate.json, has occurred - updatin= g... (live nodes size: 2) [junit4:junit4] 1> INFO - 2013-04-12 21:28:54.946; org.apache.solr.cloud= .ZkController; We are http://127.0.0.1:29782/collection1/ and leader is htt= p://127.0.0.1:29782/collection1/ [junit4:junit4] 1> INFO - 2013-04-12 21:28:54.946; org.apache.solr.cloud= .ZkController; No LogReplay needed for core=3Dcollection1 baseURL=3Dhttp://= 127.0.0.1:29782 [junit4:junit4] 1> INFO - 2013-04-12 21:28:54.946; org.apache.solr.cloud= .ZkController; I am the leader, no recovery necessary [junit4:junit4] 1> INFO - 2013-04-12 21:28:54.947; org.apache.solr.cloud= .ZkController; publishing core=3Dcollection1 state=3Dactive [junit4:junit4] 1> INFO - 2013-04-12 21:28:54.947; org.apache.solr.cloud= .ZkController; numShards not found on descriptor - reading it from system p= roperty [junit4:junit4] 1> INFO - 2013-04-12 21:28:54.949; org.apache.solr.commo= n.cloud.ZkStateReader; Updating cloud state from ZooKeeper...=20 [junit4:junit4] 1> INFO - 2013-04-12 21:28:54.950; org.apache.solr.servl= et.SolrDispatchFilter; user.dir=3D/usr/home/hudson/hudson-slave/workspace/L= ucene-Solr-Tests-4.x-java7/solr/build/solr-core/test/J1 [junit4:junit4] 1> INFO - 2013-04-12 21:28:54.951; org.apache.solr.servl= et.SolrDispatchFilter; SolrDispatchFilter.init() done [junit4:junit4] 1> INFO - 2013-04-12 21:28:54.951; org.apache.solr.clien= t.solrj.impl.HttpClientUtil; Creating new http client, config:maxConnection= s=3D128&maxConnectionsPerHost=3D32&followRedirects=3Dfalse [junit4:junit4] 1> INFO - 2013-04-12 21:28:55.180; org.eclipse.jetty.ser= ver.Server; jetty-8.1.8.v20121106 [junit4:junit4] 1> INFO - 2013-04-12 21:28:55.184; org.eclipse.jetty.ser= ver.AbstractConnector; Started SocketConnector@127.0.0.1:36990 [junit4:junit4] 1> INFO - 2013-04-12 21:28:55.185; org.apache.solr.servl= et.SolrDispatchFilter; SolrDispatchFilter.init() [junit4:junit4] 1> INFO - 2013-04-12 21:28:55.185; org.apache.solr.core.= SolrResourceLoader; JNDI not configured for solr (NoInitialContextEx) [junit4:junit4] 1> INFO - 2013-04-12 21:28:55.186; org.apache.solr.core.= SolrResourceLoader; using system property solr.solr.home: /usr/home/hudson/= hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build/solr-core/tes= t/J1/./org.apache.solr.cloud.ShardSplitTest-jetty2-1365802134968 [junit4:junit4] 1> INFO - 2013-04-12 21:28:55.186; org.apache.solr.core.= CoreContainer$Initializer; looking for solr config file: /usr/home/hudson/h= udson-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build/solr-core/test= /J1/./org.apache.solr.cloud.ShardSplitTest-jetty2-1365802134968/solr.xml [junit4:junit4] 1> INFO - 2013-04-12 21:28:55.187; org.apache.solr.core.= CoreContainer; New CoreContainer 620333778 [junit4:junit4] 1> INFO - 2013-04-12 21:28:55.188; org.apache.solr.core.= CoreContainer; Loading CoreContainer using Solr Home: '/usr/home/hudson/hud= son-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build/solr-core/test/J= 1/./org.apache.solr.cloud.ShardSplitTest-jetty2-1365802134968/' [junit4:junit4] 1> INFO - 2013-04-12 21:28:55.188; org.apache.solr.core.= SolrResourceLoader; new SolrResourceLoader for directory: '/usr/home/hudson= /hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build/solr-core/te= st/J1/./org.apache.solr.cloud.ShardSplitTest-jetty2-1365802134968/' [junit4:junit4] 1> INFO - 2013-04-12 21:28:55.256; org.apache.solr.handl= er.component.HttpShardHandlerFactory; Setting socketTimeout to: 120000 [junit4:junit4] 1> INFO - 2013-04-12 21:28:55.257; org.apache.solr.handl= er.component.HttpShardHandlerFactory; Setting urlScheme to: http:// [junit4:junit4] 1> INFO - 2013-04-12 21:28:55.257; org.apache.solr.handl= er.component.HttpShardHandlerFactory; Setting connTimeout to: 15000 [junit4:junit4] 1> INFO - 2013-04-12 21:28:55.258; org.apache.solr.handl= er.component.HttpShardHandlerFactory; Setting maxConnectionsPerHost to: 20 [junit4:junit4] 1> INFO - 2013-04-12 21:28:55.258; org.apache.solr.handl= er.component.HttpShardHandlerFactory; Setting corePoolSize to: 0 [junit4:junit4] 1> INFO - 2013-04-12 21:28:55.259; org.apache.solr.handl= er.component.HttpShardHandlerFactory; Setting maximumPoolSize to: 214748364= 7 [junit4:junit4] 1> INFO - 2013-04-12 21:28:55.259; org.apache.solr.handl= er.component.HttpShardHandlerFactory; Setting maxThreadIdleTime to: 5 [junit4:junit4] 1> INFO - 2013-04-12 21:28:55.260; org.apache.solr.handl= er.component.HttpShardHandlerFactory; Setting sizeOfQueue to: -1 [junit4:junit4] 1> INFO - 2013-04-12 21:28:55.260; org.apache.solr.handl= er.component.HttpShardHandlerFactory; Setting fairnessPolicy to: false [junit4:junit4] 1> INFO - 2013-04-12 21:28:55.261; org.apache.solr.clien= t.solrj.impl.HttpClientUtil; Creating new http client, config:maxConnection= sPerHost=3D20&maxConnections=3D10000&socketTimeout=3D120000&connTimeout=3D1= 5000&retry=3Dfalse [junit4:junit4] 1> INFO - 2013-04-12 21:28:55.283; org.apache.solr.core.= CoreContainer; Registering Log Listener [junit4:junit4] 1> INFO - 2013-04-12 21:28:55.303; org.apache.solr.core.= CoreContainer; Zookeeper client=3D127.0.0.1:47561/solr [junit4:junit4] 1> INFO - 2013-04-12 21:28:55.304; org.apache.solr.cloud= .ZkController; zkHost includes chroot [junit4:junit4] 1> INFO - 2013-04-12 21:28:55.305; org.apache.solr.commo= n.cloud.ConnectionManager; Waiting for client to connect to ZooKeeper [junit4:junit4] 1> INFO - 2013-04-12 21:28:55.309; org.apache.solr.commo= n.cloud.ConnectionManager; Watcher org.apache.solr.common.cloud.ConnectionM= anager@7b56d21b name:ZooKeeperConnection Watcher:127.0.0.1:47561 got event = WatchedEvent state:SyncConnected type:None path:null path:null type:None [junit4:junit4] 1> INFO - 2013-04-12 21:28:55.309; org.apache.solr.commo= n.cloud.ConnectionManager; Client is connected to ZooKeeper [junit4:junit4] 1> INFO - 2013-04-12 21:28:55.323; org.apache.solr.clien= t.solrj.impl.HttpClientUtil; Creating new http client, config:maxConnection= s=3D500&maxConnectionsPerHost=3D16&socketTimeout=3D120000&connTimeout=3D150= 00 [junit4:junit4] 1> INFO - 2013-04-12 21:28:55.337; org.apache.solr.commo= n.cloud.ConnectionManager; Waiting for client to connect to ZooKeeper [junit4:junit4] 1> INFO - 2013-04-12 21:28:55.340; org.apache.solr.commo= n.cloud.ConnectionManager; Watcher org.apache.solr.common.cloud.ConnectionM= anager@6e2c42c7 name:ZooKeeperConnection Watcher:127.0.0.1:47561/solr got e= vent WatchedEvent state:SyncConnected type:None path:null path:null type:No= ne [junit4:junit4] 1> INFO - 2013-04-12 21:28:55.340; org.apache.solr.commo= n.cloud.ConnectionManager; Client is connected to ZooKeeper [junit4:junit4] 1> INFO - 2013-04-12 21:28:55.350; org.apache.solr.commo= n.cloud.ZkStateReader; Updating cluster state from ZooKeeper...=20 [junit4:junit4] 1> INFO - 2013-04-12 21:28:56.354; org.apache.solr.cloud= .ZkController; Register node as live in ZooKeeper:/live_nodes/127.0.0.1:369= 90_ [junit4:junit4] 1> INFO - 2013-04-12 21:28:56.360; org.apache.solr.commo= n.cloud.SolrZkClient; makePath: /live_nodes/127.0.0.1:36990_ [junit4:junit4] 1> INFO - 2013-04-12 21:28:56.364; org.apache.solr.commo= n.cloud.ZkStateReader$3; Updating live nodes... (3) [junit4:junit4] 1> INFO - 2013-04-12 21:28:56.364; org.apache.solr.commo= n.cloud.ZkStateReader$3; Updating live nodes... (3) [junit4:junit4] 1> INFO - 2013-04-12 21:28:56.364; org.apache.solr.commo= n.cloud.ZkStateReader$3; Updating live nodes... (3) [junit4:junit4] 1> INFO - 2013-04-12 21:28:56.364; org.apache.solr.commo= n.cloud.ZkStateReader$3; Updating live nodes... (3) [junit4:junit4] 1> INFO - 2013-04-12 21:28:56.365; org.apache.solr.commo= n.cloud.ZkStateReader$2; A cluster state change: WatchedEvent state:SyncCon= nected type:NodeChildrenChanged path:/live_nodes, has occurred - updating..= . (live nodes size: 3) [junit4:junit4] 1> INFO - 2013-04-12 21:28:56.365; org.apache.solr.commo= n.cloud.ZkStateReader$2; A cluster state change: WatchedEvent state:SyncCon= nected type:NodeChildrenChanged path:/live_nodes, has occurred - updating..= . (live nodes size: 3) [junit4:junit4] 1> INFO - 2013-04-12 21:28:56.364; org.apache.solr.commo= n.cloud.ZkStateReader$2; A cluster state change: WatchedEvent state:SyncCon= nected type:NodeChildrenChanged path:/live_nodes, has occurred - updating..= . (live nodes size: 3) [junit4:junit4] 1> INFO - 2013-04-12 21:28:56.372; org.apache.solr.core.= CoreContainer; Creating SolrCore 'collection1' using instanceDir: /usr/home= /hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build/solr-= core/test/J1/./org.apache.solr.cloud.ShardSplitTest-jetty2-1365802134968/co= llection1 [junit4:junit4] 1> INFO - 2013-04-12 21:28:56.373; org.apache.solr.cloud= .ZkController; Check for collection zkNode:collection1 [junit4:junit4] 1> INFO - 2013-04-12 21:28:56.373; org.apache.solr.cloud= .ZkController; Collection zkNode exists [junit4:junit4] 1> INFO - 2013-04-12 21:28:56.374; org.apache.solr.cloud= .ZkController; Load collection config from:/collections/collection1 [junit4:junit4] 1> INFO - 2013-04-12 21:28:56.375; org.apache.solr.core.= SolrResourceLoader; new SolrResourceLoader for directory: '/usr/home/hudson= /hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build/solr-core/te= st/J1/./org.apache.solr.cloud.ShardSplitTest-jetty2-1365802134968/collectio= n1/' [junit4:junit4] 1> INFO - 2013-04-12 21:28:56.377; org.apache.solr.core.= SolrResourceLoader; Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lu= cene-Solr-Tests-4.x-java7/solr/build/solr-core/test/J1/org.apache.solr.clou= d.ShardSplitTest-jetty2-1365802134968/collection1/lib/classes/' to classloa= der [junit4:junit4] 1> INFO - 2013-04-12 21:28:56.377; org.apache.solr.core.= SolrResourceLoader; Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lu= cene-Solr-Tests-4.x-java7/solr/build/solr-core/test/J1/org.apache.solr.clou= d.ShardSplitTest-jetty2-1365802134968/collection1/lib/README' to classloade= r [junit4:junit4] 1> INFO - 2013-04-12 21:28:56.428; org.apache.solr.core.= SolrConfig; Using Lucene MatchVersion: LUCENE_43 [junit4:junit4] 1> INFO - 2013-04-12 21:28:56.446; org.apache.solr.commo= n.cloud.ZkStateReader; Updating cloud state from ZooKeeper...=20 [junit4:junit4] 1> INFO - 2013-04-12 21:28:56.447; org.apache.solr.cloud= .Overseer$ClusterStateUpdater; Update state numShards=3D2 message=3D{ [junit4:junit4] 1> "operation":"state", [junit4:junit4] 1> "core_node_name":"127.0.0.1:29782__collection1", [junit4:junit4] 1> "numShards":"2", [junit4:junit4] 1> "shard":"shard1", [junit4:junit4] 1> "roles":null, [junit4:junit4] 1> "state":"active", [junit4:junit4] 1> "shard_state":"active", [junit4:junit4] 1> "core":"collection1", [junit4:junit4] 1> "collection":"collection1", [junit4:junit4] 1> "shard_range":null, [junit4:junit4] 1> "node_name":"127.0.0.1:29782_", [junit4:junit4] 1> "base_url":"http://127.0.0.1:29782"} [junit4:junit4] 1> INFO - 2013-04-12 21:28:56.460; org.apache.solr.commo= n.cloud.ZkStateReader$2; A cluster state change: WatchedEvent state:SyncCon= nected type:NodeDataChanged path:/clusterstate.json, has occurred - updatin= g... (live nodes size: 3) [junit4:junit4] 1> INFO - 2013-04-12 21:28:56.460; org.apache.solr.commo= n.cloud.ZkStateReader$2; A cluster state change: WatchedEvent state:SyncCon= nected type:NodeDataChanged path:/clusterstate.json, has occurred - updatin= g... (live nodes size: 3) [junit4:junit4] 1> INFO - 2013-04-12 21:28:56.460; org.apache.solr.commo= n.cloud.ZkStateReader$2; A cluster state change: WatchedEvent state:SyncCon= nected type:NodeDataChanged path:/clusterstate.json, has occurred - updatin= g... (live nodes size: 3) [junit4:junit4] 1> INFO - 2013-04-12 21:28:56.460; org.apache.solr.commo= n.cloud.ZkStateReader$2; A cluster state change: WatchedEvent state:SyncCon= nected type:NodeDataChanged path:/clusterstate.json, has occurred - updatin= g... (live nodes size: 3) [junit4:junit4] 1> INFO - 2013-04-12 21:28:56.491; org.apache.solr.core.= SolrConfig; Loaded SolrConfig: solrconfig.xml [junit4:junit4] 1> INFO - 2013-04-12 21:28:56.593; org.apache.solr.schem= a.IndexSchema; Reading Solr Schema from schema.xml [junit4:junit4] 1> INFO - 2013-04-12 21:28:56.600; org.apache.solr.schem= a.IndexSchema; Schema name=3Dtest [junit4:junit4] 1> INFO - 2013-04-12 21:28:57.273; org.apache.solr.schem= a.OpenExchangeRatesOrgProvider; Initialized with rates=3Dopen-exchange-rate= s.json, refreshInterval=3D1440. [junit4:junit4] 1> INFO - 2013-04-12 21:28:57.285; org.apache.solr.schem= a.IndexSchema; default search field in schema is text [junit4:junit4] 1> INFO - 2013-04-12 21:28:57.289; org.apache.solr.schem= a.IndexSchema; unique key field: id [junit4:junit4] 1> INFO - 2013-04-12 21:28:57.308; org.apache.solr.schem= a.FileExchangeRateProvider; Reloading exchange rates from file currency.xml [junit4:junit4] 1> INFO - 2013-04-12 21:28:57.313; org.apache.solr.schem= a.FileExchangeRateProvider; Reloading exchange rates from file currency.xml [junit4:junit4] 1> INFO - 2013-04-12 21:28:57.317; org.apache.solr.schem= a.OpenExchangeRatesOrgProvider; Reloading exchange rates from open-exchange= -rates.json [junit4:junit4] 1> WARN - 2013-04-12 21:28:57.319; org.apache.solr.schem= a.OpenExchangeRatesOrgProvider$OpenExchangeRates; Unknown key IMPORTANT NOT= E [junit4:junit4] 1> WARN - 2013-04-12 21:28:57.319; org.apache.solr.schem= a.OpenExchangeRatesOrgProvider$OpenExchangeRates; Expected key, got STRING [junit4:junit4] 1> INFO - 2013-04-12 21:28:57.320; org.apache.solr.schem= a.OpenExchangeRatesOrgProvider; Reloading exchange rates from open-exchange= -rates.json [junit4:junit4] 1> WARN - 2013-04-12 21:28:57.321; org.apache.solr.schem= a.OpenExchangeRatesOrgProvider$OpenExchangeRates; Unknown key IMPORTANT NOT= E [junit4:junit4] 1> WARN - 2013-04-12 21:28:57.321; org.apache.solr.schem= a.OpenExchangeRatesOrgProvider$OpenExchangeRates; Expected key, got STRING [junit4:junit4] 1> INFO - 2013-04-12 21:28:57.322; org.apache.solr.core.= SolrCore; org.apache.solr.core.MockDirectoryFactory [junit4:junit4] 1> INFO - 2013-04-12 21:28:57.322; org.apache.solr.core.= SolrCore; [collection1] Opening new SolrCore at /usr/home/hudson/hudson-sla= ve/workspace/Lucene-Solr-Tests-4.x-java7/solr/build/solr-core/test/J1/./org= .apache.solr.cloud.ShardSplitTest-jetty2-1365802134968/collection1/, dataDi= r=3D./org.apache.solr.cloud.ShardSplitTest-1365802126502/jetty2/ [junit4:junit4] 1> INFO - 2013-04-12 21:28:57.322; org.apache.solr.core.= JmxMonitoredMap; JMX monitoring is enabled. Adding Solr mbeans to JMX Serve= r: com.sun.jmx.mbeanserver.JmxMBeanServer@71880832 [junit4:junit4] 1> INFO - 2013-04-12 21:28:57.323; org.apache.solr.core.= SolrCore; org.apache.solr.core.MockDirectoryFactory [junit4:junit4] 1> INFO - 2013-04-12 21:28:57.324; org.apache.solr.core.= CachingDirectoryFactory; return new directory for ./org.apache.solr.cloud.S= hardSplitTest-1365802126502/jetty2 [junit4:junit4] 1> INFO - 2013-04-12 21:28:57.324; org.apache.solr.core.= SolrCore; New index directory detected: old=3Dnull new=3D./org.apache.solr.= cloud.ShardSplitTest-1365802126502/jetty2/index/ [junit4:junit4] 1> WARN - 2013-04-12 21:28:57.324; org.apache.solr.core.= SolrCore; [collection1] Solr index directory './org.apache.solr.cloud.Shard= SplitTest-1365802126502/jetty2/index' doesn't exist. Creating new index... [junit4:junit4] 1> INFO - 2013-04-12 21:28:57.325; org.apache.solr.core.= CachingDirectoryFactory; return new directory for ./org.apache.solr.cloud.S= hardSplitTest-1365802126502/jetty2/index [junit4:junit4] 1> INFO - 2013-04-12 21:28:57.328; org.apache.solr.core.= SolrDeletionPolicy; SolrDeletionPolicy.onCommit: commits:num=3D1 [junit4:junit4] 1> =09commit{dir=3DMockDirWrapper(org.apache.lucene.store= .RAMDirectory@3bf9e38f lockFactory=3Dorg.apache.lucene.store.NativeFSLockFa= ctory@34407323),segFN=3Dsegments_1,generation=3D1,filenames=3D[segments_1] [junit4:junit4] 1> INFO - 2013-04-12 21:28:57.328; org.apache.solr.core.= SolrDeletionPolicy; newest commit =3D 1[segments_1] [junit4:junit4] 1> INFO - 2013-04-12 21:28:57.331; org.apache.solr.updat= e.processor.UpdateRequestProcessorChain; inserting DistributedUpdateProcess= orFactory into updateRequestProcessorChain "dedupe" [junit4:junit4] 1> INFO - 2013-04-12 21:28:57.332; org.apache.solr.updat= e.processor.UpdateRequestProcessorChain; inserting DistributedUpdateProcess= orFactory into updateRequestProcessorChain "stored_sig" [junit4:junit4] 1> INFO - 2013-04-12 21:28:57.332; org.apache.solr.updat= e.processor.UpdateRequestProcessorChain; inserting DistributedUpdateProcess= orFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit= " [junit4:junit4] 1> INFO - 2013-04-12 21:28:57.333; org.apache.solr.core.= RequestHandlers; created standard: solr.StandardRequestHandler [junit4:junit4] 1> INFO - 2013-04-12 21:28:57.334; org.apache.solr.core.= RequestHandlers; created /get: solr.RealTimeGetHandler [junit4:junit4] 1> INFO - 2013-04-12 21:28:57.334; org.apache.solr.core.= RequestHandlers; adding lazy requestHandler: solr.ReplicationHandler [junit4:junit4] 1> INFO - 2013-04-12 21:28:57.334; org.apache.solr.core.= RequestHandlers; created /replication: solr.ReplicationHandler [junit4:junit4] 1> INFO - 2013-04-12 21:28:57.335; org.apache.solr.core.= RequestHandlers; created /update: solr.UpdateRequestHandler [junit4:junit4] 1> INFO - 2013-04-12 21:28:57.336; org.apache.solr.core.= RequestHandlers; created /admin/: org.apache.solr.handler.admin.AdminHandle= rs [junit4:junit4] 1> INFO - 2013-04-12 21:28:57.348; org.apache.solr.handl= er.loader.XMLLoader; xsltCacheLifetimeSeconds=3D60 [junit4:junit4] 1> INFO - 2013-04-12 21:28:57.353; org.apache.solr.searc= h.SolrIndexSearcher; Opening Searcher@2536bbb9 main [junit4:junit4] 1> INFO - 2013-04-12 21:28:57.354; org.apache.solr.updat= e.UpdateHandler; Clearing tlog files, tlogDir=3D./org.apache.solr.cloud.Sha= rdSplitTest-1365802126502/jetty2/tlog [junit4:junit4] 1> INFO - 2013-04-12 21:28:57.355; org.apache.solr.updat= e.CommitTracker; Hard AutoCommit: disabled [junit4:junit4] 1> INFO - 2013-04-12 21:28:57.355; org.apache.solr.updat= e.CommitTracker; Soft AutoCommit: disabled [junit4:junit4] 1> INFO - 2013-04-12 21:28:57.360; org.apache.solr.core.= SolrCore; [collection1] Registered new searcher Searcher@2536bbb9 main{Stan= dardDirectoryReader(segments_1:1)} [junit4:junit4] 1> INFO - 2013-04-12 21:28:57.362; org.apache.solr.cloud= .ZkController; publishing core=3Dcollection1 state=3Ddown [junit4:junit4] 1> INFO - 2013-04-12 21:28:57.363; org.apache.solr.cloud= .ZkController; numShards not found on descriptor - reading it from system p= roperty [junit4:junit4] 1> INFO - 2013-04-12 21:28:57.965; org.apache.solr.commo= n.cloud.ZkStateReader; Updating cloud state from ZooKeeper...=20 [junit4:junit4] 1> INFO - 2013-04-12 21:28:57.966; org.apache.solr.cloud= .Overseer$ClusterStateUpdater; Update state numShards=3D2 message=3D{ [junit4:junit4] 1> "operation":"state", [junit4:junit4] 1> "core_node_name":null, [junit4:junit4] 1> "numShards":"2", [junit4:junit4] 1> "shard":null, [junit4:junit4] 1> "roles":null, [junit4:junit4] 1> "state":"down", [junit4:junit4] 1> "shard_state":"active", [junit4:junit4] 1> "core":"collection1", [junit4:junit4] 1> "collection":"collection1", [junit4:junit4] 1> "shard_range":null, [junit4:junit4] 1> "node_name":"127.0.0.1:36990_", [junit4:junit4] 1> "base_url":"http://127.0.0.1:36990"} [junit4:junit4] 1> INFO - 2013-04-12 21:28:57.967; org.apache.solr.cloud= .Overseer$ClusterStateUpdater; Collection already exists with numShards=3D2 [junit4:junit4] 1> INFO - 2013-04-12 21:28:57.967; org.apache.solr.cloud= .Overseer$ClusterStateUpdater; Assigning new node to shard=3Dshard2 [junit4:junit4] 1> INFO - 2013-04-12 21:28:57.981; org.apache.solr.commo= n.cloud.ZkStateReader$2; A cluster state change: WatchedEvent state:SyncCon= nected type:NodeDataChanged path:/clusterstate.json, has occurred - updatin= g... (live nodes size: 3) [junit4:junit4] 1> INFO - 2013-04-12 21:28:57.981; org.apache.solr.commo= n.cloud.ZkStateReader$2; A cluster state change: WatchedEvent state:SyncCon= nected type:NodeDataChanged path:/clusterstate.json, has occurred - updatin= g... (live nodes size: 3) [junit4:junit4] 1> INFO - 2013-04-12 21:28:57.981; org.apache.solr.commo= n.cloud.ZkStateReader$2; A cluster state change: WatchedEvent state:SyncCon= nected type:NodeDataChanged path:/clusterstate.json, has occurred - updatin= g... (live nodes size: 3) [junit4:junit4] 1> INFO - 2013-04-12 21:28:57.981; org.apache.solr.commo= n.cloud.ZkStateReader$2; A cluster state change: WatchedEvent state:SyncCon= nected type:NodeDataChanged path:/clusterstate.json, has occurred - updatin= g... (live nodes size: 3) [junit4:junit4] 1> INFO - 2013-04-12 21:28:58.366; org.apache.solr.core.= CoreContainer; registering core: collection1 [junit4:junit4] 1> INFO - 2013-04-12 21:28:58.366; org.apache.solr.cloud= .ZkController; Register replica - core:collection1 address:http://127.0.0.1= :36990 collection:collection1 shard:shard2 [junit4:junit4] 1> INFO - 2013-04-12 21:28:58.367; org.apache.solr.commo= n.cloud.SolrZkClient; makePath: /collections/collection1/leader_elect/shard= 2/election [junit4:junit4] 1> INFO - 2013-04-12 21:28:58.474; org.apache.solr.cloud= .ShardLeaderElectionContext; Running the leader process. [junit4:junit4] 1> INFO - 2013-04-12 21:28:58.503; org.apache.solr.cloud= .ShardLeaderElectionContext; Enough replicas found to continue. [junit4:junit4] 1> INFO - 2013-04-12 21:28:58.504; org.apache.solr.cloud= .ShardLeaderElectionContext; I may be the new leader - try and sync [junit4:junit4] 1> INFO - 2013-04-12 21:28:58.504; org.apache.solr.cloud= .SyncStrategy; Sync replicas to http://127.0.0.1:36990/collection1/ [junit4:junit4] 1> INFO - 2013-04-12 21:28:58.504; org.apache.solr.cloud= .SyncStrategy; Sync Success - now sync replicas to me [junit4:junit4] 1> INFO - 2013-04-12 21:28:58.505; org.apache.solr.cloud= .SyncStrategy; http://127.0.0.1:36990/collection1/ has no replicas [junit4:junit4] 1> INFO - 2013-04-12 21:28:58.505; org.apache.solr.cloud= .ShardLeaderElectionContext; I am the new leader: http://127.0.0.1:36990/co= llection1/ [junit4:junit4] 1> INFO - 2013-04-12 21:28:58.505; org.apache.solr.commo= n.cloud.SolrZkClient; makePath: /collections/collection1/leaders/shard2 [junit4:junit4] 1> INFO - 2013-04-12 21:28:59.486; org.apache.solr.commo= n.cloud.ZkStateReader; Updating cloud state from ZooKeeper...=20 [junit4:junit4] 1> INFO - 2013-04-12 21:28:59.518; org.apache.solr.commo= n.cloud.ZkStateReader$2; A cluster state change: WatchedEvent state:SyncCon= nected type:NodeDataChanged path:/clusterstate.json, has occurred - updatin= g... (live nodes size: 3) [junit4:junit4] 1> INFO - 2013-04-12 21:28:59.518; org.apache.solr.commo= n.cloud.ZkStateReader$2; A cluster state change: WatchedEvent state:SyncCon= nected type:NodeDataChanged path:/clusterstate.json, has occurred - updatin= g... (live nodes size: 3) [junit4:junit4] 1> INFO - 2013-04-12 21:28:59.518; org.apache.solr.commo= n.cloud.ZkStateReader$2; A cluster state change: WatchedEvent state:SyncCon= nected type:NodeDataChanged path:/clusterstate.json, has occurred - updatin= g... (live nodes size: 3) [junit4:junit4] 1> INFO - 2013-04-12 21:28:59.518; org.apache.solr.commo= n.cloud.ZkStateReader$2; A cluster state change: WatchedEvent state:SyncCon= nected type:NodeDataChanged path:/clusterstate.json, has occurred - updatin= g... (live nodes size: 3) [junit4:junit4] 1> INFO - 2013-04-12 21:28:59.570; org.apache.solr.cloud= .ZkController; We are http://127.0.0.1:36990/collection1/ and leader is htt= p://127.0.0.1:36990/collection1/ [junit4:junit4] 1> INFO - 2013-04-12 21:28:59.570; org.apache.solr.cloud= .ZkController; No LogReplay needed for core=3Dcollection1 baseURL=3Dhttp://= 127.0.0.1:36990 [junit4:junit4] 1> INFO - 2013-04-12 21:28:59.570; org.apache.solr.cloud= .ZkController; I am the leader, no recovery necessary [junit4:junit4] 1> INFO - 2013-04-12 21:28:59.571; org.apache.solr.cloud= .ZkController; publishing core=3Dcollection1 state=3Dactive [junit4:junit4] 1> INFO - 2013-04-12 21:28:59.571; org.apache.solr.cloud= .ZkController; numShards not found on descriptor - reading it from system p= roperty [junit4:junit4] 1> INFO - 2013-04-12 21:28:59.573; org.apache.solr.commo= n.cloud.ZkStateReader; Updating cloud state from ZooKeeper...=20 [junit4:junit4] 1> INFO - 2013-04-12 21:28:59.574; org.apache.solr.servl= et.SolrDispatchFilter; user.dir=3D/usr/home/hudson/hudson-slave/workspace/L= ucene-Solr-Tests-4.x-java7/solr/build/solr-core/test/J1 [junit4:junit4] 1> INFO - 2013-04-12 21:28:59.575; org.apache.solr.servl= et.SolrDispatchFilter; SolrDispatchFilter.init() done [junit4:junit4] 1> INFO - 2013-04-12 21:28:59.576; org.apache.solr.clien= t.solrj.impl.HttpClientUtil; Creating new http client, config:maxConnection= s=3D128&maxConnectionsPerHost=3D32&followRedirects=3Dfalse [junit4:junit4] 1> INFO - 2013-04-12 21:28:59.804; org.eclipse.jetty.ser= ver.Server; jetty-8.1.8.v20121106 [junit4:junit4] 1> INFO - 2013-04-12 21:28:59.807; org.eclipse.jetty.ser= ver.AbstractConnector; Started SocketConnector@127.0.0.1:24668 [junit4:junit4] 1> INFO - 2013-04-12 21:28:59.808; org.apache.solr.servl= et.SolrDispatchFilter; SolrDispatchFilter.init() [junit4:junit4] 1> INFO - 2013-04-12 21:28:59.809; org.apache.solr.core.= SolrResourceLoader; JNDI not configured for solr (NoInitialContextEx) [junit4:junit4] 1> INFO - 2013-04-12 21:28:59.809; org.apache.solr.core.= SolrResourceLoader; using system property solr.solr.home: /usr/home/hudson/= hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build/solr-core/tes= t/J1/./org.apache.solr.cloud.ShardSplitTest-jetty3-1365802139593 [junit4:junit4] 1> INFO - 2013-04-12 21:28:59.810; org.apache.solr.core.= CoreContainer$Initializer; looking for solr config file: /usr/home/hudson/h= udson-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build/solr-core/test= /J1/./org.apache.solr.cloud.ShardSplitTest-jetty3-1365802139593/solr.xml [junit4:junit4] 1> INFO - 2013-04-12 21:28:59.810; org.apache.solr.core.= CoreContainer; New CoreContainer 1266132310 [junit4:junit4] 1> INFO - 2013-04-12 21:28:59.811; org.apache.solr.core.= CoreContainer; Loading CoreContainer using Solr Home: '/usr/home/hudson/hud= son-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build/solr-core/test/J= 1/./org.apache.solr.cloud.ShardSplitTest-jetty3-1365802139593/' [junit4:junit4] 1> INFO - 2013-04-12 21:28:59.811; org.apache.solr.core.= SolrResourceLoader; new SolrResourceLoader for directory: '/usr/home/hudson= /hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build/solr-core/te= st/J1/./org.apache.solr.cloud.ShardSplitTest-jetty3-1365802139593/' [junit4:junit4] 1> INFO - 2013-04-12 21:28:59.878; org.apache.solr.handl= er.component.HttpShardHandlerFactory; Setting socketTimeout to: 120000 [junit4:junit4] 1> INFO - 2013-04-12 21:28:59.879; org.apache.solr.handl= er.component.HttpShardHandlerFactory; Setting urlScheme to: http:// [junit4:junit4] 1> INFO - 2013-04-12 21:28:59.879; org.apache.solr.handl= er.component.HttpShardHandlerFactory; Setting connTimeout to: 15000 [junit4:junit4] 1> INFO - 2013-04-12 21:28:59.880; org.apache.solr.handl= er.component.HttpShardHandlerFactory; Setting maxConnectionsPerHost to: 20 [junit4:junit4] 1> INFO - 2013-04-12 21:28:59.880; org.apache.solr.handl= er.component.HttpShardHandlerFactory; Setting corePoolSize to: 0 [junit4:junit4] 1> INFO - 2013-04-12 21:28:59.881; org.apache.solr.handl= er.component.HttpShardHandlerFactory; Setting maximumPoolSize to: 214748364= 7 [junit4:junit4] 1> INFO - 2013-04-12 21:28:59.882; org.apache.solr.handl= er.component.HttpShardHandlerFactory; Setting maxThreadIdleTime to: 5 [junit4:junit4] 1> INFO - 2013-04-12 21:28:59.882; org.apache.solr.handl= er.component.HttpShardHandlerFactory; Setting sizeOfQueue to: -1 [junit4:junit4] 1> INFO - 2013-04-12 21:28:59.883; org.apache.solr.handl= er.component.HttpShardHandlerFactory; Setting fairnessPolicy to: false [junit4:junit4] 1> INFO - 2013-04-12 21:28:59.883; org.apache.solr.clien= t.solrj.impl.HttpClientUtil; Creating new http client, config:maxConnection= sPerHost=3D20&maxConnections=3D10000&socketTimeout=3D120000&connTimeout=3D1= 5000&retry=3Dfalse [junit4:junit4] 1> INFO - 2013-04-12 21:28:59.907; org.apache.solr.core.= CoreContainer; Registering Log Listener [junit4:junit4] 1> INFO - 2013-04-12 21:28:59.926; org.apache.solr.core.= CoreContainer; Zookeeper client=3D127.0.0.1:47561/solr [junit4:junit4] 1> INFO - 2013-04-12 21:28:59.927; org.apache.solr.cloud= .ZkController; zkHost includes chroot [junit4:junit4] 1> INFO - 2013-04-12 21:28:59.928; org.apache.solr.commo= n.cloud.ConnectionManager; Waiting for client to connect to ZooKeeper [junit4:junit4] 1> INFO - 2013-04-12 21:28:59.932; org.apache.solr.commo= n.cloud.ConnectionManager; Watcher org.apache.solr.common.cloud.ConnectionM= anager@3063a0ca name:ZooKeeperConnection Watcher:127.0.0.1:47561 got event = WatchedEvent state:SyncConnected type:None path:null path:null type:None [junit4:junit4] 1> INFO - 2013-04-12 21:28:59.932; org.apache.solr.commo= n.cloud.ConnectionManager; Client is connected to ZooKeeper [junit4:junit4] 1> INFO - 2013-04-12 21:28:59.935; org.apache.solr.clien= t.solrj.impl.HttpClientUtil; Creating new http client, config:maxConnection= s=3D500&maxConnectionsPerHost=3D16&socketTimeout=3D120000&connTimeout=3D150= 00 [junit4:junit4] 1> INFO - 2013-04-12 21:28:59.949; org.apache.solr.commo= n.cloud.ConnectionManager; Waiting for client to connect to ZooKeeper [junit4:junit4] 1> INFO - 2013-04-12 21:28:59.952; org.apache.solr.commo= n.cloud.ConnectionManager; Watcher org.apache.solr.common.cloud.ConnectionM= anager@c90b8a5 name:ZooKeeperConnection Watcher:127.0.0.1:47561/solr got ev= ent WatchedEvent state:SyncConnected type:None path:null path:null type:Non= e [junit4:junit4] 1> INFO - 2013-04-12 21:28:59.952; org.apache.solr.commo= n.cloud.ConnectionManager; Client is connected to ZooKeeper [junit4:junit4] 1> INFO - 2013-04-12 21:28:59.964; org.apache.solr.commo= n.cloud.ZkStateReader; Updating cluster state from ZooKeeper...=20 [junit4:junit4] 1> INFO - 2013-04-12 21:29:00.968; org.apache.solr.cloud= .ZkController; Register node as live in ZooKeeper:/live_nodes/127.0.0.1:246= 68_ [junit4:junit4] 1> INFO - 2013-04-12 21:29:00.971; org.apache.solr.commo= n.cloud.SolrZkClient; makePath: /live_nodes/127.0.0.1:24668_ [junit4:junit4] 1> INFO - 2013-04-12 21:29:00.975; org.apache.solr.commo= n.cloud.ZkStateReader$3; Updating live nodes... (4) [junit4:junit4] 1> INFO - 2013-04-12 21:29:00.975; org.apache.solr.commo= n.cloud.ZkStateReader$3; Updating live nodes... (4) [junit4:junit4] 1> INFO - 2013-04-12 21:29:00.975; org.apache.solr.commo= n.cloud.ZkStateReader$3; Updating live nodes... (4) [junit4:junit4] 1> INFO - 2013-04-12 21:29:00.975; org.apache.solr.commo= n.cloud.ZkStateReader$2; A cluster state change: WatchedEvent state:SyncCon= nected type:NodeChildrenChanged path:/live_nodes, has occurred - updating..= . (live nodes size: 4) [junit4:junit4] 1> INFO - 2013-04-12 21:29:00.975; org.apache.solr.commo= n.cloud.ZkStateReader$3; Updating live nodes... (4) [junit4:junit4] 1> INFO - 2013-04-12 21:29:00.975; org.apache.solr.commo= n.cloud.ZkStateReader$3; Updating live nodes... (4) [junit4:junit4] 1> INFO - 2013-04-12 21:29:00.976; org.apache.solr.commo= n.cloud.ZkStateReader$2; A cluster state change: WatchedEvent state:SyncCon= nected type:NodeChildrenChanged path:/live_nodes, has occurred - updating..= . (live nodes size: 4) [junit4:junit4] 1> INFO - 2013-04-12 21:29:00.976; org.apache.solr.commo= n.cloud.ZkStateReader$2; A cluster state change: WatchedEvent state:SyncCon= nected type:NodeChildrenChanged path:/live_nodes, has occurred - updating..= . (live nodes size: 4) [junit4:junit4] 1> INFO - 2013-04-12 21:29:00.977; org.apache.solr.commo= n.cloud.ZkStateReader$2; A cluster state change: WatchedEvent state:SyncCon= nected type:NodeChildrenChanged path:/live_nodes, has occurred - updating..= . (live nodes size: 4) [junit4:junit4] 1> INFO - 2013-04-12 21:29:00.988; org.apache.solr.core.= CoreContainer; Creating SolrCore 'collection1' using instanceDir: /usr/home= /hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build/solr-= core/test/J1/./org.apache.solr.cloud.ShardSplitTest-jetty3-1365802139593/co= llection1 [junit4:junit4] 1> INFO - 2013-04-12 21:29:00.989; org.apache.solr.cloud= .ZkController; Check for collection zkNode:collection1 [junit4:junit4] 1> INFO - 2013-04-12 21:29:00.989; org.apache.solr.cloud= .ZkController; Collection zkNode exists [junit4:junit4] 1> INFO - 2013-04-12 21:29:00.990; org.apache.solr.cloud= .ZkController; Load collection config from:/collections/collection1 [junit4:junit4] 1> INFO - 2013-04-12 21:29:00.991; org.apache.solr.core.= SolrResourceLoader; new SolrResourceLoader for directory: '/usr/home/hudson= /hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build/solr-core/te= st/J1/./org.apache.solr.cloud.ShardSplitTest-jetty3-1365802139593/collectio= n1/' [junit4:junit4] 1> INFO - 2013-04-12 21:29:00.993; org.apache.solr.core.= SolrResourceLoader; Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lu= cene-Solr-Tests-4.x-java7/solr/build/solr-core/test/J1/org.apache.solr.clou= d.ShardSplitTest-jetty3-1365802139593/collection1/lib/classes/' to classloa= der [junit4:junit4] 1> INFO - 2013-04-12 21:29:00.994; org.apache.solr.core.= SolrResourceLoader; Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lu= cene-Solr-Tests-4.x-java7/solr/build/solr-core/test/J1/org.apache.solr.clou= d.ShardSplitTest-jetty3-1365802139593/collection1/lib/README' to classloade= r [junit4:junit4] 1> INFO - 2013-04-12 21:29:01.026; org.apache.solr.commo= n.cloud.ZkStateReader; Updating cloud state from ZooKeeper...=20 [junit4:junit4] 1> INFO - 2013-04-12 21:29:01.027; org.apache.solr.cloud= .Overseer$ClusterStateUpdater; Update state numShards=3D2 message=3D{ [junit4:junit4] 1> "operation":"state", [junit4:junit4] 1> "core_node_name":"127.0.0.1:36990__collection1", [junit4:junit4] 1> "numShards":"2", [junit4:junit4] 1> "shard":"shard2", [junit4:junit4] 1> "roles":null, [junit4:junit4] 1> "state":"active", [junit4:junit4] 1> "shard_state":"active", [junit4:junit4] 1> "core":"collection1", [junit4:junit4] 1> "collection":"collection1", [junit4:junit4] 1> "shard_range":null, [junit4:junit4] 1> "node_name":"127.0.0.1:36990_", [junit4:junit4] 1> "base_url":"http://127.0.0.1:36990"} [junit4:junit4] 1> INFO - 2013-04-12 21:29:01.040; org.apache.solr.commo= n.cloud.ZkStateReader$2; A cluster state change: WatchedEvent state:SyncCon= nected type:NodeDataChanged path:/clusterstate.json, has occurred - updatin= g... (live nodes size: 4) [junit4:junit4] 1> INFO - 2013-04-12 21:29:01.040; org.apache.solr.commo= n.cloud.ZkStateReader$2; A cluster state change: WatchedEvent state:SyncCon= nected type:NodeDataChanged path:/clusterstate.json, has occurred - updatin= g... (live nodes size: 4) [junit4:junit4] 1> INFO - 2013-04-12 21:29:01.040; org.apache.solr.commo= n.cloud.ZkStateReader$2; A cluster state change: WatchedEvent state:SyncCon= nected type:NodeDataChanged path:/clusterstate.json, has occurred - updatin= g... (live nodes size: 4) [junit4:junit4] 1> INFO - 2013-04-12 21:29:01.040; org.apache.solr.commo= n.cloud.ZkStateReader$2; A cluster state change: WatchedEvent state:SyncCon= nected type:NodeDataChanged path:/clusterstate.json, has occurred - updatin= g... (live nodes size: 4) [junit4:junit4] 1> INFO - 2013-04-12 21:29:01.040; org.apache.solr.commo= n.cloud.ZkStateReader$2; A cluster state change: WatchedEvent state:SyncCon= nected type:NodeDataChanged path:/clusterstate.json, has occurred - updatin= g... (live nodes size: 4) [junit4:junit4] 1> INFO - 2013-04-12 21:29:01.044; org.apache.solr.core.= SolrConfig; Using Lucene MatchVersion: LUCENE_43 [junit4:junit4] 1> INFO - 2013-04-12 21:29:01.118; org.apache.solr.core.= SolrConfig; Loaded SolrConfig: solrconfig.xml [junit4:junit4] 1> INFO - 2013-04-12 21:29:01.219; org.apache.solr.schem= a.IndexSchema; Reading Solr Schema from schema.xml [junit4:junit4] 1> INFO - 2013-04-12 21:29:01.226; org.apache.solr.schem= a.IndexSchema; Schema name=3Dtest [junit4:junit4] 1> INFO - 2013-04-12 21:29:01.885; org.apache.solr.schem= a.OpenExchangeRatesOrgProvider; Initialized with rates=3Dopen-exchange-rate= s.json, refreshInterval=3D1440. [junit4:junit4] 1> INFO - 2013-04-12 21:29:01.898; org.apache.solr.schem= a.IndexSchema; default search field in schema is text [junit4:junit4] 1> INFO - 2013-04-12 21:29:01.903; org.apache.solr.schem= a.IndexSchema; unique key field: id [junit4:junit4] 1> INFO - 2013-04-12 21:29:01.921; org.apache.solr.schem= a.FileExchangeRateProvider; Reloading exchange rates from file currency.xml [junit4:junit4] 1> INFO - 2013-04-12 21:29:01.926; org.apache.solr.schem= a.FileExchangeRateProvider; Reloading exchange rates from file currency.xml [junit4:junit4] 1> INFO - 2013-04-12 21:29:01.931; org.apache.solr.schem= a.OpenExchangeRatesOrgProvider; Reloading exchange rates from open-exchange= -rates.json [junit4:junit4] 1> WARN - 2013-04-12 21:29:01.933; org.apache.solr.schem= a.OpenExchangeRatesOrgProvider$OpenExchangeRates; Unknown key IMPORTANT NOT= E [junit4:junit4] 1> WARN - 2013-04-12 21:29:01.933; org.apache.solr.schem= a.OpenExchangeRatesOrgProvider$OpenExchangeRates; Expected key, got STRING [junit4:junit4] 1> INFO - 2013-04-12 21:29:01.933; org.apache.solr.schem= a.OpenExchangeRatesOrgProvider; Reloading exchange rates from open-exchange= -rates.json [junit4:junit4] 1> WARN - 2013-04-12 21:29:01.935; org.apache.solr.schem= a.OpenExchangeRatesOrgProvider$OpenExchangeRates; Unknown key IMPORTANT NOT= E [junit4:junit4] 1> WARN - 2013-04-12 21:29:01.935; org.apache.solr.schem= a.OpenExchangeRatesOrgProvider$OpenExchangeRates; Expected key, got STRING [junit4:junit4] 1> INFO - 2013-04-12 21:29:01.935; org.apache.solr.core.= SolrCore; org.apache.solr.core.MockDirectoryFactory [junit4:junit4] 1> INFO - 2013-04-12 21:29:01.936; org.apache.solr.core.= SolrCore; [collection1] Opening new SolrCore at /usr/home/hudson/hudson-sla= ve/workspace/Lucene-Solr-Tests-4.x-java7/solr/build/solr-core/test/J1/./org= .apache.solr.cloud.ShardSplitTest-jetty3-1365802139593/collection1/, dataDi= r=3D./org.apache.solr.cloud.ShardSplitTest-1365802126502/jetty3/ [junit4:junit4] 1> INFO - 2013-04-12 21:29:01.936; org.apache.solr.core.= JmxMonitoredMap; JMX monitoring is enabled. Adding Solr mbeans to JMX Serve= r: com.sun.jmx.mbeanserver.JmxMBeanServer@71880832 [junit4:junit4] 1> INFO - 2013-04-12 21:29:01.937; org.apache.solr.core.= SolrCore; org.apache.solr.core.MockDirectoryFactory [junit4:junit4] 1> INFO - 2013-04-12 21:29:01.938; org.apache.solr.core.= CachingDirectoryFactory; return new directory for ./org.apache.solr.cloud.S= hardSplitTest-1365802126502/jetty3 [junit4:junit4] 1> INFO - 2013-04-12 21:29:01.938; org.apache.solr.core.= SolrCore; New index directory detected: old=3Dnull new=3D./org.apache.solr.= cloud.ShardSplitTest-1365802126502/jetty3/index/ [junit4:junit4] 1> WARN - 2013-04-12 21:29:01.938; org.apache.solr.core.= SolrCore; [collection1] Solr index directory './org.apache.solr.cloud.Shard= SplitTest-1365802126502/jetty3/index' doesn't exist. Creating new index... [junit4:junit4] 1> INFO - 2013-04-12 21:29:01.939; org.apache.solr.core.= CachingDirectoryFactory; return new directory for ./org.apache.solr.cloud.S= hardSplitTest-1365802126502/jetty3/index [junit4:junit4] 1> INFO - 2013-04-12 21:29:01.942; org.apache.solr.core.= SolrDeletionPolicy; SolrDeletionPolicy.onCommit: commits:num=3D1 [junit4:junit4] 1> =09commit{dir=3DMockDirWrapper(org.apache.lucene.store= .RAMDirectory@32f6a701 lockFactory=3Dorg.apache.lucene.store.NativeFSLockFa= ctory@53815a8e),segFN=3Dsegments_1,generation=3D1,filenames=3D[segments_1] [junit4:junit4] 1> INFO - 2013-04-12 21:29:01.942; org.apache.solr.core.= SolrDeletionPolicy; newest commit =3D 1[segments_1] [junit4:junit4] 1> INFO - 2013-04-12 21:29:01.945; org.apache.solr.updat= e.processor.UpdateRequestProcessorChain; inserting DistributedUpdateProcess= orFactory into updateRequestProcessorChain "dedupe" [junit4:junit4] 1> INFO - 2013-04-12 21:29:01.946; org.apache.solr.updat= e.processor.UpdateRequestProcessorChain; inserting DistributedUpdateProcess= orFactory into updateRequestProcessorChain "stored_sig" [junit4:junit4] 1> INFO - 2013-04-12 21:29:01.947; org.apache.solr.updat= e.processor.UpdateRequestProcessorChain; inserting DistributedUpdateProcess= orFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit= " [junit4:junit4] 1> INFO - 2013-04-12 21:29:01.947; org.apache.solr.core.= RequestHandlers; created standard: solr.StandardRequestHandler [junit4:junit4] 1> INFO - 2013-04-12 21:29:01.948; org.apache.solr.core.= RequestHandlers; created /get: solr.RealTimeGetHandler [junit4:junit4] 1> INFO - 2013-04-12 21:29:01.948; org.apache.solr.core.= RequestHandlers; adding lazy requestHandler: solr.ReplicationHandler [junit4:junit4] 1> INFO - 2013-04-12 21:29:01.949; org.apache.solr.core.= RequestHandlers; created /replication: solr.ReplicationHandler [junit4:junit4] 1> INFO - 2013-04-12 21:29:01.950; org.apache.solr.core.= RequestHandlers; created /update: solr.UpdateRequestHandler [junit4:junit4] 1> INFO - 2013-04-12 21:29:01.950; org.apache.solr.core.= RequestHandlers; created /admin/: org.apache.solr.handler.admin.AdminHandle= rs [junit4:junit4] 1> INFO - 2013-04-12 21:29:01.963; org.apache.solr.handl= er.loader.XMLLoader; xsltCacheLifetimeSeconds=3D60 [junit4:junit4] 1> INFO - 2013-04-12 21:29:01.969; org.apache.solr.searc= h.SolrIndexSearcher; Opening Searcher@3c842697 main [junit4:junit4] 1> INFO - 2013-04-12 21:29:01.970; org.apache.solr.updat= e.UpdateHandler; Clearing tlog files, tlogDir=3D./org.apache.solr.cloud.Sha= rdSplitTest-1365802126502/jetty3/tlog [junit4:junit4] 1> INFO - 2013-04-12 21:29:01.971; org.apache.solr.updat= e.CommitTracker; Hard AutoCommit: disabled [junit4:junit4] 1> INFO - 2013-04-12 21:29:01.971; org.apache.solr.updat= e.CommitTracker; Soft AutoCommit: disabled [junit4:junit4] 1> INFO - 2013-04-12 21:29:01.976; org.apache.solr.core.= SolrCore; [collection1] Registered new searcher Searcher@3c842697 main{Stan= dardDirectoryReader(segments_1:1)} [junit4:junit4] 1> INFO - 2013-04-12 21:29:01.979; org.apache.solr.cloud= .ZkController; publishing core=3Dcollection1 state=3Ddown [junit4:junit4] 1> INFO - 2013-04-12 21:29:01.979; org.apache.solr.cloud= .ZkController; numShards not found on descriptor - reading it from system p= roperty [junit4:junit4] 1> INFO - 2013-04-12 21:29:02.547; org.apache.solr.commo= n.cloud.ZkStateReader; Updating cloud state from ZooKeeper...=20 [junit4:junit4] 1> INFO - 2013-04-12 21:29:02.548; org.apache.solr.cloud= .Overseer$ClusterStateUpdater; Update state numShards=3D2 message=3D{ [junit4:junit4] 1> "operation":"state", [junit4:junit4] 1> "core_node_name":null, [junit4:junit4] 1> "numShards":"2", [junit4:junit4] 1> "shard":null, [junit4:junit4] 1> "roles":null, [junit4:junit4] 1> "state":"down", [junit4:junit4] 1> "shard_state":"active", [junit4:junit4] 1> "core":"collection1", [junit4:junit4] 1> "collection":"collection1", [junit4:junit4] 1> "shard_range":null, [junit4:junit4] 1> "node_name":"127.0.0.1:24668_", [junit4:junit4] 1> "base_url":"http://127.0.0.1:24668"} [junit4:junit4] 1> INFO - 2013-04-12 21:29:02.548; org.apache.solr.cloud= .Overseer$ClusterStateUpdater; Collection already exists with numShards=3D2 [junit4:junit4] 1> INFO - 2013-04-12 21:29:02.548; org.apache.solr.cloud= .Overseer$ClusterStateUpdater; Assigning new node to shard=3Dshard1 [junit4:junit4] 1> INFO - 2013-04-12 21:29:02.566; org.apache.solr.commo= n.cloud.ZkStateReader$2; A cluster state change: WatchedEvent state:SyncCon= nected type:NodeDataChanged path:/clusterstate.json, has occurred - updatin= g... (live nodes size: 4) [junit4:junit4] 1> INFO - 2013-04-12 21:29:02.566; org.apache.solr.commo= n.cloud.ZkStateReader$2; A cluster state change: WatchedEvent state:SyncCon= nected type:NodeDataChanged path:/clusterstate.json, has occurred - updatin= g... (live nodes size: 4) [junit4:junit4] 1> INFO - 2013-04-12 21:29:02.566; org.apache.solr.commo= n.cloud.ZkStateReader$2; A cluster state change: WatchedEvent state:SyncCon= nected type:NodeDataChanged path:/clusterstate.json, has occurred - updatin= g... (live nodes size: 4) [junit4:junit4] 1> INFO - 2013-04-12 21:29:02.566; org.apache.solr.commo= n.cloud.ZkStateReader$2; A cluster state change: WatchedEvent state:SyncCon= nected type:NodeDataChanged path:/clusterstate.json, has occurred - updatin= g... (live nodes size: 4) [junit4:junit4] 1> INFO - 2013-04-12 21:29:02.566; org.apache.solr.commo= n.cloud.ZkStateReader$2; A cluster state change: WatchedEvent state:SyncCon= nected type:NodeDataChanged path:/clusterstate.json, has occurred - updatin= g... (live nodes size: 4) [junit4:junit4] 1> INFO - 2013-04-12 21:29:02.982; org.apache.solr.core.= CoreContainer; registering core: collection1 [junit4:junit4] 1> INFO - 2013-04-12 21:29:02.982; org.apache.solr.cloud= .ZkController; Register replica - core:collection1 address:http://127.0.0.1= :24668 collection:collection1 shard:shard1 [junit4:junit4] 1> INFO - 2013-04-12 21:29:02.986; org.apache.solr.cloud= .ZkController; We are http://127.0.0.1:24668/collection1/ and leader is htt= p://127.0.0.1:29782/collection1/ [junit4:junit4] 1> INFO - 2013-04-12 21:29:02.986; org.apache.solr.cloud= .ZkController; No LogReplay needed for core=3Dcollection1 baseURL=3Dhttp://= 127.0.0.1:24668 [junit4:junit4] 1> INFO - 2013-04-12 21:29:02.986; org.apache.solr.cloud= .ZkController; Core needs to recover:collection1 [junit4:junit4] 1> INFO - 2013-04-12 21:29:02.987; org.apache.solr.updat= e.DefaultSolrCoreState; Running recovery - first canceling any ongoing reco= very [junit4:junit4] 1> INFO - 2013-04-12 21:29:02.987; org.apache.solr.cloud= .RecoveryStrategy; Starting recovery process. core=3Dcollection1 recoverin= gAfterStartup=3Dtrue [junit4:junit4] 1> INFO - 2013-04-12 21:29:02.988; org.apache.solr.cloud= .RecoveryStrategy; ###### startupVersions=3D[] [junit4:junit4] 1> INFO - 2013-04-12 21:29:02.988; org.apache.solr.commo= n.cloud.ZkStateReader; Updating cloud state from ZooKeeper...=20 [junit4:junit4] 1> INFO - 2013-04-12 21:29:02.988; org.apache.solr.cloud= .ZkController; publishing core=3Dcollection1 state=3Drecovering [junit4:junit4] 1> INFO - 2013-04-12 21:29:02.989; org.apache.solr.cloud= .ZkController; numShards not found on descriptor - reading it from system p= roperty [junit4:junit4] 1> INFO - 2013-04-12 21:29:02.990; org.apache.solr.servl= et.SolrDispatchFilter; user.dir=3D/usr/home/hudson/hudson-slave/workspace/L= ucene-Solr-Tests-4.x-java7/solr/build/solr-core/test/J1 [junit4:junit4] 1> INFO - 2013-04-12 21:29:02.990; org.apache.solr.servl= et.SolrDispatchFilter; SolrDispatchFilter.init() done [junit4:junit4] 1> INFO - 2013-04-12 21:29:02.991; org.apache.solr.clien= t.solrj.impl.HttpClientUtil; Creating new http client, config:maxConnection= s=3D128&maxConnectionsPerHost=3D32&followRedirects=3Dfalse [junit4:junit4] 1> INFO - 2013-04-12 21:29:02.991; org.apache.solr.clien= t.solrj.impl.HttpClientUtil; Creating new http client, config:maxConnection= s=3D128&maxConnectionsPerHost=3D32&followRedirects=3Dfalse [junit4:junit4] 1> INFO - 2013-04-12 21:29:03.015; org.apache.solr.handl= er.admin.CoreAdminHandler; Going to wait for coreNodeName: 127.0.0.1:24668_= _collection1, state: recovering, checkLive: true, onlyIfLeader: true [junit4:junit4] 1> INFO - 2013-04-12 21:29:03.233; org.eclipse.jetty.ser= ver.Server; jetty-8.1.8.v20121106 [junit4:junit4] 1> INFO - 2013-04-12 21:29:03.236; org.eclipse.jetty.ser= ver.AbstractConnector; Started SocketConnector@127.0.0.1:49988 [junit4:junit4] 1> INFO - 2013-04-12 21:29:03.237; org.apache.solr.servl= et.SolrDispatchFilter; SolrDispatchFilter.init() [junit4:junit4] 1> INFO - 2013-04-12 21:29:03.237; org.apache.solr.core.= SolrResourceLoader; JNDI not configured for solr (NoInitialContextEx) [junit4:junit4] 1> INFO - 2013-04-12 21:29:03.238; org.apache.solr.core.= SolrResourceLoader; using system property solr.solr.home: /usr/home/hudson/= hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build/solr-core/tes= t/J1/./org.apache.solr.cloud.ShardSplitTest-jetty4-1365802143013 [junit4:junit4] 1> INFO - 2013-04-12 21:29:03.238; org.apache.solr.core.= CoreContainer$Initializer; looking for solr config file: /usr/home/hudson/h= udson-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build/solr-core/test= /J1/./org.apache.solr.cloud.ShardSplitTest-jetty4-1365802143013/solr.xml [junit4:junit4] 1> INFO - 2013-04-12 21:29:03.239; org.apache.solr.core.= CoreContainer; New CoreContainer 596755438 [junit4:junit4] 1> INFO - 2013-04-12 21:29:03.240; org.apache.solr.core.= CoreContainer; Loading CoreContainer using Solr Home: '/usr/home/hudson/hud= son-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build/solr-core/test/J= 1/./org.apache.solr.cloud.ShardSplitTest-jetty4-1365802143013/' [junit4:junit4] 1> INFO - 2013-04-12 21:29:03.240; org.apache.solr.core.= SolrResourceLoader; new SolrResourceLoader for directory: '/usr/home/hudson= /hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build/solr-core/te= st/J1/./org.apache.solr.cloud.ShardSplitTest-jetty4-1365802143013/' [junit4:junit4] 1> INFO - 2013-04-12 21:29:03.309; org.apache.solr.handl= er.component.HttpShardHandlerFactory; Setting socketTimeout to: 120000 [junit4:junit4] 1> INFO - 2013-04-12 21:29:03.310; org.apache.solr.handl= er.component.HttpShardHandlerFactory; Setting urlScheme to: http:// [junit4:junit4] 1> INFO - 2013-04-12 21:29:03.311; org.apache.solr.handl= er.component.HttpShardHandlerFactory; Setting connTimeout to: 15000 [junit4:junit4] 1> INFO - 2013-04-12 21:29:03.311; org.apache.solr.handl= er.component.HttpShardHandlerFactory; Setting maxConnectionsPerHost to: 20 [junit4:junit4] 1> INFO - 2013-04-12 21:29:03.312; org.apache.solr.handl= er.component.HttpShardHandlerFactory; Setting corePoolSize to: 0 [junit4:junit4] 1> INFO - 2013-04-12 21:29:03.312; org.apache.solr.handl= er.component.HttpShardHandlerFactory; Setting maximumPoolSize to: 214748364= 7 [junit4:junit4] 1> INFO - 2013-04-12 21:29:03.313; org.apache.solr.handl= er.component.HttpShardHandlerFactory; Setting maxThreadIdleTime to: 5 [junit4:junit4] 1> INFO - 2013-04-12 21:29:03.313; org.apache.solr.handl= er.component.HttpShardHandlerFactory; Setting sizeOfQueue to: -1 [junit4:junit4] 1> INFO - 2013-04-12 21:29:03.314; org.apache.solr.handl= er.component.HttpShardHandlerFactory; Setting fairnessPolicy to: false [junit4:junit4] 1> INFO - 2013-04-12 21:29:03.314; org.apache.solr.clien= t.solrj.impl.HttpClientUtil; Creating new http client, config:maxConnection= sPerHost=3D20&maxConnections=3D10000&socketTimeout=3D120000&connTimeout=3D1= 5000&retry=3Dfalse [junit4:junit4] 1> INFO - 2013-04-12 21:29:03.336; org.apache.solr.core.= CoreContainer; Registering Log Listener [junit4:junit4] 1> INFO - 2013-04-12 21:29:03.356; org.apache.solr.core.= CoreContainer; Zookeeper client=3D127.0.0.1:47561/solr [junit4:junit4] 1> INFO - 2013-04-12 21:29:03.357; org.apache.solr.cloud= .ZkController; zkHost includes chroot [junit4:junit4] 1> INFO - 2013-04-12 21:29:03.358; org.apache.solr.commo= n.cloud.ConnectionManager; Waiting for client to connect to ZooKeeper [junit4:junit4] 1> INFO - 2013-04-12 21:29:03.368; org.apache.solr.commo= n.cloud.ConnectionManager; Watcher org.apache.solr.common.cloud.ConnectionM= anager@78a363c3 name:ZooKeeperConnection Watcher:127.0.0.1:47561 got event = WatchedEvent state:SyncConnected type:None path:null path:null type:None [junit4:junit4] 1> INFO - 2013-04-12 21:29:03.369; org.apache.solr.commo= n.cloud.ConnectionManager; Client is connected to ZooKeeper [junit4:junit4] 1> INFO - 2013-04-12 21:29:03.371; org.apache.solr.clien= t.solrj.impl.HttpClientUtil; Creating new http client, config:maxConnection= s=3D500&maxConnectionsPerHost=3D16&socketTimeout=3D120000&connTimeout=3D150= 00 [junit4:junit4] 1> INFO - 2013-04-12 21:29:03.384; org.apache.solr.commo= n.cloud.ConnectionManager; Waiting for client to connect to ZooKeeper [junit4:junit4] 1> INFO - 2013-04-12 21:29:03.388; org.apache.solr.commo= n.cloud.ConnectionManager; Watcher org.apache.solr.common.cloud.ConnectionM= anager@3bcd8014 name:ZooKeeperConnection Watcher:127.0.0.1:47561/solr got e= vent WatchedEvent state:SyncConnected type:None path:null path:null type:No= ne [junit4:junit4] 1> INFO - 2013-04-12 21:29:03.388; org.apache.solr.commo= n.cloud.ConnectionManager; Client is connected to ZooKeeper [junit4:junit4] 1> INFO - 2013-04-12 21:29:03.444; org.apache.solr.commo= n.cloud.ZkStateReader; Updating cluster state from ZooKeeper...=20 [junit4:junit4] 1> INFO - 2013-04-12 21:29:04.072; org.apache.solr.commo= n.cloud.ZkStateReader; Updating cloud state from ZooKeeper...=20 [junit4:junit4] 1> INFO - 2013-04-12 21:29:04.073; org.apache.solr.cloud= .Overseer$ClusterStateUpdater; Update state numShards=3D2 message=3D{ [junit4:junit4] 1> "operation":"state", [junit4:junit4] 1> "core_node_name":"127.0.0.1:24668__collection1", [junit4:junit4] 1> "numShards":"2", [junit4:junit4] 1> "shard":"shard1", [junit4:junit4] 1> "roles":null, [junit4:junit4] 1> "state":"recovering", [junit4:junit4] 1> "shard_state":"active", [junit4:junit4] 1> "core":"collection1", [junit4:junit4] 1> "collection":"collection1", [junit4:junit4] 1> "shard_range":null, [junit4:junit4] 1> "node_name":"127.0.0.1:24668_", [junit4:junit4] 1> "base_url":"http://127.0.0.1:24668"} [junit4:junit4] 1> INFO - 2013-04-12 21:29:04.116; org.apache.solr.commo= n.cloud.ZkStateReader$2; A cluster state change: WatchedEvent state:SyncCon= nected type:NodeDataChanged path:/clusterstate.json, has occurred - updatin= g... (live nodes size: 4) [junit4:junit4] 1> INFO - 2013-04-12 21:29:04.116; org.apache.solr.commo= n.cloud.ZkStateReader$2; A cluster state change: WatchedEvent state:SyncCon= nected type:NodeDataChanged path:/clusterstate.json, has occurred - updatin= g... (live nodes size: 4) [junit4:junit4] 1> INFO - 2013-04-12 21:29:04.116; org.apache.solr.commo= n.cloud.ZkStateReader$2; A cluster state change: WatchedEvent state:SyncCon= nected type:NodeDataChanged path:/clusterstate.json, has occurred - updatin= g... (live nodes size: 4) [junit4:junit4] 1> INFO - 2013-04-12 21:29:04.116; org.apache.solr.commo= n.cloud.ZkStateReader$2; A cluster state change: WatchedEvent state:SyncCon= nected type:NodeDataChanged path:/clusterstate.json, has occurred - updatin= g... (live nodes size: 4) [junit4:junit4] 1> INFO - 2013-04-12 21:29:04.116; org.apache.solr.commo= n.cloud.ZkStateReader$2; A cluster state change: WatchedEvent state:SyncCon= nected type:NodeDataChanged path:/clusterstate.json, has occurred - updatin= g... (live nodes size: 4) [junit4:junit4] 1> INFO - 2013-04-12 21:29:04.116; org.apache.solr.commo= n.cloud.ZkStateReader$2; A cluster state change: WatchedEvent state:SyncCon= nected type:NodeDataChanged path:/clusterstate.json, has occurred - updatin= g... (live nodes size: 4) [junit4:junit4] 1> INFO - 2013-04-12 21:29:04.448; org.apache.solr.cloud= .ZkController; Register node as live in ZooKeeper:/live_nodes/127.0.0.1:499= 88_ [junit4:junit4] 1> INFO - 2013-04-12 21:29:04.450; org.apache.solr.commo= n.cloud.SolrZkClient; makePath: /live_nodes/127.0.0.1:49988_ [junit4:junit4] 1> INFO - 2013-04-12 21:29:04.453; org.apache.solr.commo= n.cloud.ZkStateReader$2; A cluster state change: WatchedEvent state:SyncCon= nected type:NodeChildrenChanged path:/live_nodes, has occurred - updating..= . (live nodes size: 4) [junit4:junit4] 1> INFO - 2013-04-12 21:29:04.454; org.apache.solr.commo= n.cloud.ZkStateReader$3; Updating live nodes... (5) [junit4:junit4] 1> INFO - 2013-04-12 21:29:04.454; org.apache.solr.commo= n.cloud.ZkStateReader$3; Updating live nodes... (5) [junit4:junit4] 1> INFO - 2013-04-12 21:29:04.454; org.apache.solr.commo= n.cloud.ZkStateReader$3; Updating live nodes... (5) [junit4:junit4] 1> INFO - 2013-04-12 21:29:04.454; org.apache.solr.commo= n.cloud.ZkStateReader$2; A cluster state change: WatchedEvent state:SyncCon= nected type:NodeChildrenChanged path:/live_nodes, has occurred - updating..= . (live nodes size: 5) [junit4:junit4] 1> INFO - 2013-04-12 21:29:04.454; org.apache.solr.commo= n.cloud.ZkStateReader$3; Updating live nodes... (5) [junit4:junit4] 1> INFO - 2013-04-12 21:29:04.454; org.apache.solr.commo= n.cloud.ZkStateReader$2; A cluster state change: WatchedEvent state:SyncCon= nected type:NodeChildrenChanged path:/live_nodes, has occurred - updating..= . (live nodes size: 5) [junit4:junit4] 1> INFO - 2013-04-12 21:29:04.454; org.apache.solr.commo= n.cloud.ZkStateReader$3; Updating live nodes... (5) [junit4:junit4] 1> INFO - 2013-04-12 21:29:04.456; org.apache.solr.commo= n.cloud.ZkStateReader$3; Updating live nodes... (5) [junit4:junit4] 1> INFO - 2013-04-12 21:29:04.455; org.apache.solr.commo= n.cloud.ZkStateReader$2; A cluster state change: WatchedEvent state:SyncCon= nected type:NodeChildrenChanged path:/live_nodes, has occurred - updating..= . (live nodes size: 5) [junit4:junit4] 1> INFO - 2013-04-12 21:29:04.455; org.apache.solr.commo= n.cloud.ZkStateReader$2; A cluster state change: WatchedEvent state:SyncCon= nected type:NodeChildrenChanged path:/live_nodes, has occurred - updating..= . (live nodes size: 5) [junit4:junit4] 1> INFO - 2013-04-12 21:29:04.456; org.apache.solr.commo= n.cloud.ZkStateReader$2; A cluster state change: WatchedEvent state:SyncCon= nected type:NodeChildrenChanged path:/live_nodes, has occurred - updating..= . (live nodes size: 5) [junit4:junit4] 1> INFO - 2013-04-12 21:29:04.479; org.apache.solr.core.= CoreContainer; Creating SolrCore 'collection1' using instanceDir: /usr/home= /hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build/solr-= core/test/J1/./org.apache.solr.cloud.ShardSplitTest-jetty4-1365802143013/co= llection1 [junit4:junit4] 1> INFO - 2013-04-12 21:29:04.480; org.apache.solr.cloud= .ZkController; Check for collection zkNode:collection1 [junit4:junit4] 1> INFO - 2013-04-12 21:29:04.481; org.apache.solr.cloud= .ZkController; Collection zkNode exists [junit4:junit4] 1> INFO - 2013-04-12 21:29:04.481; org.apache.solr.cloud= .ZkController; Load collection config from:/collections/collection1 [junit4:junit4] 1> INFO - 2013-04-12 21:29:04.483; org.apache.solr.core.= SolrResourceLoader; new SolrResourceLoader for directory: '/usr/home/hudson= /hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build/solr-core/te= st/J1/./org.apache.solr.cloud.ShardSplitTest-jetty4-1365802143013/collectio= n1/' [junit4:junit4] 1> INFO - 2013-04-12 21:29:04.485; org.apache.solr.core.= SolrResourceLoader; Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lu= cene-Solr-Tests-4.x-java7/solr/build/solr-core/test/J1/org.apache.solr.clou= d.ShardSplitTest-jetty4-1365802143013/collection1/lib/README' to classloade= r [junit4:junit4] 1> INFO - 2013-04-12 21:29:04.485; org.apache.solr.core.= SolrResourceLoader; Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lu= cene-Solr-Tests-4.x-java7/solr/build/solr-core/test/J1/org.apache.solr.clou= d.ShardSplitTest-jetty4-1365802143013/collection1/lib/classes/' to classloa= der [junit4:junit4] 1> INFO - 2013-04-12 21:29:04.536; org.apache.solr.core.= SolrConfig; Using Lucene MatchVersion: LUCENE_43 [junit4:junit4] 1> INFO - 2013-04-12 21:29:04.598; org.apache.solr.core.= SolrConfig; Loaded SolrConfig: solrconfig.xml [junit4:junit4] 1> INFO - 2013-04-12 21:29:04.700; org.apache.solr.schem= a.IndexSchema; Reading Solr Schema from schema.xml [junit4:junit4] 1> INFO - 2013-04-12 21:29:04.707; org.apache.solr.schem= a.IndexSchema; Schema name=3Dtest [junit4:junit4] 1> INFO - 2013-04-12 21:29:05.018; org.apache.solr.handl= er.admin.CoreAdminHandler; Waited coreNodeName: 127.0.0.1:24668__collection= 1, state: recovering, checkLive: true, onlyIfLeader: true for: 2 seconds. [junit4:junit4] 1> INFO - 2013-04-12 21:29:05.018; org.apache.solr.servl= et.SolrDispatchFilter; [admin] webapp=3Dnull path=3D/admin/cores params=3D{= coreNodeName=3D127.0.0.1:24668__collection1&state=3Drecovering&nodeName=3D1= 27.0.0.1:24668_&action=3DPREPRECOVERY&checkLive=3Dtrue&core=3Dcollection1&w= t=3Djavabin&onlyIfLeader=3Dtrue&version=3D2} status=3D0 QTime=3D2003=20 [junit4:junit4] 1> INFO - 2013-04-12 21:29:05.360; org.apache.solr.schem= a.OpenExchangeRatesOrgProvider; Initialized with rates=3Dopen-exchange-rate= s.json, refreshInterval=3D1440. [junit4:junit4] 1> INFO - 2013-04-12 21:29:05.372; org.apache.solr.schem= a.IndexSchema; default search field in schema is text [junit4:junit4] 1> INFO - 2013-04-12 21:29:05.376; org.apache.solr.schem= a.IndexSchema; unique key field: id [junit4:junit4] 1> INFO - 2013-04-12 21:29:05.395; org.apache.solr.schem= a.FileExchangeRateProvider; Reloading exchange rates from file currency.xml [junit4:junit4] 1> INFO - 2013-04-12 21:29:05.400; org.apache.solr.schem= a.FileExchangeRateProvider; Reloading exchange rates from file currency.xml [junit4:junit4] 1> INFO - 2013-04-12 21:29:05.405; org.apache.solr.schem= a.OpenExchangeRatesOrgProvider; Reloading exchange rates from open-exchange= -rates.json [junit4:junit4] 1> WARN - 2013-04-12 21:29:05.406; org.apache.solr.schem= a.OpenExchangeRatesOrgProvider$OpenExchangeRates; Unknown key IMPORTANT NOT= E [junit4:junit4] 1> WARN - 2013-04-12 21:29:05.407; org.apache.solr.schem= a.OpenExchangeRatesOrgProvider$OpenExchangeRates; Expected key, got STRING [junit4:junit4] 1> INFO - 2013-04-12 21:29:05.407; org.apache.solr.schem= a.OpenExchangeRatesOrgProvider; Reloading exchange rates from open-exchange= -rates.json [junit4:junit4] 1> WARN - 2013-04-12 21:29:05.408; org.apache.solr.schem= a.OpenExchangeRatesOrgProvider$OpenExchangeRates; Unknown key IMPORTANT NOT= E [junit4:junit4] 1> WARN - 2013-04-12 21:29:05.409; org.apache.solr.schem= a.OpenExchangeRatesOrgProvider$OpenExchangeRates; Expected key, got STRING [junit4:junit4] 1> INFO - 2013-04-12 21:29:05.409; org.apache.solr.core.= SolrCore; org.apache.solr.core.MockDirectoryFactory [junit4:junit4] 1> INFO - 2013-04-12 21:29:05.409; org.apache.solr.core.= SolrCore; [collection1] Opening new SolrCore at /usr/home/hudson/hudson-sla= ve/workspace/Lucene-Solr-Tests-4.x-java7/solr/build/solr-core/test/J1/./org= .apache.solr.cloud.ShardSplitTest-jetty4-1365802143013/collection1/, dataDi= r=3D./org.apache.solr.cloud.ShardSplitTest-1365802126502/jetty4/ [junit4:junit4] 1> INFO - 2013-04-12 21:29:05.410; org.apache.solr.core.= JmxMonitoredMap; JMX monitoring is enabled. Adding Solr mbeans to JMX Serve= r: com.sun.jmx.mbeanserver.JmxMBeanServer@71880832 [junit4:junit4] 1> INFO - 2013-04-12 21:29:05.410; org.apache.solr.core.= SolrCore; org.apache.solr.core.MockDirectoryFactory [junit4:junit4] 1> INFO - 2013-04-12 21:29:05.411; org.apache.solr.core.= CachingDirectoryFactory; return new directory for ./org.apache.solr.cloud.S= hardSplitTest-1365802126502/jetty4 [junit4:junit4] 1> INFO - 2013-04-12 21:29:05.411; org.apache.solr.core.= SolrCore; New index directory detected: old=3Dnull new=3D./org.apache.solr.= cloud.ShardSplitTest-1365802126502/jetty4/index/ [junit4:junit4] 1> WARN - 2013-04-12 21:29:05.412; org.apache.solr.core.= SolrCore; [collection1] Solr index directory './org.apache.solr.cloud.Shard= SplitTest-1365802126502/jetty4/index' doesn't exist. Creating new index... [junit4:junit4] 1> INFO - 2013-04-12 21:29:05.412; org.apache.solr.core.= CachingDirectoryFactory; return new directory for ./org.apache.solr.cloud.S= hardSplitTest-1365802126502/jetty4/index [junit4:junit4] 1> INFO - 2013-04-12 21:29:05.415; org.apache.solr.core.= SolrDeletionPolicy; SolrDeletionPolicy.onCommit: commits:num=3D1 [junit4:junit4] 1> =09commit{dir=3DMockDirWrapper(org.apache.lucene.store= .RAMDirectory@18ee1aae lockFactory=3Dorg.apache.lucene.store.NativeFSLockFa= ctory@f9df95),segFN=3Dsegments_1,generation=3D1,filenames=3D[segments_1] [junit4:junit4] 1> INFO - 2013-04-12 21:29:05.415; org.apache.solr.core.= SolrDeletionPolicy; newest commit =3D 1[segments_1] [junit4:junit4] 1> INFO - 2013-04-12 21:29:05.418; org.apache.solr.updat= e.processor.UpdateRequestProcessorChain; inserting DistributedUpdateProcess= orFactory into updateRequestProcessorChain "dedupe" [junit4:junit4] 1> INFO - 2013-04-12 21:29:05.419; org.apache.solr.updat= e.processor.UpdateRequestProcessorChain; inserting DistributedUpdateProcess= orFactory into updateRequestProcessorChain "stored_sig" [junit4:junit4] 1> INFO - 2013-04-12 21:29:05.420; org.apache.solr.updat= e.processor.UpdateRequestProcessorChain; inserting DistributedUpdateProcess= orFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit= " [junit4:junit4] 1> INFO - 2013-04-12 21:29:05.420; org.apache.solr.core.= RequestHandlers; created standard: solr.StandardRequestHandler [junit4:junit4] 1> INFO - 2013-04-12 21:29:05.421; org.apache.solr.core.= RequestHandlers; created /get: solr.RealTimeGetHandler [junit4:junit4] 1> INFO - 2013-04-12 21:29:05.421; org.apache.solr.core.= RequestHandlers; adding lazy requestHandler: solr.ReplicationHandler [junit4:junit4] 1> INFO - 2013-04-12 21:29:05.422; org.apache.solr.core.= RequestHandlers; created /replication: solr.ReplicationHandler [junit4:junit4] 1> INFO - 2013-04-12 21:29:05.422; org.apache.solr.core.= RequestHandlers; created /update: solr.UpdateRequestHandler [junit4:junit4] 1> INFO - 2013-04-12 21:29:05.423; org.apache.solr.core.= RequestHandlers; created /admin/: org.apache.solr.handler.admin.AdminHandle= rs [junit4:junit4] 1> INFO - 2013-04-12 21:29:05.435; org.apache.solr.handl= er.loader.XMLLoader; xsltCacheLifetimeSeconds=3D60 [junit4:junit4] 1> INFO - 2013-04-12 21:29:05.441; org.apache.solr.searc= h.SolrIndexSearcher; Opening Searcher@51eaf730 main [junit4:junit4] 1> INFO - 2013-04-12 21:29:05.441; org.apache.solr.updat= e.UpdateHandler; Clearing tlog files, tlogDir=3D./org.apache.solr.cloud.Sha= rdSplitTest-1365802126502/jetty4/tlog [junit4:junit4] 1> INFO - 2013-04-12 21:29:05.442; org.apache.solr.updat= e.CommitTracker; Hard AutoCommit: disabled [junit4:junit4] 1> INFO - 2013-04-12 21:29:05.442; org.apache.solr.updat= e.CommitTracker; Soft AutoCommit: disabled [junit4:junit4] 1> INFO - 2013-04-12 21:29:05.447; org.apache.solr.core.= SolrCore; [collection1] Registered new searcher Searcher@51eaf730 main{Stan= dardDirectoryReader(segments_1:1)} [junit4:junit4] 1> INFO - 2013-04-12 21:29:05.460; org.apache.solr.cloud= .ZkController; publishing core=3Dcollection1 state=3Ddown [junit4:junit4] 1> INFO - 2013-04-12 21:29:05.460; org.apache.solr.cloud= .ZkController; numShards not found on descriptor - reading it from system p= roperty [junit4:junit4] 1> INFO - 2013-04-12 21:29:05.623; org.apache.solr.commo= n.cloud.ZkStateReader; Updating cloud state from ZooKeeper...=20 [junit4:junit4] 1> INFO - 2013-04-12 21:29:05.624; org.apache.solr.cloud= .Overseer$ClusterStateUpdater; Update state numShards=3D2 message=3D{ [junit4:junit4] 1> "operation":"state", [junit4:junit4] 1> "core_node_name":null, [junit4:junit4] 1> "numShards":"2", [junit4:junit4] 1> "shard":null, [junit4:junit4] 1> "roles":null, [junit4:junit4] 1> "state":"down", [junit4:junit4] 1> "shard_state":"active", [junit4:junit4] 1> "core":"collection1", [junit4:junit4] 1> "collection":"collection1", [junit4:junit4] 1> "shard_range":null, [junit4:junit4] 1> "node_name":"127.0.0.1:49988_", [junit4:junit4] 1> "base_url":"http://127.0.0.1:49988"} [junit4:junit4] 1> INFO - 2013-04-12 21:29:05.624; org.apache.solr.cloud= .Overseer$ClusterStateUpdater; Collection already exists with numShards=3D2 [junit4:junit4] 1> INFO - 2013-04-12 21:29:05.624; org.apache.solr.cloud= .Overseer$ClusterStateUpdater; Assigning new node to shard=3Dshard2 [junit4:junit4] 1> INFO - 2013-04-12 21:29:05.638; org.apache.solr.commo= n.cloud.ZkStateReader$2; A cluster state change: WatchedEvent state:SyncCon= nected type:NodeDataChanged path:/clusterstate.json, has occurred - updatin= g... (live nodes size: 5) [junit4:junit4] 1> INFO - 2013-04-12 21:29:05.638; org.apache.solr.commo= n.cloud.ZkStateReader$2; A cluster state change: WatchedEvent state:SyncCon= nected type:NodeDataChanged path:/clusterstate.json, has occurred - updatin= g... (live nodes size: 5) [junit4:junit4] 1> INFO - 2013-04-12 21:29:05.638; org.apache.solr.commo= n.cloud.ZkStateReader$2; A cluster state change: WatchedEvent state:SyncCon= nected type:NodeDataChanged path:/clusterstate.json, has occurred - updatin= g... (live nodes size: 5) [junit4:junit4] 1> INFO - 2013-04-12 21:29:05.638; org.apache.solr.commo= n.cloud.ZkStateReader$2; A cluster state change: WatchedEvent state:SyncCon= nected type:NodeDataChanged path:/clusterstate.json, has occurred - updatin= g... (live nodes size: 5) [junit4:junit4] 1> INFO - 2013-04-12 21:29:05.638; org.apache.solr.commo= n.cloud.ZkStateReader$2; A cluster state change: WatchedEvent state:SyncCon= nected type:NodeDataChanged path:/clusterstate.json, has occurred - updatin= g... (live nodes size: 5) [junit4:junit4] 1> INFO - 2013-04-12 21:29:05.638; org.apache.solr.commo= n.cloud.ZkStateReader$2; A cluster state change: WatchedEvent state:SyncCon= nected type:NodeDataChanged path:/clusterstate.json, has occurred - updatin= g... (live nodes size: 5) [junit4:junit4] 1> INFO - 2013-04-12 21:29:06.464; org.apache.solr.core.= CoreContainer; registering core: collection1 [junit4:junit4] 1> INFO - 2013-04-12 21:29:06.464; org.apache.solr.cloud= .ZkController; Register replica - core:collection1 address:http://127.0.0.1= :49988 collection:collection1 shard:shard2 [junit4:junit4] 1> INFO - 2013-04-12 21:29:06.468; org.apache.solr.cloud= .ZkController; We are http://127.0.0.1:49988/collection1/ and leader is htt= p://127.0.0.1:36990/collection1/ [junit4:junit4] 1> INFO - 2013-04-12 21:29:06.468; org.apache.solr.cloud= .ZkController; No LogReplay needed for core=3Dcollection1 baseURL=3Dhttp://= 127.0.0.1:49988 [junit4:junit4] 1> INFO - 2013-04-12 21:29:06.469; org.apache.solr.cloud= .ZkController; Core needs to recover:collection1 [junit4:junit4] 1> INFO - 2013-04-12 21:29:06.469; org.apache.solr.updat= e.DefaultSolrCoreState; Running recovery - first canceling any ongoing reco= very [junit4:junit4] 1> INFO - 2013-04-12 21:29:06.469; org.apache.solr.cloud= .RecoveryStrategy; Starting recovery process. core=3Dcollection1 recoverin= gAfterStartup=3Dtrue [junit4:junit4] 1> INFO - 2013-04-12 21:29:06.470; org.apache.solr.cloud= .RecoveryStrategy; ###### startupVersions=3D[] [junit4:junit4] 1> INFO - 2013-04-12 21:29:06.470; org.apache.solr.commo= n.cloud.ZkStateReader; Updating cloud state from ZooKeeper...=20 [junit4:junit4] 1> INFO - 2013-04-12 21:29:06.471; org.apache.solr.cloud= .ZkController; publishing core=3Dcollection1 state=3Drecovering [junit4:junit4] 1> INFO - 2013-04-12 21:29:06.471; org.apache.solr.cloud= .ZkController; numShards not found on descriptor - reading it from system p= roperty [junit4:junit4] 1> INFO - 2013-04-12 21:29:06.472; org.apache.solr.servl= et.SolrDispatchFilter; user.dir=3D/usr/home/hudson/hudson-slave/workspace/L= ucene-Solr-Tests-4.x-java7/solr/build/solr-core/test/J1 [junit4:junit4] 1> INFO - 2013-04-12 21:29:06.473; org.apache.solr.servl= et.SolrDispatchFilter; SolrDispatchFilter.init() done [junit4:junit4] 1> INFO - 2013-04-12 21:29:06.473; org.apache.solr.clien= t.solrj.impl.HttpClientUtil; Creating new http client, config:maxConnection= s=3D128&maxConnectionsPerHost=3D32&followRedirects=3Dfalse [junit4:junit4] 1> INFO - 2013-04-12 21:29:06.473; org.apache.solr.clien= t.solrj.impl.HttpClientUtil; Creating new http client, config:maxConnection= s=3D128&maxConnectionsPerHost=3D32&followRedirects=3Dfalse [junit4:junit4] 1> INFO - 2013-04-12 21:29:06.495; org.apache.solr.commo= n.cloud.ZkStateReader; Updating cloud state from ZooKeeper...=20 [junit4:junit4] 1> INFO - 2013-04-12 21:29:06.497; org.apache.solr.handl= er.admin.CoreAdminHandler; Going to wait for coreNodeName: 127.0.0.1:49988_= _collection1, state: recovering, checkLive: true, onlyIfLeader: true [junit4:junit4] 1> INFO - 2013-04-12 21:29:06.497; org.apache.solr.cloud= .AbstractFullDistribZkTestBase; Wait for recoveries to finish - wait 15 for= each attempt [junit4:junit4] 1> INFO - 2013-04-12 21:29:06.498; org.apache.solr.cloud= .AbstractDistribZkTestBase; Wait for recoveries to finish - collection: col= lection1 failOnTimeout:true timeout (sec):15 [junit4:junit4] 1> INFO - 2013-04-12 21:29:06.499; org.apache.solr.commo= n.cloud.ZkStateReader; Updating cloud state from ZooKeeper...=20 [junit4:junit4] 1> INFO - 2013-04-12 21:29:07.020; org.apache.solr.cloud= .RecoveryStrategy; Attempting to PeerSync from http://127.0.0.1:29782/colle= ction1/ core=3Dcollection1 - recoveringAfterStartup=3Dtrue [junit4:junit4] 1> INFO - 2013-04-12 21:29:07.020; org.apache.solr.updat= e.PeerSync; PeerSync: core=3Dcollection1 url=3Dhttp://127.0.0.1:24668 START= replicas=3D[http://127.0.0.1:29782/collection1/] nUpdates=3D100 [junit4:junit4] 1> WARN - 2013-04-12 21:29:07.020; org.apache.solr.updat= e.PeerSync; no frame of reference to tell of we've missed updates [junit4:junit4] 1> INFO - 2013-04-12 21:29:07.021; org.apache.solr.cloud= .RecoveryStrategy; PeerSync Recovery was not successful - trying replicatio= n. core=3Dcollection1 [junit4:junit4] 1> INFO - 2013-04-12 21:29:07.021; org.apache.solr.cloud= .RecoveryStrategy; Starting Replication Recovery. core=3Dcollection1 [junit4:junit4] 1> INFO - 2013-04-12 21:29:07.022; org.apache.solr.cloud= .RecoveryStrategy; Begin buffering updates. core=3Dcollection1 [junit4:junit4] 1> INFO - 2013-04-12 21:29:07.022; org.apache.solr.updat= e.UpdateLog; Starting to buffer updates. FSUpdateLog{state=3DACTIVE, tlog= =3Dnull} [junit4:junit4] 1> INFO - 2013-04-12 21:29:07.022; org.apache.solr.cloud= .RecoveryStrategy; Attempting to replicate from http://127.0.0.1:29782/coll= ection1/. core=3Dcollection1 [junit4:junit4] 1> INFO - 2013-04-12 21:29:07.023; org.apache.solr.clien= t.solrj.impl.HttpClientUtil; Creating new http client, config:maxConnection= s=3D128&maxConnectionsPerHost=3D32&followRedirects=3Dfalse [junit4:junit4] 1> INFO - 2013-04-12 21:29:07.032; org.apache.solr.core.= SolrCore; [collection1] webapp=3D path=3D/get params=3D{getVersions=3D100&d= istrib=3Dfalse&wt=3Djavabin&qt=3D/get&version=3D2} status=3D0 QTime=3D1=20 [junit4:junit4] 1> INFO - 2013-04-12 21:29:07.040; org.apache.solr.updat= e.DirectUpdateHandler2; start commit{,optimize=3Dfalse,openSearcher=3Dfalse= ,waitSearcher=3Dtrue,expungeDeletes=3Dfalse,softCommit=3Dfalse,prepareCommi= t=3Dfalse} [junit4:junit4] 1> INFO - 2013-04-12 21:29:07.042; org.apache.solr.core.= SolrDeletionPolicy; SolrDeletionPolicy.onInit: commits:num=3D1 [junit4:junit4] 1> =09commit{dir=3DMockDirWrapper(org.apache.lucene.store= .RAMDirectory@471c053d lockFactory=3Dorg.apache.lucene.store.NativeFSLockFa= ctory@6e9b7ab8),segFN=3Dsegments_1,generation=3D1,filenames=3D[segments_1] [junit4:junit4] 1> INFO - 2013-04-12 21:29:07.043; org.apache.solr.core.= SolrDeletionPolicy; newest commit =3D 1[segments_1] [junit4:junit4] 1> INFO - 2013-04-12 21:29:07.044; org.apache.solr.core.= SolrDeletionPolicy; SolrDeletionPolicy.onCommit: commits:num=3D2 [junit4:junit4] 1> =09commit{dir=3DMockDirWrapper(org.apache.lucene.store= .RAMDirectory@471c053d lockFactory=3Dorg.apache.lucene.store.NativeFSLockFa= ctory@6e9b7ab8),segFN=3Dsegments_1,generation=3D1,filenames=3D[segments_1] [junit4:junit4] 1> =09commit{dir=3DMockDirWrapper(org.apache.lucene.store= .RAMDirectory@471c053d lockFactory=3Dorg.apache.lucene.store.NativeFSLockFa= ctory@6e9b7ab8),segFN=3Dsegments_2,generation=3D2,filenames=3D[segments_2] [junit4:junit4] 1> INFO - 2013-04-12 21:29:07.044; org.apache.solr.core.= SolrDeletionPolicy; newest commit =3D 2[segments_2] [junit4:junit4] 1> INFO - 2013-04-12 21:29:07.045; org.apache.solr.searc= h.SolrIndexSearcher; Opening Searcher@71a03652 realtime [junit4:junit4] 1> INFO - 2013-04-12 21:29:07.045; org.apache.solr.updat= e.DirectUpdateHandler2; end_commit_flush [junit4:junit4] 1> INFO - 2013-04-12 21:29:07.046; org.apache.solr.updat= e.processor.LogUpdateProcessor; [collection1] webapp=3D path=3D/update para= ms=3D{waitSearcher=3Dtrue&openSearcher=3Dfalse&commit=3Dtrue&wt=3Djavabin&c= ommit_end_point=3Dtrue&version=3D2&softCommit=3Dfalse} {commit=3D} 0 7 [junit4:junit4] 1> INFO - 2013-04-12 21:29:07.047; org.apache.solr.handl= er.ReplicationHandler; Commits will be reserved for 10000 [junit4:junit4] 1> INFO - 2013-04-12 21:29:07.047; org.apache.solr.handl= er.SnapPuller; No value set for 'pollInterval'. Timer Task not started. [junit4:junit4] 1> INFO - 2013-04-12 21:29:07.050; org.apache.solr.handl= er.ReplicationHandler; Commits will be reserved for 10000 [junit4:junit4] 1> INFO - 2013-04-12 21:29:07.050; org.apache.solr.core.= SolrCore; [collection1] webapp=3D path=3D/replication params=3D{command=3Di= ndexversion&qt=3D/replication&wt=3Djavabin&version=3D2} status=3D0 QTime=3D= 1=20 [junit4:junit4] 1> INFO - 2013-04-12 21:29:07.051; org.apache.solr.handl= er.SnapPuller; Master's generation: 2 [junit4:junit4] 1> INFO - 2013-04-12 21:29:07.052; org.apache.solr.handl= er.SnapPuller; Slave's generation: 1 [junit4:junit4] 1> INFO - 2013-04-12 21:29:07.052; org.apache.solr.handl= er.SnapPuller; Starting replication process [junit4:junit4] 1> INFO - 2013-04-12 21:29:07.054; org.apache.solr.core.= SolrCore; [collection1] webapp=3D path=3D/replication params=3D{command=3Df= ilelist&qt=3D/replication&wt=3Djavabin&generation=3D2&version=3D2} status= =3D0 QTime=3D0=20 [junit4:junit4] 1> INFO - 2013-04-12 21:29:07.055; org.apache.solr.handl= er.SnapPuller; Number of files in latest index in master: 1 [junit4:junit4] 1> INFO - 2013-04-12 21:29:07.057; org.apache.solr.core.= CachingDirectoryFactory; return new directory for ./org.apache.solr.cloud.S= hardSplitTest-1365802126502/jetty3/index.20130412182907056 [junit4:junit4] 1> INFO - 2013-04-12 21:29:07.057; org.apache.solr.handl= er.SnapPuller; Starting download to MockDirWrapper(org.apache.lucene.store.= RAMDirectory@75aa25ff lockFactory=3Dorg.apache.lucene.store.NativeFSLockFac= tory@30f2fdcd) fullCopy=3Dfalse [junit4:junit4] 1> INFO - 2013-04-12 21:29:07.060; org.apache.solr.core.= SolrCore; [collection1] webapp=3D path=3D/replication params=3D{file=3Dsegm= ents_2&command=3Dfilecontent&checksum=3Dtrue&wt=3Dfilestream&qt=3D/replicat= ion&generation=3D2} status=3D0 QTime=3D0=20 [junit4:junit4] 1> INFO - 2013-04-12 21:29:07.062; org.apache.solr.handl= er.SnapPuller; Total time taken for download : 0 secs [junit4:junit4] 1> INFO - 2013-04-12 21:29:07.063; org.apache.solr.updat= e.DefaultSolrCoreState; Creating new IndexWriter... [junit4:junit4] 1> INFO - 2013-04-12 21:29:07.064; org.apache.solr.updat= e.DefaultSolrCoreState; Waiting until IndexWriter is unused... core=3Dcolle= ction1 [junit4:junit4] 1> INFO - 2013-04-12 21:29:07.065; org.apache.solr.core.= SolrDeletionPolicy; SolrDeletionPolicy.onInit: commits:num=3D2 [junit4:junit4] 1> =09commit{dir=3DMockDirWrapper(org.apache.lucene.store= .RAMDirectory@32f6a701 lockFactory=3Dorg.apache.lucene.store.NativeFSLockFa= ctory@53815a8e),segFN=3Dsegments_1,generation=3D1,filenames=3D[segments_1] [junit4:junit4] 1> =09commit{dir=3DMockDirWrapper(org.apache.lucene.store= .RAMDirectory@32f6a701 lockFactory=3Dorg.apache.lucene.store.NativeFSLockFa= ctory@53815a8e),segFN=3Dsegments_2,generation=3D2,filenames=3D[segments_2] [junit4:junit4] 1> INFO - 2013-04-12 21:29:07.066; org.apache.solr.core.= SolrDeletionPolicy; newest commit =3D 2[segments_2] [junit4:junit4] 1> INFO - 2013-04-12 21:29:07.066; org.apache.solr.updat= e.DefaultSolrCoreState; New IndexWriter is ready to be used. [junit4:junit4] 1> INFO - 2013-04-12 21:29:07.067; org.apache.solr.searc= h.SolrIndexSearcher; Opening Searcher@6bde27b9 main [junit4:junit4] 1> INFO - 2013-04-12 21:29:07.068; org.apache.solr.core.= SolrCore; [collection1] Registered new searcher Searcher@6bde27b9 main{Stan= dardDirectoryReader(segments_2:1:nrt)} [junit4:junit4] 1> INFO - 2013-04-12 21:29:07.069; org.apache.solr.core.= CachingDirectoryFactory; looking to close ./org.apache.solr.cloud.ShardSpli= tTest-1365802126502/jetty3/index.20130412182907056 [CachedDir<>] [junit4:junit4] 1> INFO - 2013-04-12 21:29:07.069; org.apache.solr.core.= CachingDirectoryFactory; Closing directory: ./org.apache.solr.cloud.ShardSp= litTest-1365802126502/jetty3/index.20130412182907056 [junit4:junit4] 1> INFO - 2013-04-12 21:29:07.069; org.apache.solr.core.= CachingDirectoryFactory; Removing directory before core close: ./org.apache= .solr.cloud.ShardSplitTest-1365802126502/jetty3/index.20130412182907056 [junit4:junit4] 1> INFO - 2013-04-12 21:29:07.070; org.apache.solr.cloud= .RecoveryStrategy; No replay needed. core=3Dcollection1 [junit4:junit4] 1> INFO - 2013-04-12 21:29:07.070; org.apache.solr.cloud= .RecoveryStrategy; Replication Recovery was successful - registering as Act= ive. core=3Dcollection1 [junit4:junit4] 1> INFO - 2013-04-12 21:29:07.070; org.apache.solr.cloud= .ZkController; publishing core=3Dcollection1 state=3Dactive [junit4:junit4] 1> INFO - 2013-04-12 21:29:07.070; org.apache.solr.cloud= .ZkController; numShards not found on descriptor - reading it from system p= roperty [junit4:junit4] 1> INFO - 2013-04-12 21:29:07.072; org.apache.solr.cloud= .RecoveryStrategy; Finished recovery process. core=3Dcollection1 [junit4:junit4] 1> INFO - 2013-04-12 21:29:07.143; org.apache.solr.commo= n.cloud.ZkStateReader; Updating cloud state from ZooKeeper...=20 [junit4:junit4] 1> INFO - 2013-04-12 21:29:07.143; org.apache.solr.cloud= .Overseer$ClusterStateUpdater; Update state numShards=3D2 message=3D{ [junit4:junit4] 1> "operation":"state", [junit4:junit4] 1> "core_node_name":"127.0.0.1:49988__collection1", [junit4:junit4] 1> "numShards":"2", [junit4:junit4] 1> "shard":"shard2", [junit4:junit4] 1> "roles":null, [junit4:junit4] 1> "state":"recovering", [junit4:junit4] 1> "shard_state":"active", [junit4:junit4] 1> "core":"collection1", [junit4:junit4] 1> "collection":"collection1", [junit4:junit4] 1> "shard_range":null, [junit4:junit4] 1> "node_name":"127.0.0.1:49988_", [junit4:junit4] 1> "base_url":"http://127.0.0.1:49988"} [junit4:junit4] 1> INFO - 2013-04-12 21:29:07.148; org.apache.solr.cloud= .Overseer$ClusterStateUpdater; Update state numShards=3D2 message=3D{ [junit4:junit4] 1> "operation":"state", [junit4:junit4] 1> "core_node_name":"127.0.0.1:24668__collection1", [junit4:junit4] 1> "numShards":"2", [junit4:junit4] 1> "shard":"shard1", [junit4:junit4] 1> "roles":null, [junit4:junit4] 1> "state":"active", [junit4:junit4] 1> "shard_state":"active", [junit4:junit4] 1> "core":"collection1", [junit4:junit4] 1> "collection":"collection1", [junit4:junit4] 1> "shard_range":null, [junit4:junit4] 1> "node_name":"127.0.0.1:24668_", [junit4:junit4] 1> "base_url":"http://127.0.0.1:24668"} [junit4:junit4] 1> INFO - 2013-04-12 21:29:07.160; org.apache.solr.commo= n.cloud.ZkStateReader$2; A cluster state change: WatchedEvent state:SyncCon= nected type:NodeDataChanged path:/clusterstate.json, has occurred - updatin= g... (live nodes size: 5) [junit4:junit4] 1> INFO - 2013-04-12 21:29:07.160; org.apache.solr.commo= n.cloud.ZkStateReader$2; A cluster state change: WatchedEvent state:SyncCon= nected type:NodeDataChanged path:/clusterstate.json, has occurred - updatin= g... (live nodes size: 5) [junit4:junit4] 1> INFO - 2013-04-12 21:29:07.160; org.apache.solr.commo= n.cloud.ZkStateReader$2; A cluster state change: WatchedEvent state:SyncCon= nected type:NodeDataChanged path:/clusterstate.json, has occurred - updatin= g... (live nodes size: 5) [junit4:junit4] 1> INFO - 2013-04-12 21:29:07.160; org.apache.solr.commo= n.cloud.ZkStateReader$2; A cluster state change: WatchedEvent state:SyncCon= nected type:NodeDataChanged path:/clusterstate.json, has occurred - updatin= g... (live nodes size: 5) [junit4:junit4] 1> INFO - 2013-04-12 21:29:07.160; org.apache.solr.commo= n.cloud.ZkStateReader$2; A cluster state change: WatchedEvent state:SyncCon= nected type:NodeDataChanged path:/clusterstate.json, has occurred - updatin= g... (live nodes size: 5) [junit4:junit4] 1> INFO - 2013-04-12 21:29:07.160; org.apache.solr.commo= n.cloud.ZkStateReader$2; A cluster state change: WatchedEvent state:SyncCon= nected type:NodeDataChanged path:/clusterstate.json, has occurred - updatin= g... (live nodes size: 5) [junit4:junit4] 1> INFO - 2013-04-12 21:29:07.498; org.apache.solr.handl= er.admin.CoreAdminHandler; Waited coreNodeName: 127.0.0.1:49988__collection= 1, state: recovering, checkLive: true, onlyIfLeader: true for: 1 seconds. [junit4:junit4] 1> INFO - 2013-04-12 21:29:07.498; org.apache.solr.servl= et.SolrDispatchFilter; [admin] webapp=3Dnull path=3D/admin/cores params=3D{= coreNodeName=3D127.0.0.1:49988__collection1&state=3Drecovering&nodeName=3D1= 27.0.0.1:49988_&action=3DPREPRECOVERY&checkLive=3Dtrue&core=3Dcollection1&w= t=3Djavabin&onlyIfLeader=3Dtrue&version=3D2} status=3D0 QTime=3D1001=20 [junit4:junit4] 1> INFO - 2013-04-12 21:29:07.501; org.apache.solr.commo= n.cloud.ZkStateReader; Updating cloud state from ZooKeeper...=20 [junit4:junit4] 1> INFO - 2013-04-12 21:29:08.503; org.apache.solr.commo= n.cloud.ZkStateReader; Updating cloud state from ZooKeeper...=20 [junit4:junit4] 1> INFO - 2013-04-12 21:29:09.500; org.apache.solr.cloud= .RecoveryStrategy; Attempting to PeerSync from http://127.0.0.1:36990/colle= ction1/ core=3Dcollection1 - recoveringAfterStartup=3Dtrue [junit4:junit4] 1> INFO - 2013-04-12 21:29:09.500; org.apache.solr.updat= e.PeerSync; PeerSync: core=3Dcollection1 url=3Dhttp://127.0.0.1:49988 START= replicas=3D[http://127.0.0.1:36990/collection1/] nUpdates=3D100 [junit4:junit4] 1> WARN - 2013-04-12 21:29:09.501; org.apache.solr.updat= e.PeerSync; no frame of reference to tell of we've missed updates [junit4:junit4] 1> INFO - 2013-04-12 21:29:09.501; org.apache.solr.cloud= .RecoveryStrategy; PeerSync Recovery was not successful - trying replicatio= n. core=3Dcollection1 [junit4:junit4] 1> INFO - 2013-04-12 21:29:09.501; org.apache.solr.cloud= .RecoveryStrategy; Starting Replication Recovery. core=3Dcollection1 [junit4:junit4] 1> INFO - 2013-04-12 21:29:09.501; org.apache.solr.cloud= .RecoveryStrategy; Begin buffering updates. core=3Dcollection1 [junit4:junit4] 1> INFO - 2013-04-12 21:29:09.502; org.apache.solr.updat= e.UpdateLog; Starting to buffer updates. FSUpdateLog{state=3DACTIVE, tlog= =3Dnull} [junit4:junit4] 1> INFO - 2013-04-12 21:29:09.502; org.apache.solr.cloud= .RecoveryStrategy; Attempting to replicate from http://127.0.0.1:36990/coll= ection1/. core=3Dcollection1 [junit4:junit4] 1> INFO - 2013-04-12 21:29:09.503; org.apache.solr.clien= t.solrj.impl.HttpClientUtil; Creating new http client, config:maxConnection= s=3D128&maxConnectionsPerHost=3D32&followRedirects=3Dfalse [junit4:junit4] 1> INFO - 2013-04-12 21:29:09.506; org.apache.solr.commo= n.cloud.ZkStateReader; Updating cloud state from ZooKeeper...=20 [junit4:junit4] 1> INFO - 2013-04-12 21:29:09.509; org.apache.solr.core.= SolrCore; [collection1] webapp=3D path=3D/get params=3D{getVersions=3D100&d= istrib=3Dfalse&wt=3Djavabin&qt=3D/get&version=3D2} status=3D0 QTime=3D0=20 [junit4:junit4] 1> INFO - 2013-04-12 21:29:09.516; org.apache.solr.updat= e.DirectUpdateHandler2; start commit{,optimize=3Dfalse,openSearcher=3Dfalse= ,waitSearcher=3Dtrue,expungeDeletes=3Dfalse,softCommit=3Dfalse,prepareCommi= t=3Dfalse} [junit4:junit4] 1> INFO - 2013-04-12 21:29:09.519; org.apache.solr.core.= SolrDeletionPolicy; SolrDeletionPolicy.onInit: commits:num=3D1 [junit4:junit4] 1> =09commit{dir=3DMockDirWrapper(org.apache.lucene.store= .RAMDirectory@3bf9e38f lockFactory=3Dorg.apache.lucene.store.NativeFSLockFa= ctory@34407323),segFN=3Dsegments_1,generation=3D1,filenames=3D[segments_1] [junit4:junit4] 1> INFO - 2013-04-12 21:29:09.519; org.apache.solr.core.= SolrDeletionPolicy; newest commit =3D 1[segments_1] [junit4:junit4] 1> INFO - 2013-04-12 21:29:09.520; org.apache.solr.core.= SolrDeletionPolicy; SolrDeletionPolicy.onCommit: commits:num=3D2 [junit4:junit4] 1> =09commit{dir=3DMockDirWrapper(org.apache.lucene.store= .RAMDirectory@3bf9e38f lockFactory=3Dorg.apache.lucene.store.NativeFSLockFa= ctory@34407323),segFN=3Dsegments_1,generation=3D1,filenames=3D[segments_1] [junit4:junit4] 1> =09commit{dir=3DMockDirWrapper(org.apache.lucene.store= .RAMDirectory@3bf9e38f lockFactory=3Dorg.apache.lucene.store.NativeFSLockFa= ctory@34407323),segFN=3Dsegments_2,generation=3D2,filenames=3D[segments_2] [junit4:junit4] 1> INFO - 2013-04-12 21:29:09.521; org.apache.solr.core.= SolrDeletionPolicy; newest commit =3D 2[segments_2] [junit4:junit4] 1> INFO - 2013-04-12 21:29:09.521; org.apache.solr.searc= h.SolrIndexSearcher; Opening Searcher@15ad241f realtime [junit4:junit4] 1> INFO - 2013-04-12 21:29:09.522; org.apache.solr.updat= e.DirectUpdateHandler2; end_commit_flush [junit4:junit4] 1> INFO - 2013-04-12 21:29:09.522; org.apache.solr.updat= e.processor.LogUpdateProcessor; [collection1] webapp=3D path=3D/update para= ms=3D{waitSearcher=3Dtrue&openSearcher=3Dfalse&commit=3Dtrue&wt=3Djavabin&c= ommit_end_point=3Dtrue&version=3D2&softCommit=3Dfalse} {commit=3D} 0 6 [junit4:junit4] 1> INFO - 2013-04-12 21:29:09.523; org.apache.solr.handl= er.ReplicationHandler; Commits will be reserved for 10000 [junit4:junit4] 1> INFO - 2013-04-12 21:29:09.524; org.apache.solr.handl= er.SnapPuller; No value set for 'pollInterval'. Timer Task not started. [junit4:junit4] 1> INFO - 2013-04-12 21:29:09.526; org.apache.solr.handl= er.ReplicationHandler; Commits will be reserved for 10000 [junit4:junit4] 1> INFO - 2013-04-12 21:29:09.526; org.apache.solr.core.= SolrCore; [collection1] webapp=3D path=3D/replication params=3D{command=3Di= ndexversion&qt=3D/replication&wt=3Djavabin&version=3D2} status=3D0 QTime=3D= 1=20 [junit4:junit4] 1> INFO - 2013-04-12 21:29:09.527; org.apache.solr.handl= er.SnapPuller; Master's generation: 2 [junit4:junit4] 1> INFO - 2013-04-12 21:29:09.527; org.apache.solr.handl= er.SnapPuller; Slave's generation: 1 [junit4:junit4] 1> INFO - 2013-04-12 21:29:09.528; org.apache.solr.handl= er.SnapPuller; Starting replication process [junit4:junit4] 1> INFO - 2013-04-12 21:29:09.530; org.apache.solr.core.= SolrCore; [collection1] webapp=3D path=3D/replication params=3D{command=3Df= ilelist&qt=3D/replication&wt=3Djavabin&generation=3D2&version=3D2} status= =3D0 QTime=3D0=20 [junit4:junit4] 1> INFO - 2013-04-12 21:29:09.531; org.apache.solr.handl= er.SnapPuller; Number of files in latest index in master: 1 [junit4:junit4] 1> INFO - 2013-04-12 21:29:09.532; org.apache.solr.core.= CachingDirectoryFactory; return new directory for ./org.apache.solr.cloud.S= hardSplitTest-1365802126502/jetty4/index.20130412182909532 [junit4:junit4] 1> INFO - 2013-04-12 21:29:09.532; org.apache.solr.handl= er.SnapPuller; Starting download to MockDirWrapper(org.apache.lucene.store.= RAMDirectory@4f3a92dd lockFactory=3Dorg.apache.lucene.store.NativeFSLockFac= tory@1b2b9836) fullCopy=3Dfalse [junit4:junit4] 1> INFO - 2013-04-12 21:29:09.535; org.apache.solr.core.= SolrCore; [collection1] webapp=3D path=3D/replication params=3D{file=3Dsegm= ents_2&command=3Dfilecontent&checksum=3Dtrue&wt=3Dfilestream&qt=3D/replicat= ion&generation=3D2} status=3D0 QTime=3D0=20 [junit4:junit4] 1> INFO - 2013-04-12 21:29:09.536; org.apache.solr.handl= er.SnapPuller; Total time taken for download : 0 secs [junit4:junit4] 1> INFO - 2013-04-12 21:29:09.538; org.apache.solr.updat= e.DefaultSolrCoreState; Creating new IndexWriter... [junit4:junit4] 1> INFO - 2013-04-12 21:29:09.538; org.apache.solr.updat= e.DefaultSolrCoreState; Waiting until IndexWriter is unused... core=3Dcolle= ction1 [junit4:junit4] 1> INFO - 2013-04-12 21:29:09.540; org.apache.solr.core.= SolrDeletionPolicy; SolrDeletionPolicy.onInit: commits:num=3D2 [junit4:junit4] 1> =09commit{dir=3DMockDirWrapper(org.apache.lucene.store= .RAMDirectory@18ee1aae lockFactory=3Dorg.apache.lucene.store.NativeFSLockFa= ctory@f9df95),segFN=3Dsegments_1,generation=3D1,filenames=3D[segments_1] [junit4:junit4] 1> =09commit{dir=3DMockDirWrapper(org.apache.lucene.store= .RAMDirectory@18ee1aae lockFactory=3Dorg.apache.lucene.store.NativeFSLockFa= ctory@f9df95),segFN=3Dsegments_2,generation=3D2,filenames=3D[segments_2] [junit4:junit4] 1> INFO - 2013-04-12 21:29:09.540; org.apache.solr.core.= SolrDeletionPolicy; newest commit =3D 2[segments_2] [junit4:junit4] 1> INFO - 2013-04-12 21:29:09.541; org.apache.solr.updat= e.DefaultSolrCoreState; New IndexWriter is ready to be used. [junit4:junit4] 1> INFO - 2013-04-12 21:29:09.541; org.apache.solr.searc= h.SolrIndexSearcher; Opening Searcher@34560144 main [junit4:junit4] 1> INFO - 2013-04-12 21:29:09.542; org.apache.solr.core.= SolrCore; [collection1] Registered new searcher Searcher@34560144 main{Stan= dardDirectoryReader(segments_2:1:nrt)} [junit4:junit4] 1> INFO - 2013-04-12 21:29:09.543; org.apache.solr.core.= CachingDirectoryFactory; looking to close ./org.apache.solr.cloud.ShardSpli= tTest-1365802126502/jetty4/index.20130412182909532 [CachedDir<>] [junit4:junit4] 1> INFO - 2013-04-12 21:29:09.543; org.apache.solr.core.= CachingDirectoryFactory; Closing directory: ./org.apache.solr.cloud.ShardSp= litTest-1365802126502/jetty4/index.20130412182909532 [junit4:junit4] 1> INFO - 2013-04-12 21:29:09.543; org.apache.solr.core.= CachingDirectoryFactory; Removing directory before core close: ./org.apache= .solr.cloud.ShardSplitTest-1365802126502/jetty4/index.20130412182909532 [junit4:junit4] 1> INFO - 2013-04-12 21:29:09.544; org.apache.solr.cloud= .RecoveryStrategy; No replay needed. core=3Dcollection1 [junit4:junit4] 1> INFO - 2013-04-12 21:29:09.544; org.apache.solr.cloud= .RecoveryStrategy; Replication Recovery was successful - registering as Act= ive. core=3Dcollection1 [junit4:junit4] 1> INFO - 2013-04-12 21:29:09.544; org.apache.solr.cloud= .ZkController; publishing core=3Dcollection1 state=3Dactive [junit4:junit4] 1> INFO - 2013-04-12 21:29:09.544; org.apache.solr.cloud= .ZkController; numShards not found on descriptor - reading it from system p= roperty [junit4:junit4] 1> INFO - 2013-04-12 21:29:09.546; org.apache.solr.cloud= .RecoveryStrategy; Finished recovery process. core=3Dcollection1 [junit4:junit4] 1> INFO - 2013-04-12 21:29:10.177; org.apache.solr.commo= n.cloud.ZkStateReader; Updating cloud state from ZooKeeper...=20 [junit4:junit4] 1> INFO - 2013-04-12 21:29:10.178; org.apache.solr.cloud= .Overseer$ClusterStateUpdater; Update state numShards=3D2 message=3D{ [junit4:junit4] 1> "operation":"state", [junit4:junit4] 1> "core_node_name":"127.0.0.1:49988__collection1", [junit4:junit4] 1> "numShards":"2", [junit4:junit4] 1> "shard":"shard2", [junit4:junit4] 1> "roles":null, [junit4:junit4] 1> "state":"active", [junit4:junit4] 1> "shard_state":"active", [junit4:junit4] 1> "core":"collection1", [junit4:junit4] 1> "collection":"collection1", [junit4:junit4] 1> "shard_range":null, [junit4:junit4] 1> "node_name":"127.0.0.1:49988_", [junit4:junit4] 1> "base_url":"http://127.0.0.1:49988"} [junit4:junit4] 1> INFO - 2013-04-12 21:29:10.196; org.apache.solr.commo= n.cloud.ZkStateReader$2; A cluster state change: WatchedEvent state:SyncCon= nected type:NodeDataChanged path:/clusterstate.json, has occurred - updatin= g... (live nodes size: 5) [junit4:junit4] 1> INFO - 2013-04-12 21:29:10.196; org.apache.solr.commo= n.cloud.ZkStateReader$2; A cluster state change: WatchedEvent state:SyncCon= nected type:NodeDataChanged path:/clusterstate.json, has occurred - updatin= g... (live nodes size: 5) [junit4:junit4] 1> INFO - 2013-04-12 21:29:10.196; org.apache.solr.commo= n.cloud.ZkStateReader$2; A cluster state change: WatchedEvent state:SyncCon= nected type:NodeDataChanged path:/clusterstate.json, has occurred - updatin= g... (live nodes size: 5) [junit4:junit4] 1> INFO - 2013-04-12 21:29:10.196; org.apache.solr.commo= n.cloud.ZkStateReader$2; A cluster state change: WatchedEvent state:SyncCon= nected type:NodeDataChanged path:/clusterstate.json, has occurred - updatin= g... (live nodes size: 5) [junit4:junit4] 1> INFO - 2013-04-12 21:29:10.196; org.apache.solr.commo= n.cloud.ZkStateReader$2; A cluster state change: WatchedEvent state:SyncCon= nected type:NodeDataChanged path:/clusterstate.json, has occurred - updatin= g... (live nodes size: 5) [junit4:junit4] 1> INFO - 2013-04-12 21:29:10.196; org.apache.solr.commo= n.cloud.ZkStateReader$2; A cluster state change: WatchedEvent state:SyncCon= nected type:NodeDataChanged path:/clusterstate.json, has occurred - updatin= g... (live nodes size: 5) [junit4:junit4] 1> INFO - 2013-04-12 21:29:10.509; org.apache.solr.commo= n.cloud.ZkStateReader; Updating cloud state from ZooKeeper...=20 [junit4:junit4] 1> INFO - 2013-04-12 21:29:10.510; org.apache.solr.cloud= .AbstractDistribZkTestBase; Recoveries finished - collection: collection1 [junit4:junit4] 1> INFO - 2013-04-12 21:29:10.519; org.apache.solr.updat= e.DirectUpdateHandler2; start commit{,optimize=3Dfalse,openSearcher=3Dtrue,= waitSearcher=3Dtrue,expungeDeletes=3Dfalse,softCommit=3Dfalse,prepareCommit= =3Dfalse} [junit4:junit4] 1> INFO - 2013-04-12 21:29:10.522; org.apache.solr.core.= SolrDeletionPolicy; SolrDeletionPolicy.onInit: commits:num=3D1 [junit4:junit4] 1> =09commit{dir=3DMockDirWrapper(org.apache.lucene.store= .RAMDirectory@42e5f0e7 lockFactory=3Dorg.apache.lucene.store.NativeFSLockFa= ctory@3a71db91),segFN=3Dsegments_1,generation=3D1,filenames=3D[segments_1] [junit4:junit4] 1> INFO - 2013-04-12 21:29:10.522; org.apache.solr.core.= SolrDeletionPolicy; newest commit =3D 1[segments_1] [junit4:junit4] 1> INFO - 2013-04-12 21:29:10.523; org.apache.solr.core.= SolrDeletionPolicy; SolrDeletionPolicy.onCommit: commits:num=3D2 [junit4:junit4] 1> =09commit{dir=3DMockDirWrapper(org.apache.lucene.store= .RAMDirectory@42e5f0e7 lockFactory=3Dorg.apache.lucene.store.NativeFSLockFa= ctory@3a71db91),segFN=3Dsegments_1,generation=3D1,filenames=3D[segments_1] [junit4:junit4] 1> =09commit{dir=3DMockDirWrapper(org.apache.lucene.store= .RAMDirectory@42e5f0e7 lockFactory=3Dorg.apache.lucene.store.NativeFSLockFa= ctory@3a71db91),segFN=3Dsegments_2,generation=3D2,filenames=3D[segments_2] [junit4:junit4] 1> INFO - 2013-04-12 21:29:10.524; org.apache.solr.core.= SolrDeletionPolicy; newest commit =3D 2[segments_2] [junit4:junit4] 1> INFO - 2013-04-12 21:29:10.525; org.apache.solr.searc= h.SolrIndexSearcher; Opening Searcher@694ce2dd main [junit4:junit4] 1> INFO - 2013-04-12 21:29:10.525; org.apache.solr.updat= e.DirectUpdateHandler2; end_commit_flush [junit4:junit4] 1> INFO - 2013-04-12 21:29:10.526; org.apache.solr.core.= SolrCore; [collection1] Registered new searcher Searcher@694ce2dd main{Stan= dardDirectoryReader(segments_2:1:nrt)} [junit4:junit4] 1> INFO - 2013-04-12 21:29:10.527; org.apache.solr.updat= e.processor.LogUpdateProcessor; [collection1] webapp=3D path=3D/update para= ms=3D{waitSearcher=3Dtrue&commit=3Dtrue&wt=3Djavabin&version=3D2&softCommit= =3Dfalse} {commit=3D} 0 8 [junit4:junit4] 1> INFO - 2013-04-12 21:29:10.540; org.apache.solr.updat= e.DirectUpdateHandler2; start commit{,optimize=3Dfalse,openSearcher=3Dtrue,= waitSearcher=3Dtrue,expungeDeletes=3Dfalse,softCommit=3Dfalse,prepareCommit= =3Dfalse} [junit4:junit4] 1> INFO - 2013-04-12 21:29:10.542; org.apache.solr.core.= SolrDeletionPolicy; SolrDeletionPolicy.onCommit: commits:num=3D2 [junit4:junit4] 1> =09commit{dir=3DMockDirWrapper(org.apache.lucene.store= .RAMDirectory@471c053d lockFactory=3Dorg.apache.lucene.store.NativeFSLockFa= ctory@6e9b7ab8),segFN=3Dsegments_2,generation=3D2,filenames=3D[segments_2] [junit4:junit4] 1> =09commit{dir=3DMockDirWrapper(org.apache.lucene.store= .RAMDirectory@471c053d lockFactory=3Dorg.apache.lucene.store.NativeFSLockFa= ctory@6e9b7ab8),segFN=3Dsegments_3,generation=3D3,filenames=3D[segments_3] [junit4:junit4] 1> INFO - 2013-04-12 21:29:10.542; org.apache.solr.core.= SolrDeletionPolicy; newest commit =3D 3[segments_3] [junit4:junit4] 1> INFO - 2013-04-12 21:29:10.543; org.apache.solr.searc= h.SolrIndexSearcher; Opening Searcher@20b9f0d0 main [junit4:junit4] 1> INFO - 2013-04-12 21:29:10.543; org.apache.solr.updat= e.DirectUpdateHandler2; end_commit_flush [junit4:junit4] 1> INFO - 2013-04-12 21:29:10.544; org.apache.solr.core.= SolrCore; [collection1] Registered new searcher Searcher@20b9f0d0 main{Stan= dardDirectoryReader(segments_2:1:nrt)} [junit4:junit4] 1> INFO - 2013-04-12 21:29:10.545; org.apache.solr.updat= e.SolrCmdDistributor; Distrib commit to:[StdNode: http://127.0.0.1:24668/co= llection1/, StdNode: http://127.0.0.1:36990/collection1/, StdNode: http://1= 27.0.0.1:49988/collection1/] params:commit_end_point=3Dtrue&commit=3Dtrue&s= oftCommit=3Dfalse&waitSearcher=3Dtrue&expungeDeletes=3Dfalse [junit4:junit4] 1> INFO - 2013-04-12 21:29:10.549; org.apache.solr.updat= e.DirectUpdateHandler2; start commit{,optimize=3Dfalse,openSearcher=3Dtrue,= waitSearcher=3Dtrue,expungeDeletes=3Dfalse,softCommit=3Dfalse,prepareCommit= =3Dfalse} [junit4:junit4] 1> INFO - 2013-04-12 21:29:10.550; org.apache.solr.core.= SolrDeletionPolicy; SolrDeletionPolicy.onCommit: commits:num=3D2 [junit4:junit4] 1> =09commit{dir=3DMockDirWrapper(org.apache.lucene.store= .RAMDirectory@3bf9e38f lockFactory=3Dorg.apache.lucene.store.NativeFSLockFa= ctory@34407323),segFN=3Dsegments_2,generation=3D2,filenames=3D[segments_2] [junit4:junit4] 1> =09commit{dir=3DMockDirWrapper(org.apache.lucene.store= .RAMDirectory@3bf9e38f lockFactory=3Dorg.apache.lucene.store.NativeFSLockFa= ctory@34407323),segFN=3Dsegments_3,generation=3D3,filenames=3D[segments_3] [junit4:junit4] 1> INFO - 2013-04-12 21:29:10.551; org.apache.solr.core.= SolrDeletionPolicy; newest commit =3D 3[segments_3] [junit4:junit4] 1> INFO - 2013-04-12 21:29:10.551; org.apache.solr.searc= h.SolrIndexSearcher; Opening Searcher@1f8b314c main [junit4:junit4] 1> INFO - 2013-04-12 21:29:10.552; org.apache.solr.updat= e.DirectUpdateHandler2; end_commit_flush [junit4:junit4] 1> INFO - 2013-04-12 21:29:10.553; org.apache.solr.core.= SolrCore; [collection1] Registered new searcher Searcher@1f8b314c main{Stan= dardDirectoryReader(segments_2:1:nrt)} [junit4:junit4] 1> INFO - 2013-04-12 21:29:10.554; org.apache.solr.updat= e.processor.LogUpdateProcessor; [collection1] webapp=3D path=3D/update para= ms=3D{waitSearcher=3Dtrue&commit=3Dtrue&wt=3Djavabin&expungeDeletes=3Dfalse= &commit_end_point=3Dtrue&version=3D2&softCommit=3Dfalse} {commit=3D} 0 4 [junit4:junit4] 1> INFO - 2013-04-12 21:29:10.555; org.apache.solr.updat= e.DirectUpdateHandler2; start commit{,optimize=3Dfalse,openSearcher=3Dtrue,= waitSearcher=3Dtrue,expungeDeletes=3Dfalse,softCommit=3Dfalse,prepareCommit= =3Dfalse} [junit4:junit4] 1> INFO - 2013-04-12 21:29:10.555; org.apache.solr.updat= e.DirectUpdateHandler2; start commit{,optimize=3Dfalse,openSearcher=3Dtrue,= waitSearcher=3Dtrue,expungeDeletes=3Dfalse,softCommit=3Dfalse,prepareCommit= =3Dfalse} [junit4:junit4] 1> INFO - 2013-04-12 21:29:10.556; org.apache.solr.core.= SolrDeletionPolicy; SolrDeletionPolicy.onCommit: commits:num=3D2 [junit4:junit4] 1> =09commit{dir=3DMockDirWrapper(org.apache.lucene.store= .RAMDirectory@32f6a701 lockFactory=3Dorg.apache.lucene.store.NativeFSLockFa= ctory@53815a8e),segFN=3Dsegments_2,generation=3D2,filenames=3D[segments_2] [junit4:junit4] 1> =09commit{dir=3DMockDirWrapper(org.apache.lucene.store= .RAMDirectory@32f6a701 lockFactory=3Dorg.apache.lucene.store.NativeFSLockFa= ctory@53815a8e),segFN=3Dsegments_3,generation=3D3,filenames=3D[segments_3] [junit4:junit4] 1> INFO - 2013-04-12 21:29:10.556; org.apache.solr.core.= SolrDeletionPolicy; SolrDeletionPolicy.onCommit: commits:num=3D2 [junit4:junit4] 1> =09commit{dir=3DMockDirWrapper(org.apache.lucene.store= .RAMDirectory@18ee1aae lockFactory=3Dorg.apache.lucene.store.NativeFSLockFa= ctory@f9df95),segFN=3Dsegments_2,generation=3D2,filenames=3D[segments_2] [junit4:junit4] 1> =09commit{dir=3DMockDirWrapper(org.apache.lucene.store= .RAMDirectory@18ee1aae lockFactory=3Dorg.apache.lucene.store.NativeFSLockFa= ctory@f9df95),segFN=3Dsegments_3,generation=3D3,filenames=3D[segments_3] [junit4:junit4] 1> INFO - 2013-04-12 21:29:10.557; org.apache.solr.core.= SolrDeletionPolicy; newest commit =3D 3[segments_3] [junit4:junit4] 1> INFO - 2013-04-12 21:29:10.557; org.apache.solr.core.= SolrDeletionPolicy; newest commit =3D 3[segments_3] [junit4:junit4] 1> INFO - 2013-04-12 21:29:10.558; org.apache.solr.searc= h.SolrIndexSearcher; Opening Searcher@6934b643 main [junit4:junit4] 1> INFO - 2013-04-12 21:29:10.559; org.apache.solr.searc= h.SolrIndexSearcher; Opening Searcher@1ee50dc main [junit4:junit4] 1> INFO - 2013-04-12 21:29:10.559; org.apache.solr.updat= e.DirectUpdateHandler2; end_commit_flush [junit4:junit4] 1> INFO - 2013-04-12 21:29:10.559; org.apache.solr.updat= e.DirectUpdateHandler2; end_commit_flush [junit4:junit4] 1> INFO - 2013-04-12 21:29:10.560; org.apache.solr.core.= SolrCore; [collection1] Registered new searcher Searcher@6934b643 main{Stan= dardDirectoryReader(segments_2:1:nrt)} [junit4:junit4] 1> INFO - 2013-04-12 21:29:10.560; org.apache.solr.core.= SolrCore; [collection1] Registered new searcher Searcher@1ee50dc main{Stand= ardDirectoryReader(segments_2:1:nrt)} [junit4:junit4] 1> INFO - 2013-04-12 21:29:10.561; org.apache.solr.updat= e.processor.LogUpdateProcessor; [collection1] webapp=3D path=3D/update para= ms=3D{waitSearcher=3Dtrue&commit=3Dtrue&wt=3Djavabin&expungeDeletes=3Dfalse= &commit_end_point=3Dtrue&version=3D2&softCommit=3Dfalse} {commit=3D} 0 7 [junit4:junit4] 1> INFO - 2013-04-12 21:29:10.561; org.apache.solr.updat= e.processor.LogUpdateProcessor; [collection1] webapp=3D path=3D/update para= ms=3D{waitSearcher=3Dtrue&commit=3Dtrue&wt=3Djavabin&expungeDeletes=3Dfalse= &commit_end_point=3Dtrue&version=3D2&softCommit=3Dfalse} {commit=3D} 0 6 [junit4:junit4] 1> INFO - 2013-04-12 21:29:10.562; org.apache.solr.updat= e.processor.LogUpdateProcessor; [collection1] webapp=3D path=3D/update para= ms=3D{waitSearcher=3Dtrue&commit=3Dtrue&wt=3Djavabin&version=3D2&softCommit= =3Dfalse} {commit=3D} 0 22 [junit4:junit4] 1> INFO - 2013-04-12 21:29:10.564; org.apache.solr.commo= n.cloud.ZkStateReader; Updating cloud state from ZooKeeper...=20 [junit4:junit4] 1> INFO - 2013-04-12 21:29:10.567; org.apache.solr.core.= SolrCore; [collection1] webapp=3D path=3D/select params=3D{tests=3DcheckSha= rdConsistency&q=3D*:*&distrib=3Dfalse&wt=3Djavabin&version=3D2&rows=3D0} hi= ts=3D0 status=3D0 QTime=3D0=20 [junit4:junit4] 1> INFO - 2013-04-12 21:29:10.570; org.apache.solr.core.= SolrCore; [collection1] webapp=3D path=3D/select params=3D{tests=3DcheckSha= rdConsistency&q=3D*:*&distrib=3Dfalse&wt=3Djavabin&version=3D2&rows=3D0} hi= ts=3D0 status=3D0 QTime=3D0=20 [junit4:junit4] 1> INFO - 2013-04-12 21:29:10.573; org.apache.solr.core.= SolrCore; [collection1] webapp=3D path=3D/select params=3D{tests=3DcheckSha= rdConsistency&q=3D*:*&distrib=3Dfalse&wt=3Djavabin&version=3D2&rows=3D0} hi= ts=3D0 status=3D0 QTime=3D1=20 [junit4:junit4] 1> INFO - 2013-04-12 21:29:10.575; org.apache.solr.core.= SolrCore; [collection1] webapp=3D path=3D/select params=3D{tests=3DcheckSha= rdConsistency&q=3D*:*&distrib=3Dfalse&wt=3Djavabin&version=3D2&rows=3D0} hi= ts=3D0 status=3D0 QTime=3D0=20 [junit4:junit4] 1> INFO - 2013-04-12 21:29:12.577; org.apache.solr.commo= n.cloud.ConnectionManager; Waiting for client to connect to ZooKeeper [junit4:junit4] 1> INFO - 2013-04-12 21:29:12.580; org.apache.solr.commo= n.cloud.ConnectionManager; Watcher org.apache.solr.common.cloud.ConnectionM= anager@4a291de7 name:ZooKeeperConnection Watcher:127.0.0.1:47561 got event = WatchedEvent state:SyncConnected type:None path:null path:null type:None [junit4:junit4] 1> INFO - 2013-04-12 21:29:12.580; org.apache.solr.commo= n.cloud.ConnectionManager; Client is connected to ZooKeeper [junit4:junit4] 1> / (2) [junit4:junit4] 1> DATA: [junit4:junit4] 1> =20 [junit4:junit4] 1> /solr (7) [junit4:junit4] 1> /solr/configs (1) [junit4:junit4] 1> /solr/configs/conf1 (9) [junit4:junit4] 1> /solr/configs/conf1/mapping-ISOLatin1Accent.txt (0= ) [junit4:junit4] 1> DATA: ...supressed... [junit4:junit4] 1> /solr/configs/conf1/currency.xml (0) [junit4:junit4] 1> DATA: ...supressed... [junit4:junit4] 1> /solr/configs/conf1/protwords.txt (0) [junit4:junit4] 1> DATA: ...supressed... [junit4:junit4] 1> /solr/configs/conf1/synonyms.txt (0) [junit4:junit4] 1> DATA: ...supressed... [junit4:junit4] 1> /solr/configs/conf1/old_synonyms.txt (0) [junit4:junit4] 1> DATA: ...supressed... [junit4:junit4] 1> /solr/configs/conf1/solrconfig.xml (0) [junit4:junit4] 1> DATA: ...supressed... [junit4:junit4] 1> /solr/configs/conf1/stopwords.txt (0) [junit4:junit4] 1> DATA: ...supressed... [junit4:junit4] 1> /solr/configs/conf1/open-exchange-rates.json (0) [junit4:junit4] 1> DATA: [junit4:junit4] 1> { [junit4:junit4] 1> "disclaimer": "This data is not real, it was= synthetically created to match currency.xml. It is modeled after the data= format available from openexchangerates.org. See https://openexchangerate= s.org/documentation for details", [junit4:junit4] 1> "license": "http://www.apache.org/licenses/L= ICENSE-2.0", [junit4:junit4] 1> "timestamp": 1332070464, [junit4:junit4] 1> =20 [junit4:junit4] 1> =20 [junit4:junit4] 1> "IMPORTANT NOTE": "In order for tests to wor= k, this data must be kept in sync with ./currency.xml", [junit4:junit4] 1> =20 [junit4:junit4] 1> =20 [junit4:junit4] 1> "base": "USD", [junit4:junit4] 1> "rates": { [junit4:junit4] 1> "USD": 1, [junit4:junit4] 1> "JPY": 81.29, [junit4:junit4] 1> "EUR": 2.5, [junit4:junit4] 1> "GBP": 0.5, [junit4:junit4] 1> "MXN": 2.0 [junit4:junit4] 1> } [junit4:junit4] 1> } [junit4:junit4] 1> =20 [junit4:junit4] 1> /solr/configs/conf1/schema.xml (0) [junit4:junit4] 1> DATA: ...supressed... [junit4:junit4] 1> /solr/clusterstate.json (0) [junit4:junit4] 1> DATA: [junit4:junit4] 1> { [junit4:junit4] 1> "collection1":{ [junit4:junit4] 1> "shards":{ [junit4:junit4] 1> "shard1":{ [junit4:junit4] 1> "range":"80000000-ffffffff", [junit4:junit4] 1> "state":"active", [junit4:junit4] 1> "replicas":{ [junit4:junit4] 1> "127.0.0.1:29782__collection1":{ [junit4:junit4] 1> "shard":"shard1", [junit4:junit4] 1> "state":"active", [junit4:junit4] 1> "core":"collection1", [junit4:junit4] 1> "collection":"collection1", [junit4:junit4] 1> "node_name":"127.0.0.1:29782_", [junit4:junit4] 1> "base_url":"http://127.0.0.1:29782", [junit4:junit4] 1> "leader":"true"}, [junit4:junit4] 1> "127.0.0.1:24668__collection1":{ [junit4:junit4] 1> "shard":"shard1", [junit4:junit4] 1> "state":"active", [junit4:junit4] 1> "core":"collection1", [junit4:junit4] 1> "collection":"collection1", [junit4:junit4] 1> "node_name":"127.0.0.1:24668_", [junit4:junit4] 1> "base_url":"http://127.0.0.1:24668"}= }}, [junit4:junit4] 1> "shard2":{ [junit4:junit4] 1> "range":"0-7fffffff", [junit4:junit4] 1> "state":"active", [junit4:junit4] 1> "replicas":{ [junit4:junit4] 1> "127.0.0.1:36990__collection1":{ [junit4:junit4] 1> "shard":"shard2", [junit4:junit4] 1> "state":"active", [junit4:junit4] 1> "core":"collection1", [junit4:junit4] 1> "collection":"collection1", [junit4:junit4] 1> "node_name":"127.0.0.1:36990_", [junit4:junit4] 1> "base_url":"http://127.0.0.1:36990", [junit4:junit4] 1> "leader":"true"}, [junit4:junit4] 1> "127.0.0.1:49988__collection1":{ [junit4:junit4] 1> "shard":"shard2", [junit4:junit4] 1> "state":"active", [junit4:junit4] 1> "core":"collection1", [junit4:junit4] 1> "collection":"collection1", [junit4:junit4] 1> "node_name":"127.0.0.1:49988_", [junit4:junit4] 1> "base_url":"http://127.0.0.1:49988"}= }}}, [junit4:junit4] 1> "router":"compositeId"}, [junit4:junit4] 1> "control_collection":{ [junit4:junit4] 1> "shards":{"shard1":{ [junit4:junit4] 1> "range":"80000000-7fffffff", [junit4:junit4] 1> "state":"active", [junit4:junit4] 1> "replicas":{"127.0.0.1:47083__collection= 1":{ [junit4:junit4] 1> "shard":"shard1", [junit4:junit4] 1> "state":"active", [junit4:junit4] 1> "core":"collection1", [junit4:junit4] 1> "collection":"control_collection", [junit4:junit4] 1> "node_name":"127.0.0.1:47083_", [junit4:junit4] 1> "base_url":"http://127.0.0.1:47083", [junit4:junit4] 1> "leader":"true"}}}}, [junit4:junit4] 1> "router":"compositeId"}} [junit4:junit4] 1> /solr/aliases.json (0) [junit4:junit4] 1> /solr/live_nodes (5) [junit4:junit4] 1> /solr/live_nodes/127.0.0.1:24668_ (0) [junit4:junit4] 1> /solr/live_nodes/127.0.0.1:29782_ (0) [junit4:junit4] 1> /solr/live_nodes/127.0.0.1:47083_ (0) [junit4:junit4] 1> /solr/live_nodes/127.0.0.1:49988_ (0) [junit4:junit4] 1> /solr/live_nodes/127.0.0.1:36990_ (0) [junit4:junit4] 1> /solr/overseer (3) [junit4:junit4] 1> DATA: [junit4:junit4] 1> =20 [junit4:junit4] 1> /solr/overseer/queue (0) [junit4:junit4] 1> /solr/overseer/queue-work (0) [junit4:junit4] 1> /solr/overseer/collection-queue-work (0) [junit4:junit4] 1> /solr/collections (2) [junit4:junit4] 1> /solr/collections/collection1 (3) [junit4:junit4] 1> DATA: [junit4:junit4] 1> {"configName":"conf1"} [junit4:junit4] 1> /solr/collections/collection1/shards (0) [junit4:junit4] 1> /solr/collections/collection1/leader_elect (2) [junit4:junit4] 1> /solr/collections/collection1/leader_elect/shard1= (1) [junit4:junit4] 1> /solr/collections/collection1/leader_elect/shard= 1/election (2) [junit4:junit4] 1> /solr/collections/collection1/leader_elect/shar= d1/election/89509208162762762-127.0.0.1:24668__collection1-n_0000000001 (0) [junit4:junit4] 1> /solr/collections/collection1/leader_elect/shar= d1/election/89509208162762758-127.0.0.1:29782__collection1-n_0000000000 (0) [junit4:junit4] 1> /solr/collections/collection1/leader_elect/shard2= (1) [junit4:junit4] 1> /solr/collections/collection1/leader_elect/shard= 2/election (2) [junit4:junit4] 1> /solr/collections/collection1/leader_elect/shar= d2/election/89509208162762760-127.0.0.1:36990__collection1-n_0000000000 (0) [junit4:junit4] 1> /solr/collections/collection1/leader_elect/shar= d2/election/89509208162762764-127.0.0.1:49988__collection1-n_0000000001 (0) [junit4:junit4] 1> /solr/collections/collection1/leaders (2) [junit4:junit4] 1> /solr/collections/collection1/leaders/shard1 (0) [junit4:junit4] 1> DATA: [junit4:junit4] 1> { [junit4:junit4] 1> "core":"collection1", [junit4:junit4] 1> "node_name":"127.0.0.1:29782_", [junit4:junit4] 1> "base_url":"http://127.0.0.1:29782"} [junit4:junit4] 1> /solr/collections/collection1/leaders/shard2 (0) [junit4:junit4] 1> DATA: [junit4:junit4] 1> { [junit4:junit4] 1> "core":"collection1", [junit4:junit4] 1> "node_name":"127.0.0.1:36990_", [junit4:junit4] 1> "base_url":"http://127.0.0.1:36990"} [junit4:junit4] 1> /solr/collections/control_collection (3) [junit4:junit4] 1> DATA: [junit4:junit4] 1> {"configName":"conf1"} [junit4:junit4] 1> /solr/collections/control_collection/shards (0) [junit4:junit4] 1> /solr/collections/control_collection/leader_elect = (1) [junit4:junit4] 1> /solr/collections/control_collection/leader_elect= /shard1 (1) [junit4:junit4] 1> /solr/collections/control_collection/leader_elec= t/shard1/election (1) [junit4:junit4] 1> /solr/collections/control_collection/leader_ele= ct/shard1/election/89509208162762755-127.0.0.1:47083__collection1-n_0000000= 000 (0) [junit4:junit4] 1> /solr/collections/control_collection/leaders (1) [junit4:junit4] 1> /solr/collections/control_collection/leaders/shar= d1 (0) [junit4:junit4] 1> DATA: [junit4:junit4] 1> { [junit4:junit4] 1> "core":"collection1", [junit4:junit4] 1> "node_name":"127.0.0.1:47083_", [junit4:junit4] 1> "base_url":"http://127.0.0.1:47083"} [junit4:junit4] 1> /solr/overseer_elect (2) [junit4:junit4] 1> /solr/overseer_elect/election (5) [junit4:junit4] 1> /solr/overseer_elect/election/89509208162762764-12= 7.0.0.1:49988_-n_0000000004 (0) [junit4:junit4] 1> /solr/overseer_elect/election/89509208162762755-12= 7.0.0.1:47083_-n_0000000000 (0) [junit4:junit4] 1> /solr/overseer_elect/election/89509208162762762-12= 7.0.0.1:24668_-n_0000000003 (0) [junit4:junit4] 1> /solr/overseer_elect/election/89509208162762760-12= 7.0.0.1:36990_-n_0000000002 (0) [junit4:junit4] 1> /solr/overseer_elect/election/89509208162762758-12= 7.0.0.1:29782_-n_0000000001 (0) [junit4:junit4] 1> /solr/overseer_elect/leader (0) [junit4:junit4] 1> DATA: [junit4:junit4] 1> {"id":"89509208162762755-127.0.0.1:47083_-n_000= 0000000"} [junit4:junit4] 1> /zookeeper (1) [junit4:junit4] 1> DATA: [junit4:junit4] 1> =20 [junit4:junit4] 1>=20 [junit4:junit4] 1> INFO - 2013-04-12 21:29:12.740; org.apache.solr.updat= e.processor.LogUpdateProcessor; [collection1] webapp=3D path=3D/update para= ms=3D{update.distrib=3DFROMLEADER&_version_=3D-1432147358105206784&update.f= rom=3Dhttp://127.0.0.1:29782/collection1/&wt=3Djavabin&version=3D2} {delete= ByQuery=3D*:* (-1432147358105206784)} 0 1 [junit4:junit4] 1> INFO - 2013-04-12 21:29:12.744; org.apache.solr.updat= e.processor.LogUpdateProcessor; [collection1] webapp=3D path=3D/update para= ms=3D{update.distrib=3DFROMLEADER&_version_=3D-1432147358110449664&update.f= rom=3Dhttp://127.0.0.1:36990/collection1/&wt=3Djavabin&version=3D2} {delete= ByQuery=3D*:* (-1432147358110449664)} 0 1 [junit4:junit4] 1> INFO - 2013-04-12 21:29:12.745; org.apache.solr.updat= e.processor.LogUpdateProcessor; [collection1] webapp=3D path=3D/update para= ms=3D{update.distrib=3DTOLEADER&wt=3Djavabin&version=3D2} {deleteByQuery=3D= *:* (-1432147358110449664)} 0 7 [junit4:junit4] 1> INFO - 2013-04-12 21:29:12.746; org.apache.solr.updat= e.processor.LogUpdateProcessor; [collection1] webapp=3D path=3D/update para= ms=3D{wt=3Djavabin&version=3D2} {deleteByQuery=3D*:* (-1432147358105206784)= } 0 13 [junit4:junit4] 1> INFO - 2013-04-12 21:29:12.755; org.apache.solr.updat= e.processor.LogUpdateProcessor; [collection1] webapp=3D path=3D/update para= ms=3D{wt=3Djavabin&version=3D2} {add=3D[0 (1432147358123032576)]} 0 5 [junit4:junit4] 1> INFO - 2013-04-12 21:29:12.766; org.apache.solr.updat= e.processor.LogUpdateProcessor; [collection1] webapp=3D path=3D/update para= ms=3D{distrib.from=3Dhttp://127.0.0.1:29782/collection1/&update.distrib=3DF= ROMLEADER&wt=3Djavabin&version=3D2} {add=3D[0 (1432147358131421184)]} 0 3 [junit4:junit4] 1> INFO - 2013-04-12 21:29:12.766; org.apache.solr.updat= e.processor.LogUpdateProcessor; [collection1] webapp=3D path=3D/update para= ms=3D{wt=3Djavabin&version=3D2} {add=3D[0 (1432147358131421184)]} 0 8 [junit4:junit4] 1> INFO - 2013-04-12 21:29:12.775; org.apache.solr.updat= e.processor.LogUpdateProcessor; [collection1] webapp=3D path=3D/update para= ms=3D{wt=3Djavabin&version=3D2} {add=3D[1 (1432147358147149824)]} 0 2 [junit4:junit4] 1> INFO - 2013-04-12 21:29:12.787; org.apache.solr.updat= e.processor.LogUpdateProcessor; [collection1] webapp=3D path=3D/update para= ms=3D{distrib.from=3Dhttp://127.0.0.1:29782/collection1/&update.distrib=3DF= ROMLEADER&wt=3Djavabin&version=3D2} {add=3D[1 (1432147358154489856)]} 0 2 [junit4:junit4] 1> INFO - 2013-04-12 21:29:12.788; org.apache.solr.updat= e.processor.LogUpdateProcessor; [collection1] webapp=3D path=3D/update para= ms=3D{distrib.from=3Dhttp://127.0.0.1:36990/collection1/&update.distrib=3DT= OLEADER&wt=3Djavabin&version=3D2} {add=3D[1 (1432147358154489856)]} 0 7 [junit4:junit4] 1> INFO - 2013-04-12 21:29:12.789; org.apache.solr.updat= e.processor.LogUpdateProcessor; [collection1] webapp=3D path=3D/update para= ms=3D{wt=3Djavabin&version=3D2} {add=3D[1]} 0 11 [junit4:junit4] 1> INFO - 2013-04-12 21:29:12.794; org.apache.solr.updat= e.processor.LogUpdateProcessor; [collection1] webapp=3D path=3D/update para= ms=3D{wt=3Djavabin&version=3D2} {add=3D[2 (1432147358167072768)]} 0 2 [junit4:junit4] 1> INFO - 2013-04-12 21:29:12.805; org.apache.solr.updat= e.processor.LogUpdateProcessor; [collection1] webapp=3D path=3D/update para= ms=3D{distrib.from=3Dhttp://127.0.0.1:36990/collection1/&update.distrib=3DF= ROMLEADER&wt=3Djavabin&version=3D2} {add=3D[2 (1432147358172315648)]} 0 3 [junit4:junit4] 1> INFO - 2013-04-12 21:29:12.805; org.apache.solr.updat= e.processor.LogUpdateProcessor; [collection1] webapp=3D path=3D/update para= ms=3D{wt=3Djavabin&version=3D2} {add=3D[2 (1432147358172315648)]} 0 8 [junit4:junit4] 1> INFO - 2013-04-12 21:29:12.811; org.apache.solr.updat= e.processor.LogUpdateProcessor; [collection1] webapp=3D path=3D/update para= ms=3D{wt=3Djavabin&version=3D2} {add=3D[3 (1432147358184898560)]} 0 2 [junit4:junit4] 1> INFO - 2013-04-12 21:29:12.820; org.apache.solr.updat= e.processor.LogUpdateProcessor; [collection1] webapp=3D path=3D/update para= ms=3D{distrib.from=3Dhttp://127.0.0.1:36990/collection1/&update.distrib=3DF= ROMLEADER&wt=3Djavabin&version=3D2} {add=3D[3 (1432147358190141440)]} 0 2 [junit4:junit4] 1> INFO - 2013-04-12 21:29:12.821; org.apache.solr.updat= e.processor.LogUpdateProcessor; [collection1] webapp=3D path=3D/update para= ms=3D{wt=3Djavabin&version=3D2} {add=3D[3 (1432147358190141440)]} 0 7 [junit4:junit4] 1> INFO - 2013-04-12 21:29:12.826; org.apache.solr.updat= e.processor.LogUpdateProcessor; [collection1] webapp=3D path=3D/update para= ms=3D{wt=3Djavabin&version=3D2} {add=3D[4 (1432147358200627200)]} 0 2 [junit4:junit4] 1> INFO - 2013-04-12 21:29:12.836; org.apache.solr.updat= e.processor.LogUpdateProcessor; [collection1] webapp=3D path=3D/update para= ms=3D{distrib.from=3Dhttp://127.0.0.1:29782/collection1/&update.distrib=3DF= ROMLEADER&wt=3Djavabin&version=3D2} {add=3D[4 (1432147358205870080)]} 0 2 [junit4:junit4] 1> INFO - 2013-04-12 21:29:12.837; org.apache.solr.updat= e.processor.LogUpdateProcessor; [collection1] webapp=3D path=3D/update para= ms=3D{wt=3Djavabin&version=3D2} {add=3D[4 (1432147358205870080)]} 0 8 [junit4:junit4] 1> INFO - 2013-04-12 21:29:12.842; org.apache.solr.updat= e.processor.LogUpdateProcessor; [collection1] webapp=3D path=3D/update para= ms=3D{wt=3Djavabin&version=3D2} {add=3D[5 (1432147358217404416)]} 0 2 [junit4:junit4] 1> INFO - 2013-04-12 21:29:12.851; org.apache.solr.updat= e.processor.LogUpdateProcessor; [collection1] webapp=3D path=3D/update para= ms=3D{distrib.from=3Dhttp://127.0.0.1:36990/collection1/&update.distrib=3DF= ROMLEADER&wt=3Djavabin&version=3D2} {add=3D[5 (1432147358222647296)]} 0 2 [junit4:junit4] 1> INFO - 2013-04-12 21:29:12.852; org.apache.solr.updat= e.processor.LogUpdateProcessor; [collection1] webapp=3D path=3D/update para= ms=3D{wt=3Djavabin&version=3D2} {add=3D[5 (1432147358222647296)]} 0 7 [junit4:junit4] 1> INFO - 2013-04-12 21:29:12.857; org.apache.solr.updat= e.processor.LogUpdateProcessor; [collection1] webapp=3D path=3D/update para= ms=3D{wt=3Djavabin&version=3D2} {add=3D[6 (1432147358233133056)]} 0 2 [junit4:junit4] 1> INFO - 2013-04-12 21:29:12.866; org.apache.solr.updat= e.processor.LogUpdateProcessor; [collection1] webapp=3D path=3D/update para= ms=3D{distrib.from=3Dhttp://127.0.0.1:36990/collection1/&update.distrib=3DF= ROMLEADER&wt=3Djavabin&version=3D2} {add=3D[6 (1432147358238375936)]} 0 2 [junit4:junit4] 1> INFO - 2013-04-12 21:29:12.867; org.apache.solr.updat= e.processor.LogUpdateProcessor; [collection1] webapp=3D path=3D/update para= ms=3D{wt=3Djavabin&version=3D2} {add=3D[6 (1432147358238375936)]} 0 7 [junit4:junit4] 1> INFO - 2013-04-12 21:29:12.872; org.apache.solr.updat= e.processor.LogUpdateProcessor; [collection1] webapp=3D path=3D/update para= ms=3D{wt=3Djavabin&version=3D2} {add=3D[7 (1432147358248861696)]} 0 2 [junit4:junit4] 1> INFO - 2013-04-12 21:29:12.885; org.apache.solr.updat= e.processor.LogUpdateProcessor; [collection1] webapp=3D path=3D/update para= ms=3D{distrib.from=3Dhttp://127.0.0.1:36990/collection1/&update.distrib=3DF= ROMLEADER&wt=3Djavabin&version=3D2} {add=3D[7 (1432147358257250304)]} 0 2 [junit4:junit4] 1> INFO - 2013-04-12 21:29:12.886; org.apache.solr.updat= e.processor.LogUpdateProcessor; [collection1] webapp=3D path=3D/update para= ms=3D{distrib.from=3Dhttp://127.0.0.1:29782/collection1/&update.distrib=3DT= OLEADER&wt=3Djavabin&version=3D2} {add=3D[7 (1432147358257250304)]} 0 8 [junit4:junit4] 1> INFO - 2013-04-12 21:29:12.887; org.apache.solr.updat= e.processor.LogUpdateProcessor; [collection1] webapp=3D path=3D/update para= ms=3D{wt=3Djavabin&version=3D2} {add=3D[7]} 0 12 [junit4:junit4] 1> INFO - 2013-04-12 21:29:12.892; org.apache.solr.updat= e.processor.LogUpdateProcessor; [collection1] webapp=3D path=3D/update para= ms=3D{wt=3Djavabin&version=3D2} {add=3D[8 (1432147358269833216)]} 0 2 [junit4:junit4] 1> INFO - 2013-04-12 21:29:12.904; org.apache.solr.updat= e.processor.LogUpdateProcessor; [collection1] webapp=3D path=3D/update para= ms=3D{distrib.from=3Dhttp://127.0.0.1:29782/collection1/&update.distrib=3DF= ROMLEADER&wt=3Djavabin&version=3D2} {add=3D[8 (1432147358278221824)]} 0 2 [junit4:junit4] 1> INFO - 2013-04-12 21:29:12.905; org.apache.solr.updat= e.processor.LogUpdateProcessor; [collection1] webapp=3D path=3D/update para= ms=3D{distrib.from=3Dhttp://127.0.0.1:36990/collection1/&update.distrib=3DT= OLEADER&wt=3Djavabin&version=3D2} {add=3D[8 (1432147358278221824)]} 0 7 [junit4:junit4] 1> INFO - 2013-04-12 21:29:12.906; org.apache.solr.updat= e.processor.LogUpdateProcessor; [collection1] webapp=3D path=3D/update para= ms=3D{wt=3Djavabin&version=3D2} {add=3D[8]} 0 11 [junit4:junit4] 1> INFO - 2013-04-12 21:29:12.911; org.apache.solr.updat= e.processor.LogUpdateProcessor; [collection1] webapp=3D path=3D/update para= ms=3D{wt=3Djavabin&version=3D2} {add=3D[9 (1432147358289756160)]} 0 2 [junit4:junit4] 1> INFO - 2013-04-12 21:29:12.920; org.apache.solr.updat= e.processor.LogUpdateProcessor; [collection1] webapp=3D path=3D/update para= ms=3D{distrib.from=3Dhttp://127.0.0.1:36990/collection1/&update.distrib=3DF= ROMLEADER&wt=3Djavabin&version=3D2} {add=3D[9 (1432147358294999040)]} 0 2 [junit4:junit4] 1> INFO - 2013-04-12 21:29:12.921; org.apache.solr.updat= e.processor.LogUpdateProcessor; [collection1] webapp=3D path=3D/update para= ms=3D{wt=3Djavabin&version=3D2} {add=3D[9 (1432147358294999040)]} 0 7 [junit4:junit4] 1> INFO - 2013-04-12 21:29:12.926; org.apache.solr.updat= e.processor.LogUpdateProcessor; [collection1] webapp=3D path=3D/update para= ms=3D{wt=3Djavabin&version=3D2} {add=3D[10 (1432147358305484800)]} 0 2 [junit4:junit4] 1> INFO - 2013-04-12 21:29:12.936; org.apache.solr.updat= e.processor.LogUpdateProcessor; [collection1] webapp=3D path=3D/update para= ms=3D{distrib.from=3Dhttp://127.0.0.1:29782/collection1/&update.distrib=3DF= ROMLEADER&wt=3Djavabin&version=3D2} {add=3D[10 (1432147358310727680)]} 0 2 [junit4:junit4] 1> INFO - 2013-04-12 21:29:12.937; org.apache.solr.updat= e.processor.LogUpdateProcessor; [collection1] webapp=3D path=3D/update para= ms=3D{wt=3Djavabin&version=3D2} {add=3D[10 (1432147358310727680)]} 0 8 [junit4:junit4] 1> INFO - 2013-04-12 21:29:12.942; org.apache.solr.updat= e.processor.LogUpdateProcessor; [collection1] webapp=3D path=3D/update para= ms=3D{wt=3Djavabin&version=3D2} {add=3D[11 (1432147358322262016)]} 0 2 [junit4:junit4] 1> INFO - 2013-04-12 21:29:12.954; org.apache.solr.updat= e.processor.LogUpdateProcessor; [collection1] webapp=3D path=3D/update para= ms=3D{distrib.from=3Dhttp://127.0.0.1:29782/collection1/&update.distrib=3DF= ROMLEADER&wt=3Djavabin&version=3D2} {add=3D[11 (1432147358330650624)]} 0 2 [junit4:junit4] 1> INFO - 2013-04-12 21:29:12.955; org.apache.solr.updat= e.processor.LogUpdateProcessor; [collection1] webapp=3D path=3D/update para= ms=3D{distrib.from=3Dhttp://127.0.0.1:36990/collection1/&update.distrib=3DT= OLEADER&wt=3Djavabin&version=3D2} {add=3D[11 (1432147358330650624)]} 0 7 [junit4:junit4] 1> INFO - 2013-04-12 21:29:12.956; org.apache.solr.updat= e.processor.LogUpdateProcessor; [collection1] webapp=3D path=3D/update para= ms=3D{wt=3Djavabin&version=3D2} {add=3D[11]} 0 11 [junit4:junit4] 1> INFO - 2013-04-12 21:29:12.961; org.apache.solr.updat= e.processor.LogUpdateProcessor; [collection1] webapp=3D path=3D/update para= ms=3D{wt=3Djavabin&version=3D2} {add=3D[12 (1432147358342184960)]} 0 2 [junit4:junit4] 1> INFO - 2013-04-12 21:29:12.970; org.apache.solr.updat= e.processor.LogUpdateProcessor; [collection1] webapp=3D path=3D/update para= ms=3D{distrib.from=3Dhttp://127.0.0.1:29782/collection1/&update.distrib=3DF= ROMLEADER&wt=3Djavabin&version=3D2} {add=3D[12 (1432147358347427840)]} 0 2 [junit4:junit4] 1> INFO - 2013-04-12 21:29:12.971; org.apache.solr.updat= e.processor.LogUpdateProcessor; [collection1] webapp=3D path=3D/update para= ms=3D{wt=3Djavabin&version=3D2} {add=3D[12 (1432147358347427840)]} 0 7 [junit4:junit4] 1> INFO - 2013-04-12 21:29:12.976; org.apache.solr.updat= e.processor.LogUpdateProcessor; [collection1] webapp=3D path=3D/update para= ms=3D{wt=3Djavabin&version=3D2} {add=3D[13 (1432147358357913600)]} 0 2 [junit4:junit4] 1> INFO - 2013-04-12 21:29:12.989; org.apache.solr.updat= e.processor.LogUpdateProcessor; [collection1] webapp=3D path=3D/update para= ms=3D{distrib.from=3Dhttp://127.0.0.1:29782/collection1/&update.distrib=3DF= ROMLEADER&wt=3Djavabin&version=3D2} {add=3D[13 (1432147358366302208)]} 0 2 [junit4:junit4] 1> INFO - 2013-04-12 21:29:12.990; org.apache.solr.updat= e.processor.LogUpdateProcessor; [collection1] webapp=3D path=3D/update para= ms=3D{distrib.from=3Dhttp://127.0.0.1:36990/collection1/&update.distrib=3DT= OLEADER&wt=3Djavabin&version=3D2} {add=3D[13 (1432147358366302208)]} 0 8 [junit4:junit4] 1> INFO - 2013-04-12 21:29:12.991; org.apache.solr.updat= e.processor.LogUpdateProcessor; [collection1] webapp=3D path=3D/update para= ms=3D{wt=3Djavabin&version=3D2} {add=3D[13]} 0 12 [junit4:junit4] 1> INFO - 2013-04-12 21:29:12.996; org.apache.solr.updat= e.processor.LogUpdateProcessor; [collection1] webapp=3D path=3D/update para= ms=3D{wt=3Djavabin&version=3D2} {add=3D[14 (1432147358378885120)]} 0 2 [junit4:junit4] 1> INFO - 2013-04-12 21:29:13.006; org.apache.solr.updat= e.processor.LogUpdateProcessor; [collection1] webapp=3D path=3D/update para= ms=3D{distrib.from=3Dhttp://127.0.0.1:29782/collection1/&update.distrib=3DF= ROMLEADER&wt=3Djavabin&version=3D2} {add=3D[14 (1432147358385176576)]} 0 2 [junit4:junit4] 1> INFO - 2013-04-12 21:29:13.007; org.apache.solr.updat= e.processor.LogUpdateProcessor; [collection1] webapp=3D path=3D/update para= ms=3D{wt=3Djavabin&version=3D2} {add=3D[14 (1432147358385176576)]} 0 8 [junit4:junit4] 1> INFO - 2013-04-12 21:29:13.012; org.apache.solr.updat= e.processor.LogUpdateProcessor; [collection1] webapp=3D path=3D/update para= ms=3D{wt=3Djavabin&version=3D2} {add=3D[15 (1432147358395662336)]} 0 2 [junit4:junit4] 1> INFO - 2013-04-12 21:29:13.021; org.apache.solr.updat= e.processor.LogUpdateProcessor; [collection1] webapp=3D path=3D/update para= ms=3D{distrib.from=3Dhttp://127.0.0.1:29782/collection1/&update.distrib=3DF= ROMLEADER&wt=3Djavabin&version=3D2} {add=3D[15 (1432147358400905216)]} 0 2 [junit4:junit4] 1> INFO - 2013-04-12 21:29:13.022; org.apache.solr.updat= e.processor.LogUpdateProcessor; [collection1] webapp=3D path=3D/update para= ms=3D{wt=3Djavabin&version=3D2} {add=3D[15 (1432147358400905216)]} 0 7 [junit4:junit4] 1> INFO - 2013-04-12 21:29:13.027; org.apache.solr.updat= e.processor.LogUpdateProcessor; [collection1] webapp=3D path=3D/update para= ms=3D{wt=3Djavabin&version=3D2} {add=3D[16 (1432147358411390976)]} 0 2 [junit4:junit4] 1> INFO - 2013-04-12 21:29:13.036; org.apache.solr.updat= e.processor.LogUpdateProcessor; [collection1] webapp=3D path=3D/update para= ms=3D{distrib.from=3Dhttp://127.0.0.1:29782/collection1/&update.distrib=3DF= ROMLEADER&wt=3Djavabin&version=3D2} {add=3D[16 (1432147358416633856)]} 0 2 [junit4:junit4] 1> INFO - 2013-04-12 21:29:13.037; org.apache.solr.updat= e.processor.LogUpdateProcessor; [collection1] webapp=3D path=3D/update para= ms=3D{wt=3Djavabin&version=3D2} {add=3D[16 (1432147358416633856)]} 0 7 [junit4:junit4] 1> INFO - 2013-04-12 21:29:13.042; org.apache.solr.updat= e.processor.LogUpdateProcessor; [collection1] webapp=3D path=3D/update para= ms=3D{wt=3Djavabin&version=3D2} {add=3D[17 (1432147358427119616)]} 0 2 [junit4:junit4] 1> INFO - 2013-04-12 21:29:13.051; org.apache.solr.updat= e.processor.LogUpdateProcessor; [collection1] webapp=3D path=3D/update para= ms=3D{distrib.from=3Dhttp://127.0.0.1:36990/collection1/&update.distrib=3DF= ROMLEADER&wt=3Djavabin&version=3D2} {add=3D[17 (1432147358432362496)]} 0 2 [junit4:junit4] 1> INFO - 2013-04-12 21:29:13.052; org.apache.solr.updat= e [...truncated too long message...] le.encoding=3DISO-8859-1 [junit4:junit4] FAILURE 878s J0 | SyncSliceTest.testDistribSearch <<< [junit4:junit4] > Throwable #1: java.lang.AssertionError: shard1 is not = consistent. Got 305 from http://127.0.0.1:38575/ihjbc/pg/collection1lastCl= ient and got 5 from http://127.0.0.1:38580/ihjbc/pg/collection1 [junit4:junit4] > =09at __randomizedtesting.SeedInfo.seed([D24BF1F974128= 6A1:53AD7FE1034DE69D]:0) [junit4:junit4] > =09at org.apache.solr.cloud.AbstractFullDistribZkTestB= ase.checkShardConsistency(AbstractFullDistribZkTestBase.java:963) [junit4:junit4] > =09at org.apache.solr.cloud.SyncSliceTest.doTest(SyncS= liceTest.java:238) [junit4:junit4] > =09at org.apache.solr.BaseDistributedSearchTestCase.te= stDistribSearch(BaseDistributedSearchTestCase.java:806) [junit4:junit4] > =09at java.lang.Thread.run(Thread.java:722) [junit4:junit4] 1> INFO - 2013-04-12 21:41:43.565; org.apache.solr.SolrT= estCaseJ4; ###deleteCore [junit4:junit4] 1> WARN - 2013-04-12 21:41:44.517; org.apache.solr.commo= n.cloud.ZkStateReader$3; ZooKeeper watch triggered, but Solr cannot talk to= ZK [junit4:junit4] 1> INFO - 2013-04-12 21:41:44.517; org.apache.solr.commo= n.cloud.ZkStateReader$2; A cluster state change: WatchedEvent state:SyncCon= nected type:NodeChildrenChanged path:/live_nodes, has occurred - updating..= . (live nodes size: 1) [junit4:junit4] 1> WARN - 2013-04-12 21:41:44.517; org.apache.solr.commo= n.cloud.ZkStateReader$2; ZooKeeper watch triggered, but Solr cannot talk to= ZK [junit4:junit4] 1> WARN - 2013-04-12 21:42:11.096; org.apache.solr.updat= e.PeerSync; PeerSync: core=3Dcollection1 url=3Dhttp://127.0.0.1:38575/ihjbc= /pg couldn't connect to http://127.0.0.1:38557/ihjbc/pg/collection1/, coun= ting as success [junit4:junit4] 1> INFO - 2013-04-12 21:42:11.096; org.apache.solr.updat= e.PeerSync; PeerSync: core=3Dcollection1 url=3Dhttp://127.0.0.1:38575/ihjbc= /pg DONE. sync succeeded [junit4:junit4] 1> INFO - 2013-04-12 21:42:11.097; org.apache.solr.cloud= .SyncStrategy; We have been closed, won't attempt to sync replicas back to = leader [junit4:junit4] 1> INFO - 2013-04-12 21:42:11.097; org.apache.solr.cloud= .ShardLeaderElectionContext; Not rejoining election because CoreContainer i= s shutdown [junit4:junit4] 1> INFO - 2013-04-12 21:42:11.097; org.apache.solr.core.= SolrCore; [collection1] CLOSING SolrCore org.apache.solr.core.SolrCore@33d= 1d595 [junit4:junit4] 1> INFO - 2013-04-12 21:42:11.099; org.apache.solr.updat= e.DirectUpdateHandler2; closing DirectUpdateHandler2{commits=3D51,autocommi= ts=3D0,soft autocommits=3D0,optimizes=3D0,rollbacks=3D0,expungeDeletes=3D0,= docsPending=3D0,adds=3D0,deletesById=3D0,deletesByQuery=3D0,errors=3D0,cumu= lative_adds=3D5,cumulative_deletesById=3D0,cumulative_deletesByQuery=3D1,cu= mulative_errors=3D0} [junit4:junit4] 1> INFO - 2013-04-12 21:42:11.099; org.apache.solr.updat= e.SolrCoreState; Closing SolrCoreState [junit4:junit4] 1> INFO - 2013-04-12 21:42:11.100; org.apache.solr.updat= e.DefaultSolrCoreState; SolrCoreState ref count has reached 0 - closing Ind= exWriter [junit4:junit4] 1> INFO - 2013-04-12 21:42:11.100; org.apache.solr.updat= e.DefaultSolrCoreState; closing IndexWriter with IndexWriterCloser [junit4:junit4] 1> ERROR - 2013-04-12 21:42:11.100; org.apache.solr.updat= e.TransactionLog; Error: Forcing close of tlog{file=3D./org.apache.solr.clo= ud.SyncSliceTest-1365802025413/jetty3/tlog/tlog.0000000000000000003 refcoun= t=3D2} [junit4:junit4] 1> ERROR - 2013-04-12 21:42:11.101; org.apache.solr.updat= e.TransactionLog; Error: Forcing close of tlog{file=3D./org.apache.solr.clo= ud.SyncSliceTest-1365802025413/jetty3/tlog/tlog.0000000000000000002 refcoun= t=3D2} [junit4:junit4] 1> ERROR - 2013-04-12 21:42:11.101; org.apache.solr.updat= e.TransactionLog; Error: Forcing close of tlog{file=3D./org.apache.solr.clo= ud.SyncSliceTest-1365802025413/jetty3/tlog/tlog.0000000000000000001 refcoun= t=3D2} [junit4:junit4] 1> INFO - 2013-04-12 21:42:11.103; org.apache.solr.core.= SolrCore; [collection1] Closing main searcher on request. [junit4:junit4] 1> INFO - 2013-04-12 21:42:11.105; org.apache.solr.core.= CachingDirectoryFactory; Closing NRTCachingDirectoryFactory - 2 directories= currently being tracked [junit4:junit4] 1> INFO - 2013-04-12 21:42:11.105; org.apache.solr.core.= CachingDirectoryFactory; looking to close /usr/home/hudson/hudson-slave/wor= kspace/Lucene-Solr-Tests-4.x-java7/solr/build/solr-core/test/J0/org.apache.= solr.cloud.SyncSliceTest-1365802025413/jetty3/index.20130413003523489 [Cach= edDir<>] [junit4:junit4] 1> INFO - 2013-04-12 21:42:11.105; org.apache.solr.core.= CachingDirectoryFactory; Closing directory: /usr/home/hudson/hudson-slave/w= orkspace/Lucene-Solr-Tests-4.x-java7/solr/build/solr-core/test/J0/org.apach= e.solr.cloud.SyncSliceTest-1365802025413/jetty3/index.20130413003523489 [junit4:junit4] 1> INFO - 2013-04-12 21:42:11.106; org.apache.solr.core.= CachingDirectoryFactory; looking to close /usr/home/hudson/hudson-slave/wor= kspace/Lucene-Solr-Tests-4.x-java7/solr/build/solr-core/test/J0/org.apache.= solr.cloud.SyncSliceTest-1365802025413/jetty3 [CachedDir<>] [junit4:junit4] 1> INFO - 2013-04-12 21:42:11.106; org.apache.solr.core.= CachingDirectoryFactory; Closing directory: /usr/home/hudson/hudson-slave/w= orkspace/Lucene-Solr-Tests-4.x-java7/solr/build/solr-core/test/J0/org.apach= e.solr.cloud.SyncSliceTest-1365802025413/jetty3 [junit4:junit4] 1> WARN - 2013-04-12 21:42:11.106; org.apache.solr.commo= n.cloud.ZkStateReader$3; ZooKeeper watch triggered, but Solr cannot talk to= ZK [junit4:junit4] 1> INFO - 2013-04-12 21:42:11.107; org.apache.solr.commo= n.cloud.ZkStateReader$2; A cluster state change: WatchedEvent state:SyncCon= nected type:NodeChildrenChanged path:/live_nodes, has occurred - updating..= . (live nodes size: 2) [junit4:junit4] 1> WARN - 2013-04-12 21:42:11.107; org.apache.solr.commo= n.cloud.ZkStateReader$2; ZooKeeper watch triggered, but Solr cannot talk to= ZK [junit4:junit4] 1> INFO - 2013-04-12 21:42:11.107; org.apache.solr.commo= n.cloud.ZkStateReader$2; A cluster state change: WatchedEvent state:SyncCon= nected type:NodeDataChanged path:/clusterstate.json, has occurred - updatin= g... (live nodes size: 2) [junit4:junit4] 1> WARN - 2013-04-12 21:42:11.107; org.apache.solr.commo= n.cloud.ZkStateReader$2; ZooKeeper watch triggered, but Solr cannot talk to= ZK [junit4:junit4] 2> NOTE: test params are: codec=3DLucene40, sim=3DDefault= Similarity, locale=3Dsk_SK, timezone=3DEurope/Zaporozhye [junit4:junit4] 2> NOTE: FreeBSD 9.0-RELEASE amd64/Oracle Corporation 1.7= .0_17 (64-bit)/cpus=3D16,threads=3D3,free=3D106024976,total=3D334495744 [junit4:junit4] 2> NOTE: All tests run in this JVM: [TestStressVersions, = PingRequestHandlerTest, TestSchemaSimilarityResource, OpenCloseCoreStressTe= st, SliceStateTest, TestPHPSerializedResponseWriter, TestUpdate, SuggesterW= FSTTest, SchemaVersionSpecificBehaviorTest, TestUniqueKeyFieldResource, Sol= rTestCaseJ4Test, UniqFieldsUpdateProcessorFactoryTest, FastVectorHighlighte= rTest, TestCopyFieldCollectionResource, DateFieldTest, TestLuceneMatchVersi= on, TestRandomDVFaceting, SpellCheckCollatorTest, TestJmxMonitoredMap, Test= SchemaNameResource, LeaderElectionIntegrationTest, TestJmxIntegration, Xslt= UpdateRequestHandlerTest, DocValuesMultiTest, TestMultiCoreConfBootstrap, T= estLFUCache, TestCollationField, TestRandomFaceting, PreAnalyzedUpdateProce= ssorTest, ClusterStateTest, TestDynamicFieldResource, DistributedSpellCheck= ComponentTest, CachingDirectoryFactoryTest, DistanceFunctionTest, DocumentB= uilderTest, TestRealTimeGet, TestCollationKeyRangeQueries, TestSolrCoreProp= erties, BinaryUpdateRequestHandlerTest, RAMDirectoryFactoryTest, CoreContai= nerCoreInitFailuresTest, ZkControllerTest, SignatureUpdateProcessorFactoryT= est, CacheHeaderTest, TestFastWriter, DirectSolrSpellCheckerTest, OutputWri= terTest, TestFastLRUCache, TestSearchPerf, TestReload, TestUtils, TestCSVRe= sponseWriter, TestFastOutputStream, TestSolrDeletionPolicy2, RequestHandler= sTest, EchoParamsTest, SuggesterTSTTest, LegacyHTMLStripCharFilterTest, Plu= ginInfoTest, SolrCmdDistributorTest, TestNumberUtils, CoreAdminHandlerTest,= TestReversedWildcardFilterFactory, HardAutoCommitTest, TestLazyCores, XmlU= pdateRequestHandlerTest, TestSolrQueryParser, SpellingQueryConverterTest, S= liceStateUpdateTest, TestComponentsName, SolrCoreTest, SyncSliceTest] [junit4:junit4] Completed on J0 in 906.22s, 1 test, 1 failure <<< FAILURES! [...truncated 447 lines...] BUILD FAILED /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/build.x= ml:381: The following error occurred while executing this line: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/build.x= ml:361: The following error occurred while executing this line: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/build.x= ml:39: The following error occurred while executing this line: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/bu= ild.xml:183: The following error occurred while executing this line: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/co= mmon-build.xml:438: The following error occurred while executing this line: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/lucene/= common-build.xml:1234: The following error occurred while executing this li= ne: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/lucene/= common-build.xml:878: There were test failures: 290 suites, 1203 tests, 2 f= ailures, 27 ignored (8 assumptions) Total time: 54 minutes 29 seconds Build step 'Invoke Ant' marked build as failure Archiving artifacts Recording test results Email was triggered for: Failure Sending email for trigger: Failure ------=_Part_2050_1883127452.1365803500665 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_2050_1883127452.1365803500665--