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 1084010164 for ; Wed, 10 Apr 2013 00:39:54 +0000 (UTC) Received: (qmail 77223 invoked by uid 500); 10 Apr 2013 00:39:51 -0000 Delivered-To: apmail-lucene-dev-archive@lucene.apache.org Received: (qmail 77148 invoked by uid 500); 10 Apr 2013 00:39:51 -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 77140 invoked by uid 99); 10 Apr 2013 00:39:51 -0000 Received: from athena.apache.org (HELO athena.apache.org) (140.211.11.136) by apache.org (qpsmtpd/0.29) with ESMTP; Wed, 10 Apr 2013 00:39:51 +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; Wed, 10 Apr 2013 00:39:42 +0000 Received: from aegis.apache.org (localhost [127.0.0.1]) by aegis.apache.org (Postfix) with ESMTP id 830BDC0071 for ; Wed, 10 Apr 2013 00:39:21 +0000 (UTC) Date: Wed, 10 Apr 2013 00:39:04 +0000 (UTC) From: Apache Jenkins Server To: dev@lucene.apache.org Message-ID: <316023423.1117.1365554361347.JavaMail.hudson@aegis> In-Reply-To: <1114511977.1037.1365526721387.JavaMail.hudson@aegis> References: <1114511977.1037.1365526721387.JavaMail.hudson@aegis> Subject: [JENKINS] Lucene-Solr-Tests-4.x-Java6 - Build # 1491 - Still Failing MIME-Version: 1.0 Content-Type: multipart/mixed; boundary="----=_Part_1116_171743803.1365554344550" X-Jenkins-Job: Lucene-Solr-Tests-4.x-Java6 X-Jenkins-Result: FAILURE X-Virus-Checked: Checked by ClamAV on apache.org ------=_Part_1116_171743803.1365554344550 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: quoted-printable Build: https://builds.apache.org/job/Lucene-Solr-Tests-4.x-Java6/1491/ 2 tests failed. REGRESSION: org.apache.solr.cloud.ChaosMonkeyShardSplitTest.testDistribSea= rch Error Message: Wrong doc count on shard1_1 expected:<49> but was:<50> Stack Trace: java.lang.AssertionError: Wrong doc count on shard1_1 expected:<49> but was= :<50> =09at __randomizedtesting.SeedInfo.seed([C8B553153A049C71:4953DD0D4D5BFC4D]= :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.ChaosMonkeyShardSplitTest.doTest(ChaosMonkeySha= rdSplitTest.java:274) =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:616) =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:679) REGRESSION: org.apache.solr.cloud.CollectionsAPIDistributedZkTest.testDist= ribSearch Error Message: There are still nodes recoverying - waited for 230 seconds Stack Trace: java.lang.AssertionError: There are still nodes recoverying - waited for 23= 0 seconds =09at __randomizedtesting.SeedInfo.seed([C8B553153A049C71:4953DD0D4D5BFC4D]= :0) =09at org.junit.Assert.fail(Assert.java:93) =09at org.apache.solr.cloud.AbstractDistribZkTestBase.waitForRecoveriesToFi= nish(AbstractDistribZkTestBase.java:173) =09at org.apache.solr.cloud.AbstractDistribZkTestBase.waitForRecoveriesToFi= nish(AbstractDistribZkTestBase.java:131) =09at org.apache.solr.cloud.AbstractDistribZkTestBase.waitForRecoveriesToFi= nish(AbstractDistribZkTestBase.java:126) =09at org.apache.solr.cloud.CollectionsAPIDistributedZkTest.testCollections= API(CollectionsAPIDistributedZkTest.java:483) =09at org.apache.solr.cloud.CollectionsAPIDistributedZkTest.doTest(Collecti= onsAPIDistributedZkTest.java:146) =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:616) =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:679) Build Log: [...truncated 8630 lines...] [junit4:junit4] Suite: org.apache.solr.cloud.CollectionsAPIDistributedZkTes= t [junit4:junit4] 1> INFO - 2013-04-10 00:16:39.938; org.apache.solr.BaseD= istributedSearchTestCase; Setting hostContext system property: / [junit4:junit4] 1> INFO - 2013-04-10 00:16:39.944; org.apache.solr.SolrT= estCaseJ4; ###Starting testDistribSearch [junit4:junit4] 1> INFO - 2013-04-10 00:16:39.945; 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-10 00:16:39.946; org.apache.solr.cloud= .ZkTestServer$ZKServerMain; Starting server [junit4:junit4] 1> INFO - 2013-04-10 00:16:40.047; org.apache.solr.cloud= .ZkTestServer; start zk server on port:33468 [junit4:junit4] 1> INFO - 2013-04-10 00:16:40.048; org.apache.solr.commo= n.cloud.ConnectionManager; Waiting for client to connect to ZooKeeper [junit4:junit4] 1> INFO - 2013-04-10 00:16:40.053; org.apache.solr.commo= n.cloud.ConnectionManager; Watcher org.apache.solr.common.cloud.ConnectionM= anager@50408a33 name:ZooKeeperConnection Watcher:127.0.0.1:33468 got event = WatchedEvent state:SyncConnected type:None path:null path:null type:None [junit4:junit4] 1> INFO - 2013-04-10 00:16:40.054; org.apache.solr.commo= n.cloud.ConnectionManager; Client is connected to ZooKeeper [junit4:junit4] 1> INFO - 2013-04-10 00:16:40.054; org.apache.solr.commo= n.cloud.SolrZkClient; makePath: /solr [junit4:junit4] 1> INFO - 2013-04-10 00:16:40.068; org.apache.solr.commo= n.cloud.ConnectionManager; Waiting for client to connect to ZooKeeper [junit4:junit4] 1> INFO - 2013-04-10 00:16:40.071; org.apache.solr.commo= n.cloud.ConnectionManager; Watcher org.apache.solr.common.cloud.ConnectionM= anager@4df0bb81 name:ZooKeeperConnection Watcher:127.0.0.1:33468/solr got e= vent WatchedEvent state:SyncConnected type:None path:null path:null type:No= ne [junit4:junit4] 1> INFO - 2013-04-10 00:16:40.071; org.apache.solr.commo= n.cloud.ConnectionManager; Client is connected to ZooKeeper [junit4:junit4] 1> INFO - 2013-04-10 00:16:40.072; org.apache.solr.commo= n.cloud.SolrZkClient; makePath: /collections/collection1 [junit4:junit4] 1> INFO - 2013-04-10 00:16:40.078; org.apache.solr.commo= n.cloud.SolrZkClient; makePath: /collections/collection1/shards [junit4:junit4] 1> INFO - 2013-04-10 00:16:40.084; org.apache.solr.commo= n.cloud.SolrZkClient; makePath: /collections/control_collection [junit4:junit4] 1> INFO - 2013-04-10 00:16:40.087; org.apache.solr.commo= n.cloud.SolrZkClient; makePath: /collections/control_collection/shards [junit4:junit4] 1> INFO - 2013-04-10 00:16:40.092; org.apache.solr.cloud= .AbstractZkTestCase; put /usr/home/hudson/hudson-slave/workspace/Lucene-Sol= r-Tests-4.x-Java6/solr/build/solr-core/test-files/solr/collection1/conf/sol= rconfig-tlog.xml to /configs/conf1/solrconfig.xml [junit4:junit4] 1> INFO - 2013-04-10 00:16:40.092; org.apache.solr.commo= n.cloud.SolrZkClient; makePath: /configs/conf1/solrconfig.xml [junit4:junit4] 1> INFO - 2013-04-10 00:16:40.105; org.apache.solr.cloud= .AbstractZkTestCase; put /usr/home/hudson/hudson-slave/workspace/Lucene-Sol= r-Tests-4.x-Java6/solr/build/solr-core/test-files/solr/collection1/conf/sch= ema.xml to /configs/conf1/schema.xml [junit4:junit4] 1> INFO - 2013-04-10 00:16:40.107; org.apache.solr.commo= n.cloud.SolrZkClient; makePath: /configs/conf1/schema.xml [junit4:junit4] 1> INFO - 2013-04-10 00:16:40.217; org.apache.solr.cloud= .AbstractZkTestCase; put /usr/home/hudson/hudson-slave/workspace/Lucene-Sol= r-Tests-4.x-Java6/solr/build/solr-core/test-files/solr/collection1/conf/sto= pwords.txt to /configs/conf1/stopwords.txt [junit4:junit4] 1> INFO - 2013-04-10 00:16:40.218; org.apache.solr.commo= n.cloud.SolrZkClient; makePath: /configs/conf1/stopwords.txt [junit4:junit4] 1> INFO - 2013-04-10 00:16:40.222; org.apache.solr.cloud= .AbstractZkTestCase; put /usr/home/hudson/hudson-slave/workspace/Lucene-Sol= r-Tests-4.x-Java6/solr/build/solr-core/test-files/solr/collection1/conf/pro= twords.txt to /configs/conf1/protwords.txt [junit4:junit4] 1> INFO - 2013-04-10 00:16:40.223; org.apache.solr.commo= n.cloud.SolrZkClient; makePath: /configs/conf1/protwords.txt [junit4:junit4] 1> INFO - 2013-04-10 00:16:40.228; org.apache.solr.cloud= .AbstractZkTestCase; put /usr/home/hudson/hudson-slave/workspace/Lucene-Sol= r-Tests-4.x-Java6/solr/build/solr-core/test-files/solr/collection1/conf/cur= rency.xml to /configs/conf1/currency.xml [junit4:junit4] 1> INFO - 2013-04-10 00:16:40.229; org.apache.solr.commo= n.cloud.SolrZkClient; makePath: /configs/conf1/currency.xml [junit4:junit4] 1> INFO - 2013-04-10 00:16:40.233; org.apache.solr.cloud= .AbstractZkTestCase; put /usr/home/hudson/hudson-slave/workspace/Lucene-Sol= r-Tests-4.x-Java6/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-10 00:16:40.234; org.apache.solr.commo= n.cloud.SolrZkClient; makePath: /configs/conf1/open-exchange-rates.json [junit4:junit4] 1> INFO - 2013-04-10 00:16:40.238; org.apache.solr.cloud= .AbstractZkTestCase; put /usr/home/hudson/hudson-slave/workspace/Lucene-Sol= r-Tests-4.x-Java6/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-10 00:16:40.239; org.apache.solr.commo= n.cloud.SolrZkClient; makePath: /configs/conf1/mapping-ISOLatin1Accent.txt [junit4:junit4] 1> INFO - 2013-04-10 00:16:40.243; org.apache.solr.cloud= .AbstractZkTestCase; put /usr/home/hudson/hudson-slave/workspace/Lucene-Sol= r-Tests-4.x-Java6/solr/build/solr-core/test-files/solr/collection1/conf/old= _synonyms.txt to /configs/conf1/old_synonyms.txt [junit4:junit4] 1> INFO - 2013-04-10 00:16:40.244; org.apache.solr.commo= n.cloud.SolrZkClient; makePath: /configs/conf1/old_synonyms.txt [junit4:junit4] 1> INFO - 2013-04-10 00:16:40.248; org.apache.solr.cloud= .AbstractZkTestCase; put /usr/home/hudson/hudson-slave/workspace/Lucene-Sol= r-Tests-4.x-Java6/solr/build/solr-core/test-files/solr/collection1/conf/syn= onyms.txt to /configs/conf1/synonyms.txt [junit4:junit4] 1> INFO - 2013-04-10 00:16:40.249; org.apache.solr.commo= n.cloud.SolrZkClient; makePath: /configs/conf1/synonyms.txt [junit4:junit4] 1> INFO - 2013-04-10 00:16:40.472; org.eclipse.jetty.ser= ver.Server; jetty-8.1.8.v20121106 [junit4:junit4] 1> INFO - 2013-04-10 00:16:40.476; org.eclipse.jetty.ser= ver.AbstractConnector; Started SocketConnector@127.0.0.1:33471 [junit4:junit4] 1> INFO - 2013-04-10 00:16:40.477; org.apache.solr.servl= et.SolrDispatchFilter; SolrDispatchFilter.init() [junit4:junit4] 1> INFO - 2013-04-10 00:16:40.477; org.apache.solr.core.= SolrResourceLoader; JNDI not configured for solr (NoInitialContextEx) [junit4:junit4] 1> INFO - 2013-04-10 00:16:40.478; org.apache.solr.core.= SolrResourceLoader; using system property solr.solr.home: /usr/home/hudson/= hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/tes= t/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-controljetty-1= 365553000254 [junit4:junit4] 1> INFO - 2013-04-10 00:16:40.479; org.apache.solr.core.= CoreContainer$Initializer; looking for solr config file: /usr/home/hudson/h= udson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test= /J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-controljetty-13= 65553000254/solr.xml [junit4:junit4] 1> INFO - 2013-04-10 00:16:40.479; org.apache.solr.core.= CoreContainer; New CoreContainer 874174181 [junit4:junit4] 1> INFO - 2013-04-10 00:16:40.480; org.apache.solr.core.= CoreContainer; Loading CoreContainer using Solr Home: '/usr/home/hudson/hud= son-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J= 1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-controljetty-1365= 553000254/' [junit4:junit4] 1> INFO - 2013-04-10 00:16:40.480; org.apache.solr.core.= SolrResourceLoader; new SolrResourceLoader for directory: '/usr/home/hudson= /hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/te= st/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-controljetty-= 1365553000254/' [junit4:junit4] 1> INFO - 2013-04-10 00:16:40.539; org.apache.solr.handl= er.component.HttpShardHandlerFactory; Setting socketTimeout to: 120000 [junit4:junit4] 1> INFO - 2013-04-10 00:16:40.540; org.apache.solr.handl= er.component.HttpShardHandlerFactory; Setting urlScheme to: http:// [junit4:junit4] 1> INFO - 2013-04-10 00:16:40.540; org.apache.solr.handl= er.component.HttpShardHandlerFactory; Setting connTimeout to: 15000 [junit4:junit4] 1> INFO - 2013-04-10 00:16:40.541; org.apache.solr.handl= er.component.HttpShardHandlerFactory; Setting maxConnectionsPerHost to: 20 [junit4:junit4] 1> INFO - 2013-04-10 00:16:40.541; org.apache.solr.handl= er.component.HttpShardHandlerFactory; Setting corePoolSize to: 0 [junit4:junit4] 1> INFO - 2013-04-10 00:16:40.542; org.apache.solr.handl= er.component.HttpShardHandlerFactory; Setting maximumPoolSize to: 214748364= 7 [junit4:junit4] 1> INFO - 2013-04-10 00:16:40.542; org.apache.solr.handl= er.component.HttpShardHandlerFactory; Setting maxThreadIdleTime to: 5 [junit4:junit4] 1> INFO - 2013-04-10 00:16:40.543; org.apache.solr.handl= er.component.HttpShardHandlerFactory; Setting sizeOfQueue to: -1 [junit4:junit4] 1> INFO - 2013-04-10 00:16:40.543; org.apache.solr.handl= er.component.HttpShardHandlerFactory; Setting fairnessPolicy to: false [junit4:junit4] 1> INFO - 2013-04-10 00:16:40.544; 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-10 00:16:40.567; org.apache.solr.core.= CoreContainer; Registering Log Listener [junit4:junit4] 1> INFO - 2013-04-10 00:16:40.586; org.apache.solr.core.= CoreContainer; Zookeeper client=3D127.0.0.1:33468/solr [junit4:junit4] 1> INFO - 2013-04-10 00:16:40.587; org.apache.solr.cloud= .ZkController; zkHost includes chroot [junit4:junit4] 1> INFO - 2013-04-10 00:16:40.588; org.apache.solr.commo= n.cloud.ConnectionManager; Waiting for client to connect to ZooKeeper [junit4:junit4] 1> INFO - 2013-04-10 00:16:40.591; org.apache.solr.commo= n.cloud.ConnectionManager; Watcher org.apache.solr.common.cloud.ConnectionM= anager@1c3cbf4f name:ZooKeeperConnection Watcher:127.0.0.1:33468 got event = WatchedEvent state:SyncConnected type:None path:null path:null type:None [junit4:junit4] 1> INFO - 2013-04-10 00:16:40.592; org.apache.solr.commo= n.cloud.ConnectionManager; Client is connected to ZooKeeper [junit4:junit4] 1> INFO - 2013-04-10 00:16:40.602; 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-10 00:16:40.615; org.apache.solr.commo= n.cloud.ConnectionManager; Waiting for client to connect to ZooKeeper [junit4:junit4] 1> INFO - 2013-04-10 00:16:40.618; org.apache.solr.commo= n.cloud.ConnectionManager; Watcher org.apache.solr.common.cloud.ConnectionM= anager@5797627b name:ZooKeeperConnection Watcher:127.0.0.1:33468/solr got e= vent WatchedEvent state:SyncConnected type:None path:null path:null type:No= ne [junit4:junit4] 1> INFO - 2013-04-10 00:16:40.619; org.apache.solr.commo= n.cloud.ConnectionManager; Client is connected to ZooKeeper [junit4:junit4] 1> INFO - 2013-04-10 00:16:40.622; org.apache.solr.commo= n.cloud.SolrZkClient; makePath: /overseer/queue [junit4:junit4] 1> INFO - 2013-04-10 00:16:40.633; org.apache.solr.commo= n.cloud.SolrZkClient; makePath: /overseer/collection-queue-work [junit4:junit4] 1> INFO - 2013-04-10 00:16:40.637; org.apache.solr.commo= n.cloud.SolrZkClient; makePath: /live_nodes [junit4:junit4] 1> INFO - 2013-04-10 00:16:40.640; org.apache.solr.cloud= .ZkController; Register node as live in ZooKeeper:/live_nodes/127.0.0.1:334= 71_ [junit4:junit4] 1> INFO - 2013-04-10 00:16:40.642; org.apache.solr.commo= n.cloud.SolrZkClient; makePath: /live_nodes/127.0.0.1:33471_ [junit4:junit4] 1> INFO - 2013-04-10 00:16:40.647; org.apache.solr.commo= n.cloud.SolrZkClient; makePath: /overseer_elect/election [junit4:junit4] 1> INFO - 2013-04-10 00:16:40.661; org.apache.solr.commo= n.cloud.SolrZkClient; makePath: /overseer_elect/leader [junit4:junit4] 1> INFO - 2013-04-10 00:16:40.671; org.apache.solr.cloud= .Overseer; Overseer (id=3D89492881404854275-127.0.0.1:33471_-n_0000000000) = starting [junit4:junit4] 1> INFO - 2013-04-10 00:16:40.676; org.apache.solr.commo= n.cloud.SolrZkClient; makePath: /overseer/queue-work [junit4:junit4] 1> INFO - 2013-04-10 00:16:40.688; org.apache.solr.cloud= .OverseerCollectionProcessor; Process current queue of collection creations [junit4:junit4] 1> INFO - 2013-04-10 00:16:40.690; org.apache.solr.commo= n.cloud.SolrZkClient; makePath: /clusterstate.json [junit4:junit4] 1> INFO - 2013-04-10 00:16:40.694; org.apache.solr.commo= n.cloud.SolrZkClient; makePath: /aliases.json [junit4:junit4] 1> INFO - 2013-04-10 00:16:40.697; org.apache.solr.commo= n.cloud.ZkStateReader; Updating cluster state from ZooKeeper...=20 [junit4:junit4] 1> INFO - 2013-04-10 00:16:40.701; org.apache.solr.cloud= .Overseer$ClusterStateUpdater; Starting to work on the main queue [junit4:junit4] 1> INFO - 2013-04-10 00:16:40.705; org.apache.solr.servl= et.SolrDispatchFilter; user.dir=3D/usr/home/hudson/hudson-slave/workspace/L= ucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J1 [junit4:junit4] 1> INFO - 2013-04-10 00:16:40.705; org.apache.solr.servl= et.SolrDispatchFilter; SolrDispatchFilter.init() done [junit4:junit4] 1> INFO - 2013-04-10 00:16:40.706; 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-10 00:16:40.718; org.apache.solr.clien= t.solrj.impl.HttpClientUtil; Creating new http client, config: [junit4:junit4] 1> INFO - 2013-04-10 00:16:40.720; org.apache.solr.commo= n.cloud.ConnectionManager; Waiting for client to connect to ZooKeeper [junit4:junit4] 1> INFO - 2013-04-10 00:16:40.723; org.apache.solr.commo= n.cloud.ConnectionManager; Watcher org.apache.solr.common.cloud.ConnectionM= anager@6b783b2d name:ZooKeeperConnection Watcher:127.0.0.1:33468/solr got e= vent WatchedEvent state:SyncConnected type:None path:null path:null type:No= ne [junit4:junit4] 1> INFO - 2013-04-10 00:16:40.723; org.apache.solr.commo= n.cloud.ConnectionManager; Client is connected to ZooKeeper [junit4:junit4] 1> INFO - 2013-04-10 00:16:40.725; org.apache.solr.commo= n.cloud.ZkStateReader; Updating cluster state from ZooKeeper...=20 [junit4:junit4] 1> INFO - 2013-04-10 00:16:40.728; org.apache.solr.cloud= .ChaosMonkey; monkey: init - expire sessions:true cause connection loss:tru= e [junit4:junit4] 1> INFO - 2013-04-10 00:16:40.941; org.eclipse.jetty.ser= ver.Server; jetty-8.1.8.v20121106 [junit4:junit4] 1> INFO - 2013-04-10 00:16:40.943; org.eclipse.jetty.ser= ver.AbstractConnector; Started SocketConnector@127.0.0.1:33475 [junit4:junit4] 1> INFO - 2013-04-10 00:16:40.944; org.apache.solr.servl= et.SolrDispatchFilter; SolrDispatchFilter.init() [junit4:junit4] 1> INFO - 2013-04-10 00:16:40.945; org.apache.solr.core.= SolrResourceLoader; JNDI not configured for solr (NoInitialContextEx) [junit4:junit4] 1> INFO - 2013-04-10 00:16:40.945; org.apache.solr.core.= SolrResourceLoader; using system property solr.solr.home: /usr/home/hudson/= hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/tes= t/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty1-1365553= 000729 [junit4:junit4] 1> INFO - 2013-04-10 00:16:40.946; org.apache.solr.core.= CoreContainer$Initializer; looking for solr config file: /usr/home/hudson/h= udson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test= /J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty1-13655530= 00729/solr.xml [junit4:junit4] 1> INFO - 2013-04-10 00:16:40.946; org.apache.solr.core.= CoreContainer; New CoreContainer 1094330480 [junit4:junit4] 1> INFO - 2013-04-10 00:16:40.947; org.apache.solr.core.= CoreContainer; Loading CoreContainer using Solr Home: '/usr/home/hudson/hud= son-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J= 1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty1-1365553000= 729/' [junit4:junit4] 1> INFO - 2013-04-10 00:16:40.947; org.apache.solr.core.= SolrResourceLoader; new SolrResourceLoader for directory: '/usr/home/hudson= /hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/te= st/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty1-136555= 3000729/' [junit4:junit4] 1> INFO - 2013-04-10 00:16:41.005; org.apache.solr.handl= er.component.HttpShardHandlerFactory; Setting socketTimeout to: 120000 [junit4:junit4] 1> INFO - 2013-04-10 00:16:41.006; org.apache.solr.handl= er.component.HttpShardHandlerFactory; Setting urlScheme to: http:// [junit4:junit4] 1> INFO - 2013-04-10 00:16:41.006; org.apache.solr.handl= er.component.HttpShardHandlerFactory; Setting connTimeout to: 15000 [junit4:junit4] 1> INFO - 2013-04-10 00:16:41.007; org.apache.solr.handl= er.component.HttpShardHandlerFactory; Setting maxConnectionsPerHost to: 20 [junit4:junit4] 1> INFO - 2013-04-10 00:16:41.008; org.apache.solr.handl= er.component.HttpShardHandlerFactory; Setting corePoolSize to: 0 [junit4:junit4] 1> INFO - 2013-04-10 00:16:41.008; org.apache.solr.handl= er.component.HttpShardHandlerFactory; Setting maximumPoolSize to: 214748364= 7 [junit4:junit4] 1> INFO - 2013-04-10 00:16:41.009; org.apache.solr.handl= er.component.HttpShardHandlerFactory; Setting maxThreadIdleTime to: 5 [junit4:junit4] 1> INFO - 2013-04-10 00:16:41.009; org.apache.solr.handl= er.component.HttpShardHandlerFactory; Setting sizeOfQueue to: -1 [junit4:junit4] 1> INFO - 2013-04-10 00:16:41.010; org.apache.solr.handl= er.component.HttpShardHandlerFactory; Setting fairnessPolicy to: false [junit4:junit4] 1> INFO - 2013-04-10 00:16:41.010; 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-10 00:16:41.034; org.apache.solr.core.= CoreContainer; Registering Log Listener [junit4:junit4] 1> INFO - 2013-04-10 00:16:41.055; org.apache.solr.core.= CoreContainer; Zookeeper client=3D127.0.0.1:33468/solr [junit4:junit4] 1> INFO - 2013-04-10 00:16:41.056; org.apache.solr.cloud= .ZkController; zkHost includes chroot [junit4:junit4] 1> INFO - 2013-04-10 00:16:41.057; org.apache.solr.commo= n.cloud.ConnectionManager; Waiting for client to connect to ZooKeeper [junit4:junit4] 1> INFO - 2013-04-10 00:16:41.061; org.apache.solr.commo= n.cloud.ConnectionManager; Watcher org.apache.solr.common.cloud.ConnectionM= anager@6b1de1c2 name:ZooKeeperConnection Watcher:127.0.0.1:33468 got event = WatchedEvent state:SyncConnected type:None path:null path:null type:None [junit4:junit4] 1> INFO - 2013-04-10 00:16:41.062; org.apache.solr.commo= n.cloud.ConnectionManager; Client is connected to ZooKeeper [junit4:junit4] 1> INFO - 2013-04-10 00:16:41.077; 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-10 00:16:41.090; org.apache.solr.commo= n.cloud.ConnectionManager; Waiting for client to connect to ZooKeeper [junit4:junit4] 1> INFO - 2013-04-10 00:16:41.093; org.apache.solr.commo= n.cloud.ConnectionManager; Watcher org.apache.solr.common.cloud.ConnectionM= anager@5eb3bc48 name:ZooKeeperConnection Watcher:127.0.0.1:33468/solr got e= vent WatchedEvent state:SyncConnected type:None path:null path:null type:No= ne [junit4:junit4] 1> INFO - 2013-04-10 00:16:41.093; org.apache.solr.commo= n.cloud.ConnectionManager; Client is connected to ZooKeeper [junit4:junit4] 1> INFO - 2013-04-10 00:16:41.100; org.apache.solr.commo= n.cloud.ZkStateReader; Updating cluster state from ZooKeeper...=20 [junit4:junit4] 1> INFO - 2013-04-10 00:16:42.106; org.apache.solr.cloud= .ZkController; Register node as live in ZooKeeper:/live_nodes/127.0.0.1:334= 75_ [junit4:junit4] 1> INFO - 2013-04-10 00:16:42.108; org.apache.solr.commo= n.cloud.SolrZkClient; makePath: /live_nodes/127.0.0.1:33475_ [junit4:junit4] 1> INFO - 2013-04-10 00:16:42.112; org.apache.solr.commo= n.cloud.ZkStateReader$3; Updating live nodes... (2) [junit4:junit4] 1> INFO - 2013-04-10 00:16:42.112; org.apache.solr.commo= n.cloud.ZkStateReader$3; Updating live nodes... (2) [junit4:junit4] 1> INFO - 2013-04-10 00:16:42.112; org.apache.solr.commo= n.cloud.ZkStateReader$3; Updating live nodes... (2) [junit4:junit4] 1> INFO - 2013-04-10 00:16:42.129; org.apache.solr.servl= et.SolrDispatchFilter; user.dir=3D/usr/home/hudson/hudson-slave/workspace/L= ucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J1 [junit4:junit4] 1> INFO - 2013-04-10 00:16:42.129; org.apache.solr.servl= et.SolrDispatchFilter; SolrDispatchFilter.init() done [junit4:junit4] 1> INFO - 2013-04-10 00:16:42.130; 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-10 00:16:42.277; org.eclipse.jetty.ser= ver.Server; jetty-8.1.8.v20121106 [junit4:junit4] 1> INFO - 2013-04-10 00:16:42.280; org.eclipse.jetty.ser= ver.AbstractConnector; Started SocketConnector@127.0.0.1:33478 [junit4:junit4] 1> INFO - 2013-04-10 00:16:42.280; org.apache.solr.servl= et.SolrDispatchFilter; SolrDispatchFilter.init() [junit4:junit4] 1> INFO - 2013-04-10 00:16:42.281; org.apache.solr.core.= SolrResourceLoader; JNDI not configured for solr (NoInitialContextEx) [junit4:junit4] 1> INFO - 2013-04-10 00:16:42.281; org.apache.solr.core.= SolrResourceLoader; using system property solr.solr.home: /usr/home/hudson/= hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/tes= t/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty2-1365553= 002138 [junit4:junit4] 1> INFO - 2013-04-10 00:16:42.282; org.apache.solr.core.= CoreContainer$Initializer; looking for solr config file: /usr/home/hudson/h= udson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test= /J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty2-13655530= 02138/solr.xml [junit4:junit4] 1> INFO - 2013-04-10 00:16:42.282; org.apache.solr.core.= CoreContainer; New CoreContainer 1083420822 [junit4:junit4] 1> INFO - 2013-04-10 00:16:42.282; org.apache.solr.core.= CoreContainer; Loading CoreContainer using Solr Home: '/usr/home/hudson/hud= son-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J= 1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty2-1365553002= 138/' [junit4:junit4] 1> INFO - 2013-04-10 00:16:42.283; org.apache.solr.core.= SolrResourceLoader; new SolrResourceLoader for directory: '/usr/home/hudson= /hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/te= st/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty2-136555= 3002138/' [junit4:junit4] 1> INFO - 2013-04-10 00:16:42.318; org.apache.solr.handl= er.component.HttpShardHandlerFactory; Setting socketTimeout to: 120000 [junit4:junit4] 1> INFO - 2013-04-10 00:16:42.319; org.apache.solr.handl= er.component.HttpShardHandlerFactory; Setting urlScheme to: http:// [junit4:junit4] 1> INFO - 2013-04-10 00:16:42.319; org.apache.solr.handl= er.component.HttpShardHandlerFactory; Setting connTimeout to: 15000 [junit4:junit4] 1> INFO - 2013-04-10 00:16:42.320; org.apache.solr.handl= er.component.HttpShardHandlerFactory; Setting maxConnectionsPerHost to: 20 [junit4:junit4] 1> INFO - 2013-04-10 00:16:42.320; org.apache.solr.handl= er.component.HttpShardHandlerFactory; Setting corePoolSize to: 0 [junit4:junit4] 1> INFO - 2013-04-10 00:16:42.320; org.apache.solr.handl= er.component.HttpShardHandlerFactory; Setting maximumPoolSize to: 214748364= 7 [junit4:junit4] 1> INFO - 2013-04-10 00:16:42.321; org.apache.solr.handl= er.component.HttpShardHandlerFactory; Setting maxThreadIdleTime to: 5 [junit4:junit4] 1> INFO - 2013-04-10 00:16:42.321; org.apache.solr.handl= er.component.HttpShardHandlerFactory; Setting sizeOfQueue to: -1 [junit4:junit4] 1> INFO - 2013-04-10 00:16:42.321; org.apache.solr.handl= er.component.HttpShardHandlerFactory; Setting fairnessPolicy to: false [junit4:junit4] 1> INFO - 2013-04-10 00:16:42.322; 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-10 00:16:42.337; org.apache.solr.core.= CoreContainer; Registering Log Listener [junit4:junit4] 1> INFO - 2013-04-10 00:16:42.361; org.apache.solr.core.= CoreContainer; Zookeeper client=3D127.0.0.1:33468/solr [junit4:junit4] 1> INFO - 2013-04-10 00:16:42.362; org.apache.solr.cloud= .ZkController; zkHost includes chroot [junit4:junit4] 1> INFO - 2013-04-10 00:16:42.363; org.apache.solr.commo= n.cloud.ConnectionManager; Waiting for client to connect to ZooKeeper [junit4:junit4] 1> INFO - 2013-04-10 00:16:42.375; org.apache.solr.commo= n.cloud.ConnectionManager; Watcher org.apache.solr.common.cloud.ConnectionM= anager@431d908 name:ZooKeeperConnection Watcher:127.0.0.1:33468 got event W= atchedEvent state:SyncConnected type:None path:null path:null type:None [junit4:junit4] 1> INFO - 2013-04-10 00:16:42.376; org.apache.solr.commo= n.cloud.ConnectionManager; Client is connected to ZooKeeper [junit4:junit4] 1> INFO - 2013-04-10 00:16:42.476; 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-10 00:16:42.485; org.apache.solr.commo= n.cloud.ConnectionManager; Waiting for client to connect to ZooKeeper [junit4:junit4] 1> INFO - 2013-04-10 00:16:42.491; org.apache.solr.commo= n.cloud.ConnectionManager; Watcher org.apache.solr.common.cloud.ConnectionM= anager@77e994ed name:ZooKeeperConnection Watcher:127.0.0.1:33468/solr got e= vent WatchedEvent state:SyncConnected type:None path:null path:null type:No= ne [junit4:junit4] 1> INFO - 2013-04-10 00:16:42.492; org.apache.solr.commo= n.cloud.ConnectionManager; Client is connected to ZooKeeper [junit4:junit4] 1> INFO - 2013-04-10 00:16:42.537; org.apache.solr.commo= n.cloud.ZkStateReader; Updating cluster state from ZooKeeper...=20 [junit4:junit4] 1> INFO - 2013-04-10 00:16:43.543; org.apache.solr.cloud= .ZkController; Register node as live in ZooKeeper:/live_nodes/127.0.0.1:334= 78_ [junit4:junit4] 1> INFO - 2013-04-10 00:16:43.572; org.apache.solr.commo= n.cloud.SolrZkClient; makePath: /live_nodes/127.0.0.1:33478_ [junit4:junit4] 1> INFO - 2013-04-10 00:16:43.577; org.apache.solr.commo= n.cloud.ZkStateReader$3; Updating live nodes... (3) [junit4:junit4] 1> INFO - 2013-04-10 00:16:43.578; org.apache.solr.commo= n.cloud.ZkStateReader$3; Updating live nodes... (3) [junit4:junit4] 1> INFO - 2013-04-10 00:16:43.578; org.apache.solr.commo= n.cloud.ZkStateReader$3; Updating live nodes... (3) [junit4:junit4] 1> INFO - 2013-04-10 00:16:43.577; org.apache.solr.commo= n.cloud.ZkStateReader$3; Updating live nodes... (3) [junit4:junit4] 1> INFO - 2013-04-10 00:16:43.584; org.apache.solr.servl= et.SolrDispatchFilter; user.dir=3D/usr/home/hudson/hudson-slave/workspace/L= ucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J1 [junit4:junit4] 1> INFO - 2013-04-10 00:16:43.585; org.apache.solr.servl= et.SolrDispatchFilter; SolrDispatchFilter.init() done [junit4:junit4] 1> INFO - 2013-04-10 00:16:43.586; 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-10 00:16:43.807; org.eclipse.jetty.ser= ver.Server; jetty-8.1.8.v20121106 [junit4:junit4] 1> INFO - 2013-04-10 00:16:43.810; org.eclipse.jetty.ser= ver.AbstractConnector; Started SocketConnector@127.0.0.1:33481 [junit4:junit4] 1> INFO - 2013-04-10 00:16:43.811; org.apache.solr.servl= et.SolrDispatchFilter; SolrDispatchFilter.init() [junit4:junit4] 1> INFO - 2013-04-10 00:16:43.812; org.apache.solr.core.= SolrResourceLoader; JNDI not configured for solr (NoInitialContextEx) [junit4:junit4] 1> INFO - 2013-04-10 00:16:43.812; org.apache.solr.core.= SolrResourceLoader; using system property solr.solr.home: /usr/home/hudson/= hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/tes= t/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty3-1365553= 003596 [junit4:junit4] 1> INFO - 2013-04-10 00:16:43.813; org.apache.solr.core.= CoreContainer$Initializer; looking for solr config file: /usr/home/hudson/h= udson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test= /J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty3-13655530= 03596/solr.xml [junit4:junit4] 1> INFO - 2013-04-10 00:16:43.813; org.apache.solr.core.= CoreContainer; New CoreContainer 47799046 [junit4:junit4] 1> INFO - 2013-04-10 00:16:43.814; org.apache.solr.core.= CoreContainer; Loading CoreContainer using Solr Home: '/usr/home/hudson/hud= son-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J= 1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty3-1365553003= 596/' [junit4:junit4] 1> INFO - 2013-04-10 00:16:43.814; org.apache.solr.core.= SolrResourceLoader; new SolrResourceLoader for directory: '/usr/home/hudson= /hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/te= st/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty3-136555= 3003596/' [junit4:junit4] 1> INFO - 2013-04-10 00:16:43.869; org.apache.solr.handl= er.component.HttpShardHandlerFactory; Setting socketTimeout to: 120000 [junit4:junit4] 1> INFO - 2013-04-10 00:16:43.870; org.apache.solr.handl= er.component.HttpShardHandlerFactory; Setting urlScheme to: http:// [junit4:junit4] 1> INFO - 2013-04-10 00:16:43.870; org.apache.solr.handl= er.component.HttpShardHandlerFactory; Setting connTimeout to: 15000 [junit4:junit4] 1> INFO - 2013-04-10 00:16:43.871; org.apache.solr.handl= er.component.HttpShardHandlerFactory; Setting maxConnectionsPerHost to: 20 [junit4:junit4] 1> INFO - 2013-04-10 00:16:43.871; org.apache.solr.handl= er.component.HttpShardHandlerFactory; Setting corePoolSize to: 0 [junit4:junit4] 1> INFO - 2013-04-10 00:16:43.872; org.apache.solr.handl= er.component.HttpShardHandlerFactory; Setting maximumPoolSize to: 214748364= 7 [junit4:junit4] 1> INFO - 2013-04-10 00:16:43.872; org.apache.solr.handl= er.component.HttpShardHandlerFactory; Setting maxThreadIdleTime to: 5 [junit4:junit4] 1> INFO - 2013-04-10 00:16:43.873; org.apache.solr.handl= er.component.HttpShardHandlerFactory; Setting sizeOfQueue to: -1 [junit4:junit4] 1> INFO - 2013-04-10 00:16:43.873; org.apache.solr.handl= er.component.HttpShardHandlerFactory; Setting fairnessPolicy to: false [junit4:junit4] 1> INFO - 2013-04-10 00:16:43.874; 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-10 00:16:43.895; org.apache.solr.core.= CoreContainer; Registering Log Listener [junit4:junit4] 1> INFO - 2013-04-10 00:16:43.916; org.apache.solr.core.= CoreContainer; Zookeeper client=3D127.0.0.1:33468/solr [junit4:junit4] 1> INFO - 2013-04-10 00:16:43.916; org.apache.solr.cloud= .ZkController; zkHost includes chroot [junit4:junit4] 1> INFO - 2013-04-10 00:16:43.918; org.apache.solr.commo= n.cloud.ConnectionManager; Waiting for client to connect to ZooKeeper [junit4:junit4] 1> INFO - 2013-04-10 00:16:43.921; org.apache.solr.commo= n.cloud.ConnectionManager; Watcher org.apache.solr.common.cloud.ConnectionM= anager@64a1fcba name:ZooKeeperConnection Watcher:127.0.0.1:33468 got event = WatchedEvent state:SyncConnected type:None path:null path:null type:None [junit4:junit4] 1> INFO - 2013-04-10 00:16:43.921; org.apache.solr.commo= n.cloud.ConnectionManager; Client is connected to ZooKeeper [junit4:junit4] 1> INFO - 2013-04-10 00:16:43.924; 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-10 00:16:43.935; org.apache.solr.commo= n.cloud.ConnectionManager; Waiting for client to connect to ZooKeeper [junit4:junit4] 1> INFO - 2013-04-10 00:16:43.938; org.apache.solr.commo= n.cloud.ConnectionManager; Watcher org.apache.solr.common.cloud.ConnectionM= anager@7426dfa5 name:ZooKeeperConnection Watcher:127.0.0.1:33468/solr got e= vent WatchedEvent state:SyncConnected type:None path:null path:null type:No= ne [junit4:junit4] 1> INFO - 2013-04-10 00:16:43.938; org.apache.solr.commo= n.cloud.ConnectionManager; Client is connected to ZooKeeper [junit4:junit4] 1> INFO - 2013-04-10 00:16:43.950; org.apache.solr.commo= n.cloud.ZkStateReader; Updating cluster state from ZooKeeper...=20 [junit4:junit4] 1> INFO - 2013-04-10 00:16:44.956; org.apache.solr.cloud= .ZkController; Register node as live in ZooKeeper:/live_nodes/127.0.0.1:334= 81_ [junit4:junit4] 1> INFO - 2013-04-10 00:16:44.958; org.apache.solr.commo= n.cloud.SolrZkClient; makePath: /live_nodes/127.0.0.1:33481_ [junit4:junit4] 1> INFO - 2013-04-10 00:16:44.969; org.apache.solr.commo= n.cloud.ZkStateReader$3; Updating live nodes... (4) [junit4:junit4] 1> INFO - 2013-04-10 00:16:44.969; org.apache.solr.commo= n.cloud.ZkStateReader$3; Updating live nodes... (4) [junit4:junit4] 1> INFO - 2013-04-10 00:16:44.970; org.apache.solr.commo= n.cloud.ZkStateReader$3; Updating live nodes... (4) [junit4:junit4] 1> INFO - 2013-04-10 00:16:44.969; org.apache.solr.commo= n.cloud.ZkStateReader$3; Updating live nodes... (4) [junit4:junit4] 1> INFO - 2013-04-10 00:16:44.969; org.apache.solr.commo= n.cloud.ZkStateReader$3; Updating live nodes... (4) [junit4:junit4] 1> INFO - 2013-04-10 00:16:44.987; org.apache.solr.servl= et.SolrDispatchFilter; user.dir=3D/usr/home/hudson/hudson-slave/workspace/L= ucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J1 [junit4:junit4] 1> INFO - 2013-04-10 00:16:44.988; org.apache.solr.servl= et.SolrDispatchFilter; SolrDispatchFilter.init() done [junit4:junit4] 1> INFO - 2013-04-10 00:16:44.988; 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-10 00:16:45.211; org.eclipse.jetty.ser= ver.Server; jetty-8.1.8.v20121106 [junit4:junit4] 1> INFO - 2013-04-10 00:16:45.214; org.eclipse.jetty.ser= ver.AbstractConnector; Started SocketConnector@127.0.0.1:33487 [junit4:junit4] 1> INFO - 2013-04-10 00:16:45.215; org.apache.solr.servl= et.SolrDispatchFilter; SolrDispatchFilter.init() [junit4:junit4] 1> INFO - 2013-04-10 00:16:45.216; org.apache.solr.core.= SolrResourceLoader; JNDI not configured for solr (NoInitialContextEx) [junit4:junit4] 1> INFO - 2013-04-10 00:16:45.216; org.apache.solr.core.= SolrResourceLoader; using system property solr.solr.home: /usr/home/hudson/= hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/tes= t/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1365553= 004999 [junit4:junit4] 1> INFO - 2013-04-10 00:16:45.217; org.apache.solr.core.= CoreContainer$Initializer; looking for solr config file: /usr/home/hudson/h= udson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test= /J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-13655530= 04999/solr.xml [junit4:junit4] 1> INFO - 2013-04-10 00:16:45.217; org.apache.solr.core.= CoreContainer; New CoreContainer 1514785676 [junit4:junit4] 1> INFO - 2013-04-10 00:16:45.218; org.apache.solr.core.= CoreContainer; Loading CoreContainer using Solr Home: '/usr/home/hudson/hud= son-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J= 1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1365553004= 999/' [junit4:junit4] 1> INFO - 2013-04-10 00:16:45.218; org.apache.solr.core.= SolrResourceLoader; new SolrResourceLoader for directory: '/usr/home/hudson= /hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/te= st/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-136555= 3004999/' [junit4:junit4] 1> INFO - 2013-04-10 00:16:45.274; org.apache.solr.handl= er.component.HttpShardHandlerFactory; Setting socketTimeout to: 120000 [junit4:junit4] 1> INFO - 2013-04-10 00:16:45.275; org.apache.solr.handl= er.component.HttpShardHandlerFactory; Setting urlScheme to: http:// [junit4:junit4] 1> INFO - 2013-04-10 00:16:45.275; org.apache.solr.handl= er.component.HttpShardHandlerFactory; Setting connTimeout to: 15000 [junit4:junit4] 1> INFO - 2013-04-10 00:16:45.276; org.apache.solr.handl= er.component.HttpShardHandlerFactory; Setting maxConnectionsPerHost to: 20 [junit4:junit4] 1> INFO - 2013-04-10 00:16:45.276; org.apache.solr.handl= er.component.HttpShardHandlerFactory; Setting corePoolSize to: 0 [junit4:junit4] 1> INFO - 2013-04-10 00:16:45.277; org.apache.solr.handl= er.component.HttpShardHandlerFactory; Setting maximumPoolSize to: 214748364= 7 [junit4:junit4] 1> INFO - 2013-04-10 00:16:45.277; org.apache.solr.handl= er.component.HttpShardHandlerFactory; Setting maxThreadIdleTime to: 5 [junit4:junit4] 1> INFO - 2013-04-10 00:16:45.278; org.apache.solr.handl= er.component.HttpShardHandlerFactory; Setting sizeOfQueue to: -1 [junit4:junit4] 1> INFO - 2013-04-10 00:16:45.278; org.apache.solr.handl= er.component.HttpShardHandlerFactory; Setting fairnessPolicy to: false [junit4:junit4] 1> INFO - 2013-04-10 00:16:45.279; 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-10 00:16:45.300; org.apache.solr.core.= CoreContainer; Registering Log Listener [junit4:junit4] 1> INFO - 2013-04-10 00:16:45.320; org.apache.solr.core.= CoreContainer; Zookeeper client=3D127.0.0.1:33468/solr [junit4:junit4] 1> INFO - 2013-04-10 00:16:45.321; org.apache.solr.cloud= .ZkController; zkHost includes chroot [junit4:junit4] 1> INFO - 2013-04-10 00:16:45.322; org.apache.solr.commo= n.cloud.ConnectionManager; Waiting for client to connect to ZooKeeper [junit4:junit4] 1> INFO - 2013-04-10 00:16:45.329; org.apache.solr.commo= n.cloud.ConnectionManager; Watcher org.apache.solr.common.cloud.ConnectionM= anager@2a7ead31 name:ZooKeeperConnection Watcher:127.0.0.1:33468 got event = WatchedEvent state:SyncConnected type:None path:null path:null type:None [junit4:junit4] 1> INFO - 2013-04-10 00:16:45.329; org.apache.solr.commo= n.cloud.ConnectionManager; Client is connected to ZooKeeper [junit4:junit4] 1> INFO - 2013-04-10 00:16:45.338; 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-10 00:16:45.349; org.apache.solr.commo= n.cloud.ConnectionManager; Waiting for client to connect to ZooKeeper [junit4:junit4] 1> INFO - 2013-04-10 00:16:45.352; org.apache.solr.commo= n.cloud.ConnectionManager; Watcher org.apache.solr.common.cloud.ConnectionM= anager@3821e98d name:ZooKeeperConnection Watcher:127.0.0.1:33468/solr got e= vent WatchedEvent state:SyncConnected type:None path:null path:null type:No= ne [junit4:junit4] 1> INFO - 2013-04-10 00:16:45.353; org.apache.solr.commo= n.cloud.ConnectionManager; Client is connected to ZooKeeper [junit4:junit4] 1> INFO - 2013-04-10 00:16:45.368; org.apache.solr.commo= n.cloud.ZkStateReader; Updating cluster state from ZooKeeper...=20 [junit4:junit4] 1> INFO - 2013-04-10 00:16:46.374; org.apache.solr.cloud= .ZkController; Register node as live in ZooKeeper:/live_nodes/127.0.0.1:334= 87_ [junit4:junit4] 1> INFO - 2013-04-10 00:16:46.376; org.apache.solr.commo= n.cloud.SolrZkClient; makePath: /live_nodes/127.0.0.1:33487_ [junit4:junit4] 1> INFO - 2013-04-10 00:16:46.380; org.apache.solr.commo= n.cloud.ZkStateReader$3; Updating live nodes... (5) [junit4:junit4] 1> INFO - 2013-04-10 00:16:46.381; org.apache.solr.commo= n.cloud.ZkStateReader$3; Updating live nodes... (5) [junit4:junit4] 1> INFO - 2013-04-10 00:16:46.381; org.apache.solr.commo= n.cloud.ZkStateReader$3; Updating live nodes... (5) [junit4:junit4] 1> INFO - 2013-04-10 00:16:46.380; org.apache.solr.commo= n.cloud.ZkStateReader$3; Updating live nodes... (5) [junit4:junit4] 1> INFO - 2013-04-10 00:16:46.380; org.apache.solr.commo= n.cloud.ZkStateReader$3; Updating live nodes... (5) [junit4:junit4] 1> INFO - 2013-04-10 00:16:46.380; org.apache.solr.commo= n.cloud.ZkStateReader$3; Updating live nodes... (5) [junit4:junit4] 1> INFO - 2013-04-10 00:16:46.395; org.apache.solr.servl= et.SolrDispatchFilter; user.dir=3D/usr/home/hudson/hudson-slave/workspace/L= ucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J1 [junit4:junit4] 1> INFO - 2013-04-10 00:16:46.396; org.apache.solr.servl= et.SolrDispatchFilter; SolrDispatchFilter.init() done [junit4:junit4] 1> INFO - 2013-04-10 00:16:46.397; 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-10 00:16:46.412; 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-10 00:16:46.430; org.apache.solr.handl= er.admin.CollectionsHandler; Creating Collection : numShards=3D2&name=3Dnod= es_used_collection&replicationFactor=3D2&action=3DCREATE&wt=3Djavabin&versi= on=3D2 [junit4:junit4] 1> INFO - 2013-04-10 00:16:46.433; org.apache.solr.cloud= .DistributedQueue$LatchChildWatcher; Watcher fired on path: /overseer/colle= ction-queue-work state: SyncConnected type NodeChildrenChanged [junit4:junit4] 1> INFO - 2013-04-10 00:16:46.463; org.apache.solr.cloud= .OverseerCollectionProcessor; Overseer Collection Processor: Get the messag= e id:/overseer/collection-queue-work/qn-0000000000 message:{ [junit4:junit4] 1> "operation":"createcollection", [junit4:junit4] 1> "numShards":"2", [junit4:junit4] 1> "maxShardsPerNode":null, [junit4:junit4] 1> "createNodeSet":null, [junit4:junit4] 1> "name":"nodes_used_collection", [junit4:junit4] 1> "replicationFactor":"2"} [junit4:junit4] 1> INFO - 2013-04-10 00:16:46.463; org.apache.solr.cloud= .OverseerCollectionProcessor; Creating shard nodes_used_collection_shard1_r= eplica1 as part of slice shard1 of collection nodes_used_collection on 127.= 0.0.1:33471_ [junit4:junit4] 1> INFO - 2013-04-10 00:16:46.464; org.apache.solr.cloud= .OverseerCollectionProcessor; Creating shard nodes_used_collection_shard1_r= eplica2 as part of slice shard1 of collection nodes_used_collection on 127.= 0.0.1:33475_ [junit4:junit4] 1> INFO - 2013-04-10 00:16:46.465; org.apache.solr.cloud= .OverseerCollectionProcessor; Creating shard nodes_used_collection_shard2_r= eplica1 as part of slice shard2 of collection nodes_used_collection on 127.= 0.0.1:33478_ [junit4:junit4] 1> INFO - 2013-04-10 00:16:46.465; org.apache.solr.cloud= .OverseerCollectionProcessor; Creating shard nodes_used_collection_shard2_r= eplica2 as part of slice shard2 of collection nodes_used_collection on 127.= 0.0.1:33487_ [junit4:junit4] 1> INFO - 2013-04-10 00:16:46.468; org.apache.solr.core.= CoreContainer; Creating SolrCore 'nodes_used_collection_shard1_replica1' us= ing instanceDir: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-= 4.x-Java6/solr/build/solr-core/test/J1/./org.apache.solr.cloud.CollectionsA= PIDistributedZkTest-controljetty-1365553000254/nodes_used_collection_shard1= _replica1 [junit4:junit4] 1> INFO - 2013-04-10 00:16:46.468; org.apache.solr.core.= CoreContainer; Creating SolrCore 'nodes_used_collection_shard2_replica1' us= ing instanceDir: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-= 4.x-Java6/solr/build/solr-core/test/J1/./org.apache.solr.cloud.CollectionsA= PIDistributedZkTest-jetty2-1365553002138/nodes_used_collection_shard2_repli= ca1 [junit4:junit4] 1> INFO - 2013-04-10 00:16:46.468; org.apache.solr.core.= CoreContainer; Creating SolrCore 'nodes_used_collection_shard1_replica2' us= ing instanceDir: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-= 4.x-Java6/solr/build/solr-core/test/J1/./org.apache.solr.cloud.CollectionsA= PIDistributedZkTest-jetty1-1365553000729/nodes_used_collection_shard1_repli= ca2 [junit4:junit4] 1> INFO - 2013-04-10 00:16:46.470; org.apache.solr.cloud= .ZkController; Check for collection zkNode:nodes_used_collection [junit4:junit4] 1> INFO - 2013-04-10 00:16:46.469; org.apache.solr.core.= CoreContainer; Creating SolrCore 'nodes_used_collection_shard2_replica2' us= ing instanceDir: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-= 4.x-Java6/solr/build/solr-core/test/J1/./org.apache.solr.cloud.CollectionsA= PIDistributedZkTest-jetty4-1365553004999/nodes_used_collection_shard2_repli= ca2 [junit4:junit4] 1> INFO - 2013-04-10 00:16:46.469; org.apache.solr.cloud= .ZkController; Check for collection zkNode:nodes_used_collection [junit4:junit4] 1> INFO - 2013-04-10 00:16:46.471; org.apache.solr.cloud= .ZkController; Creating collection in ZooKeeper:nodes_used_collection [junit4:junit4] 1> INFO - 2013-04-10 00:16:46.471; org.apache.solr.cloud= .ZkController; Check for collection zkNode:nodes_used_collection [junit4:junit4] 1> INFO - 2013-04-10 00:16:46.470; org.apache.solr.cloud= .ZkController; Check for collection zkNode:nodes_used_collection [junit4:junit4] 1> INFO - 2013-04-10 00:16:46.473; org.apache.solr.cloud= .ZkController; Creating collection in ZooKeeper:nodes_used_collection [junit4:junit4] 1> INFO - 2013-04-10 00:16:46.472; org.apache.solr.cloud= .ZkController; Looking for collection configName [junit4:junit4] 1> INFO - 2013-04-10 00:16:46.474; org.apache.solr.cloud= .ZkController; Creating collection in ZooKeeper:nodes_used_collection [junit4:junit4] 1> INFO - 2013-04-10 00:16:46.474; org.apache.solr.cloud= .ZkController; Looking for collection configName [junit4:junit4] 1> INFO - 2013-04-10 00:16:46.473; org.apache.solr.cloud= .ZkController; Creating collection in ZooKeeper:nodes_used_collection [junit4:junit4] 1> INFO - 2013-04-10 00:16:46.475; org.apache.solr.cloud= .ZkController; Only one config set found in zk - using it:conf1 [junit4:junit4] 1> INFO - 2013-04-10 00:16:46.474; org.apache.solr.cloud= .ZkController; Looking for collection configName [junit4:junit4] 1> INFO - 2013-04-10 00:16:46.476; org.apache.solr.cloud= .ZkController; Only one config set found in zk - using it:conf1 [junit4:junit4] 1> INFO - 2013-04-10 00:16:46.476; org.apache.solr.commo= n.cloud.SolrZkClient; makePath: /collections/nodes_used_collection [junit4:junit4] 1> INFO - 2013-04-10 00:16:46.475; org.apache.solr.cloud= .ZkController; Looking for collection configName [junit4:junit4] 1> INFO - 2013-04-10 00:16:46.478; org.apache.solr.cloud= .ZkController; Only one config set found in zk - using it:conf1 [junit4:junit4] 1> INFO - 2013-04-10 00:16:46.477; org.apache.solr.commo= n.cloud.SolrZkClient; makePath: /collections/nodes_used_collection [junit4:junit4] 1> INFO - 2013-04-10 00:16:46.479; org.apache.solr.commo= n.cloud.SolrZkClient; makePath: /collections/nodes_used_collection [junit4:junit4] 1> INFO - 2013-04-10 00:16:46.481; org.apache.solr.cloud= .ZkController; Load collection config from:/collections/nodes_used_collecti= on [junit4:junit4] 1> INFO - 2013-04-10 00:16:46.481; org.apache.solr.commo= n.cloud.SolrZkClient; makePath: /collections/nodes_used_collection [junit4:junit4] 1> INFO - 2013-04-10 00:16:46.488; org.apache.solr.cloud= .ZkController; Load collection config from:/collections/nodes_used_collecti= on [junit4:junit4] 1> INFO - 2013-04-10 00:16:46.489; org.apache.solr.cloud= .ZkController; Load collection config from:/collections/nodes_used_collecti= on [junit4:junit4] 1> INFO - 2013-04-10 00:16:46.490; org.apache.solr.core.= SolrResourceLoader; new SolrResourceLoader for directory: '/usr/home/hudson= /hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/te= st/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty2-136555= 3002138/nodes_used_collection_shard2_replica1/' [junit4:junit4] 1> INFO - 2013-04-10 00:16:46.491; org.apache.solr.core.= SolrResourceLoader; new SolrResourceLoader for directory: '/usr/home/hudson= /hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/te= st/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty1-136555= 3000729/nodes_used_collection_shard1_replica2/' [junit4:junit4] 1> INFO - 2013-04-10 00:16:46.492; org.apache.solr.core.= SolrResourceLoader; new SolrResourceLoader for directory: '/usr/home/hudson= /hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/te= st/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-controljetty-= 1365553000254/nodes_used_collection_shard1_replica1/' [junit4:junit4] 1> INFO - 2013-04-10 00:16:46.492; org.apache.solr.cloud= .ZkController; Load collection config from:/collections/nodes_used_collecti= on [junit4:junit4] 1> INFO - 2013-04-10 00:16:46.497; org.apache.solr.core.= SolrResourceLoader; new SolrResourceLoader for directory: '/usr/home/hudson= /hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/te= st/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-136555= 3004999/nodes_used_collection_shard2_replica2/' [junit4:junit4] 1> INFO - 2013-04-10 00:16:46.562; org.apache.solr.core.= SolrConfig; Using Lucene MatchVersion: LUCENE_43 [junit4:junit4] 1> INFO - 2013-04-10 00:16:46.562; org.apache.solr.core.= SolrConfig; Using Lucene MatchVersion: LUCENE_43 [junit4:junit4] 1> INFO - 2013-04-10 00:16:46.564; org.apache.solr.core.= SolrConfig; Using Lucene MatchVersion: LUCENE_43 [junit4:junit4] 1> INFO - 2013-04-10 00:16:46.569; org.apache.solr.core.= SolrConfig; Using Lucene MatchVersion: LUCENE_43 [junit4:junit4] 1> INFO - 2013-04-10 00:16:46.641; org.apache.solr.core.= SolrConfig; Loaded SolrConfig: solrconfig.xml [junit4:junit4] 1> INFO - 2013-04-10 00:16:46.647; org.apache.solr.core.= SolrConfig; Loaded SolrConfig: solrconfig.xml [junit4:junit4] 1> INFO - 2013-04-10 00:16:46.671; org.apache.solr.core.= SolrConfig; Loaded SolrConfig: solrconfig.xml [junit4:junit4] 1> INFO - 2013-04-10 00:16:46.674; org.apache.solr.core.= SolrConfig; Loaded SolrConfig: solrconfig.xml [junit4:junit4] 1> INFO - 2013-04-10 00:16:46.713; org.apache.solr.schem= a.IndexSchema; Reading Solr Schema from schema.xml [junit4:junit4] 1> INFO - 2013-04-10 00:16:46.720; org.apache.solr.schem= a.IndexSchema; Schema name=3Dtest [junit4:junit4] 1> INFO - 2013-04-10 00:16:46.743; org.apache.solr.schem= a.IndexSchema; Reading Solr Schema from schema.xml [junit4:junit4] 1> INFO - 2013-04-10 00:16:46.749; org.apache.solr.schem= a.IndexSchema; Reading Solr Schema from schema.xml [junit4:junit4] 1> INFO - 2013-04-10 00:16:46.750; org.apache.solr.schem= a.IndexSchema; Schema name=3Dtest [junit4:junit4] 1> INFO - 2013-04-10 00:16:46.757; org.apache.solr.schem= a.IndexSchema; Schema name=3Dtest [junit4:junit4] 1> INFO - 2013-04-10 00:16:46.773; org.apache.solr.schem= a.IndexSchema; Reading Solr Schema from schema.xml [junit4:junit4] 1> INFO - 2013-04-10 00:16:46.785; org.apache.solr.schem= a.IndexSchema; Schema name=3Dtest [junit4:junit4] 1> INFO - 2013-04-10 00:16:47.488; org.apache.solr.schem= a.OpenExchangeRatesOrgProvider; Initialized with rates=3Dopen-exchange-rate= s.json, refreshInterval=3D1440. [junit4:junit4] 1> INFO - 2013-04-10 00:16:47.501; org.apache.solr.schem= a.IndexSchema; default search field in schema is text [junit4:junit4] 1> INFO - 2013-04-10 00:16:47.507; org.apache.solr.schem= a.IndexSchema; unique key field: id [junit4:junit4] 1> INFO - 2013-04-10 00:16:47.531; org.apache.solr.schem= a.FileExchangeRateProvider; Reloading exchange rates from file currency.xml [junit4:junit4] 1> INFO - 2013-04-10 00:16:47.531; org.apache.solr.schem= a.OpenExchangeRatesOrgProvider; Initialized with rates=3Dopen-exchange-rate= s.json, refreshInterval=3D1440. [junit4:junit4] 1> INFO - 2013-04-10 00:16:47.537; org.apache.solr.schem= a.FileExchangeRateProvider; Reloading exchange rates from file currency.xml [junit4:junit4] 1> INFO - 2013-04-10 00:16:47.540; org.apache.solr.schem= a.IndexSchema; default search field in schema is text [junit4:junit4] 1> INFO - 2013-04-10 00:16:47.543; org.apache.solr.schem= a.OpenExchangeRatesOrgProvider; Reloading exchange rates from open-exchange= -rates.json [junit4:junit4] 1> INFO - 2013-04-10 00:16:47.544; org.apache.solr.schem= a.IndexSchema; unique key field: id [junit4:junit4] 1> WARN - 2013-04-10 00:16:47.545; org.apache.solr.schem= a.OpenExchangeRatesOrgProvider$OpenExchangeRates; Unknown key IMPORTANT NOT= E [junit4:junit4] 1> WARN - 2013-04-10 00:16:47.546; org.apache.solr.schem= a.OpenExchangeRatesOrgProvider$OpenExchangeRates; Expected key, got STRING [junit4:junit4] 1> INFO - 2013-04-10 00:16:47.546; org.apache.solr.schem= a.OpenExchangeRatesOrgProvider; Reloading exchange rates from open-exchange= -rates.json [junit4:junit4] 1> WARN - 2013-04-10 00:16:47.548; org.apache.solr.schem= a.OpenExchangeRatesOrgProvider$OpenExchangeRates; Unknown key IMPORTANT NOT= E [junit4:junit4] 1> WARN - 2013-04-10 00:16:47.549; org.apache.solr.schem= a.OpenExchangeRatesOrgProvider$OpenExchangeRates; Expected key, got STRING [junit4:junit4] 1> INFO - 2013-04-10 00:16:47.549; org.apache.solr.core.= SolrCore; org.apache.solr.core.MockDirectoryFactory [junit4:junit4] 1> INFO - 2013-04-10 00:16:47.550; org.apache.solr.core.= SolrCore; [nodes_used_collection_shard1_replica2] Opening new SolrCore at /= usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/bui= ld/solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTes= t-jetty1-1365553000729/nodes_used_collection_shard1_replica2/, dataDir=3D/u= sr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/buil= d/solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest= -jetty1-1365553000729/nodes_used_collection_shard1_replica2/data/ [junit4:junit4] 1> INFO - 2013-04-10 00:16:47.551; org.apache.solr.core.= JmxMonitoredMap; JMX monitoring is enabled. Adding Solr mbeans to JMX Serve= r: com.sun.jmx.mbeanserver.JmxMBeanServer@18987a33 [junit4:junit4] 1> INFO - 2013-04-10 00:16:47.552; org.apache.solr.core.= SolrCore; org.apache.solr.core.MockDirectoryFactory [junit4:junit4] 1> INFO - 2013-04-10 00:16:47.568; org.apache.solr.schem= a.FileExchangeRateProvider; Reloading exchange rates from file currency.xml [junit4:junit4] 1> INFO - 2013-04-10 00:16:47.570; org.apache.solr.core.= CachingDirectoryFactory; return new directory for /usr/home/hudson/hudson-s= lave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J1/./o= rg.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty1-1365553000729/n= odes_used_collection_shard1_replica2/data [junit4:junit4] 1> INFO - 2013-04-10 00:16:47.572; org.apache.solr.core.= SolrCore; New index directory detected: old=3Dnull new=3D/usr/home/hudson/h= udson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test= /J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty1-13655530= 00729/nodes_used_collection_shard1_replica2/data/index/ [junit4:junit4] 1> WARN - 2013-04-10 00:16:47.572; org.apache.solr.core.= SolrCore; [nodes_used_collection_shard1_replica2] Solr index directory '/us= r/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build= /solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-= jetty1-1365553000729/nodes_used_collection_shard1_replica2/data/index' does= n't exist. Creating new index... [junit4:junit4] 1> INFO - 2013-04-10 00:16:47.573; org.apache.solr.core.= CachingDirectoryFactory; return new directory for /usr/home/hudson/hudson-s= lave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J1/./o= rg.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty1-1365553000729/n= odes_used_collection_shard1_replica2/data/index [junit4:junit4] 1> INFO - 2013-04-10 00:16:47.574; org.apache.solr.schem= a.OpenExchangeRatesOrgProvider; Initialized with rates=3Dopen-exchange-rate= s.json, refreshInterval=3D1440. [junit4:junit4] 1> INFO - 2013-04-10 00:16:47.575; org.apache.solr.schem= a.FileExchangeRateProvider; Reloading exchange rates from file currency.xml [junit4:junit4] 1> INFO - 2013-04-10 00:16:47.579; org.apache.solr.core.= SolrDeletionPolicy; SolrDeletionPolicy.onCommit: commits:num=3D1 [junit4:junit4] 1> =09commit{dir=3DMockDirWrapper(org.apache.lucene.store= .RAMDirectory@3158a9f lockFactory=3Dorg.apache.lucene.store.NativeFSLockFac= tory@5062e9b4),segFN=3Dsegments_1,generation=3D1,filenames=3D[segments_1] [junit4:junit4] 1> INFO - 2013-04-10 00:16:47.580; org.apache.solr.core.= SolrDeletionPolicy; newest commit =3D 1[segments_1] [junit4:junit4] 1> INFO - 2013-04-10 00:16:47.580; org.apache.solr.schem= a.OpenExchangeRatesOrgProvider; Reloading exchange rates from open-exchange= -rates.json [junit4:junit4] 1> WARN - 2013-04-10 00:16:47.582; org.apache.solr.schem= a.OpenExchangeRatesOrgProvider$OpenExchangeRates; Unknown key IMPORTANT NOT= E [junit4:junit4] 1> INFO - 2013-04-10 00:16:47.582; org.apache.solr.schem= a.OpenExchangeRatesOrgProvider; Initialized with rates=3Dopen-exchange-rate= s.json, refreshInterval=3D1440. [junit4:junit4] 1> WARN - 2013-04-10 00:16:47.584; org.apache.solr.schem= a.OpenExchangeRatesOrgProvider$OpenExchangeRates; Expected key, got STRING [junit4:junit4] 1> INFO - 2013-04-10 00:16:47.584; org.apache.solr.schem= a.IndexSchema; default search field in schema is text [junit4:junit4] 1> INFO - 2013-04-10 00:16:47.585; org.apache.solr.schem= a.OpenExchangeRatesOrgProvider; Reloading exchange rates from open-exchange= -rates.json [junit4:junit4] 1> INFO - 2013-04-10 00:16:47.585; org.apache.solr.updat= e.processor.UpdateRequestProcessorChain; inserting DistributedUpdateProcess= orFactory into updateRequestProcessorChain "dedupe" [junit4:junit4] 1> INFO - 2013-04-10 00:16:47.586; org.apache.solr.updat= e.processor.UpdateRequestProcessorChain; inserting DistributedUpdateProcess= orFactory into updateRequestProcessorChain "stored_sig" [junit4:junit4] 1> WARN - 2013-04-10 00:16:47.586; org.apache.solr.schem= a.OpenExchangeRatesOrgProvider$OpenExchangeRates; Unknown key IMPORTANT NOT= E [junit4:junit4] 1> INFO - 2013-04-10 00:16:47.587; org.apache.solr.updat= e.processor.UpdateRequestProcessorChain; inserting DistributedUpdateProcess= orFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit= " [junit4:junit4] 1> WARN - 2013-04-10 00:16:47.587; org.apache.solr.schem= a.OpenExchangeRatesOrgProvider$OpenExchangeRates; Expected key, got STRING [junit4:junit4] 1> INFO - 2013-04-10 00:16:47.588; org.apache.solr.core.= RequestHandlers; created standard: solr.StandardRequestHandler [junit4:junit4] 1> INFO - 2013-04-10 00:16:47.588; org.apache.solr.core.= SolrCore; org.apache.solr.core.MockDirectoryFactory [junit4:junit4] 1> INFO - 2013-04-10 00:16:47.589; org.apache.solr.core.= RequestHandlers; created /get: solr.RealTimeGetHandler [junit4:junit4] 1> INFO - 2013-04-10 00:16:47.589; org.apache.solr.core.= RequestHandlers; adding lazy requestHandler: solr.ReplicationHandler [junit4:junit4] 1> INFO - 2013-04-10 00:16:47.588; org.apache.solr.schem= a.IndexSchema; unique key field: id [junit4:junit4] 1> INFO - 2013-04-10 00:16:47.589; org.apache.solr.core.= RequestHandlers; created /replication: solr.ReplicationHandler [junit4:junit4] 1> INFO - 2013-04-10 00:16:47.589; org.apache.solr.core.= SolrCore; [nodes_used_collection_shard2_replica1] Opening new SolrCore at /= usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/bui= ld/solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTes= t-jetty2-1365553002138/nodes_used_collection_shard2_replica1/, dataDir=3D/u= sr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/buil= d/solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest= -jetty2-1365553002138/nodes_used_collection_shard2_replica1/data/ [junit4:junit4] 1> INFO - 2013-04-10 00:16:47.591; org.apache.solr.core.= JmxMonitoredMap; JMX monitoring is enabled. Adding Solr mbeans to JMX Serve= r: com.sun.jmx.mbeanserver.JmxMBeanServer@18987a33 [junit4:junit4] 1> INFO - 2013-04-10 00:16:47.591; org.apache.solr.core.= RequestHandlers; created /update: solr.UpdateRequestHandler [junit4:junit4] 1> INFO - 2013-04-10 00:16:47.591; org.apache.solr.core.= SolrCore; org.apache.solr.core.MockDirectoryFactory [junit4:junit4] 1> INFO - 2013-04-10 00:16:47.592; org.apache.solr.core.= RequestHandlers; created /admin/: org.apache.solr.handler.admin.AdminHandle= rs [junit4:junit4] 1> INFO - 2013-04-10 00:16:47.592; org.apache.solr.schem= a.IndexSchema; default search field in schema is text [junit4:junit4] 1> INFO - 2013-04-10 00:16:47.594; org.apache.solr.core.= CachingDirectoryFactory; return new directory for /usr/home/hudson/hudson-s= lave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J1/./o= rg.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty2-1365553002138/n= odes_used_collection_shard2_replica1/data [junit4:junit4] 1> INFO - 2013-04-10 00:16:47.595; org.apache.solr.core.= SolrCore; New index directory detected: old=3Dnull new=3D/usr/home/hudson/h= udson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test= /J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty2-13655530= 02138/nodes_used_collection_shard2_replica1/data/index/ [junit4:junit4] 1> WARN - 2013-04-10 00:16:47.595; org.apache.solr.core.= SolrCore; [nodes_used_collection_shard2_replica1] Solr index directory '/us= r/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build= /solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-= jetty2-1365553002138/nodes_used_collection_shard2_replica1/data/index' does= n't exist. Creating new index... [junit4:junit4] 1> INFO - 2013-04-10 00:16:47.596; org.apache.solr.core.= CachingDirectoryFactory; return new directory for /usr/home/hudson/hudson-s= lave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J1/./o= rg.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty2-1365553002138/n= odes_used_collection_shard2_replica1/data/index [junit4:junit4] 1> INFO - 2013-04-10 00:16:47.596; org.apache.solr.schem= a.IndexSchema; unique key field: id [junit4:junit4] 1> INFO - 2013-04-10 00:16:47.600; org.apache.solr.core.= SolrDeletionPolicy; SolrDeletionPolicy.onCommit: commits:num=3D1 [junit4:junit4] 1> =09commit{dir=3DMockDirWrapper(org.apache.lucene.store= .RAMDirectory@7ff6c1c1 lockFactory=3Dorg.apache.lucene.store.NativeFSLockFa= ctory@3ff9980),segFN=3Dsegments_1,generation=3D1,filenames=3D[segments_1] [junit4:junit4] 1> INFO - 2013-04-10 00:16:47.600; org.apache.solr.core.= SolrDeletionPolicy; newest commit =3D 1[segments_1] [junit4:junit4] 1> INFO - 2013-04-10 00:16:47.603; org.apache.solr.updat= e.processor.UpdateRequestProcessorChain; inserting DistributedUpdateProcess= orFactory into updateRequestProcessorChain "dedupe" [junit4:junit4] 1> INFO - 2013-04-10 00:16:47.604; org.apache.solr.updat= e.processor.UpdateRequestProcessorChain; inserting DistributedUpdateProcess= orFactory into updateRequestProcessorChain "stored_sig" [junit4:junit4] 1> INFO - 2013-04-10 00:16:47.605; org.apache.solr.handl= er.loader.XMLLoader; xsltCacheLifetimeSeconds=3D60 [junit4:junit4] 1> INFO - 2013-04-10 00:16:47.605; org.apache.solr.updat= e.processor.UpdateRequestProcessorChain; inserting DistributedUpdateProcess= orFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit= " [junit4:junit4] 1> INFO - 2013-04-10 00:16:47.606; org.apache.solr.core.= RequestHandlers; created standard: solr.StandardRequestHandler [junit4:junit4] 1> INFO - 2013-04-10 00:16:47.607; org.apache.solr.core.= RequestHandlers; created /get: solr.RealTimeGetHandler [junit4:junit4] 1> INFO - 2013-04-10 00:16:47.607; org.apache.solr.core.= RequestHandlers; adding lazy requestHandler: solr.ReplicationHandler [junit4:junit4] 1> INFO - 2013-04-10 00:16:47.611; org.apache.solr.core.= RequestHandlers; created /replication: solr.ReplicationHandler [junit4:junit4] 1> INFO - 2013-04-10 00:16:47.612; org.apache.solr.core.= RequestHandlers; created /update: solr.UpdateRequestHandler [junit4:junit4] 1> INFO - 2013-04-10 00:16:47.613; org.apache.solr.core.= RequestHandlers; created /admin/: org.apache.solr.handler.admin.AdminHandle= rs [junit4:junit4] 1> INFO - 2013-04-10 00:16:47.614; org.apache.solr.schem= a.FileExchangeRateProvider; Reloading exchange rates from file currency.xml [junit4:junit4] 1> INFO - 2013-04-10 00:16:47.615; org.apache.solr.searc= h.SolrIndexSearcher; Opening Searcher@695a22ad main [junit4:junit4] 1> INFO - 2013-04-10 00:16:47.616; org.apache.solr.updat= e.UpdateHandler; Clearing tlog files, tlogDir=3D/usr/home/hudson/hudson-sla= ve/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J1/./org= .apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty1-1365553000729/nod= es_used_collection_shard1_replica2/data/tlog [junit4:junit4] 1> INFO - 2013-04-10 00:16:47.618; org.apache.solr.updat= e.CommitTracker; Hard AutoCommit: disabled [junit4:junit4] 1> INFO - 2013-04-10 00:16:47.619; org.apache.solr.updat= e.CommitTracker; Soft AutoCommit: disabled [junit4:junit4] 1> INFO - 2013-04-10 00:16:47.619; org.apache.solr.handl= er.loader.XMLLoader; xsltCacheLifetimeSeconds=3D60 [junit4:junit4] 1> INFO - 2013-04-10 00:16:47.620; org.apache.solr.schem= a.FileExchangeRateProvider; Reloading exchange rates from file currency.xml [junit4:junit4] 1> INFO - 2013-04-10 00:16:47.623; org.apache.solr.core.= SolrCore; [nodes_used_collection_shard1_replica2] Registered new searcher S= earcher@695a22ad main{StandardDirectoryReader(segments_1:1)} [junit4:junit4] 1> INFO - 2013-04-10 00:16:47.624; org.apache.solr.searc= h.SolrIndexSearcher; Opening Searcher@75dd05d6 main [junit4:junit4] 1> INFO - 2013-04-10 00:16:47.625; org.apache.solr.updat= e.UpdateHandler; Clearing tlog files, tlogDir=3D/usr/home/hudson/hudson-sla= ve/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J1/./org= .apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty2-1365553002138/nod= es_used_collection_shard2_replica1/data/tlog [junit4:junit4] 1> INFO - 2013-04-10 00:16:47.626; org.apache.solr.cloud= .ZkController; publishing core=3Dnodes_used_collection_shard1_replica2 stat= e=3Ddown [junit4:junit4] 1> INFO - 2013-04-10 00:16:47.626; org.apache.solr.updat= e.CommitTracker; Hard AutoCommit: disabled [junit4:junit4] 1> INFO - 2013-04-10 00:16:47.627; org.apache.solr.updat= e.CommitTracker; Soft AutoCommit: disabled [junit4:junit4] 1> INFO - 2013-04-10 00:16:47.628; org.apache.solr.schem= a.FileExchangeRateProvider; Reloading exchange rates from file currency.xml [junit4:junit4] 1> INFO - 2013-04-10 00:16:47.628; org.apache.solr.schem= a.FileExchangeRateProvider; Reloading exchange rates from file currency.xml [junit4:junit4] 1> INFO - 2013-04-10 00:16:47.631; org.apache.solr.core.= SolrCore; [nodes_used_collection_shard2_replica1] Registered new searcher S= earcher@75dd05d6 main{StandardDirectoryReader(segments_1:1)} [junit4:junit4] 1> INFO - 2013-04-10 00:16:47.633; org.apache.solr.cloud= .ZkController; publishing core=3Dnodes_used_collection_shard2_replica1 stat= e=3Ddown [junit4:junit4] 1> INFO - 2013-04-10 00:16:47.683; org.apache.solr.schem= a.OpenExchangeRatesOrgProvider; Reloading exchange rates from open-exchange= -rates.json [junit4:junit4] 1> INFO - 2013-04-10 00:16:47.684; org.apache.solr.schem= a.OpenExchangeRatesOrgProvider; Reloading exchange rates from open-exchange= -rates.json [junit4:junit4] 1> WARN - 2013-04-10 00:16:47.684; org.apache.solr.schem= a.OpenExchangeRatesOrgProvider$OpenExchangeRates; Unknown key IMPORTANT NOT= E [junit4:junit4] 1> WARN - 2013-04-10 00:16:47.686; org.apache.solr.schem= a.OpenExchangeRatesOrgProvider$OpenExchangeRates; Unknown key IMPORTANT NOT= E [junit4:junit4] 1> WARN - 2013-04-10 00:16:47.686; org.apache.solr.schem= a.OpenExchangeRatesOrgProvider$OpenExchangeRates; Expected key, got STRING [junit4:junit4] 1> WARN - 2013-04-10 00:16:47.686; org.apache.solr.schem= a.OpenExchangeRatesOrgProvider$OpenExchangeRates; Expected key, got STRING [junit4:junit4] 1> INFO - 2013-04-10 00:16:47.687; org.apache.solr.schem= a.OpenExchangeRatesOrgProvider; Reloading exchange rates from open-exchange= -rates.json [junit4:junit4] 1> INFO - 2013-04-10 00:16:47.687; org.apache.solr.schem= a.OpenExchangeRatesOrgProvider; Reloading exchange rates from open-exchange= -rates.json [junit4:junit4] 1> WARN - 2013-04-10 00:16:47.689; org.apache.solr.schem= a.OpenExchangeRatesOrgProvider$OpenExchangeRates; Unknown key IMPORTANT NOT= E [junit4:junit4] 1> WARN - 2013-04-10 00:16:47.689; org.apache.solr.schem= a.OpenExchangeRatesOrgProvider$OpenExchangeRates; Unknown key IMPORTANT NOT= E [junit4:junit4] 1> WARN - 2013-04-10 00:16:47.690; org.apache.solr.schem= a.OpenExchangeRatesOrgProvider$OpenExchangeRates; Expected key, got STRING [junit4:junit4] 1> WARN - 2013-04-10 00:16:47.689; org.apache.solr.schem= a.OpenExchangeRatesOrgProvider$OpenExchangeRates; Expected key, got STRING [junit4:junit4] 1> INFO - 2013-04-10 00:16:47.690; org.apache.solr.core.= SolrCore; org.apache.solr.core.MockDirectoryFactory [junit4:junit4] 1> INFO - 2013-04-10 00:16:47.691; org.apache.solr.core.= SolrCore; org.apache.solr.core.MockDirectoryFactory [junit4:junit4] 1> INFO - 2013-04-10 00:16:47.691; org.apache.solr.core.= SolrCore; [nodes_used_collection_shard1_replica1] Opening new SolrCore at /= usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/bui= ld/solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTes= t-controljetty-1365553000254/nodes_used_collection_shard1_replica1/, dataDi= r=3D/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/sol= r/build/solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistributed= ZkTest-controljetty-1365553000254/nodes_used_collection_shard1_replica1/dat= a/ [junit4:junit4] 1> INFO - 2013-04-10 00:16:47.692; org.apache.solr.core.= SolrCore; [nodes_used_collection_shard2_replica2] Opening new SolrCore at /= usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/bui= ld/solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTes= t-jetty4-1365553004999/nodes_used_collection_shard2_replica2/, dataDir=3D/u= sr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/buil= d/solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest= -jetty4-1365553004999/nodes_used_collection_shard2_replica2/data/ [junit4:junit4] 1> INFO - 2013-04-10 00:16:47.692; org.apache.solr.core.= JmxMonitoredMap; JMX monitoring is enabled. Adding Solr mbeans to JMX Serve= r: com.sun.jmx.mbeanserver.JmxMBeanServer@18987a33 [junit4:junit4] 1> INFO - 2013-04-10 00:16:47.693; org.apache.solr.core.= JmxMonitoredMap; JMX monitoring is enabled. Adding Solr mbeans to JMX Serve= r: com.sun.jmx.mbeanserver.JmxMBeanServer@18987a33 [junit4:junit4] 1> INFO - 2013-04-10 00:16:47.693; org.apache.solr.core.= SolrCore; org.apache.solr.core.MockDirectoryFactory [junit4:junit4] 1> INFO - 2013-04-10 00:16:47.694; org.apache.solr.core.= SolrCore; org.apache.solr.core.MockDirectoryFactory [junit4:junit4] 1> INFO - 2013-04-10 00:16:47.696; org.apache.solr.core.= CachingDirectoryFactory; return new directory for /usr/home/hudson/hudson-s= lave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J1/./o= rg.apache.solr.cloud.CollectionsAPIDistributedZkTest-controljetty-136555300= 0254/nodes_used_collection_shard1_replica1/data [junit4:junit4] 1> INFO - 2013-04-10 00:16:47.697; org.apache.solr.core.= CachingDirectoryFactory; return new directory for /usr/home/hudson/hudson-s= lave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J1/./o= rg.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1365553004999/n= odes_used_collection_shard2_replica2/data [junit4:junit4] 1> INFO - 2013-04-10 00:16:47.697; org.apache.solr.core.= SolrCore; New index directory detected: old=3Dnull new=3D/usr/home/hudson/h= udson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test= /J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-controljetty-13= 65553000254/nodes_used_collection_shard1_replica1/data/index/ [junit4:junit4] 1> INFO - 2013-04-10 00:16:47.697; org.apache.solr.core.= SolrCore; New index directory detected: old=3Dnull new=3D/usr/home/hudson/h= udson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test= /J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-13655530= 04999/nodes_used_collection_shard2_replica2/data/index/ [junit4:junit4] 1> WARN - 2013-04-10 00:16:47.698; org.apache.solr.core.= SolrCore; [nodes_used_collection_shard1_replica1] Solr index directory '/us= r/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build= /solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-= controljetty-1365553000254/nodes_used_collection_shard1_replica1/data/index= ' doesn't exist. Creating new index... [junit4:junit4] 1> WARN - 2013-04-10 00:16:47.698; org.apache.solr.core.= SolrCore; [nodes_used_collection_shard2_replica2] Solr index directory '/us= r/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build= /solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-= jetty4-1365553004999/nodes_used_collection_shard2_replica2/data/index' does= n't exist. Creating new index... [junit4:junit4] 1> INFO - 2013-04-10 00:16:47.699; org.apache.solr.core.= CachingDirectoryFactory; return new directory for /usr/home/hudson/hudson-s= lave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J1/./o= rg.apache.solr.cloud.CollectionsAPIDistributedZkTest-controljetty-136555300= 0254/nodes_used_collection_shard1_replica1/data/index [junit4:junit4] 1> INFO - 2013-04-10 00:16:47.699; org.apache.solr.core.= CachingDirectoryFactory; return new directory for /usr/home/hudson/hudson-s= lave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J1/./o= rg.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1365553004999/n= odes_used_collection_shard2_replica2/data/index [junit4:junit4] 1> INFO - 2013-04-10 00:16:47.704; org.apache.solr.core.= SolrDeletionPolicy; SolrDeletionPolicy.onCommit: commits:num=3D1 [junit4:junit4] 1> =09commit{dir=3DMockDirWrapper(org.apache.lucene.store= .RAMDirectory@68c04835 lockFactory=3Dorg.apache.lucene.store.NativeFSLockFa= ctory@488a5770),segFN=3Dsegments_1,generation=3D1,filenames=3D[segments_1] [junit4:junit4] 1> INFO - 2013-04-10 00:16:47.704; org.apache.solr.core.= SolrDeletionPolicy; newest commit =3D 1[segments_1] [junit4:junit4] 1> INFO - 2013-04-10 00:16:47.704; org.apache.solr.core.= SolrDeletionPolicy; SolrDeletionPolicy.onCommit: commits:num=3D1 [junit4:junit4] 1> =09commit{dir=3DMockDirWrapper(org.apache.lucene.store= .RAMDirectory@4336640f lockFactory=3Dorg.apache.lucene.store.NativeFSLockFa= ctory@5dd72248),segFN=3Dsegments_1,generation=3D1,filenames=3D[segments_1] [junit4:junit4] 1> INFO - 2013-04-10 00:16:47.705; org.apache.solr.core.= SolrDeletionPolicy; newest commit =3D 1[segments_1] [junit4:junit4] 1> INFO - 2013-04-10 00:16:47.707; org.apache.solr.updat= e.processor.UpdateRequestProcessorChain; inserting DistributedUpdateProcess= orFactory into updateRequestProcessorChain "dedupe" [junit4:junit4] 1> INFO - 2013-04-10 00:16:47.708; org.apache.solr.updat= e.processor.UpdateRequestProcessorChain; inserting DistributedUpdateProcess= orFactory into updateRequestProcessorChain "stored_sig" [junit4:junit4] 1> INFO - 2013-04-10 00:16:47.708; org.apache.solr.updat= e.processor.UpdateRequestProcessorChain; inserting DistributedUpdateProcess= orFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit= " [junit4:junit4] 1> INFO - 2013-04-10 00:16:47.709; org.apache.solr.updat= e.processor.UpdateRequestProcessorChain; inserting DistributedUpdateProcess= orFactory into updateRequestProcessorChain "dedupe" [junit4:junit4] 1> INFO - 2013-04-10 00:16:47.709; org.apache.solr.core.= RequestHandlers; created standard: solr.StandardRequestHandler [junit4:junit4] 1> INFO - 2013-04-10 00:16:47.709; org.apache.solr.updat= e.processor.UpdateRequestProcessorChain; inserting DistributedUpdateProcess= orFactory into updateRequestProcessorChain "stored_sig" [junit4:junit4] 1> INFO - 2013-04-10 00:16:47.710; org.apache.solr.core.= RequestHandlers; created /get: solr.RealTimeGetHandler [junit4:junit4] 1> INFO - 2013-04-10 00:16:47.711; org.apache.solr.core.= RequestHandlers; adding lazy requestHandler: solr.ReplicationHandler [junit4:junit4] 1> INFO - 2013-04-10 00:16:47.711; org.apache.solr.updat= e.processor.UpdateRequestProcessorChain; inserting DistributedUpdateProcess= orFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit= " [junit4:junit4] 1> INFO - 2013-04-10 00:16:47.711; org.apache.solr.core.= RequestHandlers; created /replication: solr.ReplicationHandler [junit4:junit4] 1> INFO - 2013-04-10 00:16:47.712; org.apache.solr.core.= RequestHandlers; created standard: solr.StandardRequestHandler [junit4:junit4] 1> INFO - 2013-04-10 00:16:47.712; org.apache.solr.core.= RequestHandlers; created /update: solr.UpdateRequestHandler [junit4:junit4] 1> INFO - 2013-04-10 00:16:47.713; org.apache.solr.core.= RequestHandlers; created /get: solr.RealTimeGetHandler [junit4:junit4] 1> INFO - 2013-04-10 00:16:47.713; org.apache.solr.core.= RequestHandlers; adding lazy requestHandler: solr.ReplicationHandler [junit4:junit4] 1> INFO - 2013-04-10 00:16:47.713; org.apache.solr.core.= RequestHandlers; created /admin/: org.apache.solr.handler.admin.AdminHandle= rs [junit4:junit4] 1> INFO - 2013-04-10 00:16:47.714; org.apache.solr.core.= RequestHandlers; created /replication: solr.ReplicationHandler [junit4:junit4] 1> INFO - 2013-04-10 00:16:47.715; org.apache.solr.core.= RequestHandlers; created /update: solr.UpdateRequestHandler [junit4:junit4] 1> INFO - 2013-04-10 00:16:47.716; org.apache.solr.core.= RequestHandlers; created /admin/: org.apache.solr.handler.admin.AdminHandle= rs [junit4:junit4] 1> INFO - 2013-04-10 00:16:47.722; org.apache.solr.handl= er.loader.XMLLoader; xsltCacheLifetimeSeconds=3D60 [junit4:junit4] 1> INFO - 2013-04-10 00:16:47.722; org.apache.solr.handl= er.loader.XMLLoader; xsltCacheLifetimeSeconds=3D60 [junit4:junit4] 1> INFO - 2013-04-10 00:16:47.729; org.apache.solr.searc= h.SolrIndexSearcher; Opening Searcher@2ae0c389 main [junit4:junit4] 1> INFO - 2013-04-10 00:16:47.730; org.apache.solr.updat= e.UpdateHandler; Clearing tlog files, tlogDir=3D/usr/home/hudson/hudson-sla= ve/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J1/./org= .apache.solr.cloud.CollectionsAPIDistributedZkTest-controljetty-13655530002= 54/nodes_used_collection_shard1_replica1/data/tlog [junit4:junit4] 1> INFO - 2013-04-10 00:16:47.730; org.apache.solr.searc= h.SolrIndexSearcher; Opening Searcher@59fb49f6 main [junit4:junit4] 1> INFO - 2013-04-10 00:16:47.731; org.apache.solr.updat= e.UpdateHandler; Clearing tlog files, tlogDir=3D/usr/home/hudson/hudson-sla= ve/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J1/./org= .apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1365553004999/nod= es_used_collection_shard2_replica2/data/tlog [junit4:junit4] 1> INFO - 2013-04-10 00:16:47.731; org.apache.solr.updat= e.CommitTracker; Hard AutoCommit: disabled [junit4:junit4] 1> INFO - 2013-04-10 00:16:47.732; org.apache.solr.updat= e.CommitTracker; Soft AutoCommit: disabled [junit4:junit4] 1> INFO - 2013-04-10 00:16:47.732; org.apache.solr.updat= e.CommitTracker; Hard AutoCommit: disabled [junit4:junit4] 1> INFO - 2013-04-10 00:16:47.733; org.apache.solr.updat= e.CommitTracker; Soft AutoCommit: disabled [junit4:junit4] 1> INFO - 2013-04-10 00:16:47.736; org.apache.solr.core.= SolrCore; [nodes_used_collection_shard1_replica1] Registered new searcher S= earcher@2ae0c389 main{StandardDirectoryReader(segments_1:1)} [junit4:junit4] 1> INFO - 2013-04-10 00:16:47.737; org.apache.solr.core.= SolrCore; [nodes_used_collection_shard2_replica2] Registered new searcher S= earcher@59fb49f6 main{StandardDirectoryReader(segments_1:1)} [junit4:junit4] 1> INFO - 2013-04-10 00:16:47.738; org.apache.solr.cloud= .ZkController; publishing core=3Dnodes_used_collection_shard1_replica1 stat= e=3Ddown [junit4:junit4] 1> INFO - 2013-04-10 00:16:47.740; org.apache.solr.cloud= .ZkController; publishing core=3Dnodes_used_collection_shard2_replica2 stat= e=3Ddown [junit4:junit4] 1> INFO - 2013-04-10 00:16:48.217; org.apache.solr.commo= n.cloud.ZkStateReader; Updating cloud state from ZooKeeper...=20 [junit4:junit4] 1> INFO - 2013-04-10 00:16:48.218; 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":"shard1", [junit4:junit4] 1> "roles":null, [junit4:junit4] 1> "state":"down", [junit4:junit4] 1> "shard_state":"active", [junit4:junit4] 1> "core":"nodes_used_collection_shard1_replica2", [junit4:junit4] 1> "collection":"nodes_used_collection", [junit4:junit4] 1> "shard_range":null, [junit4:junit4] 1> "node_name":"127.0.0.1:33475_", [junit4:junit4] 1> "base_url":"http://127.0.0.1:33475"} [junit4:junit4] 1> INFO - 2013-04-10 00:16:48.219; org.apache.solr.cloud= .Overseer$ClusterStateUpdater; Create collection nodes_used_collection with= numShards 2 [junit4:junit4] 1> INFO - 2013-04-10 00:16:48.223; 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":"shard2", [junit4:junit4] 1> "roles":null, [junit4:junit4] 1> "state":"down", [junit4:junit4] 1> "shard_state":"active", [junit4:junit4] 1> "core":"nodes_used_collection_shard2_replica1", [junit4:junit4] 1> "collection":"nodes_used_collection", [junit4:junit4] 1> "shard_range":null, [junit4:junit4] 1> "node_name":"127.0.0.1:33478_", [junit4:junit4] 1> "base_url":"http://127.0.0.1:33478"} [junit4:junit4] 1> INFO - 2013-04-10 00:16:48.238; 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":"shard1", [junit4:junit4] 1> "roles":null, [junit4:junit4] 1> "state":"down", [junit4:junit4] 1> "shard_state":"active", [junit4:junit4] 1> "core":"nodes_used_collection_shard1_replica1", [junit4:junit4] 1> "collection":"nodes_used_collection", [junit4:junit4] 1> "shard_range":null, [junit4:junit4] 1> "node_name":"127.0.0.1:33471_", [junit4:junit4] 1> "base_url":"http://127.0.0.1:33471"} [junit4:junit4] 1> INFO - 2013-04-10 00:16:48.241; 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":"shard2", [junit4:junit4] 1> "roles":null, [junit4:junit4] 1> "state":"down", [junit4:junit4] 1> "shard_state":"active", [junit4:junit4] 1> "core":"nodes_used_collection_shard2_replica2", [junit4:junit4] 1> "collection":"nodes_used_collection", [junit4:junit4] 1> "shard_range":null, [junit4:junit4] 1> "node_name":"127.0.0.1:33487_", [junit4:junit4] 1> "base_url":"http://127.0.0.1:33487"} [junit4:junit4] 1> INFO - 2013-04-10 00:16:48.246; 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-10 00:16:48.246; 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-10 00:16:48.246; 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-10 00:16:48.246; 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-10 00:16:48.246; 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-10 00:16:48.246; 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-10 00:16:48.679; org.apache.solr.core.= CoreContainer; registering core: nodes_used_collection_shard1_replica2 [junit4:junit4] 1> INFO - 2013-04-10 00:16:48.679; org.apache.solr.cloud= .ZkController; Register replica - core:nodes_used_collection_shard1_replica= 2 address:http://127.0.0.1:33475 collection:nodes_used_collection shard:sha= rd1 [junit4:junit4] 1> INFO - 2013-04-10 00:16:48.680; org.apache.solr.core.= CoreContainer; registering core: nodes_used_collection_shard2_replica1 [junit4:junit4] 1> INFO - 2013-04-10 00:16:48.680; org.apache.solr.cloud= .ZkController; Register replica - core:nodes_used_collection_shard2_replica= 1 address:http://127.0.0.1:33478 collection:nodes_used_collection shard:sha= rd2 [junit4:junit4] 1> INFO - 2013-04-10 00:16:48.681; org.apache.solr.commo= n.cloud.SolrZkClient; makePath: /collections/nodes_used_collection/leader_e= lect/shard1/election [junit4:junit4] 1> INFO - 2013-04-10 00:16:48.682; org.apache.solr.commo= n.cloud.SolrZkClient; makePath: /collections/nodes_used_collection/leader_e= lect/shard2/election [junit4:junit4] 1> INFO - 2013-04-10 00:16:48.710; org.apache.solr.cloud= .ShardLeaderElectionContext; Running the leader process. [junit4:junit4] 1> INFO - 2013-04-10 00:16:48.722; org.apache.solr.cloud= .ShardLeaderElectionContext; Running the leader process. [junit4:junit4] 1> INFO - 2013-04-10 00:16:48.732; org.apache.solr.cloud= .ShardLeaderElectionContext; Waiting until we see more replicas up: total= =3D2 found=3D1 timeoutin=3D180000 [junit4:junit4] 1> INFO - 2013-04-10 00:16:48.733; org.apache.solr.cloud= .ShardLeaderElectionContext; Waiting until we see more replicas up: total= =3D2 found=3D1 timeoutin=3D179999 [junit4:junit4] 1> INFO - 2013-04-10 00:16:48.760; org.apache.solr.core.= CoreContainer; registering core: nodes_used_collection_shard1_replica1 [junit4:junit4] 1> INFO - 2013-04-10 00:16:48.760; org.apache.solr.cloud= .ZkController; Register replica - core:nodes_used_collection_shard1_replica= 1 address:http://127.0.0.1:33471 collection:nodes_used_collection shard:sha= rd1 [junit4:junit4] 1> INFO - 2013-04-10 00:16:48.761; org.apache.solr.core.= CoreContainer; registering core: nodes_used_collection_shard2_replica2 [junit4:junit4] 1> INFO - 2013-04-10 00:16:48.761; org.apache.solr.cloud= .ZkController; Register replica - core:nodes_used_collection_shard2_replica= 2 address:http://127.0.0.1:33487 collection:nodes_used_collection shard:sha= rd2 [junit4:junit4] 1> INFO - 2013-04-10 00:16:49.234; org.apache.solr.cloud= .ShardLeaderElectionContext; Enough replicas found to continue. [junit4:junit4] 1> INFO - 2013-04-10 00:16:49.235; org.apache.solr.cloud= .ShardLeaderElectionContext; I may be the new leader - try and sync [junit4:junit4] 1> INFO - 2013-04-10 00:16:49.235; org.apache.solr.cloud= .ShardLeaderElectionContext; Enough replicas found to continue. [junit4:junit4] 1> INFO - 2013-04-10 00:16:49.235; org.apache.solr.cloud= .SyncStrategy; Sync replicas to http://127.0.0.1:33475/nodes_used_collectio= n_shard1_replica2/ [junit4:junit4] 1> INFO - 2013-04-10 00:16:49.236; org.apache.solr.cloud= .ShardLeaderElectionContext; I may be the new leader - try and sync [junit4:junit4] 1> INFO - 2013-04-10 00:16:49.236; org.apache.solr.updat= e.PeerSync; PeerSync: core=3Dnodes_used_collection_shard1_replica2 url=3Dht= tp://127.0.0.1:33475 START replicas=3D[http://127.0.0.1:33471/nodes_used_co= llection_shard1_replica1/] nUpdates=3D100 [junit4:junit4] 1> INFO - 2013-04-10 00:16:49.236; org.apache.solr.cloud= .SyncStrategy; Sync replicas to http://127.0.0.1:33478/nodes_used_collectio= n_shard2_replica1/ [junit4:junit4] 1> INFO - 2013-04-10 00:16:49.237; org.apache.solr.updat= e.PeerSync; PeerSync: core=3Dnodes_used_collection_shard1_replica2 url=3Dht= tp://127.0.0.1:33475 DONE. We have no versions. sync failed. [junit4:junit4] 1> INFO - 2013-04-10 00:16:49.237; org.apache.solr.updat= e.PeerSync; PeerSync: core=3Dnodes_used_collection_shard2_replica1 url=3Dht= tp://127.0.0.1:33478 START replicas=3D[http://127.0.0.1:33487/nodes_used_co= llection_shard2_replica2/] nUpdates=3D100 [junit4:junit4] 1> INFO - 2013-04-10 00:16:49.237; org.apache.solr.cloud= .SyncStrategy; Leader's attempt to sync with shard failed, moving to the ne= xt canidate [junit4:junit4] 1> INFO - 2013-04-10 00:16:49.238; org.apache.solr.updat= e.PeerSync; PeerSync: core=3Dnodes_used_collection_shard2_replica1 url=3Dht= tp://127.0.0.1:33478 DONE. We have no versions. sync failed. [junit4:junit4] 1> INFO - 2013-04-10 00:16:49.239; org.apache.solr.cloud= .SyncStrategy; Leader's attempt to sync with shard failed, moving to the ne= xt canidate [junit4:junit4] 1> INFO - 2013-04-10 00:16:49.238; org.apache.solr.cloud= .ShardLeaderElectionContext; We failed sync, but we have no versions - we c= an't sync in that case - we were active before, so become leader anyway [junit4:junit4] 1> INFO - 2013-04-10 00:16:49.239; org.apache.solr.cloud= .ShardLeaderElectionContext; We failed sync, but we have no versions - we c= an't sync in that case - we were active before, so become leader anyway [junit4:junit4] 1> INFO - 2013-04-10 00:16:49.240; org.apache.solr.cloud= .ShardLeaderElectionContext; I am the new leader: http://127.0.0.1:33475/no= des_used_collection_shard1_replica2/ [junit4:junit4] 1> INFO - 2013-04-10 00:16:49.240; org.apache.solr.cloud= .ShardLeaderElectionContext; I am the new leader: http://127.0.0.1:33478/no= des_used_collection_shard2_replica1/ [junit4:junit4] 1> INFO - 2013-04-10 00:16:49.241; org.apache.solr.commo= n.cloud.SolrZkClient; makePath: /collections/nodes_used_collection/leaders/= shard1 [junit4:junit4] 1> INFO - 2013-04-10 00:16:49.241; org.apache.solr.commo= n.cloud.SolrZkClient; makePath: /collections/nodes_used_collection/leaders/= shard2 [junit4:junit4] 1> INFO - 2013-04-10 00:16:49.245; org.apache.solr.core.= SolrCore; [nodes_used_collection_shard2_replica2] webapp=3D path=3D/get par= ams=3D{getVersions=3D100&distrib=3Dfalse&wt=3Djavabin&qt=3D/get&version=3D2= } status=3D0 QTime=3D0=20 [junit4:junit4] 1> INFO - 2013-04-10 00:16:49.246; org.apache.solr.core.= SolrCore; [nodes_used_collection_shard1_replica1] webapp=3D path=3D/get par= ams=3D{getVersions=3D100&distrib=3Dfalse&wt=3Djavabin&qt=3D/get&version=3D2= } status=3D0 QTime=3D0=20 [junit4:junit4] 1> INFO - 2013-04-10 00:16:49.758; org.apache.solr.commo= n.cloud.ZkStateReader; Updating cloud state from ZooKeeper...=20 [junit4:junit4] 1> INFO - 2013-04-10 00:16:49.803; 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-10 00:16:49.803; 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-10 00:16:49.803; 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-10 00:16:49.803; 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-10 00:16:49.803; 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-10 00:16:49.803; 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-10 00:16:49.826; org.apache.solr.cloud= .ZkController; We are http://127.0.0.1:33471/nodes_used_collection_shard1_r= eplica1/ and leader is http://127.0.0.1:33475/nodes_used_collection_shard1_= replica2/ [junit4:junit4] 1> INFO - 2013-04-10 00:16:49.826; org.apache.solr.cloud= .ZkController; No LogReplay needed for core=3Dnodes_used_collection_shard1_= replica1 baseURL=3Dhttp://127.0.0.1:33471 [junit4:junit4] 1> INFO - 2013-04-10 00:16:49.827; org.apache.solr.cloud= .ZkController; Core needs to recover:nodes_used_collection_shard1_replica1 [junit4:junit4] 1> INFO - 2013-04-10 00:16:49.827; org.apache.solr.cloud= .ZkController; We are http://127.0.0.1:33487/nodes_used_collection_shard2_r= eplica2/ and leader is http://127.0.0.1:33478/nodes_used_collection_shard2_= replica1/ [junit4:junit4] 1> INFO - 2013-04-10 00:16:49.827; org.apache.solr.updat= e.DefaultSolrCoreState; Running recovery - first canceling any ongoing reco= very [junit4:junit4] 1> INFO - 2013-04-10 00:16:49.827; org.apache.solr.cloud= .ZkController; No LogReplay needed for core=3Dnodes_used_collection_shard2_= replica2 baseURL=3Dhttp://127.0.0.1:33487 [junit4:junit4] 1> INFO - 2013-04-10 00:16:49.828; org.apache.solr.cloud= .ZkController; Core needs to recover:nodes_used_collection_shard2_replica2 [junit4:junit4] 1> INFO - 2013-04-10 00:16:49.828; org.apache.solr.updat= e.DefaultSolrCoreState; Running recovery - first canceling any ongoing reco= very [junit4:junit4] 1> INFO - 2013-04-10 00:16:49.828; org.apache.solr.cloud= .RecoveryStrategy; Starting recovery process. core=3Dnodes_used_collection= _shard1_replica1 recoveringAfterStartup=3Dtrue [junit4:junit4] 1> INFO - 2013-04-10 00:16:49.829; org.apache.solr.cloud= .RecoveryStrategy; Starting recovery process. core=3Dnodes_used_collection= _shard2_replica2 recoveringAfterStartup=3Dtrue [junit4:junit4] 1> INFO - 2013-04-10 00:16:49.828; org.apache.solr.commo= n.cloud.ZkStateReader; Updating cloud state from ZooKeeper...=20 [junit4:junit4] 1> INFO - 2013-04-10 00:16:49.829; org.apache.solr.commo= n.cloud.ZkStateReader; Updating cloud state from ZooKeeper...=20 [junit4:junit4] 1> INFO - 2013-04-10 00:16:49.829; org.apache.solr.cloud= .RecoveryStrategy; ###### startupVersions=3D[] [junit4:junit4] 1> INFO - 2013-04-10 00:16:49.829; org.apache.solr.cloud= .RecoveryStrategy; ###### startupVersions=3D[] [junit4:junit4] 1> INFO - 2013-04-10 00:16:49.830; org.apache.solr.core.= CoreContainer; Persisting cores config to /usr/home/hudson/hudson-slave/wor= kspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J1/./org.apach= e.solr.cloud.CollectionsAPIDistributedZkTest-controljetty-1365553000254/sol= r.xml [junit4:junit4] 1> INFO - 2013-04-10 00:16:49.830; org.apache.solr.cloud= .ZkController; publishing core=3Dnodes_used_collection_shard2_replica2 stat= e=3Drecovering [junit4:junit4] 1> INFO - 2013-04-10 00:16:49.831; org.apache.solr.core.= CoreContainer; Persisting cores config to /usr/home/hudson/hudson-slave/wor= kspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J1/./org.apach= e.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1365553004999/solr.xml [junit4:junit4] 1> INFO - 2013-04-10 00:16:49.831; org.apache.solr.cloud= .ZkController; publishing core=3Dnodes_used_collection_shard1_replica1 stat= e=3Drecovering [junit4:junit4] 1> INFO - 2013-04-10 00:16:49.833; org.apache.solr.cloud= .ZkController; We are http://127.0.0.1:33478/nodes_used_collection_shard2_r= eplica1/ and leader is http://127.0.0.1:33478/nodes_used_collection_shard2_= replica1/ [junit4:junit4] 1> INFO - 2013-04-10 00:16:49.833; 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-10 00:16:49.833; org.apache.solr.cloud= .ZkController; We are http://127.0.0.1:33475/nodes_used_collection_shard1_r= eplica2/ and leader is http://127.0.0.1:33475/nodes_used_collection_shard1_= replica2/ [junit4:junit4] 1> INFO - 2013-04-10 00:16:49.833; 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-10 00:16:49.833; org.apache.solr.cloud= .ZkController; No LogReplay needed for core=3Dnodes_used_collection_shard2_= replica1 baseURL=3Dhttp://127.0.0.1:33478 [junit4:junit4] 1> INFO - 2013-04-10 00:16:49.834; org.apache.solr.cloud= .ZkController; I am the leader, no recovery necessary [junit4:junit4] 1> INFO - 2013-04-10 00:16:49.834; org.apache.solr.cloud= .ZkController; No LogReplay needed for core=3Dnodes_used_collection_shard1_= replica2 baseURL=3Dhttp://127.0.0.1:33475 [junit4:junit4] 1> INFO - 2013-04-10 00:16:49.835; org.apache.solr.cloud= .ZkController; I am the leader, no recovery necessary [junit4:junit4] 1> INFO - 2013-04-10 00:16:49.835; org.apache.solr.cloud= .ZkController; publishing core=3Dnodes_used_collection_shard2_replica1 stat= e=3Dactive [junit4:junit4] 1> INFO - 2013-04-10 00:16:49.835; org.apache.solr.cloud= .ZkController; publishing core=3Dnodes_used_collection_shard1_replica2 stat= e=3Dactive [junit4:junit4] 1> INFO - 2013-04-10 00:16:49.842; org.apache.solr.core.= SolrXMLSerializer; Persisting cores config to /usr/home/hudson/hudson-slave= /workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J1/./org.a= pache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1365553004999/solr.= xml [junit4:junit4] 1> INFO - 2013-04-10 00:16:49.844; org.apache.solr.core.= SolrXMLSerializer; Persisting cores config to /usr/home/hudson/hudson-slave= /workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J1/./org.a= pache.solr.cloud.CollectionsAPIDistributedZkTest-controljetty-1365553000254= /solr.xml [junit4:junit4] 1> INFO - 2013-04-10 00:16:49.844; org.apache.solr.servl= et.SolrDispatchFilter; [admin] webapp=3Dnull path=3D/admin/cores params=3D{= numShards=3D2&shard=3Dshard2&name=3Dnodes_used_collection_shard2_replica2&a= ction=3DCREATE&collection=3Dnodes_used_collection&wt=3Djavabin&qt=3D/admin/= cores&version=3D2} status=3D0 QTime=3D3375=20 [junit4:junit4] 1> INFO - 2013-04-10 00:16:49.845; org.apache.solr.commo= n.cloud.ZkStateReader; Updating cloud state from ZooKeeper...=20 [junit4:junit4] 1> INFO - 2013-04-10 00:16:49.846; org.apache.solr.servl= et.SolrDispatchFilter; [admin] webapp=3Dnull path=3D/admin/cores params=3D{= numShards=3D2&shard=3Dshard1&name=3Dnodes_used_collection_shard1_replica1&a= ction=3DCREATE&collection=3Dnodes_used_collection&wt=3Djavabin&qt=3D/admin/= cores&version=3D2} status=3D0 QTime=3D3378=20 [junit4:junit4] 1> INFO - 2013-04-10 00:16:49.847; org.apache.solr.handl= er.admin.CoreAdminHandler; Going to wait for coreNodeName: 127.0.0.1:33487_= _nodes_used_collection_shard2_replica2, state: recovering, checkLive: true,= onlyIfLeader: true [junit4:junit4] 1> INFO - 2013-04-10 00:16:49.847; org.apache.solr.commo= n.cloud.ZkStateReader; Updating cloud state from ZooKeeper...=20 [junit4:junit4] 1> INFO - 2013-04-10 00:16:49.847; org.apache.solr.core.= CoreContainer; Persisting cores config to /usr/home/hudson/hudson-slave/wor= kspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J1/./org.apach= e.solr.cloud.CollectionsAPIDistributedZkTest-jetty2-1365553002138/solr.xml [junit4:junit4] 1> INFO - 2013-04-10 00:16:49.848; org.apache.solr.core.= CoreContainer; Persisting cores config to /usr/home/hudson/hudson-slave/wor= kspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J1/./org.apach= e.solr.cloud.CollectionsAPIDistributedZkTest-jetty1-1365553000729/solr.xml [junit4:junit4] 1> INFO - 2013-04-10 00:16:49.847; org.apache.solr.handl= er.admin.CoreAdminHandler; Going to wait for coreNodeName: 127.0.0.1:33471_= _nodes_used_collection_shard1_replica1, state: recovering, checkLive: true,= onlyIfLeader: true [junit4:junit4] 1> INFO - 2013-04-10 00:16:49.860; org.apache.solr.core.= SolrXMLSerializer; Persisting cores config to /usr/home/hudson/hudson-slave= /workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J1/./org.a= pache.solr.cloud.CollectionsAPIDistributedZkTest-jetty1-1365553000729/solr.= xml [junit4:junit4] 1> INFO - 2013-04-10 00:16:49.862; org.apache.solr.servl= et.SolrDispatchFilter; [admin] webapp=3Dnull path=3D/admin/cores params=3D{= numShards=3D2&shard=3Dshard1&name=3Dnodes_used_collection_shard1_replica2&a= ction=3DCREATE&collection=3Dnodes_used_collection&wt=3Djavabin&qt=3D/admin/= cores&version=3D2} status=3D0 QTime=3D3394=20 [junit4:junit4] 1> INFO - 2013-04-10 00:16:49.866; org.apache.solr.core.= SolrXMLSerializer; Persisting cores config to /usr/home/hudson/hudson-slave= /workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J1/./org.a= pache.solr.cloud.CollectionsAPIDistributedZkTest-jetty2-1365553002138/solr.= xml [junit4:junit4] 1> INFO - 2013-04-10 00:16:49.868; org.apache.solr.servl= et.SolrDispatchFilter; [admin] webapp=3Dnull path=3D/admin/cores params=3D{= numShards=3D2&shard=3Dshard2&name=3Dnodes_used_collection_shard2_replica1&a= ction=3DCREATE&collection=3Dnodes_used_collection&wt=3Djavabin&qt=3D/admin/= cores&version=3D2} status=3D0 QTime=3D3400=20 [junit4:junit4] 1> INFO - 2013-04-10 00:16:49.869; org.apache.solr.cloud= .OverseerCollectionProcessor; Finished create command on all shards for col= lection: nodes_used_collection [junit4:junit4] 1> INFO - 2013-04-10 00:16:49.887; org.apache.solr.cloud= .DistributedQueue$LatchChildWatcher; Watcher fired on path: /overseer/colle= ction-queue-work/qnr-0000000000 state: SyncConnected type NodeDataChanged [junit4:junit4] 1> INFO - 2013-04-10 00:16:49.898; org.apache.solr.cloud= .DistributedQueue$LatchChildWatcher; Watcher fired on path: /overseer/colle= ction-queue-work state: SyncConnected type NodeChildrenChanged [junit4:junit4] 1> INFO - 2013-04-10 00:16:49.898; org.apache.solr.cloud= .OverseerCollectionProcessor; Overseer Collection Processor: Message id:/ov= erseer/collection-queue-work/qn-0000000000 complete, response:{success=3D{n= ull=3D{responseHeader=3D{status=3D0,QTime=3D3375},core=3Dnodes_used_collect= ion_shard2_replica2,saved=3D/usr/home/hudson/hudson-slave/workspace/Lucene-= Solr-Tests-4.x-Java6/solr/build/solr-core/test/J1/./org.apache.solr.cloud.C= ollectionsAPIDistributedZkTest-jetty4-1365553004999/solr.xml},null=3D{respo= nseHeader=3D{status=3D0,QTime=3D3378},core=3Dnodes_used_collection_shard1_r= eplica1,saved=3D/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4= .x-Java6/solr/build/solr-core/test/J1/./org.apache.solr.cloud.CollectionsAP= IDistributedZkTest-controljetty-1365553000254/solr.xml},null=3D{responseHea= der=3D{status=3D0,QTime=3D3394},core=3Dnodes_used_collection_shard1_replica= 2,saved=3D/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Jav= a6/solr/build/solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistr= ibutedZkTest-jetty1-1365553000729/solr.xml},null=3D{responseHeader=3D{statu= s=3D0,QTime=3D3400},core=3Dnodes_used_collection_shard2_replica1,saved=3D/u= sr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/buil= d/solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest= -jetty2-1365553002138/solr.xml}}} [junit4:junit4] 1> INFO - 2013-04-10 00:16:49.903; org.apache.solr.servl= et.SolrDispatchFilter; [admin] webapp=3Dnull path=3D/admin/collections para= ms=3D{numShards=3D2&name=3Dnodes_used_collection&replicationFactor=3D2&acti= on=3DCREATE&wt=3Djavabin&version=3D2} status=3D0 QTime=3D3479=20 [junit4:junit4] 1> INFO - 2013-04-10 00:16:49.904; org.apache.solr.clien= t.solrj.impl.HttpClientUtil; Creating new http client, config: [junit4:junit4] 1> INFO - 2013-04-10 00:16:49.905; org.apache.solr.commo= n.cloud.ConnectionManager; Waiting for client to connect to ZooKeeper [junit4:junit4] 1> INFO - 2013-04-10 00:16:49.907; org.apache.solr.commo= n.cloud.ConnectionManager; Watcher org.apache.solr.common.cloud.ConnectionM= anager@30b04f0b name:ZooKeeperConnection Watcher:127.0.0.1:33468/solr got e= vent WatchedEvent state:SyncConnected type:None path:null path:null type:No= ne [junit4:junit4] 1> INFO - 2013-04-10 00:16:49.907; org.apache.solr.commo= n.cloud.ConnectionManager; Client is connected to ZooKeeper [junit4:junit4] 1> INFO - 2013-04-10 00:16:49.909; org.apache.solr.commo= n.cloud.ZkStateReader; Updating cluster state from ZooKeeper...=20 [junit4:junit4] 1> INFO - 2013-04-10 00:16:49.911; org.apache.solr.clien= t.solrj.impl.HttpClientUtil; Creating new http client, config: [junit4:junit4] 1> INFO - 2013-04-10 00:16:49.916; org.apache.solr.commo= n.cloud.ConnectionManager; Waiting for client to connect to ZooKeeper [junit4:junit4] 1> INFO - 2013-04-10 00:16:49.917; org.apache.solr.commo= n.cloud.ConnectionManager; Watcher org.apache.solr.common.cloud.ConnectionM= anager@55971b94 name:ZooKeeperConnection Watcher:127.0.0.1:33468/solr got e= vent WatchedEvent state:SyncConnected type:None path:null path:null type:No= ne [junit4:junit4] 1> INFO - 2013-04-10 00:16:49.918; org.apache.solr.commo= n.cloud.ConnectionManager; Client is connected to ZooKeeper [junit4:junit4] 1> INFO - 2013-04-10 00:16:49.919; org.apache.solr.commo= n.cloud.ZkStateReader; Updating cluster state from ZooKeeper...=20 [junit4:junit4] 1> INFO - 2013-04-10 00:16:49.929; org.apache.solr.handl= er.admin.CollectionsHandler; Creating Collection : numShards=3D1&maxShardsP= erNode=3D2&name=3Dawholynewcollection_0&replicationFactor=3D5&action=3DCREA= TE&wt=3Djavabin&version=3D2 [junit4:junit4] 1> INFO - 2013-04-10 00:16:49.931; org.apache.solr.cloud= .DistributedQueue$LatchChildWatcher; Watcher fired on path: /overseer/colle= ction-queue-work state: SyncConnected type NodeChildrenChanged [junit4:junit4] 1> INFO - 2013-04-10 00:16:49.933; org.apache.solr.cloud= .OverseerCollectionProcessor; Overseer Collection Processor: Get the messag= e id:/overseer/collection-queue-work/qn-0000000002 message:{ [junit4:junit4] 1> "operation":"createcollection", [junit4:junit4] 1> "numShards":"1", [junit4:junit4] 1> "maxShardsPerNode":"2", [junit4:junit4] 1> "createNodeSet":null, [junit4:junit4] 1> "name":"awholynewcollection_0", [junit4:junit4] 1> "replicationFactor":"5"} [junit4:junit4] 1> INFO - 2013-04-10 00:16:49.933; org.apache.solr.cloud= .OverseerCollectionProcessor; Creating shard awholynewcollection_0_shard1_r= eplica1 as part of slice shard1 of collection awholynewcollection_0 on 127.= 0.0.1:33471_ [junit4:junit4] 1> INFO - 2013-04-10 00:16:49.933; org.apache.solr.cloud= .OverseerCollectionProcessor; Creating shard awholynewcollection_0_shard1_r= eplica2 as part of slice shard1 of collection awholynewcollection_0 on 127.= 0.0.1:33475_ [junit4:junit4] 1> INFO - 2013-04-10 00:16:49.934; org.apache.solr.cloud= .OverseerCollectionProcessor; Creating shard awholynewcollection_0_shard1_r= eplica3 as part of slice shard1 of collection awholynewcollection_0 on 127.= 0.0.1:33487_ [junit4:junit4] 1> INFO - 2013-04-10 00:16:49.934; org.apache.solr.cloud= .OverseerCollectionProcessor; Creating shard awholynewcollection_0_shard1_r= eplica4 as part of slice shard1 of collection awholynewcollection_0 on 127.= 0.0.1:33481_ [junit4:junit4] 1> INFO - 2013-04-10 00:16:49.934; org.apache.solr.cloud= .OverseerCollectionProcessor; Creating shard awholynewcollection_0_shard1_r= eplica5 as part of slice shard1 of collection awholynewcollection_0 on 127.= 0.0.1:33478_ [junit4:junit4] 1> INFO - 2013-04-10 00:16:49.936; org.apache.solr.core.= CoreContainer; Creating SolrCore 'awholynewcollection_0_shard1_replica4' us= ing instanceDir: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-= 4.x-Java6/solr/build/solr-core/test/J1/./org.apache.solr.cloud.CollectionsA= PIDistributedZkTest-jetty3-1365553003596/awholynewcollection_0_shard1_repli= ca4 [junit4:junit4] 1> INFO - 2013-04-10 00:16:49.937; org.apache.solr.cloud= .ZkController; Check for collection zkNode:awholynewcollection_0 [junit4:junit4] 1> INFO - 2013-04-10 00:16:49.937; org.apache.solr.core.= CoreContainer; Creating SolrCore 'awholynewcollection_0_shard1_replica5' us= ing instanceDir: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-= 4.x-Java6/solr/build/solr-core/test/J1/./org.apache.solr.cloud.CollectionsA= PIDistributedZkTest-jetty2-1365553002138/awholynewcollection_0_shard1_repli= ca5 [junit4:junit4] 1> INFO - 2013-04-10 00:16:49.938; org.apache.solr.cloud= .ZkController; Creating collection in ZooKeeper:awholynewcollection_0 [junit4:junit4] 1> INFO - 2013-04-10 00:16:49.936; org.apache.solr.core.= CoreContainer; Creating SolrCore 'awholynewcollection_0_shard1_replica2' us= ing instanceDir: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-= 4.x-Java6/solr/build/solr-core/test/J1/./org.apache.solr.cloud.CollectionsA= PIDistributedZkTest-jetty1-1365553000729/awholynewcollection_0_shard1_repli= ca2 [junit4:junit4] 1> INFO - 2013-04-10 00:16:49.936; org.apache.solr.core.= CoreContainer; Creating SolrCore 'awholynewcollection_0_shard1_replica1' us= ing instanceDir: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-= 4.x-Java6/solr/build/solr-core/test/J1/./org.apache.solr.cloud.CollectionsA= PIDistributedZkTest-controljetty-1365553000254/awholynewcollection_0_shard1= _replica1 [junit4:junit4] 1> INFO - 2013-04-10 00:16:49.939; org.apache.solr.cloud= .ZkController; Check for collection zkNode:awholynewcollection_0 [junit4:junit4] 1> INFO - 2013-04-10 00:16:49.936; org.apache.solr.core.= CoreContainer; Creating SolrCore 'awholynewcollection_0_shard1_replica3' us= ing instanceDir: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-= 4.x-Java6/solr/build/solr-core/test/J1/./org.apache.solr.cloud.CollectionsA= PIDistributedZkTest-jetty4-1365553004999/awholynewcollection_0_shard1_repli= ca3 [junit4:junit4] 1> INFO - 2013-04-10 00:16:49.939; org.apache.solr.cloud= .ZkController; Check for collection zkNode:awholynewcollection_0 [junit4:junit4] 1> INFO - 2013-04-10 00:16:49.938; org.apache.solr.cloud= .ZkController; Looking for collection configName [junit4:junit4] 1> INFO - 2013-04-10 00:16:49.938; org.apache.solr.cloud= .ZkController; Check for collection zkNode:awholynewcollection_0 [junit4:junit4] 1> INFO - 2013-04-10 00:16:49.940; org.apache.solr.cloud= .ZkController; Creating collection in ZooKeeper:awholynewcollection_0 [junit4:junit4] 1> INFO - 2013-04-10 00:16:49.940; org.apache.solr.cloud= .ZkController; Check for collection zkNode:awholynewcollection_0 [junit4:junit4] 1> INFO - 2013-04-10 00:16:49.940; org.apache.solr.cloud= .ZkController; Creating collection in ZooKeeper:awholynewcollection_0 [junit4:junit4] 1> INFO - 2013-04-10 00:16:49.942; org.apache.solr.cloud= .ZkController; Only one config set found in zk - using it:conf1 [junit4:junit4] 1> INFO - 2013-04-10 00:16:49.942; org.apache.solr.cloud= .ZkController; Creating collection in ZooKeeper:awholynewcollection_0 [junit4:junit4] 1> INFO - 2013-04-10 00:16:49.941; org.apache.solr.cloud= .ZkController; Looking for collection configName [junit4:junit4] 1> INFO - 2013-04-10 00:16:49.943; org.apache.solr.cloud= .ZkController; Creating collection in ZooKeeper:awholynewcollection_0 [junit4:junit4] 1> INFO - 2013-04-10 00:16:49.943; org.apache.solr.cloud= .ZkController; Looking for collection configName [junit4:junit4] 1> INFO - 2013-04-10 00:16:49.942; org.apache.solr.commo= n.cloud.SolrZkClient; makePath: /collections/awholynewcollection_0 [junit4:junit4] 1> INFO - 2013-04-10 00:16:49.942; org.apache.solr.cloud= .ZkController; Looking for collection configName [junit4:junit4] 1> INFO - 2013-04-10 00:16:49.944; org.apache.solr.cloud= .ZkController; Only one config set found in zk - using it:conf1 [junit4:junit4] 1> INFO - 2013-04-10 00:16:49.943; org.apache.solr.cloud= .ZkController; Looking for collection configName [junit4:junit4] 1> INFO - 2013-04-10 00:16:49.945; org.apache.solr.commo= n.cloud.SolrZkClient; makePath: /collections/awholynewcollection_0 [junit4:junit4] 1> INFO - 2013-04-10 00:16:49.945; org.apache.solr.cloud= .ZkController; Only one config set found in zk - using it:conf1 [junit4:junit4] 1> INFO - 2013-04-10 00:16:49.945; org.apache.solr.cloud= .ZkController; Only one config set found in zk - using it:conf1 [junit4:junit4] 1> INFO - 2013-04-10 00:16:49.946; org.apache.solr.commo= n.cloud.SolrZkClient; makePath: /collections/awholynewcollection_0 [junit4:junit4] 1> INFO - 2013-04-10 00:16:49.947; org.apache.solr.cloud= .ZkController; Load collection config from:/collections/awholynewcollection= _0 [junit4:junit4] 1> INFO - 2013-04-10 00:16:49.947; org.apache.solr.commo= n.cloud.SolrZkClient; makePath: /collections/awholynewcollection_0 [junit4:junit4] 1> INFO - 2013-04-10 00:16:49.947; org.apache.solr.commo= n.cloud.SolrZkClient; makePath: /collections/awholynewcollection_0 [junit4:junit4] 1> INFO - 2013-04-10 00:16:49.949; org.apache.solr.cloud= .ZkController; Load collection config from:/collections/awholynewcollection= _0 [junit4:junit4] 1> INFO - 2013-04-10 00:16:49.949; org.apache.solr.core.= SolrResourceLoader; new SolrResourceLoader for directory: '/usr/home/hudson= /hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/te= st/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty3-136555= 3003596/awholynewcollection_0_shard1_replica4/' [junit4:junit4] 1> INFO - 2013-04-10 00:16:49.957; org.apache.solr.cloud= .ZkController; Load collection config from:/collections/awholynewcollection= _0 [junit4:junit4] 1> INFO - 2013-04-10 00:16:49.958; org.apache.solr.cloud= .ZkController; Load collection config from:/collections/awholynewcollection= _0 [junit4:junit4] 1> INFO - 2013-04-10 00:16:49.958; org.apache.solr.core.= SolrResourceLoader; new SolrResourceLoader for directory: '/usr/home/hudson= /hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/te= st/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty1-136555= 3000729/awholynewcollection_0_shard1_replica2/' [junit4:junit4] 1> INFO - 2013-04-10 00:16:49.959; org.apache.solr.cloud= .ZkController; Load collection config from:/collections/awholynewcollection= _0 [junit4:junit4] 1> INFO - 2013-04-10 00:16:49.962; org.apache.solr.core.= SolrResourceLoader; new SolrResourceLoader for directory: '/usr/home/hudson= /hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/te= st/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty2-136555= 3002138/awholynewcollection_0_shard1_replica5/' [junit4:junit4] 1> INFO - 2013-04-10 00:16:49.962; org.apache.solr.core.= SolrResourceLoader; new SolrResourceLoader for directory: '/usr/home/hudson= /hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/te= st/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-136555= 3004999/awholynewcollection_0_shard1_replica3/' [junit4:junit4] 1> INFO - 2013-04-10 00:16:49.962; org.apache.solr.core.= SolrResourceLoader; new SolrResourceLoader for directory: '/usr/home/hudson= /hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/te= st/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-controljetty-= 1365553000254/awholynewcollection_0_shard1_replica1/' [junit4:junit4] 1> INFO - 2013-04-10 00:16:50.005; org.apache.solr.core.= SolrConfig; Using Lucene MatchVersion: LUCENE_43 [junit4:junit4] 1> INFO - 2013-04-10 00:16:50.005; org.apache.solr.core.= SolrConfig; Using Lucene MatchVersion: LUCENE_43 [junit4:junit4] 1> INFO - 2013-04-10 00:16:50.014; org.apache.solr.core.= SolrConfig; Using Lucene MatchVersion: LUCENE_43 [junit4:junit4] 1> INFO - 2013-04-10 00:16:50.019; org.apache.solr.core.= SolrConfig; Using Lucene MatchVersion: LUCENE_43 [junit4:junit4] 1> INFO - 2013-04-10 00:16:50.027; org.apache.solr.core.= SolrConfig; Using Lucene MatchVersion: LUCENE_43 [junit4:junit4] 1> INFO - 2013-04-10 00:16:50.081; org.apache.solr.core.= SolrConfig; Loaded SolrConfig: solrconfig.xml [junit4:junit4] 1> INFO - 2013-04-10 00:16:50.083; org.apache.solr.core.= SolrConfig; Loaded SolrConfig: solrconfig.xml [junit4:junit4] 1> INFO - 2013-04-10 00:16:50.088; org.apache.solr.core.= SolrConfig; Loaded SolrConfig: solrconfig.xml [junit4:junit4] 1> INFO - 2013-04-10 00:16:50.090; org.apache.solr.schem= a.IndexSchema; Reading Solr Schema from schema.xml [junit4:junit4] 1> INFO - 2013-04-10 00:16:50.095; org.apache.solr.schem= a.IndexSchema; Schema name=3Dtest [junit4:junit4] 1> INFO - 2013-04-10 00:16:50.104; org.apache.solr.core.= SolrConfig; Loaded SolrConfig: solrconfig.xml [junit4:junit4] 1> INFO - 2013-04-10 00:16:50.118; org.apache.solr.core.= SolrConfig; Loaded SolrConfig: solrconfig.xml [junit4:junit4] 1> INFO - 2013-04-10 00:16:50.183; org.apache.solr.schem= a.IndexSchema; Reading Solr Schema from schema.xml [junit4:junit4] 1> INFO - 2013-04-10 00:16:50.185; org.apache.solr.schem= a.IndexSchema; Reading Solr Schema from schema.xml [junit4:junit4] 1> INFO - 2013-04-10 00:16:50.191; org.apache.solr.schem= a.IndexSchema; Schema name=3Dtest [junit4:junit4] 1> INFO - 2013-04-10 00:16:50.192; org.apache.solr.schem= a.IndexSchema; Schema name=3Dtest [junit4:junit4] 1> INFO - 2013-04-10 00:16:50.206; org.apache.solr.schem= a.IndexSchema; Reading Solr Schema from schema.xml [junit4:junit4] 1> INFO - 2013-04-10 00:16:50.211; org.apache.solr.schem= a.IndexSchema; Schema name=3Dtest [junit4:junit4] 1> INFO - 2013-04-10 00:16:50.220; org.apache.solr.schem= a.IndexSchema; Reading Solr Schema from schema.xml [junit4:junit4] 1> INFO - 2013-04-10 00:16:50.229; org.apache.solr.schem= a.IndexSchema; Schema name=3Dtest [junit4:junit4] 1> INFO - 2013-04-10 00:16:50.664; org.apache.solr.schem= a.OpenExchangeRatesOrgProvider; Initialized with rates=3Dopen-exchange-rate= s.json, refreshInterval=3D1440. [junit4:junit4] 1> INFO - 2013-04-10 00:16:50.674; org.apache.solr.schem= a.IndexSchema; default search field in schema is text [junit4:junit4] 1> INFO - 2013-04-10 00:16:50.679; org.apache.solr.schem= a.IndexSchema; unique key field: id [junit4:junit4] 1> INFO - 2013-04-10 00:16:50.721; org.apache.solr.schem= a.FileExchangeRateProvider; Reloading exchange rates from file currency.xml [junit4:junit4] 1> INFO - 2013-04-10 00:16:50.726; org.apache.solr.schem= a.FileExchangeRateProvider; Reloading exchange rates from file currency.xml [junit4:junit4] 1> INFO - 2013-04-10 00:16:50.730; org.apache.solr.schem= a.OpenExchangeRatesOrgProvider; Reloading exchange rates from open-exchange= -rates.json [junit4:junit4] 1> WARN - 2013-04-10 00:16:50.732; org.apache.solr.schem= a.OpenExchangeRatesOrgProvider$OpenExchangeRates; Unknown key IMPORTANT NOT= E [junit4:junit4] 1> WARN - 2013-04-10 00:16:50.732; org.apache.solr.schem= a.OpenExchangeRatesOrgProvider$OpenExchangeRates; Expected key, got STRING [junit4:junit4] 1> INFO - 2013-04-10 00:16:50.732; org.apache.solr.schem= a.OpenExchangeRatesOrgProvider; Reloading exchange rates from open-exchange= -rates.json [junit4:junit4] 1> WARN - 2013-04-10 00:16:50.733; org.apache.solr.schem= a.OpenExchangeRatesOrgProvider$OpenExchangeRates; Unknown key IMPORTANT NOT= E [junit4:junit4] 1> WARN - 2013-04-10 00:16:50.734; org.apache.solr.schem= a.OpenExchangeRatesOrgProvider$OpenExchangeRates; Expected key, got STRING [junit4:junit4] 1> INFO - 2013-04-10 00:16:50.734; org.apache.solr.core.= SolrCore; org.apache.solr.core.MockDirectoryFactory [junit4:junit4] 1> INFO - 2013-04-10 00:16:50.734; org.apache.solr.core.= SolrCore; [awholynewcollection_0_shard1_replica1] Opening new SolrCore at /= usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/bui= ld/solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTes= t-controljetty-1365553000254/awholynewcollection_0_shard1_replica1/, dataDi= r=3D/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/sol= r/build/solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistributed= ZkTest-controljetty-1365553000254/awholynewcollection_0_shard1_replica1/dat= a/ [junit4:junit4] 1> INFO - 2013-04-10 00:16:50.735; org.apache.solr.core.= JmxMonitoredMap; JMX monitoring is enabled. Adding Solr mbeans to JMX Serve= r: com.sun.jmx.mbeanserver.JmxMBeanServer@18987a33 [junit4:junit4] 1> INFO - 2013-04-10 00:16:50.735; org.apache.solr.core.= SolrCore; org.apache.solr.core.MockDirectoryFactory [junit4:junit4] 1> INFO - 2013-04-10 00:16:50.736; org.apache.solr.core.= CachingDirectoryFactory; return new directory for /usr/home/hudson/hudson-s= lave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J1/./o= rg.apache.solr.cloud.CollectionsAPIDistributedZkTest-controljetty-136555300= 0254/awholynewcollection_0_shard1_replica1/data [junit4:junit4] 1> INFO - 2013-04-10 00:16:50.736; org.apache.solr.core.= SolrCore; New index directory detected: old=3Dnull new=3D/usr/home/hudson/h= udson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test= /J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-controljetty-13= 65553000254/awholynewcollection_0_shard1_replica1/data/index/ [junit4:junit4] 1> WARN - 2013-04-10 00:16:50.737; org.apache.solr.core.= SolrCore; [awholynewcollection_0_shard1_replica1] Solr index directory '/us= r/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build= /solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-= controljetty-1365553000254/awholynewcollection_0_shard1_replica1/data/index= ' doesn't exist. Creating new index... [junit4:junit4] 1> INFO - 2013-04-10 00:16:50.737; org.apache.solr.core.= CachingDirectoryFactory; return new directory for /usr/home/hudson/hudson-s= lave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J1/./o= rg.apache.solr.cloud.CollectionsAPIDistributedZkTest-controljetty-136555300= 0254/awholynewcollection_0_shard1_replica1/data/index [junit4:junit4] 1> INFO - 2013-04-10 00:16:50.740; org.apache.solr.core.= SolrDeletionPolicy; SolrDeletionPolicy.onCommit: commits:num=3D1 [junit4:junit4] 1> =09commit{dir=3DMockDirWrapper(org.apache.lucene.store= .RAMDirectory@8be1456 lockFactory=3Dorg.apache.lucene.store.NativeFSLockFac= tory@6ede1fb5),segFN=3Dsegments_1,generation=3D1,filenames=3D[segments_1] [junit4:junit4] 1> INFO - 2013-04-10 00:16:50.741; org.apache.solr.core.= SolrDeletionPolicy; newest commit =3D 1[segments_1] [junit4:junit4] 1> INFO - 2013-04-10 00:16:50.743; org.apache.solr.updat= e.processor.UpdateRequestProcessorChain; inserting DistributedUpdateProcess= orFactory into updateRequestProcessorChain "dedupe" [junit4:junit4] 1> INFO - 2013-04-10 00:16:50.743; org.apache.solr.updat= e.processor.UpdateRequestProcessorChain; inserting DistributedUpdateProcess= orFactory into updateRequestProcessorChain "stored_sig" [junit4:junit4] 1> INFO - 2013-04-10 00:16:50.744; org.apache.solr.updat= e.processor.UpdateRequestProcessorChain; inserting DistributedUpdateProcess= orFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit= " [junit4:junit4] 1> INFO - 2013-04-10 00:16:50.745; org.apache.solr.core.= RequestHandlers; created standard: solr.StandardRequestHandler [junit4:junit4] 1> INFO - 2013-04-10 00:16:50.745; org.apache.solr.core.= RequestHandlers; created /get: solr.RealTimeGetHandler [junit4:junit4] 1> INFO - 2013-04-10 00:16:50.745; org.apache.solr.core.= RequestHandlers; adding lazy requestHandler: solr.ReplicationHandler [junit4:junit4] 1> INFO - 2013-04-10 00:16:50.746; org.apache.solr.core.= RequestHandlers; created /replication: solr.ReplicationHandler [junit4:junit4] 1> INFO - 2013-04-10 00:16:50.746; org.apache.solr.core.= RequestHandlers; created /update: solr.UpdateRequestHandler [junit4:junit4] 1> INFO - 2013-04-10 00:16:50.747; org.apache.solr.core.= RequestHandlers; created /admin/: org.apache.solr.handler.admin.AdminHandle= rs [junit4:junit4] 1> INFO - 2013-04-10 00:16:50.754; org.apache.solr.handl= er.loader.XMLLoader; xsltCacheLifetimeSeconds=3D60 [junit4:junit4] 1> INFO - 2013-04-10 00:16:50.757; org.apache.solr.searc= h.SolrIndexSearcher; Opening Searcher@5c826a5f main [junit4:junit4] 1> INFO - 2013-04-10 00:16:50.757; org.apache.solr.updat= e.UpdateHandler; Clearing tlog files, tlogDir=3D/usr/home/hudson/hudson-sla= ve/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J1/./org= .apache.solr.cloud.CollectionsAPIDistributedZkTest-controljetty-13655530002= 54/awholynewcollection_0_shard1_replica1/data/tlog [junit4:junit4] 1> INFO - 2013-04-10 00:16:50.758; org.apache.solr.updat= e.CommitTracker; Hard AutoCommit: disabled [junit4:junit4] 1> INFO - 2013-04-10 00:16:50.759; org.apache.solr.updat= e.CommitTracker; Soft AutoCommit: disabled [junit4:junit4] 1> INFO - 2013-04-10 00:16:50.762; org.apache.solr.core.= SolrCore; [awholynewcollection_0_shard1_replica1] Registered new searcher S= earcher@5c826a5f main{StandardDirectoryReader(segments_1:1)} [junit4:junit4] 1> INFO - 2013-04-10 00:16:50.765; org.apache.solr.cloud= .ZkController; publishing core=3Dawholynewcollection_0_shard1_replica1 stat= e=3Ddown [junit4:junit4] 1> INFO - 2013-04-10 00:16:50.804; org.apache.solr.schem= a.OpenExchangeRatesOrgProvider; Initialized with rates=3Dopen-exchange-rate= s.json, refreshInterval=3D1440. [junit4:junit4] 1> INFO - 2013-04-10 00:16:50.819; org.apache.solr.schem= a.IndexSchema; default search field in schema is text [junit4:junit4] 1> INFO - 2013-04-10 00:16:50.824; org.apache.solr.schem= a.IndexSchema; unique key field: id [junit4:junit4] 1> INFO - 2013-04-10 00:16:50.833; org.apache.solr.schem= a.OpenExchangeRatesOrgProvider; Initialized with rates=3Dopen-exchange-rate= s.json, refreshInterval=3D1440. [junit4:junit4] 1> INFO - 2013-04-10 00:16:50.841; org.apache.solr.schem= a.IndexSchema; default search field in schema is text [junit4:junit4] 1> INFO - 2013-04-10 00:16:50.843; org.apache.solr.schem= a.FileExchangeRateProvider; Reloading exchange rates from file currency.xml [junit4:junit4] 1> INFO - 2013-04-10 00:16:50.845; org.apache.solr.schem= a.IndexSchema; unique key field: id [junit4:junit4] 1> INFO - 2013-04-10 00:16:50.857; org.apache.solr.schem= a.FileExchangeRateProvider; Reloading exchange rates from file currency.xml [junit4:junit4] 1> INFO - 2013-04-10 00:16:50.861; org.apache.solr.schem= a.FileExchangeRateProvider; Reloading exchange rates from file currency.xml [junit4:junit4] 1> INFO - 2013-04-10 00:16:50.864; org.apache.solr.schem= a.OpenExchangeRatesOrgProvider; Reloading exchange rates from open-exchange= -rates.json [junit4:junit4] 1> WARN - 2013-04-10 00:16:50.865; org.apache.solr.schem= a.OpenExchangeRatesOrgProvider$OpenExchangeRates; Unknown key IMPORTANT NOT= E [junit4:junit4] 1> INFO - 2013-04-10 00:16:50.865; org.apache.solr.schem= a.FileExchangeRateProvider; Reloading exchange rates from file currency.xml [junit4:junit4] 1> WARN - 2013-04-10 00:16:50.866; org.apache.solr.schem= a.OpenExchangeRatesOrgProvider$OpenExchangeRates; Expected key, got STRING [junit4:junit4] 1> INFO - 2013-04-10 00:16:50.867; org.apache.solr.schem= a.OpenExchangeRatesOrgProvider; Reloading exchange rates from open-exchange= -rates.json [junit4:junit4] 1> WARN - 2013-04-10 00:16:50.868; org.apache.solr.schem= a.OpenExchangeRatesOrgProvider$OpenExchangeRates; Unknown key IMPORTANT NOT= E [junit4:junit4] 1> WARN - 2013-04-10 00:16:50.868; org.apache.solr.schem= a.OpenExchangeRatesOrgProvider$OpenExchangeRates; Expected key, got STRING [junit4:junit4] 1> INFO - 2013-04-10 00:16:50.869; org.apache.solr.core.= SolrCore; org.apache.solr.core.MockDirectoryFactory [junit4:junit4] 1> INFO - 2013-04-10 00:16:50.869; org.apache.solr.core.= SolrCore; [awholynewcollection_0_shard1_replica5] Opening new SolrCore at /= usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/bui= ld/solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTes= t-jetty2-1365553002138/awholynewcollection_0_shard1_replica5/, dataDir=3D/u= sr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/buil= d/solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest= -jetty2-1365553002138/awholynewcollection_0_shard1_replica5/data/ [junit4:junit4] 1> INFO - 2013-04-10 00:16:50.870; org.apache.solr.core.= JmxMonitoredMap; JMX monitoring is enabled. Adding Solr mbeans to JMX Serve= r: com.sun.jmx.mbeanserver.JmxMBeanServer@18987a33 [junit4:junit4] 1> INFO - 2013-04-10 00:16:50.870; org.apache.solr.schem= a.OpenExchangeRatesOrgProvider; Reloading exchange rates from open-exchange= -rates.json [junit4:junit4] 1> INFO - 2013-04-10 00:16:50.871; org.apache.solr.core.= SolrCore; org.apache.solr.core.MockDirectoryFactory [junit4:junit4] 1> INFO - 2013-04-10 00:16:50.872; org.apache.solr.core.= CachingDirectoryFactory; return new directory for /usr/home/hudson/hudson-s= lave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J1/./o= rg.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty2-1365553002138/a= wholynewcollection_0_shard1_replica5/data [junit4:junit4] 1> WARN - 2013-04-10 00:16:50.872; org.apache.solr.schem= a.OpenExchangeRatesOrgProvider$OpenExchangeRates; Unknown key IMPORTANT NOT= E [junit4:junit4] 1> WARN - 2013-04-10 00:16:50.872; org.apache.solr.schem= a.OpenExchangeRatesOrgProvider$OpenExchangeRates; Expected key, got STRING [junit4:junit4] 1> INFO - 2013-04-10 00:16:50.872; org.apache.solr.core.= SolrCore; New index directory detected: old=3Dnull new=3D/usr/home/hudson/h= udson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test= /J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty2-13655530= 02138/awholynewcollection_0_shard1_replica5/data/index/ [junit4:junit4] 1> INFO - 2013-04-10 00:16:50.873; org.apache.solr.schem= a.OpenExchangeRatesOrgProvider; Reloading exchange rates from open-exchange= -rates.json [junit4:junit4] 1> WARN - 2013-04-10 00:16:50.873; org.apache.solr.core.= SolrCore; [awholynewcollection_0_shard1_replica5] Solr index directory '/us= r/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build= /solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-= jetty2-1365553002138/awholynewcollection_0_shard1_replica5/data/index' does= n't exist. Creating new index... [junit4:junit4] 1> INFO - 2013-04-10 00:16:50.874; org.apache.solr.core.= CachingDirectoryFactory; return new directory for /usr/home/hudson/hudson-s= lave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J1/./o= rg.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty2-1365553002138/a= wholynewcollection_0_shard1_replica5/data/index [junit4:junit4] 1> WARN - 2013-04-10 00:16:50.875; org.apache.solr.schem= a.OpenExchangeRatesOrgProvider$OpenExchangeRates; Unknown key IMPORTANT NOT= E [junit4:junit4] 1> WARN - 2013-04-10 00:16:50.875; org.apache.solr.schem= a.OpenExchangeRatesOrgProvider$OpenExchangeRates; Expected key, got STRING [junit4:junit4] 1> INFO - 2013-04-10 00:16:50.876; org.apache.solr.core.= SolrCore; org.apache.solr.core.MockDirectoryFactory [junit4:junit4] 1> INFO - 2013-04-10 00:16:50.876; org.apache.solr.core.= SolrCore; [awholynewcollection_0_shard1_replica3] Opening new SolrCore at /= usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/bui= ld/solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTes= t-jetty4-1365553004999/awholynewcollection_0_shard1_replica3/, dataDir=3D/u= sr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/buil= d/solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest= -jetty4-1365553004999/awholynewcollection_0_shard1_replica3/data/ [junit4:junit4] 1> INFO - 2013-04-10 00:16:50.876; org.apache.solr.core.= JmxMonitoredMap; JMX monitoring is enabled. Adding Solr mbeans to JMX Serve= r: com.sun.jmx.mbeanserver.JmxMBeanServer@18987a33 [junit4:junit4] 1> INFO - 2013-04-10 00:16:50.877; org.apache.solr.core.= SolrCore; org.apache.solr.core.MockDirectoryFactory [junit4:junit4] 1> INFO - 2013-04-10 00:16:50.877; org.apache.solr.core.= CachingDirectoryFactory; return new directory for /usr/home/hudson/hudson-s= lave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J1/./o= rg.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1365553004999/a= wholynewcollection_0_shard1_replica3/data [junit4:junit4] 1> INFO - 2013-04-10 00:16:50.878; org.apache.solr.core.= SolrCore; New index directory detected: old=3Dnull new=3D/usr/home/hudson/h= udson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test= /J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-13655530= 04999/awholynewcollection_0_shard1_replica3/data/index/ [junit4:junit4] 1> WARN - 2013-04-10 00:16:50.878; org.apache.solr.core.= SolrCore; [awholynewcollection_0_shard1_replica3] Solr index directory '/us= r/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build= /solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-= jetty4-1365553004999/awholynewcollection_0_shard1_replica3/data/index' does= n't exist. Creating new index... [junit4:junit4] 1> INFO - 2013-04-10 00:16:50.878; org.apache.solr.core.= CachingDirectoryFactory; return new directory for /usr/home/hudson/hudson-s= lave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J1/./o= rg.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1365553004999/a= wholynewcollection_0_shard1_replica3/data/index [junit4:junit4] 1> INFO - 2013-04-10 00:16:50.879; org.apache.solr.core.= SolrDeletionPolicy; SolrDeletionPolicy.onCommit: commits:num=3D1 [junit4:junit4] 1> =09commit{dir=3DMockDirWrapper(org.apache.lucene.store= .RAMDirectory@6a1b8d17 lockFactory=3Dorg.apache.lucene.store.NativeFSLockFa= ctory@3fc3f8fd),segFN=3Dsegments_1,generation=3D1,filenames=3D[segments_1] [junit4:junit4] 1> INFO - 2013-04-10 00:16:50.879; org.apache.solr.core.= SolrDeletionPolicy; newest commit =3D 1[segments_1] [junit4:junit4] 1> INFO - 2013-04-10 00:16:50.882; org.apache.solr.core.= SolrDeletionPolicy; SolrDeletionPolicy.onCommit: commits:num=3D1 [junit4:junit4] 1> =09commit{dir=3DMockDirWrapper(org.apache.lucene.store= .RAMDirectory@bccb4e6 lockFactory=3Dorg.apache.lucene.store.NativeFSLockFac= tory@2364553c),segFN=3Dsegments_1,generation=3D1,filenames=3D[segments_1] [junit4:junit4] 1> INFO - 2013-04-10 00:16:50.882; org.apache.solr.core.= SolrDeletionPolicy; newest commit =3D 1[segments_1] [junit4:junit4] 1> INFO - 2013-04-10 00:16:50.882; org.apache.solr.updat= e.processor.UpdateRequestProcessorChain; inserting DistributedUpdateProcess= orFactory into updateRequestProcessorChain "dedupe" [junit4:junit4] 1> INFO - 2013-04-10 00:16:50.883; org.apache.solr.updat= e.processor.UpdateRequestProcessorChain; inserting DistributedUpdateProcess= orFactory into updateRequestProcessorChain "stored_sig" [junit4:junit4] 1> INFO - 2013-04-10 00:16:50.884; org.apache.solr.updat= e.processor.UpdateRequestProcessorChain; inserting DistributedUpdateProcess= orFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit= " [junit4:junit4] 1> INFO - 2013-04-10 00:16:50.885; org.apache.solr.updat= e.processor.UpdateRequestProcessorChain; inserting DistributedUpdateProcess= orFactory into updateRequestProcessorChain "dedupe" [junit4:junit4] 1> INFO - 2013-04-10 00:16:50.885; org.apache.solr.updat= e.processor.UpdateRequestProcessorChain; inserting DistributedUpdateProcess= orFactory into updateRequestProcessorChain "stored_sig" [junit4:junit4] 1> INFO - 2013-04-10 00:16:50.885; org.apache.solr.core.= RequestHandlers; created standard: solr.StandardRequestHandler [junit4:junit4] 1> INFO - 2013-04-10 00:16:50.886; org.apache.solr.updat= e.processor.UpdateRequestProcessorChain; inserting DistributedUpdateProcess= orFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit= " [junit4:junit4] 1> INFO - 2013-04-10 00:16:50.886; org.apache.solr.core.= RequestHandlers; created /get: solr.RealTimeGetHandler [junit4:junit4] 1> INFO - 2013-04-10 00:16:50.886; org.apache.solr.core.= RequestHandlers; created standard: solr.StandardRequestHandler [junit4:junit4] 1> INFO - 2013-04-10 00:16:50.887; org.apache.solr.core.= RequestHandlers; adding lazy requestHandler: solr.ReplicationHandler [junit4:junit4] 1> INFO - 2013-04-10 00:16:50.887; org.apache.solr.core.= RequestHandlers; created /get: solr.RealTimeGetHandler [junit4:junit4] 1> INFO - 2013-04-10 00:16:50.888; org.apache.solr.core.= RequestHandlers; adding lazy requestHandler: solr.ReplicationHandler [junit4:junit4] 1> INFO - 2013-04-10 00:16:50.887; org.apache.solr.core.= RequestHandlers; created /replication: solr.ReplicationHandler [junit4:junit4] 1> INFO - 2013-04-10 00:16:50.888; org.apache.solr.core.= RequestHandlers; created /replication: solr.ReplicationHandler [junit4:junit4] 1> INFO - 2013-04-10 00:16:50.889; org.apache.solr.core.= RequestHandlers; created /update: solr.UpdateRequestHandler [junit4:junit4] 1> INFO - 2013-04-10 00:16:50.889; org.apache.solr.core.= RequestHandlers; created /update: solr.UpdateRequestHandler [junit4:junit4] 1> INFO - 2013-04-10 00:16:50.889; org.apache.solr.core.= RequestHandlers; created /admin/: org.apache.solr.handler.admin.AdminHandle= rs [junit4:junit4] 1> INFO - 2013-04-10 00:16:50.890; org.apache.solr.core.= RequestHandlers; created /admin/: org.apache.solr.handler.admin.AdminHandle= rs [junit4:junit4] 1> INFO - 2013-04-10 00:16:50.898; org.apache.solr.handl= er.loader.XMLLoader; xsltCacheLifetimeSeconds=3D60 [junit4:junit4] 1> INFO - 2013-04-10 00:16:50.899; org.apache.solr.handl= er.loader.XMLLoader; xsltCacheLifetimeSeconds=3D60 [junit4:junit4] 1> INFO - 2013-04-10 00:16:50.899; org.apache.solr.schem= a.OpenExchangeRatesOrgProvider; Initialized with rates=3Dopen-exchange-rate= s.json, refreshInterval=3D1440. [junit4:junit4] 1> INFO - 2013-04-10 00:16:50.901; org.apache.solr.searc= h.SolrIndexSearcher; Opening Searcher@21a0769d main [junit4:junit4] 1> INFO - 2013-04-10 00:16:50.901; org.apache.solr.updat= e.UpdateHandler; Clearing tlog files, tlogDir=3D/usr/home/hudson/hudson-sla= ve/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J1/./org= .apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1365553004999/awh= olynewcollection_0_shard1_replica3/data/tlog [junit4:junit4] 1> INFO - 2013-04-10 00:16:50.902; org.apache.solr.updat= e.CommitTracker; Hard AutoCommit: disabled [junit4:junit4] 1> INFO - 2013-04-10 00:16:50.903; org.apache.solr.updat= e.CommitTracker; Soft AutoCommit: disabled [junit4:junit4] 1> INFO - 2013-04-10 00:16:50.903; org.apache.solr.searc= h.SolrIndexSearcher; Opening Searcher@65694399 main [junit4:junit4] 1> INFO - 2013-04-10 00:16:50.904; org.apache.solr.updat= e.UpdateHandler; Clearing tlog files, tlogDir=3D/usr/home/hudson/hudson-sla= ve/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J1/./org= .apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty2-1365553002138/awh= olynewcollection_0_shard1_replica5/data/tlog [junit4:junit4] 1> INFO - 2013-04-10 00:16:50.905; org.apache.solr.updat= e.CommitTracker; Hard AutoCommit: disabled [junit4:junit4] 1> INFO - 2013-04-10 00:16:50.905; org.apache.solr.core.= SolrCore; [awholynewcollection_0_shard1_replica3] Registered new searcher S= earcher@21a0769d main{StandardDirectoryReader(segments_1:1)} [junit4:junit4] 1> INFO - 2013-04-10 00:16:50.906; org.apache.solr.updat= e.CommitTracker; Soft AutoCommit: disabled [junit4:junit4] 1> INFO - 2013-04-10 00:16:50.907; org.apache.solr.cloud= .ZkController; publishing core=3Dawholynewcollection_0_shard1_replica3 stat= e=3Ddown [junit4:junit4] 1> INFO - 2013-04-10 00:16:50.908; org.apache.solr.schem= a.IndexSchema; default search field in schema is text [junit4:junit4] 1> INFO - 2013-04-10 00:16:50.910; org.apache.solr.core.= SolrCore; [awholynewcollection_0_shard1_replica5] Registered new searcher S= earcher@65694399 main{StandardDirectoryReader(segments_1:1)} [junit4:junit4] 1> INFO - 2013-04-10 00:16:50.911; org.apache.solr.schem= a.IndexSchema; unique key field: id [junit4:junit4] 1> INFO - 2013-04-10 00:16:50.912; org.apache.solr.cloud= .ZkController; publishing core=3Dawholynewcollection_0_shard1_replica5 stat= e=3Ddown [junit4:junit4] 1> INFO - 2013-04-10 00:16:50.919; org.apache.solr.schem= a.OpenExchangeRatesOrgProvider; Initialized with rates=3Dopen-exchange-rate= s.json, refreshInterval=3D1440. [junit4:junit4] 1> INFO - 2013-04-10 00:16:50.926; org.apache.solr.schem= a.FileExchangeRateProvider; Reloading exchange rates from file currency.xml [junit4:junit4] 1> INFO - 2013-04-10 00:16:50.927; org.apache.solr.schem= a.IndexSchema; default search field in schema is text [junit4:junit4] 1> INFO - 2013-04-10 00:16:50.930; org.apache.solr.schem= a.IndexSchema; unique key field: id [junit4:junit4] 1> INFO - 2013-04-10 00:16:50.934; org.apache.solr.schem= a.FileExchangeRateProvider; Reloading exchange rates from file currency.xml [junit4:junit4] 1> INFO - 2013-04-10 00:16:50.938; org.apache.solr.schem= a.OpenExchangeRatesOrgProvider; Reloading exchange rates from open-exchange= -rates.json [junit4:junit4] 1> WARN - 2013-04-10 00:16:50.939; org.apache.solr.schem= a.OpenExchangeRatesOrgProvider$OpenExchangeRates; Unknown key IMPORTANT NOT= E [junit4:junit4] 1> WARN - 2013-04-10 00:16:50.940; org.apache.solr.schem= a.OpenExchangeRatesOrgProvider$OpenExchangeRates; Expected key, got STRING [junit4:junit4] 1> INFO - 2013-04-10 00:16:50.940; org.apache.solr.schem= a.OpenExchangeRatesOrgProvider; Reloading exchange rates from open-exchange= -rates.json [junit4:junit4] 1> WARN - 2013-04-10 00:16:50.941; org.apache.solr.schem= a.OpenExchangeRatesOrgProvider$OpenExchangeRates; Unknown key IMPORTANT NOT= E [junit4:junit4] 1> WARN - 2013-04-10 00:16:50.942; org.apache.solr.schem= a.OpenExchangeRatesOrgProvider$OpenExchangeRates; Expected key, got STRING [junit4:junit4] 1> INFO - 2013-04-10 00:16:50.942; org.apache.solr.core.= SolrCore; org.apache.solr.core.MockDirectoryFactory [junit4:junit4] 1> INFO - 2013-04-10 00:16:50.942; org.apache.solr.core.= SolrCore; [awholynewcollection_0_shard1_replica4] Opening new SolrCore at /= usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/bui= ld/solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTes= t-jetty3-1365553003596/awholynewcollection_0_shard1_replica4/, dataDir=3D/u= sr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/buil= d/solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest= -jetty3-1365553003596/awholynewcollection_0_shard1_replica4/data/ [junit4:junit4] 1> INFO - 2013-04-10 00:16:50.943; org.apache.solr.core.= JmxMonitoredMap; JMX monitoring is enabled. Adding Solr mbeans to JMX Serve= r: com.sun.jmx.mbeanserver.JmxMBeanServer@18987a33 [junit4:junit4] 1> INFO - 2013-04-10 00:16:50.943; org.apache.solr.core.= SolrCore; org.apache.solr.core.MockDirectoryFactory [junit4:junit4] 1> INFO - 2013-04-10 00:16:50.945; org.apache.solr.core.= CachingDirectoryFactory; return new directory for /usr/home/hudson/hudson-s= lave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J1/./o= rg.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty3-1365553003596/a= wholynewcollection_0_shard1_replica4/data [junit4:junit4] 1> INFO - 2013-04-10 00:16:50.945; org.apache.solr.core.= SolrCore; New index directory detected: old=3Dnull new=3D/usr/home/hudson/h= udson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test= /J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty3-13655530= 03596/awholynewcollection_0_shard1_replica4/data/index/ [junit4:junit4] 1> WARN - 2013-04-10 00:16:50.945; org.apache.solr.core.= SolrCore; [awholynewcollection_0_shard1_replica4] Solr index directory '/us= r/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build= /solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-= jetty3-1365553003596/awholynewcollection_0_shard1_replica4/data/index' does= n't exist. Creating new index... [junit4:junit4] 1> INFO - 2013-04-10 00:16:50.946; org.apache.solr.core.= CachingDirectoryFactory; return new directory for /usr/home/hudson/hudson-s= lave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J1/./o= rg.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty3-1365553003596/a= wholynewcollection_0_shard1_replica4/data/index [junit4:junit4] 1> INFO - 2013-04-10 00:16:50.949; org.apache.solr.core.= SolrDeletionPolicy; SolrDeletionPolicy.onCommit: commits:num=3D1 [junit4:junit4] 1> =09commit{dir=3DMockDirWrapper(org.apache.lucene.store= .RAMDirectory@593aa24f lockFactory=3Dorg.apache.lucene.store.NativeFSLockFa= ctory@71a5ad04),segFN=3Dsegments_1,generation=3D1,filenames=3D[segments_1] [junit4:junit4] 1> INFO - 2013-04-10 00:16:50.949; org.apache.solr.core.= SolrDeletionPolicy; newest commit =3D 1[segments_1] [junit4:junit4] 1> INFO - 2013-04-10 00:16:50.951; org.apache.solr.updat= e.processor.UpdateRequestProcessorChain; inserting DistributedUpdateProcess= orFactory into updateRequestProcessorChain "dedupe" [junit4:junit4] 1> INFO - 2013-04-10 00:16:50.952; org.apache.solr.updat= e.processor.UpdateRequestProcessorChain; inserting DistributedUpdateProcess= orFactory into updateRequestProcessorChain "stored_sig" [junit4:junit4] 1> INFO - 2013-04-10 00:16:50.952; org.apache.solr.updat= e.processor.UpdateRequestProcessorChain; inserting DistributedUpdateProcess= orFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit= " [junit4:junit4] 1> INFO - 2013-04-10 00:16:50.953; org.apache.solr.core.= RequestHandlers; created standard: solr.StandardRequestHandler [junit4:junit4] 1> INFO - 2013-04-10 00:16:50.953; org.apache.solr.core.= RequestHandlers; created /get: solr.RealTimeGetHandler [junit4:junit4] 1> INFO - 2013-04-10 00:16:50.954; org.apache.solr.core.= RequestHandlers; adding lazy requestHandler: solr.ReplicationHandler [junit4:junit4] 1> INFO - 2013-04-10 00:16:50.954; org.apache.solr.core.= RequestHandlers; created /replication: solr.ReplicationHandler [junit4:junit4] 1> INFO - 2013-04-10 00:16:50.954; org.apache.solr.core.= RequestHandlers; created /update: solr.UpdateRequestHandler [junit4:junit4] 1> INFO - 2013-04-10 00:16:50.955; org.apache.solr.core.= RequestHandlers; created /admin/: org.apache.solr.handler.admin.AdminHandle= rs [junit4:junit4] 1> INFO - 2013-04-10 00:16:50.960; org.apache.solr.handl= er.loader.XMLLoader; xsltCacheLifetimeSeconds=3D60 [junit4:junit4] 1> INFO - 2013-04-10 00:16:50.964; org.apache.solr.searc= h.SolrIndexSearcher; Opening Searcher@168eaf0a main [junit4:junit4] 1> INFO - 2013-04-10 00:16:50.964; org.apache.solr.updat= e.UpdateHandler; Clearing tlog files, tlogDir=3D/usr/home/hudson/hudson-sla= ve/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J1/./org= .apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty3-1365553003596/awh= olynewcollection_0_shard1_replica4/data/tlog [junit4:junit4] 1> INFO - 2013-04-10 00:16:50.965; org.apache.solr.updat= e.CommitTracker; Hard AutoCommit: disabled [junit4:junit4] 1> INFO - 2013-04-10 00:16:50.966; org.apache.solr.updat= e.CommitTracker; Soft AutoCommit: disabled [junit4:junit4] 1> INFO - 2013-04-10 00:16:50.966; org.apache.solr.schem= a.FileExchangeRateProvider; Reloading exchange rates from file currency.xml [junit4:junit4] 1> INFO - 2013-04-10 00:16:50.969; org.apache.solr.core.= SolrCore; [awholynewcollection_0_shard1_replica4] Registered new searcher S= earcher@168eaf0a main{StandardDirectoryReader(segments_1:1)} [junit4:junit4] 1> INFO - 2013-04-10 00:16:50.971; org.apache.solr.cloud= .ZkController; publishing core=3Dawholynewcollection_0_shard1_replica4 stat= e=3Ddown [junit4:junit4] 1> INFO - 2013-04-10 00:16:50.975; org.apache.solr.schem= a.FileExchangeRateProvider; Reloading exchange rates from file currency.xml [junit4:junit4] 1> INFO - 2013-04-10 00:16:50.980; org.apache.solr.schem= a.OpenExchangeRatesOrgProvider; Reloading exchange rates from open-exchange= -rates.json [junit4:junit4] 1> WARN - 2013-04-10 00:16:50.981; org.apache.solr.schem= a.OpenExchangeRatesOrgProvider$OpenExchangeRates; Unknown key IMPORTANT NOT= E [junit4:junit4] 1> WARN - 2013-04-10 00:16:50.981; org.apache.solr.schem= a.OpenExchangeRatesOrgProvider$OpenExchangeRates; Expected key, got STRING [junit4:junit4] 1> INFO - 2013-04-10 00:16:50.982; org.apache.solr.schem= a.OpenExchangeRatesOrgProvider; Reloading exchange rates from open-exchange= -rates.json [junit4:junit4] 1> WARN - 2013-04-10 00:16:50.983; org.apache.solr.schem= a.OpenExchangeRatesOrgProvider$OpenExchangeRates; Unknown key IMPORTANT NOT= E [junit4:junit4] 1> WARN - 2013-04-10 00:16:50.983; org.apache.solr.schem= a.OpenExchangeRatesOrgProvider$OpenExchangeRates; Expected key, got STRING [junit4:junit4] 1> INFO - 2013-04-10 00:16:50.983; org.apache.solr.core.= SolrCore; org.apache.solr.core.MockDirectoryFactory [junit4:junit4] 1> INFO - 2013-04-10 00:16:50.984; org.apache.solr.core.= SolrCore; [awholynewcollection_0_shard1_replica2] Opening new SolrCore at /= usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/bui= ld/solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTes= t-jetty1-1365553000729/awholynewcollection_0_shard1_replica2/, dataDir=3D/u= sr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/buil= d/solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest= -jetty1-1365553000729/awholynewcollection_0_shard1_replica2/data/ [junit4:junit4] 1> INFO - 2013-04-10 00:16:50.985; org.apache.solr.core.= JmxMonitoredMap; JMX monitoring is enabled. Adding Solr mbeans to JMX Serve= r: com.sun.jmx.mbeanserver.JmxMBeanServer@18987a33 [junit4:junit4] 1> INFO - 2013-04-10 00:16:50.985; org.apache.solr.core.= SolrCore; org.apache.solr.core.MockDirectoryFactory [junit4:junit4] 1> INFO - 2013-04-10 00:16:50.986; org.apache.solr.core.= CachingDirectoryFactory; return new directory for /usr/home/hudson/hudson-s= lave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J1/./o= rg.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty1-1365553000729/a= wholynewcollection_0_shard1_replica2/data [junit4:junit4] 1> INFO - 2013-04-10 00:16:50.986; org.apache.solr.core.= SolrCore; New index directory detected: old=3Dnull new=3D/usr/home/hudson/h= udson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test= /J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty1-13655530= 00729/awholynewcollection_0_shard1_replica2/data/index/ [junit4:junit4] 1> WARN - 2013-04-10 00:16:50.987; org.apache.solr.core.= SolrCore; [awholynewcollection_0_shard1_replica2] Solr index directory '/us= r/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build= /solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-= jetty1-1365553000729/awholynewcollection_0_shard1_replica2/data/index' does= n't exist. Creating new index... [junit4:junit4] 1> INFO - 2013-04-10 00:16:50.987; org.apache.solr.core.= CachingDirectoryFactory; return new directory for /usr/home/hudson/hudson-s= lave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J1/./o= rg.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty1-1365553000729/a= wholynewcollection_0_shard1_replica2/data/index [junit4:junit4] 1> INFO - 2013-04-10 00:16:50.990; org.apache.solr.core.= SolrDeletionPolicy; SolrDeletionPolicy.onCommit: commits:num=3D1 [junit4:junit4] 1> =09commit{dir=3DMockDirWrapper(org.apache.lucene.store= .RAMDirectory@7ab3b96f lockFactory=3Dorg.apache.lucene.store.NativeFSLockFa= ctory@4dfea0cf),segFN=3Dsegments_1,generation=3D1,filenames=3D[segments_1] [junit4:junit4] 1> INFO - 2013-04-10 00:16:50.990; org.apache.solr.core.= SolrDeletionPolicy; newest commit =3D 1[segments_1] [junit4:junit4] 1> INFO - 2013-04-10 00:16:50.992; org.apache.solr.updat= e.processor.UpdateRequestProcessorChain; inserting DistributedUpdateProcess= orFactory into updateRequestProcessorChain "dedupe" [junit4:junit4] 1> INFO - 2013-04-10 00:16:50.993; org.apache.solr.updat= e.processor.UpdateRequestProcessorChain; inserting DistributedUpdateProcess= orFactory into updateRequestProcessorChain "stored_sig" [junit4:junit4] 1> INFO - 2013-04-10 00:16:50.993; org.apache.solr.updat= e.processor.UpdateRequestProcessorChain; inserting DistributedUpdateProcess= orFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit= " [junit4:junit4] 1> INFO - 2013-04-10 00:16:50.994; org.apache.solr.core.= RequestHandlers; created standard: solr.StandardRequestHandler [junit4:junit4] 1> INFO - 2013-04-10 00:16:50.995; org.apache.solr.core.= RequestHandlers; created /get: solr.RealTimeGetHandler [junit4:junit4] 1> INFO - 2013-04-10 00:16:50.995; org.apache.solr.core.= RequestHandlers; adding lazy requestHandler: solr.ReplicationHandler [junit4:junit4] 1> INFO - 2013-04-10 00:16:50.995; org.apache.solr.core.= RequestHandlers; created /replication: solr.ReplicationHandler [junit4:junit4] 1> INFO - 2013-04-10 00:16:50.996; org.apache.solr.core.= RequestHandlers; created /update: solr.UpdateRequestHandler [junit4:junit4] 1> INFO - 2013-04-10 00:16:50.996; org.apache.solr.core.= RequestHandlers; created /admin/: org.apache.solr.handler.admin.AdminHandle= rs [junit4:junit4] 1> INFO - 2013-04-10 00:16:51.001; org.apache.solr.handl= er.loader.XMLLoader; xsltCacheLifetimeSeconds=3D60 [junit4:junit4] 1> INFO - 2013-04-10 00:16:51.005; org.apache.solr.searc= h.SolrIndexSearcher; Opening Searcher@523a4f93 main [junit4:junit4] 1> INFO - 2013-04-10 00:16:51.006; org.apache.solr.updat= e.UpdateHandler; Clearing tlog files, tlogDir=3D/usr/home/hudson/hudson-sla= ve/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J1/./org= .apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty1-1365553000729/awh= olynewcollection_0_shard1_replica2/data/tlog [junit4:junit4] 1> INFO - 2013-04-10 00:16:51.007; org.apache.solr.updat= e.CommitTracker; Hard AutoCommit: disabled [junit4:junit4] 1> INFO - 2013-04-10 00:16:51.007; org.apache.solr.updat= e.CommitTracker; Soft AutoCommit: disabled [junit4:junit4] 1> INFO - 2013-04-10 00:16:51.010; org.apache.solr.core.= SolrCore; [awholynewcollection_0_shard1_replica2] Registered new searcher S= earcher@523a4f93 main{StandardDirectoryReader(segments_1:1)} [junit4:junit4] 1> INFO - 2013-04-10 00:16:51.012; org.apache.solr.cloud= .ZkController; publishing core=3Dawholynewcollection_0_shard1_replica2 stat= e=3Ddown [junit4:junit4] 1> INFO - 2013-04-10 00:16:51.314; org.apache.solr.commo= n.cloud.ZkStateReader; Updating cloud state from ZooKeeper...=20 [junit4:junit4] 1> INFO - 2013-04-10 00:16:51.314; 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:33487__nodes_used_collec= tion_shard2_replica2", [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":"nodes_used_collection_shard2_replica2", [junit4:junit4] 1> "collection":"nodes_used_collection", [junit4:junit4] 1> "shard_range":null, [junit4:junit4] 1> "node_name":"127.0.0.1:33487_", [junit4:junit4] 1> "base_url":"http://127.0.0.1:33487"} [junit4:junit4] 1> INFO - 2013-04-10 00:16:51.318; 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:33471__nodes_used_collec= tion_shard1_replica1", [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":"nodes_used_collection_shard1_replica1", [junit4:junit4] 1> "collection":"nodes_used_collection", [junit4:junit4] 1> "shard_range":null, [junit4:junit4] 1> "node_name":"127.0.0.1:33471_", [junit4:junit4] 1> "base_url":"http://127.0.0.1:33471"} [junit4:junit4] 1> INFO - 2013-04-10 00:16:51.329; 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:33478__nodes_used_collec= tion_shard2_replica1", [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":"nodes_used_collection_shard2_replica1", [junit4:junit4] 1> "collection":"nodes_used_collection", [junit4:junit4] 1> "shard_range":null, [junit4:junit4] 1> "node_name":"127.0.0.1:33478_", [junit4:junit4] 1> "base_url":"http://127.0.0.1:33478"} [junit4:junit4] 1> INFO - 2013-04-10 00:16:51.333; 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:33475__nodes_used_collec= tion_shard1_replica2", [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":"nodes_used_collection_shard1_replica2", [junit4:junit4] 1> "collection":"nodes_used_collection", [junit4:junit4] 1> "shard_range":null, [junit4:junit4] 1> "node_name":"127.0.0.1:33475_", [junit4:junit4] 1> "base_url":"http://127.0.0.1:33475"} [junit4:junit4] 1> INFO - 2013-04-10 00:16:51.342; 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":"shard1", [junit4:junit4] 1> "roles":null, [junit4:junit4] 1> "state":"down", [junit4:junit4] 1> "shard_state":"active", [junit4:junit4] 1> "core":"awholynewcollection_0_shard1_replica1", [junit4:junit4] 1> "collection":"awholynewcollection_0", [junit4:junit4] 1> "shard_range":null, [junit4:junit4] 1> "node_name":"127.0.0.1:33471_", [junit4:junit4] 1> "base_url":"http://127.0.0.1:33471"} [junit4:junit4] 1> INFO - 2013-04-10 00:16:51.343; org.apache.solr.cloud= .Overseer$ClusterStateUpdater; Create collection awholynewcollection_0 with= numShards 1 [junit4:junit4] 1> INFO - 2013-04-10 00:16:51.346; 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":"shard1", [junit4:junit4] 1> "roles":null, [junit4:junit4] 1> "state":"down", [junit4:junit4] 1> "shard_state":"active", [junit4:junit4] 1> "core":"awholynewcollection_0_shard1_replica3", [junit4:junit4] 1> "collection":"awholynewcollection_0", [junit4:junit4] 1> "shard_range":null, [junit4:junit4] 1> "node_name":"127.0.0.1:33487_", [junit4:junit4] 1> "base_url":"http://127.0.0.1:33487"} [junit4:junit4] 1> INFO - 2013-04-10 00:16:51.350; 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":"shard1", [junit4:junit4] 1> "roles":null, [junit4:junit4] 1> "state":"down", [junit4:junit4] 1> "shard_state":"active", [junit4:junit4] 1> "core":"awholynewcollection_0_shard1_replica5", [junit4:junit4] 1> "collection":"awholynewcollection_0", [junit4:junit4] 1> "shard_range":null, [junit4:junit4] 1> "node_name":"127.0.0.1:33478_", [junit4:junit4] 1> "base_url":"http://127.0.0.1:33478"} [junit4:junit4] 1> INFO - 2013-04-10 00:16:51.353; 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":"shard1", [junit4:junit4] 1> "roles":null, [junit4:junit4] 1> "state":"down", [junit4:junit4] 1> "shard_state":"active", [junit4:junit4] 1> "core":"awholynewcollection_0_shard1_replica4", [junit4:junit4] 1> "collection":"awholynewcollection_0", [junit4:junit4] 1> "shard_range":null, [junit4:junit4] 1> "node_name":"127.0.0.1:33481_", [junit4:junit4] 1> "base_url":"http://127.0.0.1:33481"} [junit4:junit4] 1> INFO - 2013-04-10 00:16:51.356; 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":"shard1", [junit4:junit4] 1> "roles":null, [junit4:junit4] 1> "state":"down", [junit4:junit4] 1> "shard_state":"active", [junit4:junit4] 1> "core":"awholynewcollection_0_shard1_replica2", [junit4:junit4] 1> "collection":"awholynewcollection_0", [junit4:junit4] 1> "shard_range":null, [junit4:junit4] 1> "node_name":"127.0.0.1:33475_", [junit4:junit4] 1> "base_url":"http://127.0.0.1:33475"} [junit4:junit4] 1> INFO - 2013-04-10 00:16:51.359; 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-10 00:16:51.360; 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-10 00:16:51.360; 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-10 00:16:51.360; 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-10 00:16:51.360; 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-10 00:16:51.360; 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-10 00:16:51.359; 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-10 00:16:51.359; 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-10 00:16:51.768; org.apache.solr.core.= CoreContainer; registering core: awholynewcollection_0_shard1_replica1 [junit4:junit4] 1> INFO - 2013-04-10 00:16:51.768; org.apache.solr.cloud= .ZkController; Register replica - core:awholynewcollection_0_shard1_replica= 1 address:http://127.0.0.1:33471 collection:awholynewcollection_0 shard:sha= rd1 [junit4:junit4] 1> INFO - 2013-04-10 00:16:51.769; org.apache.solr.commo= n.cloud.SolrZkClient; makePath: /collections/awholynewcollection_0/leader_e= lect/shard1/election [junit4:junit4] 1> INFO - 2013-04-10 00:16:51.786; org.apache.solr.cloud= .ShardLeaderElectionContext; Running the leader process. [junit4:junit4] 1> INFO - 2013-04-10 00:16:51.788; org.apache.solr.cloud= .ShardLeaderElectionContext; Waiting until we see more replicas up: total= =3D5 found=3D1 timeoutin=3D180000 [junit4:junit4] 1> INFO - 2013-04-10 00:16:51.849; org.apache.solr.handl= er.admin.CoreAdminHandler; Waited coreNodeName: 127.0.0.1:33487__nodes_used= _collection_shard2_replica2, state: recovering, checkLive: true, onlyIfLead= er: true for: 2 seconds. [junit4:junit4] 1> INFO - 2013-04-10 00:16:51.849; org.apache.solr.servl= et.SolrDispatchFilter; [admin] webapp=3Dnull path=3D/admin/cores params=3D{= coreNodeName=3D127.0.0.1:33487__nodes_used_collection_shard2_replica2&state= =3Drecovering&nodeName=3D127.0.0.1:33487_&action=3DPREPRECOVERY&checkLive= =3Dtrue&core=3Dnodes_used_collection_shard2_replica1&wt=3Djavabin&onlyIfLea= der=3Dtrue&version=3D2} status=3D0 QTime=3D2002=20 [junit4:junit4] 1> INFO - 2013-04-10 00:16:51.851; org.apache.solr.handl= er.admin.CoreAdminHandler; Waited coreNodeName: 127.0.0.1:33471__nodes_used= _collection_shard1_replica1, state: recovering, checkLive: true, onlyIfLead= er: true for: 2 seconds. [junit4:junit4] 1> INFO - 2013-04-10 00:16:51.851; org.apache.solr.servl= et.SolrDispatchFilter; [admin] webapp=3Dnull path=3D/admin/cores params=3D{= coreNodeName=3D127.0.0.1:33471__nodes_used_collection_shard1_replica1&state= =3Drecovering&nodeName=3D127.0.0.1:33471_&action=3DPREPRECOVERY&checkLive= =3Dtrue&core=3Dnodes_used_collection_shard1_replica2&wt=3Djavabin&onlyIfLea= der=3Dtrue&version=3D2} status=3D0 QTime=3D2004=20 [junit4:junit4] 1> INFO - 2013-04-10 00:16:51.910; org.apache.solr.core.= CoreContainer; registering core: awholynewcollection_0_shard1_replica3 [junit4:junit4] 1> INFO - 2013-04-10 00:16:51.910; org.apache.solr.cloud= .ZkController; Register replica - core:awholynewcollection_0_shard1_replica= 3 address:http://127.0.0.1:33487 collection:awholynewcollection_0 shard:sha= rd1 [junit4:junit4] 1> INFO - 2013-04-10 00:16:51.915; org.apache.solr.core.= CoreContainer; registering core: awholynewcollection_0_shard1_replica5 [junit4:junit4] 1> INFO - 2013-04-10 00:16:51.915; org.apache.solr.cloud= .ZkController; Register replica - core:awholynewcollection_0_shard1_replica= 5 address:http://127.0.0.1:33478 collection:awholynewcollection_0 shard:sha= rd1 [junit4:junit4] 1> INFO - 2013-04-10 00:16:51.973; org.apache.solr.core.= CoreContainer; registering core: awholynewcollection_0_shard1_replica4 [junit4:junit4] 1> INFO - 2013-04-10 00:16:51.973; org.apache.solr.cloud= .ZkController; Register replica - core:awholynewcollection_0_shard1_replica= 4 address:http://127.0.0.1:33481 collection:awholynewcollection_0 shard:sha= rd1 [junit4:junit4] 1> INFO - 2013-04-10 00:16:52.014; org.apache.solr.core.= CoreContainer; registering core: awholynewcollection_0_shard1_replica2 [junit4:junit4] 1> INFO - 2013-04-10 00:16:52.014; org.apache.solr.cloud= .ZkController; Register replica - core:awholynewcollection_0_shard1_replica= 2 address:http://127.0.0.1:33475 collection:awholynewcollection_0 shard:sha= rd1 [junit4:junit4] 1> INFO - 2013-04-10 00:16:52.290; org.apache.solr.cloud= .ShardLeaderElectionContext; Enough replicas found to continue. [junit4:junit4] 1> INFO - 2013-04-10 00:16:52.291; org.apache.solr.cloud= .ShardLeaderElectionContext; I may be the new leader - try and sync [junit4:junit4] 1> INFO - 2013-04-10 00:16:52.291; org.apache.solr.cloud= .SyncStrategy; Sync replicas to http://127.0.0.1:33471/awholynewcollection_= 0_shard1_replica1/ [junit4:junit4] 1> INFO - 2013-04-10 00:16:52.292; org.apache.solr.updat= e.PeerSync; PeerSync: core=3Dawholynewcollection_0_shard1_replica1 url=3Dht= tp://127.0.0.1:33471 START replicas=3D[http://127.0.0.1:33487/awholynewcoll= ection_0_shard1_replica3/, http://127.0.0.1:33478/awholynewcollection_0_sha= rd1_replica5/, http://127.0.0.1:33481/awholynewcollection_0_shard1_replica4= /, http://127.0.0.1:33475/awholynewcollection_0_shard1_replica2/] nUpdates= =3D100 [junit4:junit4] 1> INFO - 2013-04-10 00:16:52.295; org.apache.solr.updat= e.PeerSync; PeerSync: core=3Dawholynewcollection_0_shard1_replica1 url=3Dht= tp://127.0.0.1:33471 DONE. We have no versions. sync failed. [junit4:junit4] 1> INFO - 2013-04-10 00:16:52.295; org.apache.solr.cloud= .SyncStrategy; Leader's attempt to sync with shard failed, moving to the ne= xt canidate [junit4:junit4] 1> INFO - 2013-04-10 00:16:52.296; org.apache.solr.cloud= .ShardLeaderElectionContext; We failed sync, but we have no versions - we c= an't sync in that case - we were active before, so become leader anyway [junit4:junit4] 1> INFO - 2013-04-10 00:16:52.297; org.apache.solr.cloud= .ShardLeaderElectionContext; I am the new leader: http://127.0.0.1:33471/aw= holynewcollection_0_shard1_replica1/ [junit4:junit4] 1> INFO - 2013-04-10 00:16:52.297; org.apache.solr.commo= n.cloud.SolrZkClient; makePath: /collections/awholynewcollection_0/leaders/= shard1 [junit4:junit4] 1> INFO - 2013-04-10 00:16:52.302; org.apache.solr.core.= SolrCore; [awholynewcollection_0_shard1_replica4] webapp=3D path=3D/get par= ams=3D{getVersions=3D100&distrib=3Dfalse&wt=3Djavabin&qt=3D/get&version=3D2= } status=3D0 QTime=3D1=20 [junit4:junit4] 1> INFO - 2013-04-10 00:16:52.302; org.apache.solr.core.= SolrCore; [awholynewcollection_0_shard1_replica5] webapp=3D path=3D/get par= ams=3D{getVersions=3D100&distrib=3Dfalse&wt=3Djavabin&qt=3D/get&version=3D2= } status=3D0 QTime=3D0=20 [junit4:junit4] 1> INFO - 2013-04-10 00:16:52.302; org.apache.solr.core.= SolrCore; [awholynewcollection_0_shard1_replica2] webapp=3D path=3D/get par= ams=3D{getVersions=3D100&distrib=3Dfalse&wt=3Djavabin&qt=3D/get&version=3D2= } status=3D0 QTime=3D1=20 [junit4:junit4] 1> INFO - 2013-04-10 00:16:52.304; org.apache.solr.core.= SolrCore; [awholynewcollection_0_shard1_replica3] webapp=3D path=3D/get par= ams=3D{getVersions=3D100&distrib=3Dfalse&wt=3Djavabin&qt=3D/get&version=3D2= } status=3D0 QTime=3D0=20 [junit4:junit4] 1> INFO - 2013-04-10 00:16:52.881; org.apache.solr.commo= n.cloud.ZkStateReader; Updating cloud state from ZooKeeper...=20 [junit4:junit4] 1> INFO - 2013-04-10 00:16:52.901; 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-10 00:16:52.901; 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-10 00:16:52.901; 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-10 00:16:52.901; 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-10 00:16:52.901; 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-10 00:16:52.901; 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-10 00:16:52.901; 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-10 00:16:52.901; 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-10 00:16:52.914; org.apache.solr.cloud= .ZkController; We are http://127.0.0.1:33487/awholynewcollection_0_shard1_r= eplica3/ and leader is http://127.0.0.1:33471/awholynewcollection_0_shard1_= replica1/ [junit4:junit4] 1> INFO - 2013-04-10 00:16:52.915; org.apache.solr.cloud= .ZkController; No LogReplay needed for core=3Dawholynewcollection_0_shard1_= replica3 baseURL=3Dhttp://127.0.0.1:33487 [junit4:junit4] 1> INFO - 2013-04-10 00:16:52.915; org.apache.solr.cloud= .ZkController; Core needs to recover:awholynewcollection_0_shard1_replica3 [junit4:junit4] 1> INFO - 2013-04-10 00:16:52.915; org.apache.solr.updat= e.DefaultSolrCoreState; Running recovery - first canceling any ongoing reco= very [junit4:junit4] 1> INFO - 2013-04-10 00:16:52.916; org.apache.solr.cloud= .RecoveryStrategy; Starting recovery process. core=3Dawholynewcollection_0= _shard1_replica3 recoveringAfterStartup=3Dtrue [junit4:junit4] 1> INFO - 2013-04-10 00:16:52.916; org.apache.solr.cloud= .RecoveryStrategy; ###### startupVersions=3D[] [junit4:junit4] 1> INFO - 2013-04-10 00:16:52.916; org.apache.solr.commo= n.cloud.ZkStateReader; Updating cloud state from ZooKeeper...=20 [junit4:junit4] 1> INFO - 2013-04-10 00:16:52.916; org.apache.solr.cloud= .ZkController; publishing core=3Dawholynewcollection_0_shard1_replica3 stat= e=3Drecovering [junit4:junit4] 1> INFO - 2013-04-10 00:16:52.918; org.apache.solr.core.= CoreContainer; Persisting cores config to /usr/home/hudson/hudson-slave/wor= kspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J1/./org.apach= e.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1365553004999/solr.xml [junit4:junit4] 1> INFO - 2013-04-10 00:16:52.919; 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-10 00:16:52.920; org.apache.solr.cloud= .ZkController; We are http://127.0.0.1:33478/awholynewcollection_0_shard1_r= eplica5/ and leader is http://127.0.0.1:33471/awholynewcollection_0_shard1_= replica1/ [junit4:junit4] 1> INFO - 2013-04-10 00:16:52.920; org.apache.solr.cloud= .ZkController; No LogReplay needed for core=3Dawholynewcollection_0_shard1_= replica5 baseURL=3Dhttp://127.0.0.1:33478 [junit4:junit4] 1> INFO - 2013-04-10 00:16:52.921; org.apache.solr.cloud= .ZkController; Core needs to recover:awholynewcollection_0_shard1_replica5 [junit4:junit4] 1> INFO - 2013-04-10 00:16:52.921; org.apache.solr.updat= e.DefaultSolrCoreState; Running recovery - first canceling any ongoing reco= very [junit4:junit4] 1> INFO - 2013-04-10 00:16:52.921; org.apache.solr.cloud= .RecoveryStrategy; Starting recovery process. core=3Dawholynewcollection_0= _shard1_replica5 recoveringAfterStartup=3Dtrue [junit4:junit4] 1> INFO - 2013-04-10 00:16:52.922; org.apache.solr.cloud= .RecoveryStrategy; ###### startupVersions=3D[] [junit4:junit4] 1> INFO - 2013-04-10 00:16:52.924; org.apache.solr.cloud= .ZkController; publishing core=3Dawholynewcollection_0_shard1_replica5 stat= e=3Drecovering [junit4:junit4] 1> INFO - 2013-04-10 00:16:52.925; org.apache.solr.commo= n.cloud.ZkStateReader; Updating cloud state from ZooKeeper...=20 [junit4:junit4] 1> INFO - 2013-04-10 00:16:52.926; org.apache.solr.cloud= .ZkController; We are http://127.0.0.1:33471/awholynewcollection_0_shard1_r= eplica1/ and leader is http://127.0.0.1:33471/awholynewcollection_0_shard1_= replica1/ [junit4:junit4] 1> INFO - 2013-04-10 00:16:52.926; 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-10 00:16:52.926; org.apache.solr.core.= CoreContainer; Persisting cores config to /usr/home/hudson/hudson-slave/wor= kspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J1/./org.apach= e.solr.cloud.CollectionsAPIDistributedZkTest-jetty2-1365553002138/solr.xml [junit4:junit4] 1> INFO - 2013-04-10 00:16:52.926; org.apache.solr.cloud= .ZkController; No LogReplay needed for core=3Dawholynewcollection_0_shard1_= replica1 baseURL=3Dhttp://127.0.0.1:33471 [junit4:junit4] 1> INFO - 2013-04-10 00:16:52.927; org.apache.solr.cloud= .ZkController; I am the leader, no recovery necessary [junit4:junit4] 1> INFO - 2013-04-10 00:16:52.927; org.apache.solr.cloud= .ZkController; publishing core=3Dawholynewcollection_0_shard1_replica1 stat= e=3Dactive [junit4:junit4] 1> INFO - 2013-04-10 00:16:52.929; org.apache.solr.core.= SolrXMLSerializer; Persisting cores config to /usr/home/hudson/hudson-slave= /workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J1/./org.a= pache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1365553004999/solr.= xml [junit4:junit4] 1> INFO - 2013-04-10 00:16:52.929; org.apache.solr.commo= n.cloud.ZkStateReader; Updating cloud state from ZooKeeper...=20 [junit4:junit4] 1> INFO - 2013-04-10 00:16:52.930; org.apache.solr.core.= CoreContainer; Persisting cores config to /usr/home/hudson/hudson-slave/wor= kspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J1/./org.apach= e.solr.cloud.CollectionsAPIDistributedZkTest-controljetty-1365553000254/sol= r.xml [junit4:junit4] 1> INFO - 2013-04-10 00:16:52.930; org.apache.solr.servl= et.SolrDispatchFilter; [admin] webapp=3Dnull path=3D/admin/cores params=3D{= numShards=3D1&shard=3Dshard1&name=3Dawholynewcollection_0_shard1_replica3&a= ction=3DCREATE&collection=3Dawholynewcollection_0&wt=3Djavabin&qt=3D/admin/= cores&version=3D2} status=3D0 QTime=3D2994=20 [junit4:junit4] 1> INFO - 2013-04-10 00:16:52.936; org.apache.solr.handl= er.admin.CoreAdminHandler; Going to wait for coreNodeName: 127.0.0.1:33487_= _awholynewcollection_0_shard1_replica3, state: recovering, checkLive: true,= onlyIfLeader: true [junit4:junit4] 1> INFO - 2013-04-10 00:16:52.936; org.apache.solr.handl= er.admin.CoreAdminHandler; Going to wait for coreNodeName: 127.0.0.1:33478_= _awholynewcollection_0_shard1_replica5, state: recovering, checkLive: true,= onlyIfLeader: true [junit4:junit4] 1> INFO - 2013-04-10 00:16:52.937; org.apache.solr.core.= SolrXMLSerializer; Persisting cores config to /usr/home/hudson/hudson-slave= /workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J1/./org.a= pache.solr.cloud.CollectionsAPIDistributedZkTest-jetty2-1365553002138/solr.= xml [junit4:junit4] 1> INFO - 2013-04-10 00:16:52.939; org.apache.solr.servl= et.SolrDispatchFilter; [admin] webapp=3Dnull path=3D/admin/cores params=3D{= numShards=3D1&shard=3Dshard1&name=3Dawholynewcollection_0_shard1_replica5&a= ction=3DCREATE&collection=3Dawholynewcollection_0&wt=3Djavabin&qt=3D/admin/= cores&version=3D2} status=3D0 QTime=3D3002=20 [junit4:junit4] 1> INFO - 2013-04-10 00:16:52.942; org.apache.solr.core.= SolrXMLSerializer; Persisting cores config to /usr/home/hudson/hudson-slave= /workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J1/./org.a= pache.solr.cloud.CollectionsAPIDistributedZkTest-controljetty-1365553000254= /solr.xml [junit4:junit4] 1> INFO - 2013-04-10 00:16:52.943; org.apache.solr.servl= et.SolrDispatchFilter; [admin] webapp=3Dnull path=3D/admin/cores params=3D{= numShards=3D1&shard=3Dshard1&name=3Dawholynewcollection_0_shard1_replica1&a= ction=3DCREATE&collection=3Dawholynewcollection_0&wt=3Djavabin&qt=3D/admin/= cores&version=3D2} status=3D0 QTime=3D3007=20 [junit4:junit4] 1> INFO - 2013-04-10 00:16:52.978; org.apache.solr.cloud= .ZkController; We are http://127.0.0.1:33481/awholynewcollection_0_shard1_r= eplica4/ and leader is http://127.0.0.1:33471/awholynewcollection_0_shard1_= replica1/ [junit4:junit4] 1> INFO - 2013-04-10 00: [...truncated too long message...] tty4/index;done=3Dfalse>>] [junit4:junit4] 1> INFO - 2013-04-10 00:38:38.978; org.apache.solr.core.= CachingDirectoryFactory; Closing directory: /usr/home/hudson/hudson-slave/w= orkspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J1/org.apach= e.solr.cloud.ChaosMonkeyShardSplitTest-1365554175408/jetty4/index [junit4:junit4] 1> INFO - 2013-04-10 00:38:38.978; org.apache.solr.core.= CachingDirectoryFactory; looking to close /usr/home/hudson/hudson-slave/wor= kspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J1/org.apache.= solr.cloud.ChaosMonkeyShardSplitTest-1365554175408/jetty4 [CachedDir<>] [junit4:junit4] 1> INFO - 2013-04-10 00:38:38.978; org.apache.solr.core.= CachingDirectoryFactory; Closing directory: /usr/home/hudson/hudson-slave/w= orkspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J1/org.apach= e.solr.cloud.ChaosMonkeyShardSplitTest-1365554175408/jetty4 [junit4:junit4] 1> INFO - 2013-04-10 00:38:38.978; org.apache.solr.commo= n.cloud.SolrZkClient; makePath: /collections/collection1/leaders/shard2 [junit4:junit4] 1> WARN - 2013-04-10 00:38:38.979; org.apache.solr.cloud= .LeaderElector$1;=20 [junit4:junit4] 1> org.apache.zookeeper.KeeperException$SessionExpiredExc= eption: KeeperErrorCode =3D Session expired for /collections/collection1/le= ader_elect/shard2/election/89492958439997452-127.0.0.1:20645__collection1-n= _0000000001 [junit4:junit4] 1> =09at org.apache.zookeeper.KeeperException.create(Keep= erException.java:127) [junit4:junit4] 1> =09at org.apache.zookeeper.KeeperException.create(Keep= erException.java:51) [junit4:junit4] 1> =09at org.apache.zookeeper.ZooKeeper.delete(ZooKeeper.= java:873) [junit4:junit4] 1> =09at org.apache.solr.common.cloud.SolrZkClient$2.exec= ute(SolrZkClient.java:152) [junit4:junit4] 1> =09at org.apache.solr.common.cloud.SolrZkClient$2.exec= ute(SolrZkClient.java:149) [junit4:junit4] 1> =09at org.apache.solr.common.cloud.ZkCmdExecutor.retry= Operation(ZkCmdExecutor.java:65) [junit4:junit4] 1> =09at org.apache.solr.common.cloud.SolrZkClient.delete= (SolrZkClient.java:149) [junit4:junit4] 1> =09at org.apache.solr.cloud.ElectionContext.cancelElec= tion(ElectionContext.java:63) [junit4:junit4] 1> =09at org.apache.solr.cloud.ShardLeaderElectionContext= .runLeaderProcess(ElectionContext.java:246) [junit4:junit4] 1> =09at org.apache.solr.cloud.LeaderElector.runIamLeader= Process(LeaderElector.java:156) [junit4:junit4] 1> =09at org.apache.solr.cloud.LeaderElector.checkIfIamLe= ader(LeaderElector.java:100) [junit4:junit4] 1> =09at org.apache.solr.cloud.LeaderElector.access$000(L= eaderElector.java:55) [junit4:junit4] 1> =09at org.apache.solr.cloud.LeaderElector$1.process(Le= aderElector.java:129) [junit4:junit4] 1> =09at org.apache.zookeeper.ClientCnxn$EventThread.proc= essEvent(ClientCnxn.java:519) [junit4:junit4] 1> =09at org.apache.zookeeper.ClientCnxn$EventThread.run(= ClientCnxn.java:495) [junit4:junit4] 1> WARN - 2013-04-10 00:38:38.979; org.apache.solr.commo= n.cloud.ZkStateReader$3; ZooKeeper watch triggered, but Solr cannot talk to= ZK [junit4:junit4] 1> INFO - 2013-04-10 00:38:38.979; 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> WARN - 2013-04-10 00:38:38.980; org.apache.solr.commo= n.cloud.ZkStateReader$2; ZooKeeper watch triggered, but Solr cannot talk to= ZK [junit4:junit4] 1> INFO - 2013-04-10 00:38:38.980; 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> WARN - 2013-04-10 00:38:38.980; org.apache.solr.commo= n.cloud.ZkStateReader$2; ZooKeeper watch triggered, but Solr cannot talk to= ZK [junit4:junit4] 1> WARN - 2013-04-10 00:38:38.980; org.apache.solr.cloud= .LeaderElector$1;=20 [junit4:junit4] 1> org.apache.zookeeper.KeeperException$SessionExpiredExc= eption: KeeperErrorCode =3D Session expired for /overseer_elect/election [junit4:junit4] 1> =09at org.apache.zookeeper.KeeperException.create(Keep= erException.java:127) [junit4:junit4] 1> =09at org.apache.zookeeper.KeeperException.create(Keep= erException.java:51) [junit4:junit4] 1> =09at org.apache.zookeeper.ZooKeeper.getChildren(ZooKe= eper.java:1468) [junit4:junit4] 1> =09at org.apache.solr.common.cloud.SolrZkClient$6.exec= ute(SolrZkClient.java:235) [junit4:junit4] 1> =09at org.apache.solr.common.cloud.SolrZkClient$6.exec= ute(SolrZkClient.java:232) [junit4:junit4] 1> =09at org.apache.solr.common.cloud.ZkCmdExecutor.retry= Operation(ZkCmdExecutor.java:65) [junit4:junit4] 1> =09at org.apache.solr.common.cloud.SolrZkClient.getChi= ldren(SolrZkClient.java:232) [junit4:junit4] 1> =09at org.apache.solr.cloud.LeaderElector.checkIfIamLe= ader(LeaderElector.java:84) [junit4:junit4] 1> =09at org.apache.solr.cloud.LeaderElector.access$000(L= eaderElector.java:55) [junit4:junit4] 1> =09at org.apache.solr.cloud.LeaderElector$1.process(Le= aderElector.java:129) [junit4:junit4] 1> =09at org.apache.zookeeper.ClientCnxn$EventThread.proc= essEvent(ClientCnxn.java:519) [junit4:junit4] 1> =09at org.apache.zookeeper.ClientCnxn$EventThread.run(= ClientCnxn.java:495) [junit4:junit4] 2> NOTE: test params are: codec=3DAppending, sim=3DDefaul= tSimilarity, locale=3Dar_AE, timezone=3DEtc/GMT-7 [junit4:junit4] 2> NOTE: FreeBSD 9.0-RELEASE amd64/Sun Microsystems Inc. = 1.6.0_32 (64-bit)/cpus=3D16,threads=3D3,free=3D61971712,total=3D453640192 [junit4:junit4] 2> NOTE: All tests run in this JVM: [FileUtilsTest, TestN= umberUtils, TestPostingsSolrHighlighter, TestAnalyzedSuggestions, TestField= TypeResource, TestDFRSimilarityFactory, HardAutoCommitTest, CoreContainerCo= reInitFailuresTest, TestCodecSupport, SimplePostToolTest, TestUniqueKeyFiel= dResource, SpellCheckComponentTest, ZkNodePropsTest, EchoParamsTest, StatsC= omponentTest, TestLMJelinekMercerSimilarityFactory, XsltUpdateRequestHandle= rTest, DisMaxRequestHandlerTest, TestElisionMultitermQuery, TestDistributed= Search, BasicZkTest, FullSolrCloudDistribCmdsTest, CollectionsAPIDistribute= dZkTest, TestFoldingMultitermQuery, TestBinaryField, DebugComponentTest, Te= stRandomFaceting, TestUtils, HighlighterConfigTest, SuggesterTSTTest, Direc= tUpdateHandlerTest, TestBinaryResponseWriter, OpenCloseCoreStressTest, Test= RTGBase, TestSystemIdResolver, IndexSchemaRuntimeFieldTest, RequiredFieldsT= est, TestCSVLoader, TestCollationKeyRangeQueries, ShardRoutingCustomTest, P= reAnalyzedUpdateProcessorTest, IndexReaderFactoryTest, TestJmxMonitoredMap,= SpellCheckCollatorTest, OutputWriterTest, TestDefaultSimilarityFactory, Te= stCoreDiscovery, PingRequestHandlerTest, TermVectorComponentDistributedTest= , TestCopyFieldCollectionResource, TestLazyCores, PathHierarchyTokenizerFac= toryTest, ClusterStateTest, BadIndexSchemaTest, SampleTest, TestPartialUpda= teDeduplication, SolrIndexConfigTest, SolrCoreCheckLockOnStartupTest, Curre= ncyFieldXmlFileTest, TestAtomicUpdateErrorCases, TestStressReorder, TestRec= overy, BasicDistributedZk2Test, ZkSolrClientTest, NotRequiredUniqueKeyTest,= DOMUtilTest, TestMultiCoreConfBootstrap, TestCollationField, ChaosMonkeySa= feLeaderTest, LeaderElectionTest, TestZkChroot, TestDistributedGrouping, Zk= ControllerTest, TestReload, TestCoreContainer, SolrCoreTest, QueryElevation= ComponentTest, ConvertedLegacyTest, TestFiltering, TestExtendedDismaxParser= , SolrRequestParserTest, TestStressLucene, SpatialFilterTest, NoCacheHeader= Test, WordBreakSolrSpellCheckerTest, TestUpdate, TestWordDelimiterFilterFac= tory, DefaultValueUpdateProcessorTest, TestRemoteStreaming, DistanceFunctio= nTest, LukeRequestHandlerTest, DirectSolrSpellCheckerTest, DocumentAnalysis= RequestHandlerTest, TestOmitPositions, RequestHandlersTest, TestValueSource= Cache, TestIndexingPerformance, TestSolrQueryParser, FastVectorHighlighterT= est, TestJmxIntegration, JSONWriterTest, UniqFieldsUpdateProcessorFactoryTe= st, TestComponentsName, SOLR749Test, TestQuerySenderListener, UpdateParamsT= est, ResponseLogComponentTest, TestMergePolicyConfig, TestSolrDeletionPolic= y2, MultiTermTest, TestDocSet, NumericFieldsTest, TestConfig, TestFuzzyAnal= yzedSuggestions, DirectSolrConnectionTest, SpellPossibilityIteratorTest, Te= stLMDirichletSimilarityFactory, TestBM25SimilarityFactory, TimeZoneUtilsTes= t, TestFastOutputStream, OpenExchangeRatesOrgProviderTest, DateMathParserTe= st, TestSolrXMLSerializer, PreAnalyzedFieldTest, TestDocumentBuilder, Chaos= MonkeyShardSplitTest] [junit4:junit4] Completed on J1 in 144.00s, 1 test, 1 failure <<< FAILURES! [...truncated 17 lines...] BUILD FAILED /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/build.x= ml:381: The following error occurred while executing this line: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/build.x= ml:361: The following error occurred while executing this line: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/build.x= ml:39: The following error occurred while executing this line: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/bu= ild.xml:183: The following error occurred while executing this line: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/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-Java6/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-Java6/lucene/= common-build.xml:878: There were test failures: 288 suites, 1187 tests, 2 f= ailures, 27 ignored (8 assumptions) Total time: 51 minutes 59 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_1116_171743803.1365554344550 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_1116_171743803.1365554344550--