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 CD5F3100E8 for ; Wed, 1 May 2013 07:45:28 +0000 (UTC) Received: (qmail 65845 invoked by uid 500); 1 May 2013 07:45:27 -0000 Delivered-To: apmail-lucene-dev-archive@lucene.apache.org Received: (qmail 65522 invoked by uid 500); 1 May 2013 07:45:24 -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 65343 invoked by uid 99); 1 May 2013 07:45:20 -0000 Received: from nike.apache.org (HELO nike.apache.org) (192.87.106.230) by apache.org (qpsmtpd/0.29) with ESMTP; Wed, 01 May 2013 07:45:20 +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, 01 May 2013 07:44:58 +0000 Received: from aegis.apache.org (localhost [127.0.0.1]) by aegis.apache.org (Postfix) with ESMTP id A229FC0071 for ; Wed, 1 May 2013 07:44:35 +0000 (UTC) Date: Wed, 1 May 2013 07:44:12 +0000 (UTC) From: Apache Jenkins Server To: dev@lucene.apache.org Message-ID: <1317589878.6768.1367394275645.JavaMail.hudson@aegis> Subject: [JENKINS] Lucene-Solr-Tests-trunk-java7 - Build # 3948 - Failure MIME-Version: 1.0 Content-Type: multipart/mixed; boundary="----=_Part_6767_863640653.1367394252654" X-Jenkins-Job: Lucene-Solr-Tests-trunk-java7 X-Jenkins-Result: FAILURE X-Virus-Checked: Checked by ClamAV on apache.org ------=_Part_6767_863640653.1367394252654 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: quoted-printable Build: https://builds.apache.org/job/Lucene-Solr-Tests-trunk-java7/3948/ 1 tests failed. 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([E4AE6EDB44088510:6548E0C33357E52C]= :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:511) =09at org.apache.solr.cloud.CollectionsAPIDistributedZkTest.doTest(Collecti= onsAPIDistributedZkTest.java:145) =09at org.apache.solr.BaseDistributedSearchTestCase.testDistribSearch(BaseD= istributedSearchTestCase.java:815) =09at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method) =09at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.= java:57) =09at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAcces= sorImpl.java:43) =09at java.lang.reflect.Method.invoke(Method.java:601) =09at com.carrotsearch.randomizedtesting.RandomizedRunner.invoke(Randomized= Runner.java:1559) =09at com.carrotsearch.randomizedtesting.RandomizedRunner.access$600(Random= izedRunner.java:79) =09at com.carrotsearch.randomizedtesting.RandomizedRunner$6.evaluate(Random= izedRunner.java:737) =09at com.carrotsearch.randomizedtesting.RandomizedRunner$7.evaluate(Random= izedRunner.java:773) =09at com.carrotsearch.randomizedtesting.RandomizedRunner$8.evaluate(Random= izedRunner.java:787) =09at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$= 1.evaluate(SystemPropertiesRestoreRule.java:53) =09at org.apache.lucene.util.TestRuleSetupTeardownChained$1.evaluate(TestRu= leSetupTeardownChained.java:50) =09at org.apache.lucene.util.TestRuleFieldCacheSanity$1.evaluate(TestRuleFi= eldCacheSanity.java:51) =09at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBef= oreAfterRule.java:46) =09at com.carrotsearch.randomizedtesting.rules.SystemPropertiesInvariantRul= e$1.evaluate(SystemPropertiesInvariantRule.java:55) =09at org.apache.lucene.util.TestRuleThreadAndTestName$1.evaluate(TestRuleT= hreadAndTestName.java:49) =09at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(Test= RuleIgnoreAfterMaxFailures.java:70) =09at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFai= lure.java:48) =09at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(St= atementAdapter.java:36) =09at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.= run(ThreadLeakControl.java:358) =09at com.carrotsearch.randomizedtesting.ThreadLeakControl.forkTimeoutingTa= sk(ThreadLeakControl.java:782) =09at com.carrotsearch.randomizedtesting.ThreadLeakControl$3.evaluate(Threa= dLeakControl.java:442) =09at com.carrotsearch.randomizedtesting.RandomizedRunner.runSingleTest(Ran= domizedRunner.java:746) =09at com.carrotsearch.randomizedtesting.RandomizedRunner$3.evaluate(Random= izedRunner.java:648) =09at com.carrotsearch.randomizedtesting.RandomizedRunner$4.evaluate(Random= izedRunner.java:682) =09at com.carrotsearch.randomizedtesting.RandomizedRunner$5.evaluate(Random= izedRunner.java:693) =09at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(St= atementAdapter.java:36) =09at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$= 1.evaluate(SystemPropertiesRestoreRule.java:53) =09at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBef= oreAfterRule.java:46) =09at org.apache.lucene.util.TestRuleStoreClassName$1.evaluate(TestRuleStor= eClassName.java:42) =09at com.carrotsearch.randomizedtesting.rules.SystemPropertiesInvariantRul= e$1.evaluate(SystemPropertiesInvariantRule.java:55) =09at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMeth= odsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:39) =09at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMeth= odsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:39) =09at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(St= atementAdapter.java:36) =09at org.apache.lucene.util.TestRuleAssertionsRequired$1.evaluate(TestRule= AssertionsRequired.java:43) =09at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFai= lure.java:48) =09at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(Test= RuleIgnoreAfterMaxFailures.java:70) =09at org.apache.lucene.util.TestRuleIgnoreTestSuites$1.evaluate(TestRuleIg= noreTestSuites.java:55) =09at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(St= atementAdapter.java:36) =09at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.= run(ThreadLeakControl.java:358) =09at java.lang.Thread.run(Thread.java:722) Build Log: [...truncated 9385 lines...] [junit4:junit4] Suite: org.apache.solr.cloud.CollectionsAPIDistributedZkTes= t [junit4:junit4] 1> INFO - 2013-05-01 07:26:33.360; org.apache.solr.BaseD= istributedSearchTestCase; Setting hostContext system property: /wyc/rw [junit4:junit4] 1> INFO - 2013-05-01 07:26:33.366; org.apache.solr.SolrT= estCaseJ4; ###Starting testDistribSearch [junit4:junit4] 1> INFO - 2013-05-01 07:26:33.368; 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-05-01 07:26:33.368; org.apache.solr.cloud= .ZkTestServer$ZKServerMain; Starting server [junit4:junit4] 1> INFO - 2013-05-01 07:26:33.469; org.apache.solr.cloud= .ZkTestServer; start zk server on port:33673 [junit4:junit4] 1> INFO - 2013-05-01 07:26:33.470; org.apache.solr.commo= n.cloud.ConnectionManager; Waiting for client to connect to ZooKeeper [junit4:junit4] 1> INFO - 2013-05-01 07:26:33.473; org.apache.solr.commo= n.cloud.ConnectionManager; Watcher org.apache.solr.common.cloud.ConnectionM= anager@3533aa4b name:ZooKeeperConnection Watcher:127.0.0.1:33673 got event = WatchedEvent state:SyncConnected type:None path:null path:null type:None [junit4:junit4] 1> INFO - 2013-05-01 07:26:33.474; org.apache.solr.commo= n.cloud.ConnectionManager; Client is connected to ZooKeeper [junit4:junit4] 1> INFO - 2013-05-01 07:26:33.474; org.apache.solr.commo= n.cloud.SolrZkClient; makePath: /solr [junit4:junit4] 1> INFO - 2013-05-01 07:26:33.485; org.apache.solr.commo= n.cloud.ConnectionManager; Waiting for client to connect to ZooKeeper [junit4:junit4] 1> INFO - 2013-05-01 07:26:33.487; org.apache.solr.commo= n.cloud.ConnectionManager; Watcher org.apache.solr.common.cloud.ConnectionM= anager@273bd432 name:ZooKeeperConnection Watcher:127.0.0.1:33673/solr got e= vent WatchedEvent state:SyncConnected type:None path:null path:null type:No= ne [junit4:junit4] 1> INFO - 2013-05-01 07:26:33.487; org.apache.solr.commo= n.cloud.ConnectionManager; Client is connected to ZooKeeper [junit4:junit4] 1> INFO - 2013-05-01 07:26:33.488; org.apache.solr.commo= n.cloud.SolrZkClient; makePath: /collections/collection1 [junit4:junit4] 1> INFO - 2013-05-01 07:26:33.498; org.apache.solr.commo= n.cloud.SolrZkClient; makePath: /collections/collection1/shards [junit4:junit4] 1> INFO - 2013-05-01 07:26:33.502; org.apache.solr.commo= n.cloud.SolrZkClient; makePath: /collections/control_collection [junit4:junit4] 1> INFO - 2013-05-01 07:26:33.505; org.apache.solr.commo= n.cloud.SolrZkClient; makePath: /collections/control_collection/shards [junit4:junit4] 1> INFO - 2013-05-01 07:26:33.513; org.apache.solr.cloud= .AbstractZkTestCase; put /usr/home/hudson/hudson-slave/workspace/Lucene-Sol= r-Tests-trunk-java7/solr/build/solr-core/test-files/solr/collection1/conf/s= olrconfig-tlog.xml to /configs/conf1/solrconfig.xml [junit4:junit4] 1> INFO - 2013-05-01 07:26:33.514; org.apache.solr.commo= n.cloud.SolrZkClient; makePath: /configs/conf1/solrconfig.xml [junit4:junit4] 1> INFO - 2013-05-01 07:26:33.527; org.apache.solr.cloud= .AbstractZkTestCase; put /usr/home/hudson/hudson-slave/workspace/Lucene-Sol= r-Tests-trunk-java7/solr/build/solr-core/test-files/solr/collection1/conf/s= chema.xml to /configs/conf1/schema.xml [junit4:junit4] 1> INFO - 2013-05-01 07:26:33.528; org.apache.solr.commo= n.cloud.SolrZkClient; makePath: /configs/conf1/schema.xml [junit4:junit4] 1> INFO - 2013-05-01 07:26:33.634; org.apache.solr.cloud= .AbstractZkTestCase; put /usr/home/hudson/hudson-slave/workspace/Lucene-Sol= r-Tests-trunk-java7/solr/build/solr-core/test-files/solr/collection1/conf/s= topwords.txt to /configs/conf1/stopwords.txt [junit4:junit4] 1> INFO - 2013-05-01 07:26:33.635; org.apache.solr.commo= n.cloud.SolrZkClient; makePath: /configs/conf1/stopwords.txt [junit4:junit4] 1> INFO - 2013-05-01 07:26:33.638; org.apache.solr.cloud= .AbstractZkTestCase; put /usr/home/hudson/hudson-slave/workspace/Lucene-Sol= r-Tests-trunk-java7/solr/build/solr-core/test-files/solr/collection1/conf/p= rotwords.txt to /configs/conf1/protwords.txt [junit4:junit4] 1> INFO - 2013-05-01 07:26:33.639; org.apache.solr.commo= n.cloud.SolrZkClient; makePath: /configs/conf1/protwords.txt [junit4:junit4] 1> INFO - 2013-05-01 07:26:33.643; org.apache.solr.cloud= .AbstractZkTestCase; put /usr/home/hudson/hudson-slave/workspace/Lucene-Sol= r-Tests-trunk-java7/solr/build/solr-core/test-files/solr/collection1/conf/c= urrency.xml to /configs/conf1/currency.xml [junit4:junit4] 1> INFO - 2013-05-01 07:26:33.643; org.apache.solr.commo= n.cloud.SolrZkClient; makePath: /configs/conf1/currency.xml [junit4:junit4] 1> INFO - 2013-05-01 07:26:33.655; org.apache.solr.cloud= .AbstractZkTestCase; put /usr/home/hudson/hudson-slave/workspace/Lucene-Sol= r-Tests-trunk-java7/solr/build/solr-core/test-files/solr/collection1/conf/o= pen-exchange-rates.json to /configs/conf1/open-exchange-rates.json [junit4:junit4] 1> INFO - 2013-05-01 07:26:33.656; org.apache.solr.commo= n.cloud.SolrZkClient; makePath: /configs/conf1/open-exchange-rates.json [junit4:junit4] 1> INFO - 2013-05-01 07:26:33.659; org.apache.solr.cloud= .AbstractZkTestCase; put /usr/home/hudson/hudson-slave/workspace/Lucene-Sol= r-Tests-trunk-java7/solr/build/solr-core/test-files/solr/collection1/conf/m= apping-ISOLatin1Accent.txt to /configs/conf1/mapping-ISOLatin1Accent.txt [junit4:junit4] 1> INFO - 2013-05-01 07:26:33.660; org.apache.solr.commo= n.cloud.SolrZkClient; makePath: /configs/conf1/mapping-ISOLatin1Accent.txt [junit4:junit4] 1> INFO - 2013-05-01 07:26:33.664; org.apache.solr.cloud= .AbstractZkTestCase; put /usr/home/hudson/hudson-slave/workspace/Lucene-Sol= r-Tests-trunk-java7/solr/build/solr-core/test-files/solr/collection1/conf/o= ld_synonyms.txt to /configs/conf1/old_synonyms.txt [junit4:junit4] 1> INFO - 2013-05-01 07:26:33.664; org.apache.solr.commo= n.cloud.SolrZkClient; makePath: /configs/conf1/old_synonyms.txt [junit4:junit4] 1> INFO - 2013-05-01 07:26:33.668; org.apache.solr.cloud= .AbstractZkTestCase; put /usr/home/hudson/hudson-slave/workspace/Lucene-Sol= r-Tests-trunk-java7/solr/build/solr-core/test-files/solr/collection1/conf/s= ynonyms.txt to /configs/conf1/synonyms.txt [junit4:junit4] 1> INFO - 2013-05-01 07:26:33.668; org.apache.solr.commo= n.cloud.SolrZkClient; makePath: /configs/conf1/synonyms.txt [junit4:junit4] 1> INFO - 2013-05-01 07:26:33.898; org.eclipse.jetty.ser= ver.Server; jetty-8.1.10.v20130312 [junit4:junit4] 1> INFO - 2013-05-01 07:26:33.903; org.eclipse.jetty.ser= ver.AbstractConnector; Started SocketConnector@127.0.0.1:33541 [junit4:junit4] 1> INFO - 2013-05-01 07:26:33.903; org.apache.solr.servl= et.SolrDispatchFilter; SolrDispatchFilter.init() [junit4:junit4] 1> INFO - 2013-05-01 07:26:33.904; org.apache.solr.core.= SolrResourceLoader; JNDI not configured for solr (NoInitialContextEx) [junit4:junit4] 1> INFO - 2013-05-01 07:26:33.905; org.apache.solr.core.= SolrResourceLoader; using system property solr.solr.home: /usr/home/hudson/= hudson-slave/workspace/Lucene-Solr-Tests-trunk-java7/solr/build/solr-core/t= est/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-controljetty= -1367393193679 [junit4:junit4] 1> INFO - 2013-05-01 07:26:33.905; org.apache.solr.core.= CoreContainer$Initializer; looking for solr config file: /usr/home/hudson/h= udson-slave/workspace/Lucene-Solr-Tests-trunk-java7/solr/build/solr-core/te= st/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-controljetty-= 1367393193679/solr.xml [junit4:junit4] 1> INFO - 2013-05-01 07:26:33.906; org.apache.solr.core.= CoreContainer; New CoreContainer 2139526784 [junit4:junit4] 1> INFO - 2013-05-01 07:26:33.906; org.apache.solr.core.= CoreContainer; Loading CoreContainer using Solr Home: '/usr/home/hudson/hud= son-slave/workspace/Lucene-Solr-Tests-trunk-java7/solr/build/solr-core/test= /J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-controljetty-13= 67393193679/' [junit4:junit4] 1> INFO - 2013-05-01 07:26:33.907; org.apache.solr.core.= SolrResourceLoader; new SolrResourceLoader for directory: '/usr/home/hudson= /hudson-slave/workspace/Lucene-Solr-Tests-trunk-java7/solr/build/solr-core/= test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-controljett= y-1367393193679/' [junit4:junit4] 1> INFO - 2013-05-01 07:26:34.030; org.apache.solr.core.= SolrCoreDiscoverer; Looking for cores in /usr/home/hudson/hudson-slave/work= space/Lucene-Solr-Tests-trunk-java7/solr/build/solr-core/test/J1/org.apache= .solr.cloud.CollectionsAPIDistributedZkTest-controljetty-1367393193679 [junit4:junit4] 1> INFO - 2013-05-01 07:26:34.036; org.apache.solr.core.= SolrCoreDiscoverer; Discovered properties file /usr/home/hudson/hudson-slav= e/workspace/Lucene-Solr-Tests-trunk-java7/solr/build/solr-core/test/J1/./or= g.apache.solr.cloud.CollectionsAPIDistributedZkTest-controljetty-1367393193= 679/conf/core.properties, adding to cores [junit4:junit4] 1> INFO - 2013-05-01 07:26:34.039; org.apache.solr.core.= SolrCoreDiscoverer; Looking for cores in /usr/home/hudson/hudson-slave/work= space/Lucene-Solr-Tests-trunk-java7/solr/build/solr-core/test/J1/org.apache= .solr.cloud.CollectionsAPIDistributedZkTest-controljetty-1367393193679/coll= ection1 [junit4:junit4] 1> INFO - 2013-05-01 07:26:34.040; org.apache.solr.core.= SolrCoreDiscoverer; Looking for cores in /usr/home/hudson/hudson-slave/work= space/Lucene-Solr-Tests-trunk-java7/solr/build/solr-core/test/J1/org.apache= .solr.cloud.CollectionsAPIDistributedZkTest-controljetty-1367393193679/coll= ection1/lib [junit4:junit4] 1> INFO - 2013-05-01 07:26:34.042; org.apache.solr.core.= SolrCoreDiscoverer; Looking for cores in /usr/home/hudson/hudson-slave/work= space/Lucene-Solr-Tests-trunk-java7/solr/build/solr-core/test/J1/org.apache= .solr.cloud.CollectionsAPIDistributedZkTest-controljetty-1367393193679/coll= ection1/lib/classes [junit4:junit4] 1> INFO - 2013-05-01 07:26:34.044; org.apache.solr.core.= SolrCoreDiscoverer; Looking for cores in /usr/home/hudson/hudson-slave/work= space/Lucene-Solr-Tests-trunk-java7/solr/build/solr-core/test/J1/org.apache= .solr.cloud.CollectionsAPIDistributedZkTest-controljetty-1367393193679/coll= ection1/conf [junit4:junit4] 1> INFO - 2013-05-01 07:26:34.107; org.apache.solr.core.= SolrCoreDiscoverer; Looking for cores in /usr/home/hudson/hudson-slave/work= space/Lucene-Solr-Tests-trunk-java7/solr/build/solr-core/test/J1/org.apache= .solr.cloud.CollectionsAPIDistributedZkTest-controljetty-1367393193679/coll= ection1/conf/xslt [junit4:junit4] 1> INFO - 2013-05-01 07:26:34.196; org.apache.solr.handl= er.component.HttpShardHandlerFactory; Setting socketTimeout to: 0 [junit4:junit4] 1> INFO - 2013-05-01 07:26:34.196; org.apache.solr.handl= er.component.HttpShardHandlerFactory; Setting urlScheme to: http:// [junit4:junit4] 1> INFO - 2013-05-01 07:26:34.197; org.apache.solr.handl= er.component.HttpShardHandlerFactory; Setting connTimeout to: 0 [junit4:junit4] 1> INFO - 2013-05-01 07:26:34.197; org.apache.solr.handl= er.component.HttpShardHandlerFactory; Setting maxConnectionsPerHost to: 20 [junit4:junit4] 1> INFO - 2013-05-01 07:26:34.198; org.apache.solr.handl= er.component.HttpShardHandlerFactory; Setting corePoolSize to: 0 [junit4:junit4] 1> INFO - 2013-05-01 07:26:34.199; org.apache.solr.handl= er.component.HttpShardHandlerFactory; Setting maximumPoolSize to: 214748364= 7 [junit4:junit4] 1> INFO - 2013-05-01 07:26:34.199; org.apache.solr.handl= er.component.HttpShardHandlerFactory; Setting maxThreadIdleTime to: 5 [junit4:junit4] 1> INFO - 2013-05-01 07:26:34.200; org.apache.solr.handl= er.component.HttpShardHandlerFactory; Setting sizeOfQueue to: -1 [junit4:junit4] 1> INFO - 2013-05-01 07:26:34.200; org.apache.solr.handl= er.component.HttpShardHandlerFactory; Setting fairnessPolicy to: false [junit4:junit4] 1> INFO - 2013-05-01 07:26:34.201; org.apache.solr.clien= t.solrj.impl.HttpClientUtil; Creating new http client, config:maxConnection= sPerHost=3D20&maxConnections=3D10000&socketTimeout=3D0&connTimeout=3D0&retr= y=3Dfalse [junit4:junit4] 1> INFO - 2013-05-01 07:26:34.215; org.apache.solr.core.= CoreContainer; Registering Log Listener [junit4:junit4] 1> INFO - 2013-05-01 07:26:34.216; org.apache.solr.core.= ZkContainer; Zookeeper client=3D127.0.0.1:33673/solr [junit4:junit4] 1> INFO - 2013-05-01 07:26:34.217; org.apache.solr.cloud= .ZkController; zkHost includes chroot [junit4:junit4] 1> INFO - 2013-05-01 07:26:34.218; org.apache.solr.commo= n.cloud.ConnectionManager; Waiting for client to connect to ZooKeeper [junit4:junit4] 1> INFO - 2013-05-01 07:26:34.220; org.apache.solr.commo= n.cloud.ConnectionManager; Watcher org.apache.solr.common.cloud.ConnectionM= anager@13eeb9c6 name:ZooKeeperConnection Watcher:127.0.0.1:33673 got event = WatchedEvent state:SyncConnected type:None path:null path:null type:None [junit4:junit4] 1> INFO - 2013-05-01 07:26:34.221; org.apache.solr.commo= n.cloud.ConnectionManager; Client is connected to ZooKeeper [junit4:junit4] 1> INFO - 2013-05-01 07:26:34.223; 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-05-01 07:26:34.234; org.apache.solr.commo= n.cloud.ConnectionManager; Waiting for client to connect to ZooKeeper [junit4:junit4] 1> INFO - 2013-05-01 07:26:34.236; org.apache.solr.commo= n.cloud.ConnectionManager; Watcher org.apache.solr.common.cloud.ConnectionM= anager@713bfa18 name:ZooKeeperConnection Watcher:127.0.0.1:33673/solr got e= vent WatchedEvent state:SyncConnected type:None path:null path:null type:No= ne [junit4:junit4] 1> INFO - 2013-05-01 07:26:34.236; org.apache.solr.commo= n.cloud.ConnectionManager; Client is connected to ZooKeeper [junit4:junit4] 1> INFO - 2013-05-01 07:26:34.239; org.apache.solr.commo= n.cloud.SolrZkClient; makePath: /overseer/queue [junit4:junit4] 1> INFO - 2013-05-01 07:26:34.248; org.apache.solr.commo= n.cloud.SolrZkClient; makePath: /overseer/collection-queue-work [junit4:junit4] 1> INFO - 2013-05-01 07:26:34.252; org.apache.solr.commo= n.cloud.SolrZkClient; makePath: /live_nodes [junit4:junit4] 1> INFO - 2013-05-01 07:26:34.259; org.apache.solr.cloud= .ZkController; Register node as live in ZooKeeper:/live_nodes/127.0.0.1:335= 41_wyc%2Frw [junit4:junit4] 1> INFO - 2013-05-01 07:26:34.261; org.apache.solr.commo= n.cloud.SolrZkClient; makePath: /live_nodes/127.0.0.1:33541_wyc%2Frw [junit4:junit4] 1> INFO - 2013-05-01 07:26:34.265; org.apache.solr.commo= n.cloud.SolrZkClient; makePath: /overseer_elect/election [junit4:junit4] 1> INFO - 2013-05-01 07:26:34.277; org.apache.solr.commo= n.cloud.SolrZkClient; makePath: /overseer_elect/leader [junit4:junit4] 1> INFO - 2013-05-01 07:26:34.289; org.apache.solr.cloud= .Overseer; Overseer (id=3D89613480320958467-127.0.0.1:33541_wyc%2Frw-n_0000= 000000) starting [junit4:junit4] 1> INFO - 2013-05-01 07:26:34.301; org.apache.solr.commo= n.cloud.SolrZkClient; makePath: /overseer/queue-work [junit4:junit4] 1> INFO - 2013-05-01 07:26:34.306; org.apache.solr.cloud= .OverseerCollectionProcessor; Process current queue of collection creations [junit4:junit4] 1> INFO - 2013-05-01 07:26:34.307; org.apache.solr.commo= n.cloud.SolrZkClient; makePath: /clusterstate.json [junit4:junit4] 1> INFO - 2013-05-01 07:26:34.310; org.apache.solr.commo= n.cloud.SolrZkClient; makePath: /aliases.json [junit4:junit4] 1> INFO - 2013-05-01 07:26:34.312; org.apache.solr.commo= n.cloud.ZkStateReader; Updating cluster state from ZooKeeper...=20 [junit4:junit4] 1> INFO - 2013-05-01 07:26:34.318; org.apache.solr.servl= et.SolrDispatchFilter; user.dir=3D/usr/home/hudson/hudson-slave/workspace/L= ucene-Solr-Tests-trunk-java7/solr/build/solr-core/test/J1 [junit4:junit4] 1> INFO - 2013-05-01 07:26:34.318; org.apache.solr.cloud= .Overseer$ClusterStateUpdater; Starting to work on the main queue [junit4:junit4] 1> INFO - 2013-05-01 07:26:34.319; org.apache.solr.servl= et.SolrDispatchFilter; SolrDispatchFilter.init() done [junit4:junit4] 1> INFO - 2013-05-01 07:26:34.320; 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-05-01 07:26:34.330; org.apache.solr.clien= t.solrj.impl.HttpClientUtil; Creating new http client, config: [junit4:junit4] 1> INFO - 2013-05-01 07:26:34.331; org.apache.solr.commo= n.cloud.ConnectionManager; Waiting for client to connect to ZooKeeper [junit4:junit4] 1> INFO - 2013-05-01 07:26:34.333; org.apache.solr.commo= n.cloud.ConnectionManager; Watcher org.apache.solr.common.cloud.ConnectionM= anager@26668260 name:ZooKeeperConnection Watcher:127.0.0.1:33673/solr got e= vent WatchedEvent state:SyncConnected type:None path:null path:null type:No= ne [junit4:junit4] 1> INFO - 2013-05-01 07:26:34.334; org.apache.solr.commo= n.cloud.ConnectionManager; Client is connected to ZooKeeper [junit4:junit4] 1> INFO - 2013-05-01 07:26:34.336; org.apache.solr.commo= n.cloud.ZkStateReader; Updating cluster state from ZooKeeper...=20 [junit4:junit4] 1> INFO - 2013-05-01 07:26:34.338; org.apache.solr.cloud= .ChaosMonkey; monkey: init - expire sessions:true cause connection loss:tru= e [junit4:junit4] 1> INFO - 2013-05-01 07:26:34.562; org.eclipse.jetty.ser= ver.Server; jetty-8.1.10.v20130312 [junit4:junit4] 1> INFO - 2013-05-01 07:26:34.565; org.eclipse.jetty.ser= ver.AbstractConnector; Started SocketConnector@127.0.0.1:52550 [junit4:junit4] 1> INFO - 2013-05-01 07:26:34.566; org.apache.solr.servl= et.SolrDispatchFilter; SolrDispatchFilter.init() [junit4:junit4] 1> INFO - 2013-05-01 07:26:34.567; org.apache.solr.core.= SolrResourceLoader; JNDI not configured for solr (NoInitialContextEx) [junit4:junit4] 1> INFO - 2013-05-01 07:26:34.567; org.apache.solr.core.= SolrResourceLoader; using system property solr.solr.home: /usr/home/hudson/= hudson-slave/workspace/Lucene-Solr-Tests-trunk-java7/solr/build/solr-core/t= est/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty1-13673= 93194339 [junit4:junit4] 1> INFO - 2013-05-01 07:26:34.568; org.apache.solr.core.= CoreContainer$Initializer; looking for solr config file: /usr/home/hudson/h= udson-slave/workspace/Lucene-Solr-Tests-trunk-java7/solr/build/solr-core/te= st/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty1-136739= 3194339/solr.xml [junit4:junit4] 1> INFO - 2013-05-01 07:26:34.568; org.apache.solr.core.= CoreContainer; New CoreContainer 1507997566 [junit4:junit4] 1> INFO - 2013-05-01 07:26:34.569; org.apache.solr.core.= CoreContainer; Loading CoreContainer using Solr Home: '/usr/home/hudson/hud= son-slave/workspace/Lucene-Solr-Tests-trunk-java7/solr/build/solr-core/test= /J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty1-13673931= 94339/' [junit4:junit4] 1> INFO - 2013-05-01 07:26:34.570; org.apache.solr.core.= SolrResourceLoader; new SolrResourceLoader for directory: '/usr/home/hudson= /hudson-slave/workspace/Lucene-Solr-Tests-trunk-java7/solr/build/solr-core/= test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty1-1367= 393194339/' [junit4:junit4] 1> INFO - 2013-05-01 07:26:34.679; org.apache.solr.core.= SolrCoreDiscoverer; Looking for cores in /usr/home/hudson/hudson-slave/work= space/Lucene-Solr-Tests-trunk-java7/solr/build/solr-core/test/J1/org.apache= .solr.cloud.CollectionsAPIDistributedZkTest-jetty1-1367393194339 [junit4:junit4] 1> INFO - 2013-05-01 07:26:34.681; org.apache.solr.core.= SolrCoreDiscoverer; Discovered properties file /usr/home/hudson/hudson-slav= e/workspace/Lucene-Solr-Tests-trunk-java7/solr/build/solr-core/test/J1/./or= g.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty1-1367393194339/co= nf/core.properties, adding to cores [junit4:junit4] 1> INFO - 2013-05-01 07:26:34.686; org.apache.solr.core.= SolrCoreDiscoverer; Looking for cores in /usr/home/hudson/hudson-slave/work= space/Lucene-Solr-Tests-trunk-java7/solr/build/solr-core/test/J1/org.apache= .solr.cloud.CollectionsAPIDistributedZkTest-jetty1-1367393194339/collection= 1 [junit4:junit4] 1> INFO - 2013-05-01 07:26:34.687; org.apache.solr.core.= SolrCoreDiscoverer; Looking for cores in /usr/home/hudson/hudson-slave/work= space/Lucene-Solr-Tests-trunk-java7/solr/build/solr-core/test/J1/org.apache= .solr.cloud.CollectionsAPIDistributedZkTest-jetty1-1367393194339/collection= 1/lib [junit4:junit4] 1> INFO - 2013-05-01 07:26:34.689; org.apache.solr.core.= SolrCoreDiscoverer; Looking for cores in /usr/home/hudson/hudson-slave/work= space/Lucene-Solr-Tests-trunk-java7/solr/build/solr-core/test/J1/org.apache= .solr.cloud.CollectionsAPIDistributedZkTest-jetty1-1367393194339/collection= 1/lib/classes [junit4:junit4] 1> INFO - 2013-05-01 07:26:34.690; org.apache.solr.core.= SolrCoreDiscoverer; Looking for cores in /usr/home/hudson/hudson-slave/work= space/Lucene-Solr-Tests-trunk-java7/solr/build/solr-core/test/J1/org.apache= .solr.cloud.CollectionsAPIDistributedZkTest-jetty1-1367393194339/collection= 1/conf [junit4:junit4] 1> INFO - 2013-05-01 07:26:34.725; org.apache.solr.core.= SolrCoreDiscoverer; Looking for cores in /usr/home/hudson/hudson-slave/work= space/Lucene-Solr-Tests-trunk-java7/solr/build/solr-core/test/J1/org.apache= .solr.cloud.CollectionsAPIDistributedZkTest-jetty1-1367393194339/collection= 1/conf/xslt [junit4:junit4] 1> INFO - 2013-05-01 07:26:34.842; org.apache.solr.handl= er.component.HttpShardHandlerFactory; Setting socketTimeout to: 0 [junit4:junit4] 1> INFO - 2013-05-01 07:26:34.843; org.apache.solr.handl= er.component.HttpShardHandlerFactory; Setting urlScheme to: http:// [junit4:junit4] 1> INFO - 2013-05-01 07:26:34.843; org.apache.solr.handl= er.component.HttpShardHandlerFactory; Setting connTimeout to: 0 [junit4:junit4] 1> INFO - 2013-05-01 07:26:34.844; org.apache.solr.handl= er.component.HttpShardHandlerFactory; Setting maxConnectionsPerHost to: 20 [junit4:junit4] 1> INFO - 2013-05-01 07:26:34.844; org.apache.solr.handl= er.component.HttpShardHandlerFactory; Setting corePoolSize to: 0 [junit4:junit4] 1> INFO - 2013-05-01 07:26:34.845; org.apache.solr.handl= er.component.HttpShardHandlerFactory; Setting maximumPoolSize to: 214748364= 7 [junit4:junit4] 1> INFO - 2013-05-01 07:26:34.846; org.apache.solr.handl= er.component.HttpShardHandlerFactory; Setting maxThreadIdleTime to: 5 [junit4:junit4] 1> INFO - 2013-05-01 07:26:34.846; org.apache.solr.handl= er.component.HttpShardHandlerFactory; Setting sizeOfQueue to: -1 [junit4:junit4] 1> INFO - 2013-05-01 07:26:34.847; org.apache.solr.handl= er.component.HttpShardHandlerFactory; Setting fairnessPolicy to: false [junit4:junit4] 1> INFO - 2013-05-01 07:26:34.847; org.apache.solr.clien= t.solrj.impl.HttpClientUtil; Creating new http client, config:maxConnection= sPerHost=3D20&maxConnections=3D10000&socketTimeout=3D0&connTimeout=3D0&retr= y=3Dfalse [junit4:junit4] 1> INFO - 2013-05-01 07:26:34.862; org.apache.solr.core.= CoreContainer; Registering Log Listener [junit4:junit4] 1> INFO - 2013-05-01 07:26:34.863; org.apache.solr.core.= ZkContainer; Zookeeper client=3D127.0.0.1:33673/solr [junit4:junit4] 1> INFO - 2013-05-01 07:26:34.863; org.apache.solr.cloud= .ZkController; zkHost includes chroot [junit4:junit4] 1> INFO - 2013-05-01 07:26:34.864; org.apache.solr.commo= n.cloud.ConnectionManager; Waiting for client to connect to ZooKeeper [junit4:junit4] 1> INFO - 2013-05-01 07:26:34.867; org.apache.solr.commo= n.cloud.ConnectionManager; Watcher org.apache.solr.common.cloud.ConnectionM= anager@2efe0b17 name:ZooKeeperConnection Watcher:127.0.0.1:33673 got event = WatchedEvent state:SyncConnected type:None path:null path:null type:None [junit4:junit4] 1> INFO - 2013-05-01 07:26:34.868; org.apache.solr.commo= n.cloud.ConnectionManager; Client is connected to ZooKeeper [junit4:junit4] 1> INFO - 2013-05-01 07:26:34.872; 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-05-01 07:26:34.883; org.apache.solr.commo= n.cloud.ConnectionManager; Waiting for client to connect to ZooKeeper [junit4:junit4] 1> INFO - 2013-05-01 07:26:34.885; org.apache.solr.commo= n.cloud.ConnectionManager; Watcher org.apache.solr.common.cloud.ConnectionM= anager@5b165eb9 name:ZooKeeperConnection Watcher:127.0.0.1:33673/solr got e= vent WatchedEvent state:SyncConnected type:None path:null path:null type:No= ne [junit4:junit4] 1> INFO - 2013-05-01 07:26:34.885; org.apache.solr.commo= n.cloud.ConnectionManager; Client is connected to ZooKeeper [junit4:junit4] 1> INFO - 2013-05-01 07:26:34.943; org.apache.solr.commo= n.cloud.ZkStateReader; Updating cluster state from ZooKeeper...=20 [junit4:junit4] 1> INFO - 2013-05-01 07:26:35.947; org.apache.solr.cloud= .ZkController; Register node as live in ZooKeeper:/live_nodes/127.0.0.1:525= 50_wyc%2Frw [junit4:junit4] 1> INFO - 2013-05-01 07:26:35.953; org.apache.solr.commo= n.cloud.SolrZkClient; makePath: /live_nodes/127.0.0.1:52550_wyc%2Frw [junit4:junit4] 1> INFO - 2013-05-01 07:26:35.957; org.apache.solr.commo= n.cloud.ZkStateReader$3; Updating live nodes... (2) [junit4:junit4] 1> INFO - 2013-05-01 07:26:35.957; org.apache.solr.commo= n.cloud.ZkStateReader$3; Updating live nodes... (2) [junit4:junit4] 1> INFO - 2013-05-01 07:26:35.957; org.apache.solr.commo= n.cloud.ZkStateReader$3; Updating live nodes... (2) [junit4:junit4] 1> INFO - 2013-05-01 07:26:35.972; org.apache.solr.servl= et.SolrDispatchFilter; user.dir=3D/usr/home/hudson/hudson-slave/workspace/L= ucene-Solr-Tests-trunk-java7/solr/build/solr-core/test/J1 [junit4:junit4] 1> INFO - 2013-05-01 07:26:35.973; org.apache.solr.servl= et.SolrDispatchFilter; SolrDispatchFilter.init() done [junit4:junit4] 1> INFO - 2013-05-01 07:26:35.973; 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-05-01 07:26:36.200; org.eclipse.jetty.ser= ver.Server; jetty-8.1.10.v20130312 [junit4:junit4] 1> INFO - 2013-05-01 07:26:36.203; org.eclipse.jetty.ser= ver.AbstractConnector; Started SocketConnector@127.0.0.1:22540 [junit4:junit4] 1> INFO - 2013-05-01 07:26:36.204; org.apache.solr.servl= et.SolrDispatchFilter; SolrDispatchFilter.init() [junit4:junit4] 1> INFO - 2013-05-01 07:26:36.204; org.apache.solr.core.= SolrResourceLoader; JNDI not configured for solr (NoInitialContextEx) [junit4:junit4] 1> INFO - 2013-05-01 07:26:36.205; org.apache.solr.core.= SolrResourceLoader; using system property solr.solr.home: /usr/home/hudson/= hudson-slave/workspace/Lucene-Solr-Tests-trunk-java7/solr/build/solr-core/t= est/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty2-13673= 93195983 [junit4:junit4] 1> INFO - 2013-05-01 07:26:36.205; org.apache.solr.core.= CoreContainer$Initializer; looking for solr config file: /usr/home/hudson/h= udson-slave/workspace/Lucene-Solr-Tests-trunk-java7/solr/build/solr-core/te= st/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty2-136739= 3195983/solr.xml [junit4:junit4] 1> INFO - 2013-05-01 07:26:36.206; org.apache.solr.core.= CoreContainer; New CoreContainer 1928927276 [junit4:junit4] 1> INFO - 2013-05-01 07:26:36.207; org.apache.solr.core.= CoreContainer; Loading CoreContainer using Solr Home: '/usr/home/hudson/hud= son-slave/workspace/Lucene-Solr-Tests-trunk-java7/solr/build/solr-core/test= /J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty2-13673931= 95983/' [junit4:junit4] 1> INFO - 2013-05-01 07:26:36.207; org.apache.solr.core.= SolrResourceLoader; new SolrResourceLoader for directory: '/usr/home/hudson= /hudson-slave/workspace/Lucene-Solr-Tests-trunk-java7/solr/build/solr-core/= test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty2-1367= 393195983/' [junit4:junit4] 1> INFO - 2013-05-01 07:26:36.307; org.apache.solr.core.= SolrCoreDiscoverer; Looking for cores in /usr/home/hudson/hudson-slave/work= space/Lucene-Solr-Tests-trunk-java7/solr/build/solr-core/test/J1/org.apache= .solr.cloud.CollectionsAPIDistributedZkTest-jetty2-1367393195983 [junit4:junit4] 1> INFO - 2013-05-01 07:26:36.312; org.apache.solr.core.= SolrCoreDiscoverer; Looking for cores in /usr/home/hudson/hudson-slave/work= space/Lucene-Solr-Tests-trunk-java7/solr/build/solr-core/test/J1/org.apache= .solr.cloud.CollectionsAPIDistributedZkTest-jetty2-1367393195983/collection= 1 [junit4:junit4] 1> INFO - 2013-05-01 07:26:36.314; org.apache.solr.core.= SolrCoreDiscoverer; Looking for cores in /usr/home/hudson/hudson-slave/work= space/Lucene-Solr-Tests-trunk-java7/solr/build/solr-core/test/J1/org.apache= .solr.cloud.CollectionsAPIDistributedZkTest-jetty2-1367393195983/collection= 1/conf [junit4:junit4] 1> INFO - 2013-05-01 07:26:36.403; org.apache.solr.core.= SolrCoreDiscoverer; Looking for cores in /usr/home/hudson/hudson-slave/work= space/Lucene-Solr-Tests-trunk-java7/solr/build/solr-core/test/J1/org.apache= .solr.cloud.CollectionsAPIDistributedZkTest-jetty2-1367393195983/collection= 1/conf/xslt [junit4:junit4] 1> INFO - 2013-05-01 07:26:36.456; org.apache.solr.core.= SolrCoreDiscoverer; Looking for cores in /usr/home/hudson/hudson-slave/work= space/Lucene-Solr-Tests-trunk-java7/solr/build/solr-core/test/J1/org.apache= .solr.cloud.CollectionsAPIDistributedZkTest-jetty2-1367393195983/collection= 1/lib [junit4:junit4] 1> INFO - 2013-05-01 07:26:36.458; org.apache.solr.core.= SolrCoreDiscoverer; Looking for cores in /usr/home/hudson/hudson-slave/work= space/Lucene-Solr-Tests-trunk-java7/solr/build/solr-core/test/J1/org.apache= .solr.cloud.CollectionsAPIDistributedZkTest-jetty2-1367393195983/collection= 1/lib/classes [junit4:junit4] 1> INFO - 2013-05-01 07:26:36.462; org.apache.solr.core.= SolrCoreDiscoverer; Discovered properties file /usr/home/hudson/hudson-slav= e/workspace/Lucene-Solr-Tests-trunk-java7/solr/build/solr-core/test/J1/./or= g.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty2-1367393195983/co= nf/core.properties, adding to cores [junit4:junit4] 1> INFO - 2013-05-01 07:26:36.468; org.apache.solr.handl= er.component.HttpShardHandlerFactory; Setting socketTimeout to: 0 [junit4:junit4] 1> INFO - 2013-05-01 07:26:36.468; org.apache.solr.handl= er.component.HttpShardHandlerFactory; Setting urlScheme to: http:// [junit4:junit4] 1> INFO - 2013-05-01 07:26:36.469; org.apache.solr.handl= er.component.HttpShardHandlerFactory; Setting connTimeout to: 0 [junit4:junit4] 1> INFO - 2013-05-01 07:26:36.469; org.apache.solr.handl= er.component.HttpShardHandlerFactory; Setting maxConnectionsPerHost to: 20 [junit4:junit4] 1> INFO - 2013-05-01 07:26:36.470; org.apache.solr.handl= er.component.HttpShardHandlerFactory; Setting corePoolSize to: 0 [junit4:junit4] 1> INFO - 2013-05-01 07:26:36.470; org.apache.solr.handl= er.component.HttpShardHandlerFactory; Setting maximumPoolSize to: 214748364= 7 [junit4:junit4] 1> INFO - 2013-05-01 07:26:36.471; org.apache.solr.handl= er.component.HttpShardHandlerFactory; Setting maxThreadIdleTime to: 5 [junit4:junit4] 1> INFO - 2013-05-01 07:26:36.472; org.apache.solr.handl= er.component.HttpShardHandlerFactory; Setting sizeOfQueue to: -1 [junit4:junit4] 1> INFO - 2013-05-01 07:26:36.472; org.apache.solr.handl= er.component.HttpShardHandlerFactory; Setting fairnessPolicy to: false [junit4:junit4] 1> INFO - 2013-05-01 07:26:36.473; org.apache.solr.clien= t.solrj.impl.HttpClientUtil; Creating new http client, config:maxConnection= sPerHost=3D20&maxConnections=3D10000&socketTimeout=3D0&connTimeout=3D0&retr= y=3Dfalse [junit4:junit4] 1> INFO - 2013-05-01 07:26:36.487; org.apache.solr.core.= CoreContainer; Registering Log Listener [junit4:junit4] 1> INFO - 2013-05-01 07:26:36.487; org.apache.solr.core.= ZkContainer; Zookeeper client=3D127.0.0.1:33673/solr [junit4:junit4] 1> INFO - 2013-05-01 07:26:36.488; org.apache.solr.cloud= .ZkController; zkHost includes chroot [junit4:junit4] 1> INFO - 2013-05-01 07:26:36.489; org.apache.solr.commo= n.cloud.ConnectionManager; Waiting for client to connect to ZooKeeper [junit4:junit4] 1> INFO - 2013-05-01 07:26:36.492; org.apache.solr.commo= n.cloud.ConnectionManager; Watcher org.apache.solr.common.cloud.ConnectionM= anager@2216fce9 name:ZooKeeperConnection Watcher:127.0.0.1:33673 got event = WatchedEvent state:SyncConnected type:None path:null path:null type:None [junit4:junit4] 1> INFO - 2013-05-01 07:26:36.493; org.apache.solr.commo= n.cloud.ConnectionManager; Client is connected to ZooKeeper [junit4:junit4] 1> INFO - 2013-05-01 07:26:36.496; 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-05-01 07:26:36.506; org.apache.solr.commo= n.cloud.ConnectionManager; Waiting for client to connect to ZooKeeper [junit4:junit4] 1> INFO - 2013-05-01 07:26:36.508; org.apache.solr.commo= n.cloud.ConnectionManager; Watcher org.apache.solr.common.cloud.ConnectionM= anager@7859e38a name:ZooKeeperConnection Watcher:127.0.0.1:33673/solr got e= vent WatchedEvent state:SyncConnected type:None path:null path:null type:No= ne [junit4:junit4] 1> INFO - 2013-05-01 07:26:36.509; org.apache.solr.commo= n.cloud.ConnectionManager; Client is connected to ZooKeeper [junit4:junit4] 1> INFO - 2013-05-01 07:26:36.521; org.apache.solr.commo= n.cloud.ZkStateReader; Updating cluster state from ZooKeeper...=20 [junit4:junit4] 1> INFO - 2013-05-01 07:26:37.525; org.apache.solr.cloud= .ZkController; Register node as live in ZooKeeper:/live_nodes/127.0.0.1:225= 40_wyc%2Frw [junit4:junit4] 1> INFO - 2013-05-01 07:26:37.554; org.apache.solr.commo= n.cloud.SolrZkClient; makePath: /live_nodes/127.0.0.1:22540_wyc%2Frw [junit4:junit4] 1> INFO - 2013-05-01 07:26:37.558; org.apache.solr.commo= n.cloud.ZkStateReader$3; Updating live nodes... (3) [junit4:junit4] 1> INFO - 2013-05-01 07:26:37.558; org.apache.solr.commo= n.cloud.ZkStateReader$3; Updating live nodes... (3) [junit4:junit4] 1> INFO - 2013-05-01 07:26:37.558; org.apache.solr.commo= n.cloud.ZkStateReader$3; Updating live nodes... (3) [junit4:junit4] 1> INFO - 2013-05-01 07:26:37.558; org.apache.solr.commo= n.cloud.ZkStateReader$3; Updating live nodes... (3) [junit4:junit4] 1> INFO - 2013-05-01 07:26:37.565; org.apache.solr.servl= et.SolrDispatchFilter; user.dir=3D/usr/home/hudson/hudson-slave/workspace/L= ucene-Solr-Tests-trunk-java7/solr/build/solr-core/test/J1 [junit4:junit4] 1> INFO - 2013-05-01 07:26:37.565; org.apache.solr.servl= et.SolrDispatchFilter; SolrDispatchFilter.init() done [junit4:junit4] 1> INFO - 2013-05-01 07:26:37.566; 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-05-01 07:26:37.793; org.eclipse.jetty.ser= ver.Server; jetty-8.1.10.v20130312 [junit4:junit4] 1> INFO - 2013-05-01 07:26:37.796; org.eclipse.jetty.ser= ver.AbstractConnector; Started SocketConnector@127.0.0.1:62715 [junit4:junit4] 1> INFO - 2013-05-01 07:26:37.797; org.apache.solr.servl= et.SolrDispatchFilter; SolrDispatchFilter.init() [junit4:junit4] 1> INFO - 2013-05-01 07:26:37.797; org.apache.solr.core.= SolrResourceLoader; JNDI not configured for solr (NoInitialContextEx) [junit4:junit4] 1> INFO - 2013-05-01 07:26:37.798; org.apache.solr.core.= SolrResourceLoader; using system property solr.solr.home: /usr/home/hudson/= hudson-slave/workspace/Lucene-Solr-Tests-trunk-java7/solr/build/solr-core/t= est/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty3-13673= 93197576 [junit4:junit4] 1> INFO - 2013-05-01 07:26:37.798; org.apache.solr.core.= CoreContainer$Initializer; looking for solr config file: /usr/home/hudson/h= udson-slave/workspace/Lucene-Solr-Tests-trunk-java7/solr/build/solr-core/te= st/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty3-136739= 3197576/solr.xml [junit4:junit4] 1> INFO - 2013-05-01 07:26:37.799; org.apache.solr.core.= CoreContainer; New CoreContainer 1666002700 [junit4:junit4] 1> INFO - 2013-05-01 07:26:37.800; org.apache.solr.core.= CoreContainer; Loading CoreContainer using Solr Home: '/usr/home/hudson/hud= son-slave/workspace/Lucene-Solr-Tests-trunk-java7/solr/build/solr-core/test= /J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty3-13673931= 97576/' [junit4:junit4] 1> INFO - 2013-05-01 07:26:37.800; org.apache.solr.core.= SolrResourceLoader; new SolrResourceLoader for directory: '/usr/home/hudson= /hudson-slave/workspace/Lucene-Solr-Tests-trunk-java7/solr/build/solr-core/= test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty3-1367= 393197576/' [junit4:junit4] 1> INFO - 2013-05-01 07:26:37.901; org.apache.solr.core.= SolrCoreDiscoverer; Looking for cores in /usr/home/hudson/hudson-slave/work= space/Lucene-Solr-Tests-trunk-java7/solr/build/solr-core/test/J1/org.apache= .solr.cloud.CollectionsAPIDistributedZkTest-jetty3-1367393197576 [junit4:junit4] 1> INFO - 2013-05-01 07:26:37.903; org.apache.solr.core.= SolrCoreDiscoverer; Discovered properties file /usr/home/hudson/hudson-slav= e/workspace/Lucene-Solr-Tests-trunk-java7/solr/build/solr-core/test/J1/./or= g.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty3-1367393197576/co= nf/core.properties, adding to cores [junit4:junit4] 1> INFO - 2013-05-01 07:26:37.908; org.apache.solr.core.= SolrCoreDiscoverer; Looking for cores in /usr/home/hudson/hudson-slave/work= space/Lucene-Solr-Tests-trunk-java7/solr/build/solr-core/test/J1/org.apache= .solr.cloud.CollectionsAPIDistributedZkTest-jetty3-1367393197576/collection= 1 [junit4:junit4] 1> INFO - 2013-05-01 07:26:37.909; org.apache.solr.core.= SolrCoreDiscoverer; Looking for cores in /usr/home/hudson/hudson-slave/work= space/Lucene-Solr-Tests-trunk-java7/solr/build/solr-core/test/J1/org.apache= .solr.cloud.CollectionsAPIDistributedZkTest-jetty3-1367393197576/collection= 1/lib [junit4:junit4] 1> INFO - 2013-05-01 07:26:37.910; org.apache.solr.core.= SolrCoreDiscoverer; Looking for cores in /usr/home/hudson/hudson-slave/work= space/Lucene-Solr-Tests-trunk-java7/solr/build/solr-core/test/J1/org.apache= .solr.cloud.CollectionsAPIDistributedZkTest-jetty3-1367393197576/collection= 1/lib/classes [junit4:junit4] 1> INFO - 2013-05-01 07:26:37.912; org.apache.solr.core.= SolrCoreDiscoverer; Looking for cores in /usr/home/hudson/hudson-slave/work= space/Lucene-Solr-Tests-trunk-java7/solr/build/solr-core/test/J1/org.apache= .solr.cloud.CollectionsAPIDistributedZkTest-jetty3-1367393197576/collection= 1/conf [junit4:junit4] 1> INFO - 2013-05-01 07:26:37.955; org.apache.solr.core.= SolrCoreDiscoverer; Looking for cores in /usr/home/hudson/hudson-slave/work= space/Lucene-Solr-Tests-trunk-java7/solr/build/solr-core/test/J1/org.apache= .solr.cloud.CollectionsAPIDistributedZkTest-jetty3-1367393197576/collection= 1/conf/xslt [junit4:junit4] 1> INFO - 2013-05-01 07:26:38.059; org.apache.solr.handl= er.component.HttpShardHandlerFactory; Setting socketTimeout to: 0 [junit4:junit4] 1> INFO - 2013-05-01 07:26:38.060; org.apache.solr.handl= er.component.HttpShardHandlerFactory; Setting urlScheme to: http:// [junit4:junit4] 1> INFO - 2013-05-01 07:26:38.060; org.apache.solr.handl= er.component.HttpShardHandlerFactory; Setting connTimeout to: 0 [junit4:junit4] 1> INFO - 2013-05-01 07:26:38.061; org.apache.solr.handl= er.component.HttpShardHandlerFactory; Setting maxConnectionsPerHost to: 20 [junit4:junit4] 1> INFO - 2013-05-01 07:26:38.061; org.apache.solr.handl= er.component.HttpShardHandlerFactory; Setting corePoolSize to: 0 [junit4:junit4] 1> INFO - 2013-05-01 07:26:38.062; org.apache.solr.handl= er.component.HttpShardHandlerFactory; Setting maximumPoolSize to: 214748364= 7 [junit4:junit4] 1> INFO - 2013-05-01 07:26:38.062; org.apache.solr.handl= er.component.HttpShardHandlerFactory; Setting maxThreadIdleTime to: 5 [junit4:junit4] 1> INFO - 2013-05-01 07:26:38.063; org.apache.solr.handl= er.component.HttpShardHandlerFactory; Setting sizeOfQueue to: -1 [junit4:junit4] 1> INFO - 2013-05-01 07:26:38.064; org.apache.solr.handl= er.component.HttpShardHandlerFactory; Setting fairnessPolicy to: false [junit4:junit4] 1> INFO - 2013-05-01 07:26:38.064; org.apache.solr.clien= t.solrj.impl.HttpClientUtil; Creating new http client, config:maxConnection= sPerHost=3D20&maxConnections=3D10000&socketTimeout=3D0&connTimeout=3D0&retr= y=3Dfalse [junit4:junit4] 1> INFO - 2013-05-01 07:26:38.080; org.apache.solr.core.= CoreContainer; Registering Log Listener [junit4:junit4] 1> INFO - 2013-05-01 07:26:38.081; org.apache.solr.core.= ZkContainer; Zookeeper client=3D127.0.0.1:33673/solr [junit4:junit4] 1> INFO - 2013-05-01 07:26:38.081; org.apache.solr.cloud= .ZkController; zkHost includes chroot [junit4:junit4] 1> INFO - 2013-05-01 07:26:38.083; org.apache.solr.commo= n.cloud.ConnectionManager; Waiting for client to connect to ZooKeeper [junit4:junit4] 1> INFO - 2013-05-01 07:26:38.086; org.apache.solr.commo= n.cloud.ConnectionManager; Watcher org.apache.solr.common.cloud.ConnectionM= anager@1e731484 name:ZooKeeperConnection Watcher:127.0.0.1:33673 got event = WatchedEvent state:SyncConnected type:None path:null path:null type:None [junit4:junit4] 1> INFO - 2013-05-01 07:26:38.087; org.apache.solr.commo= n.cloud.ConnectionManager; Client is connected to ZooKeeper [junit4:junit4] 1> INFO - 2013-05-01 07:26:38.089; 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-05-01 07:26:38.101; org.apache.solr.commo= n.cloud.ConnectionManager; Waiting for client to connect to ZooKeeper [junit4:junit4] 1> INFO - 2013-05-01 07:26:38.103; org.apache.solr.commo= n.cloud.ConnectionManager; Watcher org.apache.solr.common.cloud.ConnectionM= anager@35281ace name:ZooKeeperConnection Watcher:127.0.0.1:33673/solr got e= vent WatchedEvent state:SyncConnected type:None path:null path:null type:No= ne [junit4:junit4] 1> INFO - 2013-05-01 07:26:38.104; org.apache.solr.commo= n.cloud.ConnectionManager; Client is connected to ZooKeeper [junit4:junit4] 1> INFO - 2013-05-01 07:26:38.115; org.apache.solr.commo= n.cloud.ZkStateReader; Updating cluster state from ZooKeeper...=20 [junit4:junit4] 1> INFO - 2013-05-01 07:26:39.119; org.apache.solr.cloud= .ZkController; Register node as live in ZooKeeper:/live_nodes/127.0.0.1:627= 15_wyc%2Frw [junit4:junit4] 1> INFO - 2013-05-01 07:26:39.147; org.apache.solr.commo= n.cloud.SolrZkClient; makePath: /live_nodes/127.0.0.1:62715_wyc%2Frw [junit4:junit4] 1> INFO - 2013-05-01 07:26:39.151; org.apache.solr.commo= n.cloud.ZkStateReader$3; Updating live nodes... (4) [junit4:junit4] 1> INFO - 2013-05-01 07:26:39.151; org.apache.solr.commo= n.cloud.ZkStateReader$3; Updating live nodes... (4) [junit4:junit4] 1> INFO - 2013-05-01 07:26:39.151; org.apache.solr.commo= n.cloud.ZkStateReader$3; Updating live nodes... (4) [junit4:junit4] 1> INFO - 2013-05-01 07:26:39.151; org.apache.solr.commo= n.cloud.ZkStateReader$3; Updating live nodes... (4) [junit4:junit4] 1> INFO - 2013-05-01 07:26:39.151; org.apache.solr.commo= n.cloud.ZkStateReader$3; Updating live nodes... (4) [junit4:junit4] 1> INFO - 2013-05-01 07:26:39.164; org.apache.solr.servl= et.SolrDispatchFilter; user.dir=3D/usr/home/hudson/hudson-slave/workspace/L= ucene-Solr-Tests-trunk-java7/solr/build/solr-core/test/J1 [junit4:junit4] 1> INFO - 2013-05-01 07:26:39.165; org.apache.solr.servl= et.SolrDispatchFilter; SolrDispatchFilter.init() done [junit4:junit4] 1> INFO - 2013-05-01 07:26:39.165; 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-05-01 07:26:39.394; org.eclipse.jetty.ser= ver.Server; jetty-8.1.10.v20130312 [junit4:junit4] 1> INFO - 2013-05-01 07:26:39.397; org.eclipse.jetty.ser= ver.AbstractConnector; Started SocketConnector@127.0.0.1:48327 [junit4:junit4] 1> INFO - 2013-05-01 07:26:39.398; org.apache.solr.servl= et.SolrDispatchFilter; SolrDispatchFilter.init() [junit4:junit4] 1> INFO - 2013-05-01 07:26:39.398; org.apache.solr.core.= SolrResourceLoader; JNDI not configured for solr (NoInitialContextEx) [junit4:junit4] 1> INFO - 2013-05-01 07:26:39.399; org.apache.solr.core.= SolrResourceLoader; using system property solr.solr.home: /usr/home/hudson/= hudson-slave/workspace/Lucene-Solr-Tests-trunk-java7/solr/build/solr-core/t= est/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-13673= 93199177 [junit4:junit4] 1> INFO - 2013-05-01 07:26:39.399; org.apache.solr.core.= CoreContainer$Initializer; looking for solr config file: /usr/home/hudson/h= udson-slave/workspace/Lucene-Solr-Tests-trunk-java7/solr/build/solr-core/te= st/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-136739= 3199177/solr.xml [junit4:junit4] 1> INFO - 2013-05-01 07:26:39.400; org.apache.solr.core.= CoreContainer; New CoreContainer 505363862 [junit4:junit4] 1> INFO - 2013-05-01 07:26:39.401; org.apache.solr.core.= CoreContainer; Loading CoreContainer using Solr Home: '/usr/home/hudson/hud= son-slave/workspace/Lucene-Solr-Tests-trunk-java7/solr/build/solr-core/test= /J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-13673931= 99177/' [junit4:junit4] 1> INFO - 2013-05-01 07:26:39.401; org.apache.solr.core.= SolrResourceLoader; new SolrResourceLoader for directory: '/usr/home/hudson= /hudson-slave/workspace/Lucene-Solr-Tests-trunk-java7/solr/build/solr-core/= test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1367= 393199177/' [junit4:junit4] 1> INFO - 2013-05-01 07:26:39.506; org.apache.solr.core.= SolrCoreDiscoverer; Looking for cores in /usr/home/hudson/hudson-slave/work= space/Lucene-Solr-Tests-trunk-java7/solr/build/solr-core/test/J1/org.apache= .solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1367393199177 [junit4:junit4] 1> INFO - 2013-05-01 07:26:39.510; org.apache.solr.core.= SolrCoreDiscoverer; Looking for cores in /usr/home/hudson/hudson-slave/work= space/Lucene-Solr-Tests-trunk-java7/solr/build/solr-core/test/J1/org.apache= .solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1367393199177/collection= 1 [junit4:junit4] 1> INFO - 2013-05-01 07:26:39.511; org.apache.solr.core.= SolrCoreDiscoverer; Looking for cores in /usr/home/hudson/hudson-slave/work= space/Lucene-Solr-Tests-trunk-java7/solr/build/solr-core/test/J1/org.apache= .solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1367393199177/collection= 1/conf [junit4:junit4] 1> INFO - 2013-05-01 07:26:39.534; org.apache.solr.core.= SolrCoreDiscoverer; Looking for cores in /usr/home/hudson/hudson-slave/work= space/Lucene-Solr-Tests-trunk-java7/solr/build/solr-core/test/J1/org.apache= .solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1367393199177/collection= 1/conf/xslt [junit4:junit4] 1> INFO - 2013-05-01 07:26:39.661; org.apache.solr.core.= SolrCoreDiscoverer; Looking for cores in /usr/home/hudson/hudson-slave/work= space/Lucene-Solr-Tests-trunk-java7/solr/build/solr-core/test/J1/org.apache= .solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1367393199177/collection= 1/lib [junit4:junit4] 1> INFO - 2013-05-01 07:26:39.664; org.apache.solr.core.= SolrCoreDiscoverer; Looking for cores in /usr/home/hudson/hudson-slave/work= space/Lucene-Solr-Tests-trunk-java7/solr/build/solr-core/test/J1/org.apache= .solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1367393199177/collection= 1/lib/classes [junit4:junit4] 1> INFO - 2013-05-01 07:26:39.668; org.apache.solr.core.= SolrCoreDiscoverer; Discovered properties file /usr/home/hudson/hudson-slav= e/workspace/Lucene-Solr-Tests-trunk-java7/solr/build/solr-core/test/J1/./or= g.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1367393199177/co= nf/core.properties, adding to cores [junit4:junit4] 1> INFO - 2013-05-01 07:26:39.675; org.apache.solr.handl= er.component.HttpShardHandlerFactory; Setting socketTimeout to: 0 [junit4:junit4] 1> INFO - 2013-05-01 07:26:39.675; org.apache.solr.handl= er.component.HttpShardHandlerFactory; Setting urlScheme to: http:// [junit4:junit4] 1> INFO - 2013-05-01 07:26:39.676; org.apache.solr.handl= er.component.HttpShardHandlerFactory; Setting connTimeout to: 0 [junit4:junit4] 1> INFO - 2013-05-01 07:26:39.677; org.apache.solr.handl= er.component.HttpShardHandlerFactory; Setting maxConnectionsPerHost to: 20 [junit4:junit4] 1> INFO - 2013-05-01 07:26:39.677; org.apache.solr.handl= er.component.HttpShardHandlerFactory; Setting corePoolSize to: 0 [junit4:junit4] 1> INFO - 2013-05-01 07:26:39.678; org.apache.solr.handl= er.component.HttpShardHandlerFactory; Setting maximumPoolSize to: 214748364= 7 [junit4:junit4] 1> INFO - 2013-05-01 07:26:39.678; org.apache.solr.handl= er.component.HttpShardHandlerFactory; Setting maxThreadIdleTime to: 5 [junit4:junit4] 1> INFO - 2013-05-01 07:26:39.679; org.apache.solr.handl= er.component.HttpShardHandlerFactory; Setting sizeOfQueue to: -1 [junit4:junit4] 1> INFO - 2013-05-01 07:26:39.680; org.apache.solr.handl= er.component.HttpShardHandlerFactory; Setting fairnessPolicy to: false [junit4:junit4] 1> INFO - 2013-05-01 07:26:39.680; org.apache.solr.clien= t.solrj.impl.HttpClientUtil; Creating new http client, config:maxConnection= sPerHost=3D20&maxConnections=3D10000&socketTimeout=3D0&connTimeout=3D0&retr= y=3Dfalse [junit4:junit4] 1> INFO - 2013-05-01 07:26:39.696; org.apache.solr.core.= CoreContainer; Registering Log Listener [junit4:junit4] 1> INFO - 2013-05-01 07:26:39.697; org.apache.solr.core.= ZkContainer; Zookeeper client=3D127.0.0.1:33673/solr [junit4:junit4] 1> INFO - 2013-05-01 07:26:39.697; org.apache.solr.cloud= .ZkController; zkHost includes chroot [junit4:junit4] 1> INFO - 2013-05-01 07:26:39.698; org.apache.solr.commo= n.cloud.ConnectionManager; Waiting for client to connect to ZooKeeper [junit4:junit4] 1> INFO - 2013-05-01 07:26:39.721; org.apache.solr.commo= n.cloud.ConnectionManager; Watcher org.apache.solr.common.cloud.ConnectionM= anager@292377c2 name:ZooKeeperConnection Watcher:127.0.0.1:33673 got event = WatchedEvent state:SyncConnected type:None path:null path:null type:None [junit4:junit4] 1> INFO - 2013-05-01 07:26:39.722; org.apache.solr.commo= n.cloud.ConnectionManager; Client is connected to ZooKeeper [junit4:junit4] 1> INFO - 2013-05-01 07:26:39.799; 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-05-01 07:26:39.811; org.apache.solr.commo= n.cloud.ConnectionManager; Waiting for client to connect to ZooKeeper [junit4:junit4] 1> INFO - 2013-05-01 07:26:39.827; org.apache.solr.commo= n.cloud.ConnectionManager; Watcher org.apache.solr.common.cloud.ConnectionM= anager@49b56a0f name:ZooKeeperConnection Watcher:127.0.0.1:33673/solr got e= vent WatchedEvent state:SyncConnected type:None path:null path:null type:No= ne [junit4:junit4] 1> INFO - 2013-05-01 07:26:39.828; org.apache.solr.commo= n.cloud.ConnectionManager; Client is connected to ZooKeeper [junit4:junit4] 1> INFO - 2013-05-01 07:26:39.932; org.apache.solr.commo= n.cloud.ZkStateReader; Updating cluster state from ZooKeeper...=20 [junit4:junit4] 1> INFO - 2013-05-01 07:26:40.936; org.apache.solr.cloud= .ZkController; Register node as live in ZooKeeper:/live_nodes/127.0.0.1:483= 27_wyc%2Frw [junit4:junit4] 1> INFO - 2013-05-01 07:26:40.939; org.apache.solr.commo= n.cloud.SolrZkClient; makePath: /live_nodes/127.0.0.1:48327_wyc%2Frw [junit4:junit4] 1> INFO - 2013-05-01 07:26:40.943; org.apache.solr.commo= n.cloud.ZkStateReader$3; Updating live nodes... (5) [junit4:junit4] 1> INFO - 2013-05-01 07:26:40.944; org.apache.solr.commo= n.cloud.ZkStateReader$3; Updating live nodes... (5) [junit4:junit4] 1> INFO - 2013-05-01 07:26:40.944; org.apache.solr.commo= n.cloud.ZkStateReader$3; Updating live nodes... (5) [junit4:junit4] 1> INFO - 2013-05-01 07:26:40.944; org.apache.solr.commo= n.cloud.ZkStateReader$3; Updating live nodes... (5) [junit4:junit4] 1> INFO - 2013-05-01 07:26:40.944; org.apache.solr.commo= n.cloud.ZkStateReader$3; Updating live nodes... (5) [junit4:junit4] 1> INFO - 2013-05-01 07:26:40.943; org.apache.solr.commo= n.cloud.ZkStateReader$3; Updating live nodes... (5) [junit4:junit4] 1> INFO - 2013-05-01 07:26:40.954; org.apache.solr.servl= et.SolrDispatchFilter; user.dir=3D/usr/home/hudson/hudson-slave/workspace/L= ucene-Solr-Tests-trunk-java7/solr/build/solr-core/test/J1 [junit4:junit4] 1> INFO - 2013-05-01 07:26:40.955; org.apache.solr.servl= et.SolrDispatchFilter; SolrDispatchFilter.init() done [junit4:junit4] 1> INFO - 2013-05-01 07:26:40.956; 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-05-01 07:26:40.969; 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-05-01 07:26:40.984; 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-05-01 07:26:40.994; org.apache.solr.cloud= .DistributedQueue$LatchChildWatcher; Watcher fired on path: /overseer/colle= ction-queue-work state: SyncConnected type NodeChildrenChanged [junit4:junit4] 1> INFO - 2013-05-01 07:26:41.003; 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-05-01 07:26:41.003; 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:62715_wyc%2Frw [junit4:junit4] 1> INFO - 2013-05-01 07:26:41.004; 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:33541_wyc%2Frw [junit4:junit4] 1> INFO - 2013-05-01 07:26:41.004; 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:48327_wyc%2Frw [junit4:junit4] 1> INFO - 2013-05-01 07:26:41.005; 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:22540_wyc%2Frw [junit4:junit4] 1> INFO - 2013-05-01 07:26:41.007; org.apache.solr.core.= CoreContainer; Creating SolrCore 'nodes_used_collection_shard1_replica1' us= ing instanceDir: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-= trunk-java7/solr/build/solr-core/test/J1/./org.apache.solr.cloud.Collection= sAPIDistributedZkTest-jetty3-1367393197576/nodes_used_collection_shard1_rep= lica1 [junit4:junit4] 1> INFO - 2013-05-01 07:26:41.007; org.apache.solr.core.= CoreContainer; Creating SolrCore 'nodes_used_collection_shard2_replica1' us= ing instanceDir: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-= trunk-java7/solr/build/solr-core/test/J1/./org.apache.solr.cloud.Collection= sAPIDistributedZkTest-jetty4-1367393199177/nodes_used_collection_shard2_rep= lica1 [junit4:junit4] 1> INFO - 2013-05-01 07:26:41.008; org.apache.solr.cloud= .ZkController; Check for collection zkNode:nodes_used_collection [junit4:junit4] 1> INFO - 2013-05-01 07:26:41.007; org.apache.solr.core.= CoreContainer; Creating SolrCore 'nodes_used_collection_shard1_replica2' us= ing instanceDir: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-= trunk-java7/solr/build/solr-core/test/J1/./org.apache.solr.cloud.Collection= sAPIDistributedZkTest-controljetty-1367393193679/nodes_used_collection_shar= d1_replica2 [junit4:junit4] 1> INFO - 2013-05-01 07:26:41.008; org.apache.solr.core.= CoreContainer; Creating SolrCore 'nodes_used_collection_shard2_replica2' us= ing instanceDir: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-= trunk-java7/solr/build/solr-core/test/J1/./org.apache.solr.cloud.Collection= sAPIDistributedZkTest-jetty2-1367393195983/nodes_used_collection_shard2_rep= lica2 [junit4:junit4] 1> INFO - 2013-05-01 07:26:41.007; org.apache.solr.cloud= .ZkController; Check for collection zkNode:nodes_used_collection [junit4:junit4] 1> INFO - 2013-05-01 07:26:41.009; org.apache.solr.cloud= .ZkController; Check for collection zkNode:nodes_used_collection [junit4:junit4] 1> INFO - 2013-05-01 07:26:41.009; org.apache.solr.cloud= .ZkController; Creating collection in ZooKeeper:nodes_used_collection [junit4:junit4] 1> INFO - 2013-05-01 07:26:41.009; org.apache.solr.cloud= .ZkController; Check for collection zkNode:nodes_used_collection [junit4:junit4] 1> INFO - 2013-05-01 07:26:41.010; org.apache.solr.cloud= .ZkController; Creating collection in ZooKeeper:nodes_used_collection [junit4:junit4] 1> INFO - 2013-05-01 07:26:41.011; org.apache.solr.cloud= .ZkController; Creating collection in ZooKeeper:nodes_used_collection [junit4:junit4] 1> INFO - 2013-05-01 07:26:41.010; org.apache.solr.cloud= .ZkController; Looking for collection configName [junit4:junit4] 1> INFO - 2013-05-01 07:26:41.010; org.apache.solr.cloud= .ZkController; Creating collection in ZooKeeper:nodes_used_collection [junit4:junit4] 1> INFO - 2013-05-01 07:26:41.012; org.apache.solr.cloud= .ZkController; Looking for collection configName [junit4:junit4] 1> INFO - 2013-05-01 07:26:41.011; org.apache.solr.cloud= .ZkController; Looking for collection configName [junit4:junit4] 1> INFO - 2013-05-01 07:26:41.014; org.apache.solr.cloud= .ZkController; Only one config set found in zk - using it:conf1 [junit4:junit4] 1> INFO - 2013-05-01 07:26:41.013; org.apache.solr.cloud= .ZkController; Looking for collection configName [junit4:junit4] 1> INFO - 2013-05-01 07:26:41.014; org.apache.solr.cloud= .ZkController; Only one config set found in zk - using it:conf1 [junit4:junit4] 1> INFO - 2013-05-01 07:26:41.014; org.apache.solr.commo= n.cloud.SolrZkClient; makePath: /collections/nodes_used_collection [junit4:junit4] 1> INFO - 2013-05-01 07:26:41.015; org.apache.solr.commo= n.cloud.SolrZkClient; makePath: /collections/nodes_used_collection [junit4:junit4] 1> INFO - 2013-05-01 07:26:41.015; org.apache.solr.cloud= .ZkController; Only one config set found in zk - using it:conf1 [junit4:junit4] 1> INFO - 2013-05-01 07:26:41.015; org.apache.solr.cloud= .ZkController; Only one config set found in zk - using it:conf1 [junit4:junit4] 1> INFO - 2013-05-01 07:26:41.016; org.apache.solr.commo= n.cloud.SolrZkClient; makePath: /collections/nodes_used_collection [junit4:junit4] 1> INFO - 2013-05-01 07:26:41.017; org.apache.solr.commo= n.cloud.SolrZkClient; makePath: /collections/nodes_used_collection [junit4:junit4] 1> INFO - 2013-05-01 07:26:41.021; org.apache.solr.cloud= .ZkController; Load collection config from:/collections/nodes_used_collecti= on [junit4:junit4] 1> INFO - 2013-05-01 07:26:41.029; org.apache.solr.cloud= .ZkController; Load collection config from:/collections/nodes_used_collecti= on [junit4:junit4] 1> INFO - 2013-05-01 07:26:41.037; org.apache.solr.cloud= .ZkController; Load collection config from:/collections/nodes_used_collecti= on [junit4:junit4] 1> INFO - 2013-05-01 07:26:41.039; org.apache.solr.core.= SolrResourceLoader; new SolrResourceLoader for directory: '/usr/home/hudson= /hudson-slave/workspace/Lucene-Solr-Tests-trunk-java7/solr/build/solr-core/= test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1367= 393199177/nodes_used_collection_shard2_replica1/' [junit4:junit4] 1> INFO - 2013-05-01 07:26:41.039; org.apache.solr.cloud= .ZkController; Load collection config from:/collections/nodes_used_collecti= on [junit4:junit4] 1> INFO - 2013-05-01 07:26:41.041; org.apache.solr.core.= SolrResourceLoader; new SolrResourceLoader for directory: '/usr/home/hudson= /hudson-slave/workspace/Lucene-Solr-Tests-trunk-java7/solr/build/solr-core/= test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-controljett= y-1367393193679/nodes_used_collection_shard1_replica2/' [junit4:junit4] 1> INFO - 2013-05-01 07:26:41.041; org.apache.solr.core.= SolrResourceLoader; new SolrResourceLoader for directory: '/usr/home/hudson= /hudson-slave/workspace/Lucene-Solr-Tests-trunk-java7/solr/build/solr-core/= test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty2-1367= 393195983/nodes_used_collection_shard2_replica2/' [junit4:junit4] 1> INFO - 2013-05-01 07:26:41.042; org.apache.solr.core.= SolrResourceLoader; new SolrResourceLoader for directory: '/usr/home/hudson= /hudson-slave/workspace/Lucene-Solr-Tests-trunk-java7/solr/build/solr-core/= test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty3-1367= 393197576/nodes_used_collection_shard1_replica1/' [junit4:junit4] 1> INFO - 2013-05-01 07:26:41.135; org.apache.solr.core.= SolrConfig; Using Lucene MatchVersion: LUCENE_50 [junit4:junit4] 1> INFO - 2013-05-01 07:26:41.136; org.apache.solr.core.= SolrConfig; Using Lucene MatchVersion: LUCENE_50 [junit4:junit4] 1> INFO - 2013-05-01 07:26:41.136; org.apache.solr.core.= SolrConfig; Using Lucene MatchVersion: LUCENE_50 [junit4:junit4] 1> INFO - 2013-05-01 07:26:41.143; org.apache.solr.core.= SolrConfig; Using Lucene MatchVersion: LUCENE_50 [junit4:junit4] 1> INFO - 2013-05-01 07:26:41.214; org.apache.solr.core.= SolrConfig; Loaded SolrConfig: solrconfig.xml [junit4:junit4] 1> INFO - 2013-05-01 07:26:41.217; org.apache.solr.core.= SolrConfig; Loaded SolrConfig: solrconfig.xml [junit4:junit4] 1> INFO - 2013-05-01 07:26:41.217; org.apache.solr.core.= SolrConfig; Loaded SolrConfig: solrconfig.xml [junit4:junit4] 1> INFO - 2013-05-01 07:26:41.233; org.apache.solr.core.= SolrConfig; Loaded SolrConfig: solrconfig.xml [junit4:junit4] 1> INFO - 2013-05-01 07:26:41.316; org.apache.solr.schem= a.IndexSchema; Reading Solr Schema from schema.xml [junit4:junit4] 1> INFO - 2013-05-01 07:26:41.318; org.apache.solr.schem= a.IndexSchema; Reading Solr Schema from schema.xml [junit4:junit4] 1> INFO - 2013-05-01 07:26:41.319; org.apache.solr.schem= a.IndexSchema; Reading Solr Schema from schema.xml [junit4:junit4] 1> INFO - 2013-05-01 07:26:41.325; org.apache.solr.schem= a.IndexSchema; Schema name=3Dtest [junit4:junit4] 1> INFO - 2013-05-01 07:26:41.325; org.apache.solr.schem= a.IndexSchema; Schema name=3Dtest [junit4:junit4] 1> INFO - 2013-05-01 07:26:41.327; org.apache.solr.schem= a.IndexSchema; Schema name=3Dtest [junit4:junit4] 1> INFO - 2013-05-01 07:26:41.335; org.apache.solr.schem= a.IndexSchema; Reading Solr Schema from schema.xml [junit4:junit4] 1> INFO - 2013-05-01 07:26:41.343; org.apache.solr.schem= a.IndexSchema; Schema name=3Dtest [junit4:junit4] 1> INFO - 2013-05-01 07:26:42.110; org.apache.solr.schem= a.OpenExchangeRatesOrgProvider; Initialized with rates=3Dopen-exchange-rate= s.json, refreshInterval=3D1440. [junit4:junit4] 1> INFO - 2013-05-01 07:26:42.122; org.apache.solr.schem= a.IndexSchema; default search field in schema is text [junit4:junit4] 1> INFO - 2013-05-01 07:26:42.127; org.apache.solr.schem= a.IndexSchema; unique key field: id [junit4:junit4] 1> INFO - 2013-05-01 07:26:42.142; org.apache.solr.schem= a.FileExchangeRateProvider; Reloading exchange rates from file currency.xml [junit4:junit4] 1> INFO - 2013-05-01 07:26:42.148; org.apache.solr.schem= a.FileExchangeRateProvider; Reloading exchange rates from file currency.xml [junit4:junit4] 1> INFO - 2013-05-01 07:26:42.150; org.apache.solr.schem= a.OpenExchangeRatesOrgProvider; Initialized with rates=3Dopen-exchange-rate= s.json, refreshInterval=3D1440. [junit4:junit4] 1> INFO - 2013-05-01 07:26:42.154; org.apache.solr.schem= a.OpenExchangeRatesOrgProvider; Reloading exchange rates from open-exchange= -rates.json [junit4:junit4] 1> WARN - 2013-05-01 07:26:42.155; org.apache.solr.schem= a.OpenExchangeRatesOrgProvider$OpenExchangeRates; Unknown key IMPORTANT NOT= E [junit4:junit4] 1> WARN - 2013-05-01 07:26:42.156; org.apache.solr.schem= a.OpenExchangeRatesOrgProvider$OpenExchangeRates; Expected key, got STRING [junit4:junit4] 1> INFO - 2013-05-01 07:26:42.156; org.apache.solr.schem= a.OpenExchangeRatesOrgProvider; Reloading exchange rates from open-exchange= -rates.json [junit4:junit4] 1> WARN - 2013-05-01 07:26:42.158; org.apache.solr.schem= a.OpenExchangeRatesOrgProvider$OpenExchangeRates; Unknown key IMPORTANT NOT= E [junit4:junit4] 1> WARN - 2013-05-01 07:26:42.158; org.apache.solr.schem= a.OpenExchangeRatesOrgProvider$OpenExchangeRates; Expected key, got STRING [junit4:junit4] 1> INFO - 2013-05-01 07:26:42.159; org.apache.solr.core.= SolrCore; org.apache.solr.core.MockDirectoryFactory [junit4:junit4] 1> INFO - 2013-05-01 07:26:42.159; org.apache.solr.core.= SolrCore; [nodes_used_collection_shard2_replica2] Opening new SolrCore at /= usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-java7/solr/b= uild/solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkT= est-jetty2-1367393195983/nodes_used_collection_shard2_replica2/, dataDir=3D= /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-java7/solr/= build/solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZk= Test-jetty2-1367393195983/nodes_used_collection_shard2_replica2/data/ [junit4:junit4] 1> INFO - 2013-05-01 07:26:42.160; org.apache.solr.core.= JmxMonitoredMap; JMX monitoring is enabled. Adding Solr mbeans to JMX Serve= r: com.sun.jmx.mbeanserver.JmxMBeanServer@342371e7 [junit4:junit4] 1> INFO - 2013-05-01 07:26:42.160; org.apache.solr.schem= a.IndexSchema; default search field in schema is text [junit4:junit4] 1> INFO - 2013-05-01 07:26:42.160; org.apache.solr.core.= SolrCore; org.apache.solr.core.MockDirectoryFactory [junit4:junit4] 1> INFO - 2013-05-01 07:26:42.161; org.apache.solr.core.= CachingDirectoryFactory; return new directory for /usr/home/hudson/hudson-s= lave/workspace/Lucene-Solr-Tests-trunk-java7/solr/build/solr-core/test/J1/.= /org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty2-1367393195983= /nodes_used_collection_shard2_replica2/data [junit4:junit4] 1> INFO - 2013-05-01 07:26:42.162; org.apache.solr.core.= SolrCore; New index directory detected: old=3Dnull new=3D/usr/home/hudson/h= udson-slave/workspace/Lucene-Solr-Tests-trunk-java7/solr/build/solr-core/te= st/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty2-136739= 3195983/nodes_used_collection_shard2_replica2/data/index/ [junit4:junit4] 1> WARN - 2013-05-01 07:26:42.162; org.apache.solr.core.= SolrCore; [nodes_used_collection_shard2_replica2] Solr index directory '/us= r/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-java7/solr/bui= ld/solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTes= t-jetty2-1367393195983/nodes_used_collection_shard2_replica2/data/index' do= esn't exist. Creating new index... [junit4:junit4] 1> INFO - 2013-05-01 07:26:42.163; org.apache.solr.core.= CachingDirectoryFactory; return new directory for /usr/home/hudson/hudson-s= lave/workspace/Lucene-Solr-Tests-trunk-java7/solr/build/solr-core/test/J1/.= /org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty2-1367393195983= /nodes_used_collection_shard2_replica2/data/index [junit4:junit4] 1> INFO - 2013-05-01 07:26:42.164; org.apache.solr.schem= a.IndexSchema; unique key field: id [junit4:junit4] 1> INFO - 2013-05-01 07:26:42.167; org.apache.solr.core.= SolrDeletionPolicy; SolrDeletionPolicy.onCommit: commits: num=3D1 [junit4:junit4] 1> =09commit{dir=3DMockDirWrapper(org.apache.lucene.store= .RAMDirectory@3ccc1ba1 lockFactory=3Dorg.apache.lucene.store.NativeFSLockFa= ctory@799aea1a),segFN=3Dsegments_1,generation=3D1} [junit4:junit4] 1> INFO - 2013-05-01 07:26:42.168; org.apache.solr.core.= SolrDeletionPolicy; newest commit generation =3D 1 [junit4:junit4] 1> INFO - 2013-05-01 07:26:42.171; org.apache.solr.updat= e.processor.UpdateRequestProcessorChain; inserting DistributedUpdateProcess= orFactory into updateRequestProcessorChain "dedupe" [junit4:junit4] 1> INFO - 2013-05-01 07:26:42.172; org.apache.solr.updat= e.processor.UpdateRequestProcessorChain; inserting DistributedUpdateProcess= orFactory into updateRequestProcessorChain "stored_sig" [junit4:junit4] 1> INFO - 2013-05-01 07:26:42.173; org.apache.solr.updat= e.processor.UpdateRequestProcessorChain; inserting DistributedUpdateProcess= orFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit= " [junit4:junit4] 1> INFO - 2013-05-01 07:26:42.174; org.apache.solr.core.= RequestHandlers; created standard: solr.StandardRequestHandler [junit4:junit4] 1> INFO - 2013-05-01 07:26:42.174; org.apache.solr.core.= RequestHandlers; created /get: solr.RealTimeGetHandler [junit4:junit4] 1> INFO - 2013-05-01 07:26:42.175; org.apache.solr.core.= RequestHandlers; adding lazy requestHandler: solr.ReplicationHandler [junit4:junit4] 1> INFO - 2013-05-01 07:26:42.175; org.apache.solr.core.= RequestHandlers; created /replication: solr.ReplicationHandler [junit4:junit4] 1> INFO - 2013-05-01 07:26:42.176; org.apache.solr.core.= RequestHandlers; created /update: solr.UpdateRequestHandler [junit4:junit4] 1> INFO - 2013-05-01 07:26:42.177; org.apache.solr.core.= RequestHandlers; created /admin/: org.apache.solr.handler.admin.AdminHandle= rs [junit4:junit4] 1> INFO - 2013-05-01 07:26:42.181; org.apache.solr.schem= a.FileExchangeRateProvider; Reloading exchange rates from file currency.xml [junit4:junit4] 1> INFO - 2013-05-01 07:26:42.195; org.apache.solr.handl= er.loader.XMLLoader; xsltCacheLifetimeSeconds=3D60 [junit4:junit4] 1> INFO - 2013-05-01 07:26:42.199; org.apache.solr.searc= h.SolrIndexSearcher; Opening Searcher@5b41cc87 main [junit4:junit4] 1> INFO - 2013-05-01 07:26:42.200; org.apache.solr.updat= e.UpdateHandler; Clearing tlog files, tlogDir=3D/usr/home/hudson/hudson-sla= ve/workspace/Lucene-Solr-Tests-trunk-java7/solr/build/solr-core/test/J1/./o= rg.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty2-1367393195983/n= odes_used_collection_shard2_replica2/data/tlog [junit4:junit4] 1> INFO - 2013-05-01 07:26:42.201; org.apache.solr.updat= e.CommitTracker; Hard AutoCommit: disabled [junit4:junit4] 1> INFO - 2013-05-01 07:26:42.202; org.apache.solr.updat= e.CommitTracker; Soft AutoCommit: disabled [junit4:junit4] 1> INFO - 2013-05-01 07:26:42.204; org.apache.solr.schem= a.FileExchangeRateProvider; Reloading exchange rates from file currency.xml [junit4:junit4] 1> INFO - 2013-05-01 07:26:42.206; org.apache.solr.core.= SolrCore; [nodes_used_collection_shard2_replica2] Registered new searcher S= earcher@5b41cc87 main{StandardDirectoryReader(segments_1:1)} [junit4:junit4] 1> INFO - 2013-05-01 07:26:42.208; org.apache.solr.cloud= .ZkController; publishing core=3Dnodes_used_collection_shard2_replica2 stat= e=3Ddown [junit4:junit4] 1> INFO - 2013-05-01 07:26:42.209; org.apache.solr.schem= a.OpenExchangeRatesOrgProvider; Reloading exchange rates from open-exchange= -rates.json [junit4:junit4] 1> WARN - 2013-05-01 07:26:42.238; org.apache.solr.schem= a.OpenExchangeRatesOrgProvider$OpenExchangeRates; Unknown key IMPORTANT NOT= E [junit4:junit4] 1> WARN - 2013-05-01 07:26:42.239; org.apache.solr.schem= a.OpenExchangeRatesOrgProvider$OpenExchangeRates; Expected key, got STRING [junit4:junit4] 1> INFO - 2013-05-01 07:26:42.240; org.apache.solr.schem= a.OpenExchangeRatesOrgProvider; Reloading exchange rates from open-exchange= -rates.json [junit4:junit4] 1> WARN - 2013-05-01 07:26:42.241; org.apache.solr.schem= a.OpenExchangeRatesOrgProvider$OpenExchangeRates; Unknown key IMPORTANT NOT= E [junit4:junit4] 1> WARN - 2013-05-01 07:26:42.242; org.apache.solr.schem= a.OpenExchangeRatesOrgProvider$OpenExchangeRates; Expected key, got STRING [junit4:junit4] 1> INFO - 2013-05-01 07:26:42.242; org.apache.solr.core.= SolrCore; org.apache.solr.core.MockDirectoryFactory [junit4:junit4] 1> INFO - 2013-05-01 07:26:42.243; org.apache.solr.core.= SolrCore; [nodes_used_collection_shard2_replica1] Opening new SolrCore at /= usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-java7/solr/b= uild/solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkT= est-jetty4-1367393199177/nodes_used_collection_shard2_replica1/, dataDir=3D= /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-java7/solr/= build/solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZk= Test-jetty4-1367393199177/nodes_used_collection_shard2_replica1/data/ [junit4:junit4] 1> INFO - 2013-05-01 07:26:42.243; org.apache.solr.core.= JmxMonitoredMap; JMX monitoring is enabled. Adding Solr mbeans to JMX Serve= r: com.sun.jmx.mbeanserver.JmxMBeanServer@342371e7 [junit4:junit4] 1> INFO - 2013-05-01 07:26:42.244; org.apache.solr.core.= SolrCore; org.apache.solr.core.MockDirectoryFactory [junit4:junit4] 1> INFO - 2013-05-01 07:26:42.245; org.apache.solr.core.= CachingDirectoryFactory; return new directory for /usr/home/hudson/hudson-s= lave/workspace/Lucene-Solr-Tests-trunk-java7/solr/build/solr-core/test/J1/.= /org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1367393199177= /nodes_used_collection_shard2_replica1/data [junit4:junit4] 1> INFO - 2013-05-01 07:26:42.245; org.apache.solr.core.= SolrCore; New index directory detected: old=3Dnull new=3D/usr/home/hudson/h= udson-slave/workspace/Lucene-Solr-Tests-trunk-java7/solr/build/solr-core/te= st/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-136739= 3199177/nodes_used_collection_shard2_replica1/data/index/ [junit4:junit4] 1> WARN - 2013-05-01 07:26:42.246; org.apache.solr.core.= SolrCore; [nodes_used_collection_shard2_replica1] Solr index directory '/us= r/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-java7/solr/bui= ld/solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTes= t-jetty4-1367393199177/nodes_used_collection_shard2_replica1/data/index' do= esn't exist. Creating new index... [junit4:junit4] 1> INFO - 2013-05-01 07:26:42.246; org.apache.solr.core.= CachingDirectoryFactory; return new directory for /usr/home/hudson/hudson-s= lave/workspace/Lucene-Solr-Tests-trunk-java7/solr/build/solr-core/test/J1/.= /org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1367393199177= /nodes_used_collection_shard2_replica1/data/index [junit4:junit4] 1> INFO - 2013-05-01 07:26:42.251; org.apache.solr.core.= SolrDeletionPolicy; SolrDeletionPolicy.onCommit: commits: num=3D1 [junit4:junit4] 1> =09commit{dir=3DMockDirWrapper(org.apache.lucene.store= .RAMDirectory@75de8caa lockFactory=3Dorg.apache.lucene.store.NativeFSLockFa= ctory@16bd80f2),segFN=3Dsegments_1,generation=3D1} [junit4:junit4] 1> INFO - 2013-05-01 07:26:42.251; org.apache.solr.core.= SolrDeletionPolicy; newest commit generation =3D 1 [junit4:junit4] 1> INFO - 2013-05-01 07:26:42.254; org.apache.solr.updat= e.processor.UpdateRequestProcessorChain; inserting DistributedUpdateProcess= orFactory into updateRequestProcessorChain "dedupe" [junit4:junit4] 1> INFO - 2013-05-01 07:26:42.255; org.apache.solr.updat= e.processor.UpdateRequestProcessorChain; inserting DistributedUpdateProcess= orFactory into updateRequestProcessorChain "stored_sig" [junit4:junit4] 1> INFO - 2013-05-01 07:26:42.255; org.apache.solr.updat= e.processor.UpdateRequestProcessorChain; inserting DistributedUpdateProcess= orFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit= " [junit4:junit4] 1> INFO - 2013-05-01 07:26:42.256; org.apache.solr.core.= RequestHandlers; created standard: solr.StandardRequestHandler [junit4:junit4] 1> INFO - 2013-05-01 07:26:42.257; org.apache.solr.core.= RequestHandlers; created /get: solr.RealTimeGetHandler [junit4:junit4] 1> INFO - 2013-05-01 07:26:42.257; org.apache.solr.core.= RequestHandlers; adding lazy requestHandler: solr.ReplicationHandler [junit4:junit4] 1> INFO - 2013-05-01 07:26:42.258; org.apache.solr.core.= RequestHandlers; created /replication: solr.ReplicationHandler [junit4:junit4] 1> INFO - 2013-05-01 07:26:42.258; org.apache.solr.core.= RequestHandlers; created /update: solr.UpdateRequestHandler [junit4:junit4] 1> INFO - 2013-05-01 07:26:42.259; org.apache.solr.core.= RequestHandlers; created /admin/: org.apache.solr.handler.admin.AdminHandle= rs [junit4:junit4] 1> INFO - 2013-05-01 07:26:42.273; org.apache.solr.handl= er.loader.XMLLoader; xsltCacheLifetimeSeconds=3D60 [junit4:junit4] 1> INFO - 2013-05-01 07:26:42.277; org.apache.solr.searc= h.SolrIndexSearcher; Opening Searcher@14f90fd main [junit4:junit4] 1> INFO - 2013-05-01 07:26:42.277; org.apache.solr.updat= e.UpdateHandler; Clearing tlog files, tlogDir=3D/usr/home/hudson/hudson-sla= ve/workspace/Lucene-Solr-Tests-trunk-java7/solr/build/solr-core/test/J1/./o= rg.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1367393199177/n= odes_used_collection_shard2_replica1/data/tlog [junit4:junit4] 1> INFO - 2013-05-01 07:26:42.279; org.apache.solr.updat= e.CommitTracker; Hard AutoCommit: disabled [junit4:junit4] 1> INFO - 2013-05-01 07:26:42.279; org.apache.solr.updat= e.CommitTracker; Soft AutoCommit: disabled [junit4:junit4] 1> INFO - 2013-05-01 07:26:42.282; org.apache.solr.core.= SolrCore; [nodes_used_collection_shard2_replica1] Registered new searcher S= earcher@14f90fd main{StandardDirectoryReader(segments_1:1)} [junit4:junit4] 1> INFO - 2013-05-01 07:26:42.284; org.apache.solr.cloud= .ZkController; publishing core=3Dnodes_used_collection_shard2_replica1 stat= e=3Ddown [junit4:junit4] 1> INFO - 2013-05-01 07:26:42.347; org.apache.solr.schem= a.OpenExchangeRatesOrgProvider; Initialized with rates=3Dopen-exchange-rate= s.json, refreshInterval=3D1440. [junit4:junit4] 1> INFO - 2013-05-01 07:26:42.364; org.apache.solr.schem= a.IndexSchema; default search field in schema is text [junit4:junit4] 1> INFO - 2013-05-01 07:26:42.371; org.apache.solr.schem= a.IndexSchema; unique key field: id [junit4:junit4] 1> INFO - 2013-05-01 07:26:42.389; org.apache.solr.schem= a.FileExchangeRateProvider; Reloading exchange rates from file currency.xml [junit4:junit4] 1> INFO - 2013-05-01 07:26:42.395; org.apache.solr.schem= a.OpenExchangeRatesOrgProvider; Initialized with rates=3Dopen-exchange-rate= s.json, refreshInterval=3D1440. [junit4:junit4] 1> INFO - 2013-05-01 07:26:42.407; org.apache.solr.schem= a.IndexSchema; default search field in schema is text [junit4:junit4] 1> INFO - 2013-05-01 07:26:42.411; org.apache.solr.schem= a.FileExchangeRateProvider; Reloading exchange rates from file currency.xml [junit4:junit4] 1> INFO - 2013-05-01 07:26:42.413; org.apache.solr.schem= a.IndexSchema; unique key field: id [junit4:junit4] 1> INFO - 2013-05-01 07:26:42.418; org.apache.solr.schem= a.OpenExchangeRatesOrgProvider; Reloading exchange rates from open-exchange= -rates.json [junit4:junit4] 1> WARN - 2013-05-01 07:26:42.419; org.apache.solr.schem= a.OpenExchangeRatesOrgProvider$OpenExchangeRates; Unknown key IMPORTANT NOT= E [junit4:junit4] 1> WARN - 2013-05-01 07:26:42.420; org.apache.solr.schem= a.OpenExchangeRatesOrgProvider$OpenExchangeRates; Expected key, got STRING [junit4:junit4] 1> INFO - 2013-05-01 07:26:42.420; org.apache.solr.schem= a.OpenExchangeRatesOrgProvider; Reloading exchange rates from open-exchange= -rates.json [junit4:junit4] 1> WARN - 2013-05-01 07:26:42.421; org.apache.solr.schem= a.OpenExchangeRatesOrgProvider$OpenExchangeRates; Unknown key IMPORTANT NOT= E [junit4:junit4] 1> WARN - 2013-05-01 07:26:42.422; org.apache.solr.schem= a.OpenExchangeRatesOrgProvider$OpenExchangeRates; Expected key, got STRING [junit4:junit4] 1> INFO - 2013-05-01 07:26:42.422; org.apache.solr.core.= SolrCore; org.apache.solr.core.MockDirectoryFactory [junit4:junit4] 1> INFO - 2013-05-01 07:26:42.423; org.apache.solr.core.= SolrCore; [nodes_used_collection_shard1_replica2] Opening new SolrCore at /= usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-java7/solr/b= uild/solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkT= est-controljetty-1367393193679/nodes_used_collection_shard1_replica2/, data= Dir=3D/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-java7= /solr/build/solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistrib= utedZkTest-controljetty-1367393193679/nodes_used_collection_shard1_replica2= /data/ [junit4:junit4] 1> INFO - 2013-05-01 07:26:42.424; org.apache.solr.core.= JmxMonitoredMap; JMX monitoring is enabled. Adding Solr mbeans to JMX Serve= r: com.sun.jmx.mbeanserver.JmxMBeanServer@342371e7 [junit4:junit4] 1> INFO - 2013-05-01 07:26:42.425; org.apache.solr.core.= SolrCore; org.apache.solr.core.MockDirectoryFactory [junit4:junit4] 1> INFO - 2013-05-01 07:26:42.426; org.apache.solr.core.= CachingDirectoryFactory; return new directory for /usr/home/hudson/hudson-s= lave/workspace/Lucene-Solr-Tests-trunk-java7/solr/build/solr-core/test/J1/.= /org.apache.solr.cloud.CollectionsAPIDistributedZkTest-controljetty-1367393= 193679/nodes_used_collection_shard1_replica2/data [junit4:junit4] 1> INFO - 2013-05-01 07:26:42.426; org.apache.solr.core.= SolrCore; New index directory detected: old=3Dnull new=3D/usr/home/hudson/h= udson-slave/workspace/Lucene-Solr-Tests-trunk-java7/solr/build/solr-core/te= st/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-controljetty-= 1367393193679/nodes_used_collection_shard1_replica2/data/index/ [junit4:junit4] 1> WARN - 2013-05-01 07:26:42.426; org.apache.solr.core.= SolrCore; [nodes_used_collection_shard1_replica2] Solr index directory '/us= r/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-java7/solr/bui= ld/solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTes= t-controljetty-1367393193679/nodes_used_collection_shard1_replica2/data/ind= ex' doesn't exist. Creating new index... [junit4:junit4] 1> INFO - 2013-05-01 07:26:42.427; org.apache.solr.core.= CachingDirectoryFactory; return new directory for /usr/home/hudson/hudson-s= lave/workspace/Lucene-Solr-Tests-trunk-java7/solr/build/solr-core/test/J1/.= /org.apache.solr.cloud.CollectionsAPIDistributedZkTest-controljetty-1367393= 193679/nodes_used_collection_shard1_replica2/data/index [junit4:junit4] 1> INFO - 2013-05-01 07:26:42.430; org.apache.solr.schem= a.FileExchangeRateProvider; Reloading exchange rates from file currency.xml [junit4:junit4] 1> INFO - 2013-05-01 07:26:42.432; org.apache.solr.core.= SolrDeletionPolicy; SolrDeletionPolicy.onCommit: commits: num=3D1 [junit4:junit4] 1> =09commit{dir=3DMockDirWrapper(org.apache.lucene.store= .RAMDirectory@3c9792cf lockFactory=3Dorg.apache.lucene.store.NativeFSLockFa= ctory@72e02618),segFN=3Dsegments_1,generation=3D1} [junit4:junit4] 1> INFO - 2013-05-01 07:26:42.432; org.apache.solr.core.= SolrDeletionPolicy; newest commit generation =3D 1 [junit4:junit4] 1> INFO - 2013-05-01 07:26:42.436; org.apache.solr.updat= e.processor.UpdateRequestProcessorChain; inserting DistributedUpdateProcess= orFactory into updateRequestProcessorChain "dedupe" [junit4:junit4] 1> INFO - 2013-05-01 07:26:42.437; org.apache.solr.updat= e.processor.UpdateRequestProcessorChain; inserting DistributedUpdateProcess= orFactory into updateRequestProcessorChain "stored_sig" [junit4:junit4] 1> INFO - 2013-05-01 07:26:42.438; org.apache.solr.updat= e.processor.UpdateRequestProcessorChain; inserting DistributedUpdateProcess= orFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit= " [junit4:junit4] 1> INFO - 2013-05-01 07:26:42.439; org.apache.solr.core.= RequestHandlers; created standard: solr.StandardRequestHandler [junit4:junit4] 1> INFO - 2013-05-01 07:26:42.440; org.apache.solr.core.= RequestHandlers; created /get: solr.RealTimeGetHandler [junit4:junit4] 1> INFO - 2013-05-01 07:26:42.441; org.apache.solr.core.= RequestHandlers; adding lazy requestHandler: solr.ReplicationHandler [junit4:junit4] 1> INFO - 2013-05-01 07:26:42.441; org.apache.solr.core.= RequestHandlers; created /replication: solr.ReplicationHandler [junit4:junit4] 1> INFO - 2013-05-01 07:26:42.442; org.apache.solr.core.= RequestHandlers; created /update: solr.UpdateRequestHandler [junit4:junit4] 1> INFO - 2013-05-01 07:26:42.443; org.apache.solr.core.= RequestHandlers; created /admin/: org.apache.solr.handler.admin.AdminHandle= rs [junit4:junit4] 1> INFO - 2013-05-01 07:26:42.444; org.apache.solr.schem= a.FileExchangeRateProvider; Reloading exchange rates from file currency.xml [junit4:junit4] 1> INFO - 2013-05-01 07:26:42.461; org.apache.solr.handl= er.loader.XMLLoader; xsltCacheLifetimeSeconds=3D60 [junit4:junit4] 1> INFO - 2013-05-01 07:26:42.462; org.apache.solr.schem= a.OpenExchangeRatesOrgProvider; Reloading exchange rates from open-exchange= -rates.json [junit4:junit4] 1> WARN - 2013-05-01 07:26:42.463; org.apache.solr.schem= a.OpenExchangeRatesOrgProvider$OpenExchangeRates; Unknown key IMPORTANT NOT= E [junit4:junit4] 1> WARN - 2013-05-01 07:26:42.464; org.apache.solr.schem= a.OpenExchangeRatesOrgProvider$OpenExchangeRates; Expected key, got STRING [junit4:junit4] 1> INFO - 2013-05-01 07:26:42.465; org.apache.solr.schem= a.OpenExchangeRatesOrgProvider; Reloading exchange rates from open-exchange= -rates.json [junit4:junit4] 1> INFO - 2013-05-01 07:26:42.465; org.apache.solr.searc= h.SolrIndexSearcher; Opening Searcher@57806f6 main [junit4:junit4] 1> INFO - 2013-05-01 07:26:42.466; org.apache.solr.updat= e.UpdateHandler; Clearing tlog files, tlogDir=3D/usr/home/hudson/hudson-sla= ve/workspace/Lucene-Solr-Tests-trunk-java7/solr/build/solr-core/test/J1/./o= rg.apache.solr.cloud.CollectionsAPIDistributedZkTest-controljetty-136739319= 3679/nodes_used_collection_shard1_replica2/data/tlog [junit4:junit4] 1> WARN - 2013-05-01 07:26:42.466; org.apache.solr.schem= a.OpenExchangeRatesOrgProvider$OpenExchangeRates; Unknown key IMPORTANT NOT= E [junit4:junit4] 1> WARN - 2013-05-01 07:26:42.467; org.apache.solr.schem= a.OpenExchangeRatesOrgProvider$OpenExchangeRates; Expected key, got STRING [junit4:junit4] 1> INFO - 2013-05-01 07:26:42.467; org.apache.solr.updat= e.CommitTracker; Hard AutoCommit: disabled [junit4:junit4] 1> INFO - 2013-05-01 07:26:42.467; org.apache.solr.core.= SolrCore; org.apache.solr.core.MockDirectoryFactory [junit4:junit4] 1> INFO - 2013-05-01 07:26:42.468; org.apache.solr.updat= e.CommitTracker; Soft AutoCommit: disabled [junit4:junit4] 1> INFO - 2013-05-01 07:26:42.468; org.apache.solr.core.= SolrCore; [nodes_used_collection_shard1_replica1] Opening new SolrCore at /= usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-java7/solr/b= uild/solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkT= est-jetty3-1367393197576/nodes_used_collection_shard1_replica1/, dataDir=3D= /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-java7/solr/= build/solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZk= Test-jetty3-1367393197576/nodes_used_collection_shard1_replica1/data/ [junit4:junit4] 1> INFO - 2013-05-01 07:26:42.469; org.apache.solr.core.= JmxMonitoredMap; JMX monitoring is enabled. Adding Solr mbeans to JMX Serve= r: com.sun.jmx.mbeanserver.JmxMBeanServer@342371e7 [junit4:junit4] 1> INFO - 2013-05-01 07:26:42.470; org.apache.solr.core.= SolrCore; org.apache.solr.core.MockDirectoryFactory [junit4:junit4] 1> INFO - 2013-05-01 07:26:42.471; org.apache.solr.core.= CachingDirectoryFactory; return new directory for /usr/home/hudson/hudson-s= lave/workspace/Lucene-Solr-Tests-trunk-java7/solr/build/solr-core/test/J1/.= /org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty3-1367393197576= /nodes_used_collection_shard1_replica1/data [junit4:junit4] 1> INFO - 2013-05-01 07:26:42.472; org.apache.solr.core.= SolrCore; New index directory detected: old=3Dnull new=3D/usr/home/hudson/h= udson-slave/workspace/Lucene-Solr-Tests-trunk-java7/solr/build/solr-core/te= st/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty3-136739= 3197576/nodes_used_collection_shard1_replica1/data/index/ [junit4:junit4] 1> INFO - 2013-05-01 07:26:42.472; org.apache.solr.core.= SolrCore; [nodes_used_collection_shard1_replica2] Registered new searcher S= earcher@57806f6 main{StandardDirectoryReader(segments_1:1)} [junit4:junit4] 1> WARN - 2013-05-01 07:26:42.472; org.apache.solr.core.= SolrCore; [nodes_used_collection_shard1_replica1] Solr index directory '/us= r/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-java7/solr/bui= ld/solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTes= t-jetty3-1367393197576/nodes_used_collection_shard1_replica1/data/index' do= esn't exist. Creating new index... [junit4:junit4] 1> INFO - 2013-05-01 07:26:42.474; org.apache.solr.core.= CachingDirectoryFactory; return new directory for /usr/home/hudson/hudson-s= lave/workspace/Lucene-Solr-Tests-trunk-java7/solr/build/solr-core/test/J1/.= /org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty3-1367393197576= /nodes_used_collection_shard1_replica1/data/index [junit4:junit4] 1> INFO - 2013-05-01 07:26:42.475; org.apache.solr.cloud= .ZkController; publishing core=3Dnodes_used_collection_shard1_replica2 stat= e=3Ddown [junit4:junit4] 1> INFO - 2013-05-01 07:26:42.478; org.apache.solr.core.= SolrDeletionPolicy; SolrDeletionPolicy.onCommit: commits: num=3D1 [junit4:junit4] 1> =09commit{dir=3DMockDirWrapper(org.apache.lucene.store= .RAMDirectory@49e2fe0e lockFactory=3Dorg.apache.lucene.store.NativeFSLockFa= ctory@37f106b6),segFN=3Dsegments_1,generation=3D1} [junit4:junit4] 1> INFO - 2013-05-01 07:26:42.478; org.apache.solr.core.= SolrDeletionPolicy; newest commit generation =3D 1 [junit4:junit4] 1> INFO - 2013-05-01 07:26:42.481; org.apache.solr.updat= e.processor.UpdateRequestProcessorChain; inserting DistributedUpdateProcess= orFactory into updateRequestProcessorChain "dedupe" [junit4:junit4] 1> INFO - 2013-05-01 07:26:42.482; org.apache.solr.updat= e.processor.UpdateRequestProcessorChain; inserting DistributedUpdateProcess= orFactory into updateRequestProcessorChain "stored_sig" [junit4:junit4] 1> INFO - 2013-05-01 07:26:42.482; org.apache.solr.updat= e.processor.UpdateRequestProcessorChain; inserting DistributedUpdateProcess= orFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit= " [junit4:junit4] 1> INFO - 2013-05-01 07:26:42.483; org.apache.solr.core.= RequestHandlers; created standard: solr.StandardRequestHandler [junit4:junit4] 1> INFO - 2013-05-01 07:26:42.484; org.apache.solr.core.= RequestHandlers; created /get: solr.RealTimeGetHandler [junit4:junit4] 1> INFO - 2013-05-01 07:26:42.484; org.apache.solr.core.= RequestHandlers; adding lazy requestHandler: solr.ReplicationHandler [junit4:junit4] 1> INFO - 2013-05-01 07:26:42.485; org.apache.solr.core.= RequestHandlers; created /replication: solr.ReplicationHandler [junit4:junit4] 1> INFO - 2013-05-01 07:26:42.485; org.apache.solr.core.= RequestHandlers; created /update: solr.UpdateRequestHandler [junit4:junit4] 1> INFO - 2013-05-01 07:26:42.486; org.apache.solr.core.= RequestHandlers; created /admin/: org.apache.solr.handler.admin.AdminHandle= rs [junit4:junit4] 1> INFO - 2013-05-01 07:26:42.496; org.apache.solr.handl= er.loader.XMLLoader; xsltCacheLifetimeSeconds=3D60 [junit4:junit4] 1> INFO - 2013-05-01 07:26:42.502; org.apache.solr.searc= h.SolrIndexSearcher; Opening Searcher@59a1ac9e main [junit4:junit4] 1> INFO - 2013-05-01 07:26:42.502; org.apache.solr.updat= e.UpdateHandler; Clearing tlog files, tlogDir=3D/usr/home/hudson/hudson-sla= ve/workspace/Lucene-Solr-Tests-trunk-java7/solr/build/solr-core/test/J1/./o= rg.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty3-1367393197576/n= odes_used_collection_shard1_replica1/data/tlog [junit4:junit4] 1> INFO - 2013-05-01 07:26:42.504; org.apache.solr.updat= e.CommitTracker; Hard AutoCommit: disabled [junit4:junit4] 1> INFO - 2013-05-01 07:26:42.504; org.apache.solr.updat= e.CommitTracker; Soft AutoCommit: disabled [junit4:junit4] 1> INFO - 2013-05-01 07:26:42.507; org.apache.solr.core.= SolrCore; [nodes_used_collection_shard1_replica1] Registered new searcher S= earcher@59a1ac9e main{StandardDirectoryReader(segments_1:1)} [junit4:junit4] 1> INFO - 2013-05-01 07:26:42.509; org.apache.solr.cloud= .ZkController; publishing core=3Dnodes_used_collection_shard1_replica1 stat= e=3Ddown [junit4:junit4] 1> INFO - 2013-05-01 07:26:43.333; org.apache.solr.commo= n.cloud.ZkStateReader; Updating cloud state from ZooKeeper...=20 [junit4:junit4] 1> INFO - 2013-05-01 07:26:43.334; 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:22540_wyc%2Frw", [junit4:junit4] 1> "base_url":"http://127.0.0.1:22540/wyc/rw"} [junit4:junit4] 1> INFO - 2013-05-01 07:26:43.334; org.apache.solr.cloud= .Overseer$ClusterStateUpdater; Create collection nodes_used_collection with= numShards 2 [junit4:junit4] 1> INFO - 2013-05-01 07:26:43.338; 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:48327_wyc%2Frw", [junit4:junit4] 1> "base_url":"http://127.0.0.1:48327/wyc/rw"} [junit4:junit4] 1> INFO - 2013-05-01 07:26:43.353; 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:33541_wyc%2Frw", [junit4:junit4] 1> "base_url":"http://127.0.0.1:33541/wyc/rw"} [junit4:junit4] 1> INFO - 2013-05-01 07:26:43.363; 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:62715_wyc%2Frw", [junit4:junit4] 1> "base_url":"http://127.0.0.1:62715/wyc/rw"} [junit4:junit4] 1> INFO - 2013-05-01 07:26:43.368; 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-05-01 07:26:43.369; 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-05-01 07:26:43.369; 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-05-01 07:26:43.369; 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-05-01 07:26:43.369; 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-05-01 07:26:43.369; 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-05-01 07:26:43.503; org.apache.solr.core.= CoreContainer; registering core: nodes_used_collection_shard1_replica2 [junit4:junit4] 1> INFO - 2013-05-01 07:26:43.503; org.apache.solr.cloud= .ZkController; Register replica - core:nodes_used_collection_shard1_replica= 2 address:http://127.0.0.1:33541/wyc/rw collection:nodes_used_collection sh= ard:shard1 [junit4:junit4] 1> INFO - 2013-05-01 07:26:43.504; org.apache.solr.commo= n.cloud.SolrZkClient; makePath: /collections/nodes_used_collection/leader_e= lect/shard1/election [junit4:junit4] 1> INFO - 2013-05-01 07:26:43.511; org.apache.solr.core.= CoreContainer; registering core: nodes_used_collection_shard1_replica1 [junit4:junit4] 1> INFO - 2013-05-01 07:26:43.511; org.apache.solr.cloud= .ZkController; Register replica - core:nodes_used_collection_shard1_replica= 1 address:http://127.0.0.1:62715/wyc/rw collection:nodes_used_collection sh= ard:shard1 [junit4:junit4] 1> INFO - 2013-05-01 07:26:43.532; org.apache.solr.cloud= .ShardLeaderElectionContext; Running the leader process. [junit4:junit4] 1> INFO - 2013-05-01 07:26:43.535; org.apache.solr.cloud= .ShardLeaderElectionContext; Enough replicas found to continue. [junit4:junit4] 1> INFO - 2013-05-01 07:26:43.535; org.apache.solr.cloud= .ShardLeaderElectionContext; I may be the new leader - try and sync [junit4:junit4] 1> INFO - 2013-05-01 07:26:43.536; org.apache.solr.cloud= .SyncStrategy; Sync replicas to http://127.0.0.1:62715/wyc/rw/nodes_used_co= llection_shard1_replica1/ [junit4:junit4] 1> INFO - 2013-05-01 07:26:43.536; org.apache.solr.updat= e.PeerSync; PeerSync: core=3Dnodes_used_collection_shard1_replica1 url=3Dht= tp://127.0.0.1:62715/wyc/rw START replicas=3D[http://127.0.0.1:33541/wyc/rw= /nodes_used_collection_shard1_replica2/] nUpdates=3D100 [junit4:junit4] 1> INFO - 2013-05-01 07:26:43.537; org.apache.solr.updat= e.PeerSync; PeerSync: core=3Dnodes_used_collection_shard1_replica1 url=3Dht= tp://127.0.0.1:62715/wyc/rw DONE. We have no versions. sync failed. [junit4:junit4] 1> INFO - 2013-05-01 07:26:43.537; org.apache.solr.cloud= .SyncStrategy; Leader's attempt to sync with shard failed, moving to the ne= xt canidate [junit4:junit4] 1> INFO - 2013-05-01 07:26:43.538; 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-05-01 07:26:43.539; org.apache.solr.cloud= .ShardLeaderElectionContext; I am the new leader: http://127.0.0.1:62715/wy= c/rw/nodes_used_collection_shard1_replica1/ [junit4:junit4] 1> INFO - 2013-05-01 07:26:43.540; org.apache.solr.commo= n.cloud.SolrZkClient; makePath: /collections/nodes_used_collection/leaders/= shard1 [junit4:junit4] 1> INFO - 2013-05-01 07:26:43.548; org.apache.solr.core.= SolrCore; [nodes_used_collection_shard1_replica2] webapp=3D/wyc/rw path=3D/= get params=3D{getVersions=3D100&distrib=3Dfalse&wt=3Djavabin&qt=3D/get&vers= ion=3D2} status=3D0 QTime=3D0=20 [junit4:junit4] 1> INFO - 2013-05-01 07:26:44.239; org.apache.solr.core.= CoreContainer; registering core: nodes_used_collection_shard2_replica2 [junit4:junit4] 1> INFO - 2013-05-01 07:26:44.239; org.apache.solr.cloud= .ZkController; Register replica - core:nodes_used_collection_shard2_replica= 2 address:http://127.0.0.1:22540/wyc/rw collection:nodes_used_collection sh= ard:shard2 [junit4:junit4] 1> INFO - 2013-05-01 07:26:44.241; org.apache.solr.commo= n.cloud.SolrZkClient; makePath: /collections/nodes_used_collection/leader_e= lect/shard2/election [junit4:junit4] 1> INFO - 2013-05-01 07:26:44.259; org.apache.solr.cloud= .ShardLeaderElectionContext; Running the leader process. [junit4:junit4] 1> INFO - 2013-05-01 07:26:44.270; org.apache.solr.cloud= .ShardLeaderElectionContext; Waiting until we see more replicas up: total= =3D2 found=3D1 timeoutin=3D179999 [junit4:junit4] 1> INFO - 2013-05-01 07:26:44.288; org.apache.solr.core.= CoreContainer; registering core: nodes_used_collection_shard2_replica1 [junit4:junit4] 1> INFO - 2013-05-01 07:26:44.288; org.apache.solr.cloud= .ZkController; Register replica - core:nodes_used_collection_shard2_replica= 1 address:http://127.0.0.1:48327/wyc/rw collection:nodes_used_collection sh= ard:shard2 [junit4:junit4] 1> INFO - 2013-05-01 07:26:44.772; org.apache.solr.cloud= .ShardLeaderElectionContext; Enough replicas found to continue. [junit4:junit4] 1> INFO - 2013-05-01 07:26:44.772; org.apache.solr.cloud= .ShardLeaderElectionContext; I may be the new leader - try and sync [junit4:junit4] 1> INFO - 2013-05-01 07:26:44.773; org.apache.solr.cloud= .SyncStrategy; Sync replicas to http://127.0.0.1:22540/wyc/rw/nodes_used_co= llection_shard2_replica2/ [junit4:junit4] 1> INFO - 2013-05-01 07:26:44.773; org.apache.solr.updat= e.PeerSync; PeerSync: core=3Dnodes_used_collection_shard2_replica2 url=3Dht= tp://127.0.0.1:22540/wyc/rw START replicas=3D[http://127.0.0.1:48327/wyc/rw= /nodes_used_collection_shard2_replica1/] nUpdates=3D100 [junit4:junit4] 1> INFO - 2013-05-01 07:26:44.774; org.apache.solr.updat= e.PeerSync; PeerSync: core=3Dnodes_used_collection_shard2_replica2 url=3Dht= tp://127.0.0.1:22540/wyc/rw DONE. We have no versions. sync failed. [junit4:junit4] 1> INFO - 2013-05-01 07:26:44.775; org.apache.solr.cloud= .SyncStrategy; Leader's attempt to sync with shard failed, moving to the ne= xt canidate [junit4:junit4] 1> INFO - 2013-05-01 07:26:44.775; 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-05-01 07:26:44.776; org.apache.solr.cloud= .ShardLeaderElectionContext; I am the new leader: http://127.0.0.1:22540/wy= c/rw/nodes_used_collection_shard2_replica2/ [junit4:junit4] 1> INFO - 2013-05-01 07:26:44.777; org.apache.solr.commo= n.cloud.SolrZkClient; makePath: /collections/nodes_used_collection/leaders/= shard2 [junit4:junit4] 1> INFO - 2013-05-01 07:26:44.784; org.apache.solr.core.= SolrCore; [nodes_used_collection_shard2_replica1] webapp=3D/wyc/rw path=3D/= get params=3D{getVersions=3D100&distrib=3Dfalse&wt=3Djavabin&qt=3D/get&vers= ion=3D2} status=3D0 QTime=3D1=20 [junit4:junit4] 1> INFO - 2013-05-01 07:26:44.903; org.apache.solr.commo= n.cloud.ZkStateReader; Updating cloud state from ZooKeeper...=20 [junit4:junit4] 1> INFO - 2013-05-01 07:26:45.032; 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-05-01 07:26:45.032; 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-05-01 07:26:45.032; 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-05-01 07:26:45.032; 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-05-01 07:26:45.032; 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-05-01 07:26:45.032; 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-05-01 07:26:45.055; org.apache.solr.cloud= .ZkController; We are http://127.0.0.1:22540/wyc/rw/nodes_used_collection_s= hard2_replica2/ and leader is http://127.0.0.1:22540/wyc/rw/nodes_used_coll= ection_shard2_replica2/ [junit4:junit4] 1> INFO - 2013-05-01 07:26:45.055; org.apache.solr.cloud= .ZkController; No LogReplay needed for core=3Dnodes_used_collection_shard2_= replica2 baseURL=3Dhttp://127.0.0.1:22540/wyc/rw [junit4:junit4] 1> INFO - 2013-05-01 07:26:45.056; org.apache.solr.cloud= .ZkController; I am the leader, no recovery necessary [junit4:junit4] 1> INFO - 2013-05-01 07:26:45.056; org.apache.solr.cloud= .ZkController; publishing core=3Dnodes_used_collection_shard2_replica2 stat= e=3Dactive [junit4:junit4] 1> INFO - 2013-05-01 07:26:45.063; org.apache.solr.commo= n.cloud.ZkStateReader; Updating cloud state from ZooKeeper...=20 [junit4:junit4] 1> INFO - 2013-05-01 07:26:45.064; 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=3D4057=20 [junit4:junit4] 1> INFO - 2013-05-01 07:26:45.078; org.apache.solr.cloud= .ZkController; We are http://127.0.0.1:62715/wyc/rw/nodes_used_collection_s= hard1_replica1/ and leader is http://127.0.0.1:62715/wyc/rw/nodes_used_coll= ection_shard1_replica1/ [junit4:junit4] 1> INFO - 2013-05-01 07:26:45.078; org.apache.solr.cloud= .ZkController; No LogReplay needed for core=3Dnodes_used_collection_shard1_= replica1 baseURL=3Dhttp://127.0.0.1:62715/wyc/rw [junit4:junit4] 1> INFO - 2013-05-01 07:26:45.078; org.apache.solr.cloud= .ZkController; I am the leader, no recovery necessary [junit4:junit4] 1> INFO - 2013-05-01 07:26:45.079; org.apache.solr.cloud= .ZkController; publishing core=3Dnodes_used_collection_shard1_replica1 stat= e=3Dactive [junit4:junit4] 1> INFO - 2013-05-01 07:26:45.081; org.apache.solr.commo= n.cloud.ZkStateReader; Updating cloud state from ZooKeeper...=20 [junit4:junit4] 1> INFO - 2013-05-01 07:26:45.083; 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=3D4077=20 [junit4:junit4] 1> INFO - 2013-05-01 07:26:45.094; org.apache.solr.cloud= .ZkController; We are http://127.0.0.1:33541/wyc/rw/nodes_used_collection_s= hard1_replica2/ and leader is http://127.0.0.1:62715/wyc/rw/nodes_used_coll= ection_shard1_replica1/ [junit4:junit4] 1> INFO - 2013-05-01 07:26:45.094; org.apache.solr.cloud= .ZkController; No LogReplay needed for core=3Dnodes_used_collection_shard1_= replica2 baseURL=3Dhttp://127.0.0.1:33541/wyc/rw [junit4:junit4] 1> INFO - 2013-05-01 07:26:45.095; org.apache.solr.cloud= .ZkController; Core needs to recover:nodes_used_collection_shard1_replica2 [junit4:junit4] 1> INFO - 2013-05-01 07:26:45.095; org.apache.solr.updat= e.DefaultSolrCoreState; Running recovery - first canceling any ongoing reco= very [junit4:junit4] 1> INFO - 2013-05-01 07:26:45.096; org.apache.solr.cloud= .RecoveryStrategy; Starting recovery process. core=3Dnodes_used_collection= _shard1_replica2 recoveringAfterStartup=3Dtrue [junit4:junit4] 1> INFO - 2013-05-01 07:26:45.097; org.apache.solr.cloud= .RecoveryStrategy; ###### startupVersions=3D[] [junit4:junit4] 1> INFO - 2013-05-01 07:26:45.097; org.apache.solr.commo= n.cloud.ZkStateReader; Updating cloud state from ZooKeeper...=20 [junit4:junit4] 1> INFO - 2013-05-01 07:26:45.097; org.apache.solr.cloud= .ZkController; publishing core=3Dnodes_used_collection_shard1_replica2 stat= e=3Drecovering [junit4:junit4] 1> INFO - 2013-05-01 07:26:45.098; 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=3D4091=20 [junit4:junit4] 1> INFO - 2013-05-01 07:26:45.099; 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-05-01 07:26:45.115; org.apache.solr.handl= er.admin.CoreAdminHandler; Going to wait for coreNodeName: 127.0.0.1:33541_= wyc%2Frw_nodes_used_collection_shard1_replica2, state: recovering, checkLiv= e: true, onlyIfLeader: true [junit4:junit4] 1> INFO - 2013-05-01 07:26:45.293; org.apache.solr.cloud= .ZkController; We are http://127.0.0.1:48327/wyc/rw/nodes_used_collection_s= hard2_replica1/ and leader is http://127.0.0.1:22540/wyc/rw/nodes_used_coll= ection_shard2_replica2/ [junit4:junit4] 1> INFO - 2013-05-01 07:26:45.294; org.apache.solr.cloud= .ZkController; No LogReplay needed for core=3Dnodes_used_collection_shard2_= replica1 baseURL=3Dhttp://127.0.0.1:48327/wyc/rw [junit4:junit4] 1> INFO - 2013-05-01 07:26:45.294; org.apache.solr.cloud= .ZkController; Core needs to recover:nodes_used_collection_shard2_replica1 [junit4:junit4] 1> INFO - 2013-05-01 07:26:45.295; org.apache.solr.updat= e.DefaultSolrCoreState; Running recovery - first canceling any ongoing reco= very [junit4:junit4] 1> INFO - 2013-05-01 07:26:45.296; org.apache.solr.cloud= .RecoveryStrategy; Starting recovery process. core=3Dnodes_used_collection= _shard2_replica1 recoveringAfterStartup=3Dtrue [junit4:junit4] 1> INFO - 2013-05-01 07:26:45.296; org.apache.solr.cloud= .RecoveryStrategy; ###### startupVersions=3D[] [junit4:junit4] 1> INFO - 2013-05-01 07:26:45.296; org.apache.solr.commo= n.cloud.ZkStateReader; Updating cloud state from ZooKeeper...=20 [junit4:junit4] 1> INFO - 2013-05-01 07:26:45.297; org.apache.solr.cloud= .ZkController; publishing core=3Dnodes_used_collection_shard2_replica1 stat= e=3Drecovering [junit4:junit4] 1> INFO - 2013-05-01 07:26:45.298; 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=3D4291=20 [junit4:junit4] 1> INFO - 2013-05-01 07:26:45.299; org.apache.solr.cloud= .OverseerCollectionProcessor; Finished create command on all shards for col= lection: nodes_used_collection [junit4:junit4] 1> INFO - 2013-05-01 07:26:45.304; 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-05-01 07:26:45.315; 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-05-01 07:26:45.315; org.apache.solr.handl= er.admin.CoreAdminHandler; Going to wait for coreNodeName: 127.0.0.1:48327_= wyc%2Frw_nodes_used_collection_shard2_replica1, state: recovering, checkLiv= e: true, onlyIfLeader: true [junit4:junit4] 1> INFO - 2013-05-01 07:26:45.316; org.apache.solr.cloud= .DistributedQueue$LatchChildWatcher; Watcher fired on path: /overseer/colle= ction-queue-work state: SyncConnected type NodeChildrenChanged [junit4:junit4] 1> INFO - 2013-05-01 07:26:45.316; 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=3D4057},core=3Dnodes_used_collect= ion_shard2_replica2},null=3D{responseHeader=3D{status=3D0,QTime=3D4077},cor= e=3Dnodes_used_collection_shard1_replica1},null=3D{responseHeader=3D{status= =3D0,QTime=3D4091},core=3Dnodes_used_collection_shard1_replica2},null=3D{re= sponseHeader=3D{status=3D0,QTime=3D4291},core=3Dnodes_used_collection_shard= 2_replica1}}} [junit4:junit4] 1> INFO - 2013-05-01 07:26:45.328; 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=3D4344=20 [junit4:junit4] 1> INFO - 2013-05-01 07:26:45.328; org.apache.solr.clien= t.solrj.impl.HttpClientUtil; Creating new http client, config: [junit4:junit4] 1> INFO - 2013-05-01 07:26:45.330; org.apache.solr.commo= n.cloud.ConnectionManager; Waiting for client to connect to ZooKeeper [junit4:junit4] 1> INFO - 2013-05-01 07:26:45.332; org.apache.solr.commo= n.cloud.ConnectionManager; Watcher org.apache.solr.common.cloud.ConnectionM= anager@7766a04f name:ZooKeeperConnection Watcher:127.0.0.1:33673/solr got e= vent WatchedEvent state:SyncConnected type:None path:null path:null type:No= ne [junit4:junit4] 1> INFO - 2013-05-01 07:26:45.332; org.apache.solr.commo= n.cloud.ConnectionManager; Client is connected to ZooKeeper [junit4:junit4] 1> INFO - 2013-05-01 07:26:45.334; org.apache.solr.commo= n.cloud.ZkStateReader; Updating cluster state from ZooKeeper...=20 [junit4:junit4] 1> INFO - 2013-05-01 07:26:45.337; org.apache.solr.clien= t.solrj.impl.HttpClientUtil; Creating new http client, config: [junit4:junit4] 1> INFO - 2013-05-01 07:26:45.339; org.apache.solr.commo= n.cloud.ConnectionManager; Waiting for client to connect to ZooKeeper [junit4:junit4] 1> INFO - 2013-05-01 07:26:45.341; org.apache.solr.commo= n.cloud.ConnectionManager; Watcher org.apache.solr.common.cloud.ConnectionM= anager@7c3ea78a name:ZooKeeperConnection Watcher:127.0.0.1:33673/solr got e= vent WatchedEvent state:SyncConnected type:None path:null path:null type:No= ne [junit4:junit4] 1> INFO - 2013-05-01 07:26:45.341; org.apache.solr.commo= n.cloud.ConnectionManager; Client is connected to ZooKeeper [junit4:junit4] 1> INFO - 2013-05-01 07:26:45.343; org.apache.solr.commo= n.cloud.ZkStateReader; Updating cluster state from ZooKeeper...=20 [junit4:junit4] 1> INFO - 2013-05-01 07:26:45.356; org.apache.solr.handl= er.admin.CollectionsHandler; Creating Collection : numShards=3D3&maxShardsP= erNode=3D2&name=3Dawholynewcollection_0&replicationFactor=3D3&action=3DCREA= TE&wt=3Djavabin&version=3D2 [junit4:junit4] 1> INFO - 2013-05-01 07:26:45.357; org.apache.solr.cloud= .DistributedQueue$LatchChildWatcher; Watcher fired on path: /overseer/colle= ction-queue-work state: SyncConnected type NodeChildrenChanged [junit4:junit4] 1> INFO - 2013-05-01 07:26:45.359; 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":"3", [junit4:junit4] 1> "maxShardsPerNode":"2", [junit4:junit4] 1> "createNodeSet":null, [junit4:junit4] 1> "name":"awholynewcollection_0", [junit4:junit4] 1> "replicationFactor":"3"} [junit4:junit4] 1> INFO - 2013-05-01 07:26:45.359; 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:33541_wyc%2Frw [junit4:junit4] 1> INFO - 2013-05-01 07:26:45.360; 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:22540_wyc%2Frw [junit4:junit4] 1> INFO - 2013-05-01 07:26:45.360; 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:48327_wyc%2Frw [junit4:junit4] 1> INFO - 2013-05-01 07:26:45.360; org.apache.solr.cloud= .OverseerCollectionProcessor; Creating shard awholynewcollection_0_shard2_r= eplica1 as part of slice shard2 of collection awholynewcollection_0 on 127.= 0.0.1:52550_wyc%2Frw [junit4:junit4] 1> INFO - 2013-05-01 07:26:45.361; org.apache.solr.cloud= .OverseerCollectionProcessor; Creating shard awholynewcollection_0_shard2_r= eplica2 as part of slice shard2 of collection awholynewcollection_0 on 127.= 0.0.1:62715_wyc%2Frw [junit4:junit4] 1> INFO - 2013-05-01 07:26:45.361; org.apache.solr.cloud= .OverseerCollectionProcessor; Creating shard awholynewcollection_0_shard2_r= eplica3 as part of slice shard2 of collection awholynewcollection_0 on 127.= 0.0.1:33541_wyc%2Frw [junit4:junit4] 1> INFO - 2013-05-01 07:26:45.361; org.apache.solr.cloud= .OverseerCollectionProcessor; Creating shard awholynewcollection_0_shard3_r= eplica1 as part of slice shard3 of collection awholynewcollection_0 on 127.= 0.0.1:22540_wyc%2Frw [junit4:junit4] 1> INFO - 2013-05-01 07:26:45.362; org.apache.solr.core.= CoreContainer; Creating SolrCore 'awholynewcollection_0_shard2_replica1' us= ing instanceDir: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-= trunk-java7/solr/build/solr-core/test/J1/./org.apache.solr.cloud.Collection= sAPIDistributedZkTest-jetty1-1367393194339/awholynewcollection_0_shard2_rep= lica1 [junit4:junit4] 1> INFO - 2013-05-01 07:26:45.362; org.apache.solr.core.= CoreContainer; Creating SolrCore 'awholynewcollection_0_shard1_replica3' us= ing instanceDir: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-= trunk-java7/solr/build/solr-core/test/J1/./org.apache.solr.cloud.Collection= sAPIDistributedZkTest-jetty4-1367393199177/awholynewcollection_0_shard1_rep= lica3 [junit4:junit4] 1> INFO - 2013-05-01 07:26:45.363; org.apache.solr.core.= CoreContainer; Creating SolrCore 'awholynewcollection_0_shard2_replica3' us= ing instanceDir: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-= trunk-java7/solr/build/solr-core/test/J1/./org.apache.solr.cloud.Collection= sAPIDistributedZkTest-controljetty-1367393193679/awholynewcollection_0_shar= d2_replica3 [junit4:junit4] 1> INFO - 2013-05-01 07:26:45.363; org.apache.solr.cloud= .ZkController; Check for collection zkNode:awholynewcollection_0 [junit4:junit4] 1> INFO - 2013-05-01 07:26:45.363; org.apache.solr.core.= CoreContainer; Creating SolrCore 'awholynewcollection_0_shard1_replica1' us= ing instanceDir: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-= trunk-java7/solr/build/solr-core/test/J1/./org.apache.solr.cloud.Collection= sAPIDistributedZkTest-controljetty-1367393193679/awholynewcollection_0_shar= d1_replica1 [junit4:junit4] 1> INFO - 2013-05-01 07:26:45.364; org.apache.solr.cloud= .ZkController; Check for collection zkNode:awholynewcollection_0 [junit4:junit4] 1> INFO - 2013-05-01 07:26:45.362; org.apache.solr.core.= CoreContainer; Creating SolrCore 'awholynewcollection_0_shard1_replica2' us= ing instanceDir: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-= trunk-java7/solr/build/solr-core/test/J1/./org.apache.solr.cloud.Collection= sAPIDistributedZkTest-jetty2-1367393195983/awholynewcollection_0_shard1_rep= lica2 [junit4:junit4] 1> INFO - 2013-05-01 07:26:45.365; org.apache.solr.cloud= .ZkController; Check for collection zkNode:awholynewcollection_0 [junit4:junit4] 1> INFO - 2013-05-01 07:26:45.362; org.apache.solr.cloud= .ZkController; Check for collection zkNode:awholynewcollection_0 [junit4:junit4] 1> INFO - 2013-05-01 07:26:45.362; org.apache.solr.cloud= .OverseerCollectionProcessor; Creating shard awholynewcollection_0_shard3_r= eplica2 as part of slice shard3 of collection awholynewcollection_0 on 127.= 0.0.1:48327_wyc%2Frw [junit4:junit4] 1> INFO - 2013-05-01 07:26:45.366; org.apache.solr.cloud= .ZkController; Creating collection in ZooKeeper:awholynewcollection_0 [junit4:junit4] 1> INFO - 2013-05-01 07:26:45.366; org.apache.solr.cloud= .ZkController; Creating collection in ZooKeeper:awholynewcollection_0 [junit4:junit4] 1> INFO - 2013-05-01 07:26:45.364; org.apache.solr.cloud= .ZkController; Creating collection in ZooKeeper:awholynewcollection_0 [junit4:junit4] 1> INFO - 2013-05-01 07:26:45.363; org.apache.solr.core.= CoreContainer; Creating SolrCore 'awholynewcollection_0_shard2_replica2' us= ing instanceDir: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-= trunk-java7/solr/build/solr-core/test/J1/./org.apache.solr.cloud.Collection= sAPIDistributedZkTest-jetty3-1367393197576/awholynewcollection_0_shard2_rep= lica2 [junit4:junit4] 1> INFO - 2013-05-01 07:26:45.368; org.apache.solr.cloud= .ZkController; Check for collection zkNode:awholynewcollection_0 [junit4:junit4] 1> INFO - 2013-05-01 07:26:45.363; org.apache.solr.core.= CoreContainer; Creating SolrCore 'awholynewcollection_0_shard3_replica1' us= ing instanceDir: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-= trunk-java7/solr/build/solr-core/test/J1/./org.apache.solr.cloud.Collection= sAPIDistributedZkTest-jetty2-1367393195983/awholynewcollection_0_shard3_rep= lica1 [junit4:junit4] 1> INFO - 2013-05-01 07:26:45.369; org.apache.solr.cloud= .ZkController; Check for collection zkNode:awholynewcollection_0 [junit4:junit4] 1> INFO - 2013-05-01 07:26:45.363; org.apache.solr.cloud= .ZkController; Check for collection zkNode:awholynewcollection_0 [junit4:junit4] 1> INFO - 2013-05-01 07:26:45.369; org.apache.solr.cloud= .ZkController; Creating collection in ZooKeeper:awholynewcollection_0 [junit4:junit4] 1> INFO - 2013-05-01 07:26:45.368; org.apache.solr.core.= CoreContainer; Creating SolrCore 'awholynewcollection_0_shard3_replica2' us= ing instanceDir: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-= trunk-java7/solr/build/solr-core/test/J1/./org.apache.solr.cloud.Collection= sAPIDistributedZkTest-jetty4-1367393199177/awholynewcollection_0_shard3_rep= lica2 [junit4:junit4] 1> INFO - 2013-05-01 07:26:45.371; org.apache.solr.cloud= .ZkController; Creating collection in ZooKeeper:awholynewcollection_0 [junit4:junit4] 1> INFO - 2013-05-01 07:26:45.368; org.apache.solr.cloud= .ZkController; Looking for collection configName [junit4:junit4] 1> INFO - 2013-05-01 07:26:45.367; org.apache.solr.cloud= .ZkController; Looking for collection configName [junit4:junit4] 1> INFO - 2013-05-01 07:26:45.367; org.apache.solr.cloud= .ZkController; Looking for collection configName [junit4:junit4] 1> INFO - 2013-05-01 07:26:45.367; org.apache.solr.cloud= .OverseerCollectionProcessor; Creating shard awholynewcollection_0_shard3_r= eplica3 as part of slice shard3 of collection awholynewcollection_0 on 127.= 0.0.1:52550_wyc%2Frw [junit4:junit4] 1> INFO - 2013-05-01 07:26:45.367; org.apache.solr.cloud= .ZkController; Creating collection in ZooKeeper:awholynewcollection_0 [junit4:junit4] 1> INFO - 2013-05-01 07:26:45.373; org.apache.solr.cloud= .ZkController; Only one config set found in zk - using it:conf1 [junit4:junit4] 1> INFO - 2013-05-01 07:26:45.373; org.apache.solr.cloud= .ZkController; Only one config set found in zk - using it:conf1 [junit4:junit4] 1> INFO - 2013-05-01 07:26:45.371; org.apache.solr.cloud= .ZkController; Looking for collection configName [junit4:junit4] 1> INFO - 2013-05-01 07:26:45.371; org.apache.solr.cloud= .ZkController; Creating collection in ZooKeeper:awholynewcollection_0 [junit4:junit4] 1> INFO - 2013-05-01 07:26:45.371; org.apache.solr.cloud= .ZkController; Check for collection zkNode:awholynewcollection_0 [junit4:junit4] 1> INFO - 2013-05-01 07:26:45.370; org.apache.solr.cloud= .ZkController; Looking for collection configName [junit4:junit4] 1> INFO - 2013-05-01 07:26:45.375; org.apache.solr.cloud= .ZkController; Looking for collection configName [junit4:junit4] 1> INFO - 2013-05-01 07:26:45.375; org.apache.solr.core.= CoreContainer; Creating SolrCore 'awholynewcollection_0_shard3_replica3' us= ing instanceDir: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-= trunk-java7/solr/build/solr-core/test/J1/./org.apache.solr.cloud.Collection= sAPIDistributedZkTest-jetty1-1367393194339/awholynewcollection_0_shard3_rep= lica3 [junit4:junit4] 1> INFO - 2013-05-01 07:26:45.375; org.apache.solr.commo= n.cloud.SolrZkClient; makePath: /collections/awholynewcollection_0 [junit4:junit4] 1> INFO - 2013-05-01 07:26:45.374; org.apache.solr.commo= n.cloud.SolrZkClient; makePath: /collections/awholynewcollection_0 [junit4:junit4] 1> INFO - 2013-05-01 07:26:45.374; org.apache.solr.cloud= .ZkController; Only one config set found in zk - using it:conf1 [junit4:junit4] 1> INFO - 2013-05-01 07:26:45.374; org.apache.solr.cloud= .ZkController; Looking for collection configName [junit4:junit4] 1> INFO - 2013-05-01 07:26:45.379; org.apache.solr.commo= n.cloud.SolrZkClient; makePath: /collections/awholynewcollection_0 [junit4:junit4] 1> INFO - 2013-05-01 07:26:45.378; org.apache.solr.cloud= .ZkController; Only one config set found in zk - using it:conf1 [junit4:junit4] 1> INFO - 2013-05-01 07:26:45.378; org.apache.solr.cloud= .ZkController; Check for collection zkNode:awholynewcollection_0 [junit4:junit4] 1> INFO - 2013-05-01 07:26:45.377; org.apache.solr.cloud= .ZkController; Only one config set found in zk - using it:conf1 [junit4:junit4] 1> INFO - 2013-05-01 07:26:45.377; org.apache.solr.cloud= .ZkController; Only one config set found in zk - using it:conf1 [junit4:junit4] 1> INFO - 2013-05-01 07:26:45.382; org.apache.solr.cloud= .ZkController; Load collection config from:/collections/awholynewcollection= _0 [junit4:junit4] 1> INFO - 2013-05-01 07:26:45.377; org.apache.solr.cloud= .ZkController; Creating collection in ZooKeeper:awholynewcollection_0 [junit4:junit4] 1> INFO - 2013-05-01 07:26:45.382; org.apache.solr.cloud= .ZkController; Collection zkNode exists [junit4:junit4] 1> INFO - 2013-05-01 07:26:45.382; org.apache.solr.commo= n.cloud.SolrZkClient; makePath: /collections/awholynewcollection_0 [junit4:junit4] 1> INFO - 2013-05-01 07:26:45.382; org.apache.solr.commo= n.cloud.SolrZkClient; makePath: /collections/awholynewcollection_0 [junit4:junit4] 1> INFO - 2013-05-01 07:26:45.382; org.apache.solr.cloud= .ZkController; Load collection config from:/collections/awholynewcollection= _0 [junit4:junit4] 1> INFO - 2013-05-01 07:26:45.382; org.apache.solr.commo= n.cloud.SolrZkClient; makePath: /collections/awholynewcollection_0 [junit4:junit4] 1> INFO - 2013-05-01 07:26:45.381; org.apache.solr.commo= n.cloud.SolrZkClient; makePath: /collections/awholynewcollection_0 [junit4:junit4] 1> INFO - 2013-05-01 07:26:45.383; org.apache.solr.cloud= .ZkController; Load collection config from:/collections/awholynewcollection= _0 [junit4:junit4] 1> INFO - 2013-05-01 07:26:45.383; org.apache.solr.cloud= .ZkController; Looking for collection configName [junit4:junit4] 1> INFO - 2013-05-01 07:26:45.391; org.apache.solr.cloud= .ZkController; Load collection config from:/collections/awholynewcollection= _0 [junit4:junit4] 1> INFO - 2013-05-01 07:26:45.392; org.apache.solr.core.= SolrResourceLoader; new SolrResourceLoader for directory: '/usr/home/hudson= /hudson-slave/workspace/Lucene-Solr-Tests-trunk-java7/solr/build/solr-core/= test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-controljett= y-1367393193679/awholynewcollection_0_shard2_replica3/' [junit4:junit4] 1> INFO - 2013-05-01 07:26:45.393; org.apache.solr.core.= SolrResourceLoader; new SolrResourceLoader for directory: '/usr/home/hudson= /hudson-slave/workspace/Lucene-Solr-Tests-trunk-java7/solr/build/solr-core/= test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-controljett= y-1367393193679/awholynewcollection_0_shard1_replica1/' [junit4:junit4] 1> INFO - 2013-05-01 07:26:45.393; org.apache.solr.core.= SolrResourceLoader; new SolrResourceLoader for directory: '/usr/home/hudson= /hudson-slave/workspace/Lucene-Solr-Tests-trunk-java7/solr/build/solr-core/= test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty1-1367= 393194339/awholynewcollection_0_shard3_replica3/' [junit4:junit4] 1> INFO - 2013-05-01 07:26:45.394; org.apache.solr.cloud= .ZkController; Load collection config from:/collections/awholynewcollection= _0 [junit4:junit4] 1> INFO - 2013-05-01 07:26:45.394; org.apache.solr.cloud= .ZkController; Load collection config from:/collections/awholynewcollection= _0 [junit4:junit4] 1> INFO - 2013-05-01 07:26:45.393; org.apache.solr.cloud= .ZkController; Load collection config from:/collections/awholynewcollection= _0 [junit4:junit4] 1> INFO - 2013-05-01 07:26:45.393; org.apache.solr.cloud= .ZkController; Load collection config from:/collections/awholynewcollection= _0 [junit4:junit4] 1> INFO - 2013-05-01 07:26:45.392; org.apache.solr.commo= n.cloud.SolrZkClient; makePath: /collections/awholynewcollection_0 [junit4:junit4] 1> INFO - 2013-05-01 07:26:45.395; org.apache.solr.core.= SolrResourceLoader; new SolrResourceLoader for directory: '/usr/home/hudson= /hudson-slave/workspace/Lucene-Solr-Tests-trunk-java7/solr/build/solr-core/= test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty2-1367= 393195983/awholynewcollection_0_shard1_replica2/' [junit4:junit4] 1> INFO - 2013-05-01 07:26:45.397; org.apache.solr.core.= SolrResourceLoader; new SolrResourceLoader for directory: '/usr/home/hudson= /hudson-slave/workspace/Lucene-Solr-Tests-trunk-java7/solr/build/solr-core/= test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty2-1367= 393195983/awholynewcollection_0_shard3_replica1/' [junit4:junit4] 1> INFO - 2013-05-01 07:26:45.397; org.apache.solr.core.= SolrResourceLoader; new SolrResourceLoader for directory: '/usr/home/hudson= /hudson-slave/workspace/Lucene-Solr-Tests-trunk-java7/solr/build/solr-core/= test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1367= 393199177/awholynewcollection_0_shard1_replica3/' [junit4:junit4] 1> INFO - 2013-05-01 07:26:45.398; org.apache.solr.core.= SolrResourceLoader; new SolrResourceLoader for directory: '/usr/home/hudson= /hudson-slave/workspace/Lucene-Solr-Tests-trunk-java7/solr/build/solr-core/= test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty1-1367= 393194339/awholynewcollection_0_shard2_replica1/' [junit4:junit4] 1> INFO - 2013-05-01 07:26:45.398; org.apache.solr.core.= SolrResourceLoader; new SolrResourceLoader for directory: '/usr/home/hudson= /hudson-slave/workspace/Lucene-Solr-Tests-trunk-java7/solr/build/solr-core/= test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty3-1367= 393197576/awholynewcollection_0_shard2_replica2/' [junit4:junit4] 1> INFO - 2013-05-01 07:26:45.398; org.apache.solr.cloud= .ZkController; Load collection config from:/collections/awholynewcollection= _0 [junit4:junit4] 1> INFO - 2013-05-01 07:26:45.401; org.apache.solr.core.= SolrResourceLoader; new SolrResourceLoader for directory: '/usr/home/hudson= /hudson-slave/workspace/Lucene-Solr-Tests-trunk-java7/solr/build/solr-core/= test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1367= 393199177/awholynewcollection_0_shard3_replica2/' [junit4:junit4] 1> INFO - 2013-05-01 07:26:45.513; org.apache.solr.core.= SolrConfig; Using Lucene MatchVersion: LUCENE_50 [junit4:junit4] 1> INFO - 2013-05-01 07:26:45.518; org.apache.solr.core.= SolrConfig; Using Lucene MatchVersion: LUCENE_50 [junit4:junit4] 1> INFO - 2013-05-01 07:26:45.518; org.apache.solr.core.= SolrConfig; Using Lucene MatchVersion: LUCENE_50 [junit4:junit4] 1> INFO - 2013-05-01 07:26:45.518; org.apache.solr.core.= SolrConfig; Using Lucene MatchVersion: LUCENE_50 [junit4:junit4] 1> INFO - 2013-05-01 07:26:45.522; org.apache.solr.core.= SolrConfig; Using Lucene MatchVersion: LUCENE_50 [junit4:junit4] 1> INFO - 2013-05-01 07:26:45.523; org.apache.solr.core.= SolrConfig; Using Lucene MatchVersion: LUCENE_50 [junit4:junit4] 1> INFO - 2013-05-01 07:26:45.525; org.apache.solr.core.= SolrConfig; Using Lucene MatchVersion: LUCENE_50 [junit4:junit4] 1> INFO - 2013-05-01 07:26:45.535; org.apache.solr.core.= SolrConfig; Using Lucene MatchVersion: LUCENE_50 [junit4:junit4] 1> INFO - 2013-05-01 07:26:45.551; org.apache.solr.core.= SolrConfig; Using Lucene MatchVersion: LUCENE_50 [junit4:junit4] 1> INFO - 2013-05-01 07:26:45.613; org.apache.solr.core.= SolrConfig; Loaded SolrConfig: solrconfig.xml [junit4:junit4] 1> INFO - 2013-05-01 07:26:45.619; org.apache.solr.core.= SolrConfig; Loaded SolrConfig: solrconfig.xml [junit4:junit4] 1> INFO - 2013-05-01 07:26:45.620; org.apache.solr.core.= SolrConfig; Loaded SolrConfig: solrconfig.xml [junit4:junit4] 1> INFO - 2013-05-01 07:26:45.621; org.apache.solr.schem= a.IndexSchema; Reading Solr Schema from schema.xml [junit4:junit4] 1> INFO - 2013-05-01 07:26:45.622; org.apache.solr.schem= a.IndexSchema; Reading Solr Schema from schema.xml [junit4:junit4] 1> INFO - 2013-05-01 07:26:45.621; org.apache.solr.core.= SolrConfig; Loaded SolrConfig: solrconfig.xml [junit4:junit4] 1> INFO - 2013-05-01 07:26:45.622; org.apache.solr.core.= SolrConfig; Loaded SolrConfig: solrconfig.xml [junit4:junit4] 1> INFO - 2013-05-01 07:26:45.623; org.apache.solr.schem= a.IndexSchema; Reading Solr Schema from schema.xml [junit4:junit4] 1> INFO - 2013-05-01 07:26:45.624; org.apache.solr.core.= SolrConfig; Loaded SolrConfig: solrconfig.xml [junit4:junit4] 1> INFO - 2013-05-01 07:26:45.624; org.apache.solr.schem= a.IndexSchema; Reading Solr Schema from schema.xml [junit4:junit4] 1> INFO - 2013-05-01 07:26:45.631; org.apache.solr.schem= a.IndexSchema; Schema name=3Dtest [junit4:junit4] 1> INFO - 2013-05-01 07:26:45.633; org.apache.solr.core.= SolrConfig; Loaded SolrConfig: solrconfig.xml [junit4:junit4] 1> INFO - 2013-05-01 07:26:45.633; org.apache.solr.schem= a.IndexSchema; Schema name=3Dtest [junit4:junit4] 1> INFO - 2013-05-01 07:26:45.634; org.apache.solr.schem= a.IndexSchema; Reading Solr Schema from schema.xml [junit4:junit4] 1> INFO - 2013-05-01 07:26:45.634; org.apache.solr.schem= a.IndexSchema; Schema name=3Dtest [junit4:junit4] 1> INFO - 2013-05-01 07:26:45.635; org.apache.solr.schem= a.IndexSchema; Reading Solr Schema from schema.xml [junit4:junit4] 1> INFO - 2013-05-01 07:26:45.636; org.apache.solr.schem= a.IndexSchema; Schema name=3Dtest [junit4:junit4] 1> INFO - 2013-05-01 07:26:45.643; org.apache.solr.schem= a.IndexSchema; Schema name=3Dtest [junit4:junit4] 1> INFO - 2013-05-01 07:26:45.644; org.apache.solr.schem= a.IndexSchema; Schema name=3Dtest [junit4:junit4] 1> INFO - 2013-05-01 07:26:45.652; org.apache.solr.core.= SolrConfig; Loaded SolrConfig: solrconfig.xml [junit4:junit4] 1> INFO - 2013-05-01 07:26:45.672; org.apache.solr.core.= SolrConfig; Loaded SolrConfig: solrconfig.xml [junit4:junit4] 1> INFO - 2013-05-01 07:26:45.673; org.apache.solr.schem= a.IndexSchema; Reading Solr Schema from schema.xml [junit4:junit4] 1> INFO - 2013-05-01 07:26:45.674; org.apache.solr.schem= a.IndexSchema; Reading Solr Schema from schema.xml [junit4:junit4] 1> INFO - 2013-05-01 07:26:45.686; org.apache.solr.schem= a.IndexSchema; Schema name=3Dtest [junit4:junit4] 1> INFO - 2013-05-01 07:26:45.687; org.apache.solr.schem= a.IndexSchema; Schema name=3Dtest [junit4:junit4] 1> INFO - 2013-05-01 07:26:45.724; org.apache.solr.schem= a.IndexSchema; Reading Solr Schema from schema.xml [junit4:junit4] 1> INFO - 2013-05-01 07:26:45.755; org.apache.solr.schem= a.IndexSchema; Schema name=3Dtest [junit4:junit4] 1> INFO - 2013-05-01 07:26:46.558; org.apache.solr.commo= n.cloud.ZkStateReader; Updating cloud state from ZooKeeper...=20 [junit4:junit4] 1> INFO - 2013-05-01 07:26:46.559; 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:22540_wyc%2Frw_nodes_use= d_collection_shard2_replica2", [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_replica2", [junit4:junit4] 1> "collection":"nodes_used_collection", [junit4:junit4] 1> "shard_range":null, [junit4:junit4] 1> "node_name":"127.0.0.1:22540_wyc%2Frw", [junit4:junit4] 1> "base_url":"http://127.0.0.1:22540/wyc/rw"} [junit4:junit4] 1> INFO - 2013-05-01 07:26:46.566; 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:62715_wyc%2Frw_nodes_use= d_collection_shard1_replica1", [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_replica1", [junit4:junit4] 1> "collection":"nodes_used_collection", [junit4:junit4] 1> "shard_range":null, [junit4:junit4] 1> "node_name":"127.0.0.1:62715_wyc%2Frw", [junit4:junit4] 1> "base_url":"http://127.0.0.1:62715/wyc/rw"} [junit4:junit4] 1> INFO - 2013-05-01 07:26:46.577; 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:33541_wyc%2Frw_nodes_use= d_collection_shard1_replica2", [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_replica2", [junit4:junit4] 1> "collection":"nodes_used_collection", [junit4:junit4] 1> "shard_range":null, [junit4:junit4] 1> "node_name":"127.0.0.1:33541_wyc%2Frw", [junit4:junit4] 1> "base_url":"http://127.0.0.1:33541/wyc/rw"} [junit4:junit4] 1> INFO - 2013-05-01 07:26:46.584; 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:48327_wyc%2Frw_nodes_use= d_collection_shard2_replica1", [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_replica1", [junit4:junit4] 1> "collection":"nodes_used_collection", [junit4:junit4] 1> "shard_range":null, [junit4:junit4] 1> "node_name":"127.0.0.1:48327_wyc%2Frw", [junit4:junit4] 1> "base_url":"http://127.0.0.1:48327/wyc/rw"} [junit4:junit4] 1> INFO - 2013-05-01 07:26:46.597; 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-05-01 07:26:46.597; 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-05-01 07:26:46.597; 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-05-01 07:26:46.597; 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-05-01 07:26:46.597; 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-05-01 07:26:46.597; 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-05-01 07:26:46.597; 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-05-01 07:26:46.597; 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-05-01 07:26:46.757; org.apache.solr.schem= a.OpenExchangeRatesOrgProvider; Initialized with rates=3Dopen-exchange-rate= s.json, refreshInterval=3D1440. [junit4:junit4] 1> INFO - 2013-05-01 07:26:46.766; org.apache.solr.schem= a.OpenExchangeRatesOrgProvider; Initialized with rates=3Dopen-exchange-rate= s.json, refreshInterval=3D1440. [junit4:junit4] 1> INFO - 2013-05-01 07:26:46.767; org.apache.solr.schem= a.OpenExchangeRatesOrgProvider; Initialized with rates=3Dopen-exchange-rate= s.json, refreshInterval=3D1440. [junit4:junit4] 1> INFO - 2013-05-01 07:26:46.773; org.apache.solr.schem= a.IndexSchema; default search field in schema is text [junit4:junit4] 1> INFO - 2013-05-01 07:26:46.773; org.apache.solr.schem= a.OpenExchangeRatesOrgProvider; Initialized with rates=3Dopen-exchange-rate= s.json, refreshInterval=3D1440. [junit4:junit4] 1> INFO - 2013-05-01 07:26:46.778; org.apache.solr.schem= a.IndexSchema; default search field in schema is text [junit4:junit4] 1> INFO - 2013-05-01 07:26:46.778; org.apache.solr.schem= a.IndexSchema; unique key field: id [junit4:junit4] 1> INFO - 2013-05-01 07:26:46.782; org.apache.solr.schem= a.IndexSchema; default search field in schema is text [junit4:junit4] 1> INFO - 2013-05-01 07:26:46.784; org.apache.solr.schem= a.IndexSchema; unique key field: id [junit4:junit4] 1> INFO - 2013-05-01 07:26:46.784; org.apache.solr.schem= a.IndexSchema; default search field in schema is text [junit4:junit4] 1> INFO - 2013-05-01 07:26:46.790; org.apache.solr.schem= a.IndexSchema; unique key field: id [junit4:junit4] 1> INFO - 2013-05-01 07:26:46.790; org.apache.solr.schem= a.IndexSchema; unique key field: id [junit4:junit4] 1> INFO - 2013-05-01 07:26:46.796; org.apache.solr.schem= a.OpenExchangeRatesOrgProvider; Initialized with rates=3Dopen-exchange-rate= s.json, refreshInterval=3D1440. [junit4:junit4] 1> INFO - 2013-05-01 07:26:46.799; org.apache.solr.schem= a.FileExchangeRateProvider; Reloading exchange rates from file currency.xml [junit4:junit4] 1> INFO - 2013-05-01 07:26:46.804; org.apache.solr.schem= a.FileExchangeRateProvider; Reloading exchange rates from file currency.xml [junit4:junit4] 1> INFO - 2013-05-01 07:26:46.808; org.apache.solr.schem= a.FileExchangeRateProvider; Reloading exchange rates from file currency.xml [junit4:junit4] 1> INFO - 2013-05-01 07:26:46.810; org.apache.solr.schem= a.IndexSchema; default search field in schema is text [junit4:junit4] 1> INFO - 2013-05-01 07:26:46.811; org.apache.solr.schem= a.FileExchangeRateProvider; Reloading exchange rates from file currency.xml [junit4:junit4] 1> INFO - 2013-05-01 07:26:46.811; org.apache.solr.schem= a.FileExchangeRateProvider; Reloading exchange rates from file currency.xml [junit4:junit4] 1> INFO - 2013-05-01 07:26:46.814; org.apache.solr.schem= a.FileExchangeRateProvider; Reloading exchange rates from file currency.xml [junit4:junit4] 1> INFO - 2013-05-01 07:26:46.816; org.apache.solr.schem= a.IndexSchema; unique key field: id [junit4:junit4] 1> INFO - 2013-05-01 07:26:46.817; org.apache.solr.schem= a.OpenExchangeRatesOrgProvider; Reloading exchange rates from open-exchange= -rates.json [junit4:junit4] 1> INFO - 2013-05-01 07:26:46.818; org.apache.solr.schem= a.OpenExchangeRatesOrgProvider; Initialized with rates=3Dopen-exchange-rate= s.json, refreshInterval=3D1440. [junit4:junit4] 1> INFO - 2013-05-01 07:26:46.818; org.apache.solr.schem= a.OpenExchangeRatesOrgProvider; Reloading exchange rates from open-exchange= -rates.json [junit4:junit4] 1> WARN - 2013-05-01 07:26:46.819; org.apache.solr.schem= a.OpenExchangeRatesOrgProvider$OpenExchangeRates; Unknown key IMPORTANT NOT= E [junit4:junit4] 1> INFO - 2013-05-01 07:26:46.818; org.apache.solr.schem= a.FileExchangeRateProvider; Reloading exchange rates from file currency.xml [junit4:junit4] 1> WARN - 2013-05-01 07:26:46.820; org.apache.solr.schem= a.OpenExchangeRatesOrgProvider$OpenExchangeRates; Expected key, got STRING [junit4:junit4] 1> WARN - 2013-05-01 07:26:46.820; org.apache.solr.schem= a.OpenExchangeRatesOrgProvider$OpenExchangeRates; Unknown key IMPORTANT NOT= E [junit4:junit4] 1> WARN - 2013-05-01 07:26:46.822; org.apache.solr.schem= a.OpenExchangeRatesOrgProvider$OpenExchangeRates; Expected key, got STRING [junit4:junit4] 1> INFO - 2013-05-01 07:26:46.821; org.apache.solr.schem= a.OpenExchangeRatesOrgProvider; Reloading exchange rates from open-exchange= -rates.json [junit4:junit4] 1> INFO - 2013-05-01 07:26:46.823; org.apache.solr.schem= a.FileExchangeRateProvider; Reloading exchange rates from file currency.xml [junit4:junit4] 1> INFO - 2013-05-01 07:26:46.822; org.apache.solr.schem= a.OpenExchangeRatesOrgProvider; Reloading exchange rates from open-exchange= -rates.json [junit4:junit4] 1> WARN - 2013-05-01 07:26:46.824; org.apache.solr.schem= a.OpenExchangeRatesOrgProvider$OpenExchangeRates; Unknown key IMPORTANT NOT= E [junit4:junit4] 1> WARN - 2013-05-01 07:26:46.824; org.apache.solr.schem= a.OpenExchangeRatesOrgProvider$OpenExchangeRates; Expected key, got STRING [junit4:junit4] 1> WARN - 2013-05-01 07:26:46.825; org.apache.solr.schem= a.OpenExchangeRatesOrgProvider$OpenExchangeRates; Unknown key IMPORTANT NOT= E [junit4:junit4] 1> INFO - 2013-05-01 07:26:46.825; org.apache.solr.core.= SolrCore; org.apache.solr.core.MockDirectoryFactory [junit4:junit4] 1> WARN - 2013-05-01 07:26:46.825; org.apache.solr.schem= a.OpenExchangeRatesOrgProvider$OpenExchangeRates; Expected key, got STRING [junit4:junit4] 1> INFO - 2013-05-01 07:26:46.826; org.apache.solr.core.= SolrCore; [awholynewcollection_0_shard3_replica3] Opening new SolrCore at /= usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-java7/solr/b= uild/solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkT= est-jetty1-1367393194339/awholynewcollection_0_shard3_replica3/, dataDir=3D= /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-java7/solr/= build/solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZk= Test-jetty1-1367393194339/awholynewcollection_0_shard3_replica3/data/ [junit4:junit4] 1> INFO - 2013-05-01 07:26:46.827; org.apache.solr.schem= a.OpenExchangeRatesOrgProvider; Reloading exchange rates from open-exchange= -rates.json [junit4:junit4] 1> INFO - 2013-05-01 07:26:46.826; org.apache.solr.core.= SolrCore; org.apache.solr.core.MockDirectoryFactory [junit4:junit4] 1> INFO - 2013-05-01 07:26:46.827; org.apache.solr.core.= JmxMonitoredMap; JMX monitoring is enabled. Adding Solr mbeans to JMX Serve= r: com.sun.jmx.mbeanserver.JmxMBeanServer@342371e7 [junit4:junit4] 1> INFO - 2013-05-01 07:26:46.828; org.apache.solr.core.= SolrCore; [awholynewcollection_0_shard3_replica2] Opening new SolrCore at /= usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-java7/solr/b= uild/solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkT= est-jetty4-1367393199177/awholynewcollection_0_shard3_replica2/, dataDir=3D= /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-java7/solr/= build/solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZk= Test-jetty4-1367393199177/awholynewcollection_0_shard3_replica2/data/ [junit4:junit4] 1> INFO - 2013-05-01 07:26:46.829; org.apache.solr.core.= SolrCore; org.apache.solr.core.MockDirectoryFactory [junit4:junit4] 1> WARN - 2013-05-01 07:26:46.829; org.apache.solr.schem= a.OpenExchangeRatesOrgProvider$OpenExchangeRates; Unknown key IMPORTANT NOT= E [junit4:junit4] 1> INFO - 2013-05-01 07:26:46.830; org.apache.solr.core.= CachingDirectoryFactory; return new directory for /usr/home/hudson/hudson-s= lave/workspace/Lucene-Solr-Tests-trunk-java7/solr/build/solr-core/test/J1/.= /org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty1-1367393194339= /awholynewcollection_0_shard3_replica3/data [junit4:junit4] 1> WARN - 2013-05-01 07:26:46.830; org.apache.solr.schem= a.OpenExchangeRatesOrgProvider$OpenExchangeRates; Expected key, got STRING [junit4:junit4] 1> INFO - 2013-05-01 07:26:46.829; org.apache.solr.core.= JmxMonitoredMap; JMX monitoring is enabled. Adding Solr mbeans to JMX Serve= r: com.sun.jmx.mbeanserver.JmxMBeanServer@342371e7 [junit4:junit4] 1> INFO - 2013-05-01 07:26:46.831; org.apache.solr.schem= a.OpenExchangeRatesOrgProvider; Reloading exchange rates from open-exchange= -rates.json [junit4:junit4] 1> INFO - 2013-05-01 07:26:46.831; org.apache.solr.schem= a.OpenExchangeRatesOrgProvider; Reloading exchange rates from open-exchange= -rates.json [junit4:junit4] 1> INFO - 2013-05-01 07:26:46.831; org.apache.solr.core.= SolrCore; New index directory detected: old=3Dnull new=3D/usr/home/hudson/h= udson-slave/workspace/Lucene-Solr-Tests-trunk-java7/solr/build/solr-core/te= st/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty1-136739= 3194339/awholynewcollection_0_shard3_replica3/data/index/ [junit4:junit4] 1> INFO - 2013-05-01 07:26:46.832; org.apache.solr.schem= a.IndexSchema; default search field in schema is text [junit4:junit4] 1> INFO - 2013-05-01 07:26:46.832; org.apache.solr.core.= SolrCore; org.apache.solr.core.MockDirectoryFactory [junit4:junit4] 1> WARN - 2013-05-01 07:26:46.834; org.apache.solr.schem= a.OpenExchangeRatesOrgProvider$OpenExchangeRates; Unknown key IMPORTANT NOT= E [junit4:junit4] 1> INFO - 2013-05-01 07:26:46.835; org.apache.solr.core.= CachingDirectoryFactory; return new directory for /usr/home/hudson/hudson-s= lave/workspace/Lucene-Solr-Tests-trunk-java7/solr/build/solr-core/test/J1/.= /org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1367393199177= /awholynewcollection_0_shard3_replica2/data [junit4:junit4] 1> WARN - 2013-05-01 07:26:46.834; org.apache.solr.core.= SolrCore; [awholynewcollection_0_shard3_replica3] Solr index directory '/us= r/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-java7/solr/bui= ld/solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTes= t-jetty1-1367393194339/awholynewcollection_0_shard3_replica3/data/index' do= esn't exist. Creating new index... [junit4:junit4] 1> WARN - 2013-05-01 07:26:46.834; org.apache.solr.schem= a.OpenExchangeRatesOrgProvider$OpenExchangeRates; Unknown key IMPORTANT NOT= E [junit4:junit4] 1> INFO - 2013-05-01 07:26:46.837; org.apache.solr.core.= CachingDirectoryFactory; return new directory for /usr/home/hudson/hudson-s= lave/workspace/Lucene-Solr-Tests-trunk-java7/solr/build/solr-core/test/J1/.= /org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty1-1367393194339= /awholynewcollection_0_shard3_replica3/data/index [junit4:junit4] 1> INFO - 2013-05-01 07:26:46.836; org.apache.solr.core.= SolrCore; New index directory detected: old=3Dnull new=3D/usr/home/hudson/h= udson-slave/workspace/Lucene-Solr-Tests-trunk-java7/solr/build/solr-core/te= st/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-136739= 3199177/awholynewcollection_0_shard3_replica2/data/index/ [junit4:junit4] 1> WARN - 2013-05-01 07:26:46.836; org.apache.solr.schem= a.OpenExchangeRatesOrgProvider$OpenExchangeRates; Expected key, got STRING [junit4:junit4] 1> INFO - 2013-05-01 07:26:46.835; org.apache.solr.schem= a.FileExchangeRateProvider; Reloading exchange rates from file currency.xml [junit4:junit4] 1> INFO - 2013-05-01 07:26:46.839; org.apache.solr.schem= a.OpenExchangeRatesOrgProvider; Reloading exchange rates from open-exchange= -rates.json [junit4:junit4] 1> WARN - 2013-05-01 07:26:46.838; org.apache.solr.core.= SolrCore; [awholynewcollection_0_shard3_replica2] Solr index directory '/us= r/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-java7/solr/bui= ld/solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTes= t-jetty4-1367393199177/awholynewcollection_0_shard3_replica2/data/index' do= esn't exist. Creating new index... [junit4:junit4] 1> INFO - 2013-05-01 07:26:46.841; org.apache.solr.schem= a.IndexSchema; unique key field: id [junit4:junit4] 1> WARN - 2013-05-01 07:26:46.837; org.apache.solr.schem= a.OpenExchangeRatesOrgProvider$OpenExchangeRates; Expected key, got STRING [junit4:junit4] 1> WARN - 2013-05-01 07:26:46.841; org.apache.solr.schem= a.OpenExchangeRatesOrgProvider$OpenExchangeRates; Unknown key IMPORTANT NOT= E [junit4:junit4] 1> WARN - 2013-05-01 07:26:46.843; org.apache.solr.schem= a.OpenExchangeRatesOrgProvider$OpenExchangeRates; Expected key, got STRING [junit4:junit4] 1> INFO - 2013-05-01 07:26:46.841; org.apache.solr.core.= CachingDirectoryFactory; return new directory for /usr/home/hudson/hudson-s= lave/workspace/Lucene-Solr-Tests-trunk-java7/solr/build/solr-core/test/J1/.= /org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1367393199177= /awholynewcollection_0_shard3_replica2/data/index [junit4:junit4] 1> INFO - 2013-05-01 07:26:46.843; org.apache.solr.schem= a.OpenExchangeRatesOrgProvider; Initialized with rates=3Dopen-exchange-rate= s.json, refreshInterval=3D1440. [junit4:junit4] 1> INFO - 2013-05-01 07:26:46.843; org.apache.solr.core.= SolrCore; org.apache.solr.core.MockDirectoryFactory [junit4:junit4] 1> INFO - 2013-05-01 07:26:46.843; org.apache.solr.core.= SolrDeletionPolicy; SolrDeletionPolicy.onCommit: commits: num=3D1 [junit4:junit4] 1> =09commit{dir=3DMockDirWrapper(org.apache.lucene.store= .RAMDirectory@268a6a56 lockFactory=3Dorg.apache.lucene.store.NativeFSLockFa= ctory@b5f0896),segFN=3Dsegments_1,generation=3D1} [junit4:junit4] 1> INFO - 2013-05-01 07:26:46.842; org.apache.solr.core.= SolrCore; org.apache.solr.core.MockDirectoryFactory [junit4:junit4] 1> INFO - 2013-05-01 07:26:46.846; org.apache.solr.schem= a.FileExchangeRateProvider; Reloading exchange rates from file currency.xml [junit4:junit4] 1> INFO - 2013-05-01 07:26:46.846; org.apache.solr.core.= SolrDeletionPolicy; newest commit generation =3D 1 [junit4:junit4] 1> INFO - 2013-05-01 07:26:46.845; org.apache.solr.core.= SolrCore; [awholynewcollection_0_shard3_replica1] Opening new SolrCore at /= usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-java7/solr/b= uild/solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkT= est-jetty2-1367393195983/awholynewcollection_0_shard3_replica1/, dataDir=3D= /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-java7/solr/= build/solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZk= Test-jetty2-1367393195983/awholynewcollection_0_shard3_replica1/data/ [junit4:junit4] 1> INFO - 2013-05-01 07:26:46.846; org.apache.solr.core.= SolrCore; [awholynewcollection_0_shard2_replica1] Opening new SolrCore at /= usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-java7/solr/b= uild/solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkT= est-jetty1-1367393194339/awholynewcollection_0_shard2_replica1/, dataDir=3D= /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-java7/solr/= build/solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZk= Test-jetty1-1367393194339/awholynewcollection_0_shard2_replica1/data/ [junit4:junit4] 1> INFO - 2013-05-01 07:26:46.848; org.apache.solr.core.= SolrDeletionPolicy; SolrDeletionPolicy.onCommit: commits: num=3D1 [junit4:junit4] 1> =09commit{dir=3DMockDirWrapper(org.apache.lucene.store= .RAMDirectory@4b4bfa67 lockFactory=3Dorg.apache.lucene.store.NativeFSLockFa= ctory@382a7d6a),segFN=3Dsegments_1,generation=3D1} [junit4:junit4] 1> INFO - 2013-05-01 07:26:46.849; org.apache.solr.core.= SolrDeletionPolicy; newest commit generation =3D 1 [junit4:junit4] 1> INFO - 2013-05-01 07:26:46.848; org.apache.solr.core.= JmxMonitoredMap; JMX monitoring is enabled. Adding Solr mbeans to JMX Serve= r: com.sun.jmx.mbeanserver.JmxMBeanServer@342371e7 [junit4:junit4] 1> INFO - 2013-05-01 07:26:46.849; org.apache.solr.core.= JmxMonitoredMap; JMX monitoring is enabled. Adding Solr mbeans to JMX Serve= r: com.sun.jmx.mbeanserver.JmxMBeanServer@342371e7 [junit4:junit4] 1> INFO - 2013-05-01 07:26:46.851; org.apache.solr.core.= SolrCore; org.apache.solr.core.MockDirectoryFactory [junit4:junit4] 1> INFO - 2013-05-01 07:26:46.851; org.apache.solr.core.= SolrCore; org.apache.solr.core.MockDirectoryFactory [junit4:junit4] 1> INFO - 2013-05-01 07:26:46.850; org.apache.solr.updat= e.processor.UpdateRequestProcessorChain; inserting DistributedUpdateProcess= orFactory into updateRequestProcessorChain "dedupe" [junit4:junit4] 1> INFO - 2013-05-01 07:26:46.852; org.apache.solr.updat= e.processor.UpdateRequestProcessorChain; inserting DistributedUpdateProcess= orFactory into updateRequestProcessorChain "stored_sig" [junit4:junit4] 1> INFO - 2013-05-01 07:26:46.852; org.apache.solr.core.= CachingDirectoryFactory; return new directory for /usr/home/hudson/hudson-s= lave/workspace/Lucene-Solr-Tests-trunk-java7/solr/build/solr-core/test/J1/.= /org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty1-1367393194339= /awholynewcollection_0_shard2_replica1/data [junit4:junit4] 1> INFO - 2013-05-01 07:26:46.853; org.apache.solr.updat= e.processor.UpdateRequestProcessorChain; inserting DistributedUpdateProcess= orFactory into updateRequestProcessorChain "dedupe" [junit4:junit4] 1> INFO - 2013-05-01 07:26:46.852; org.apache.solr.core.= CachingDirectoryFactory; return new directory for /usr/home/hudson/hudson-s= lave/workspace/Lucene-Solr-Tests-trunk-java7/solr/build/solr-core/test/J1/.= /org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty2-1367393195983= /awholynewcollection_0_shard3_replica1/data [junit4:junit4] 1> INFO - 2013-05-01 07:26:46.854; org.apache.solr.updat= e.processor.UpdateRequestProcessorChain; inserting DistributedUpdateProcess= orFactory into updateRequestProcessorChain "stored_sig" [junit4:junit4] 1> INFO - 2013-05-01 07:26:46.853; org.apache.solr.core.= SolrCore; New index directory detected: old=3Dnull new=3D/usr/home/hudson/h= udson-slave/workspace/Lucene-Solr-Tests-trunk-java7/solr/build/solr-core/te= st/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty1-136739= 3194339/awholynewcollection_0_shard2_replica1/data/index/ [junit4:junit4] 1> INFO - 2013-05-01 07:26:46.855; org.apache.solr.updat= e.processor.UpdateRequestProcessorChain; inserting DistributedUpdateProcess= orFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit= " [junit4:junit4] 1> INFO - 2013-05-01 07:26:46.853; org.apache.solr.updat= e.processor.UpdateRequestProcessorChain; inserting DistributedUpdateProcess= orFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit= " [junit4:junit4] 1> INFO - 2013-05-01 07:26:46.856; org.apache.solr.core.= RequestHandlers; created standard: solr.StandardRequestHandler [junit4:junit4] 1> WARN - 2013-05-01 07:26:46.855; org.apache.solr.core.= SolrCore; [awholynewcollection_0_shard2_replica1] Solr index directory '/us= r/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-java7/solr/bui= ld/solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTes= t-jetty1-1367393194339/awholynewcollection_0_shard2_replica1/data/index' do= esn't exist. Creating new index... [junit4:junit4] 1> INFO - 2013-05-01 07:26:46.854; org.apache.solr.core.= SolrCore; New index directory detected: old=3Dnull new=3D/usr/home/hudson/h= udson-slave/workspace/Lucene-Solr-Tests-trunk-java7/solr/build/solr-core/te= st/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty2-136739= 3195983/awholynewcollection_0_shard3_replica1/data/index/ [junit4:junit4] 1> INFO - 2013-05-01 07:26:46.857; org.apache.solr.core.= CachingDirectoryFactory; return new directory for /usr/home/hudson/hudson-s= lave/workspace/Lucene-Solr-Tests-trunk-java7/solr/build/solr-core/test/J1/.= /org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty1-1367393194339= /awholynewcollection_0_shard2_replica1/data/index [junit4:junit4] 1> INFO - 2013-05-01 07:26:46.857; org.apache.solr.core.= RequestHandlers; created /get: solr.RealTimeGetHandler [junit4:junit4] 1> INFO - 2013-05-01 07:26:46.856; org.apache.solr.core.= RequestHandlers; created standard: solr.StandardRequestHandler [junit4:junit4] 1> INFO - 2013-05-01 07:26:46.859; org.apache.solr.core.= RequestHandlers; adding lazy requestHandler: solr.ReplicationHandler [junit4:junit4] 1> WARN - 2013-05-01 07:26:46.858; org.apache.solr.core.= SolrCore; [awholynewcollection_0_shard3_replica1] Solr index directory '/us= r/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-java7/solr/bui= ld/solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTes= t-jetty2-1367393195983/awholynewcollection_0_shard3_replica1/data/index' do= esn't exist. Creating new index... [junit4:junit4] 1> INFO - 2013-05-01 07:26:46.859; org.apache.solr.core.= RequestHandlers; created /replication: solr.ReplicationHandler [junit4:junit4] 1> INFO - 2013-05-01 07:26:46.859; org.apache.solr.core.= RequestHandlers; created /get: solr.RealTimeGetHandler [junit4:junit4] 1> INFO - 2013-05-01 07:26:46.861; org.apache.solr.core.= RequestHandlers; created /update: solr.UpdateRequestHandler [junit4:junit4] 1> INFO - 2013-05-01 07:26:46.861; org.apache.solr.core.= CachingDirectoryFactory; return new directory for /usr/home/hudson/hudson-s= lave/workspace/Lucene-Solr-Tests-trunk-java7/solr/build/solr-core/test/J1/.= /org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty2-1367393195983= /awholynewcollection_0_shard3_replica1/data/index [junit4:junit4] 1> INFO - 2013-05-01 07:26:46.862; org.apache.solr.core.= RequestHandlers; created /admin/: org.apache.solr.handler.admin.AdminHandle= rs [junit4:junit4] 1> INFO - 2013-05-01 07:26:46.861; org.apache.solr.core.= RequestHandlers; adding lazy requestHandler: solr.ReplicationHandler [junit4:junit4] 1> INFO - 2013-05-01 07:26:46.863; org.apache.solr.core.= RequestHandlers; created /replication: solr.ReplicationHandler [junit4:junit4] 1> INFO - 2013-05-01 07:26:46.863; org.apache.solr.core.= SolrDeletionPolicy; SolrDeletionPolicy.onCommit: commits: num=3D1 [junit4:junit4] 1> =09commit{dir=3DMockDirWrapper(org.apache.lucene.store= .RAMDirectory@5a28e3d5 lockFactory=3Dorg.apache.lucene.store.NativeFSLockFa= ctory@671f46a2),segFN=3Dsegments_1,generation=3D1} [junit4:junit4] 1> INFO - 2013-05-01 07:26:46.864; org.apache.solr.core.= RequestHandlers; created /update: solr.UpdateRequestHandler [junit4:junit4] 1> INFO - 2013-05-01 07:26:46.864; org.apache.solr.schem= a.IndexSchema; default search field in schema is text [junit4:junit4] 1> INFO - 2013-05-01 07:26:46.864; org.apache.solr.core.= SolrDeletionPolicy; newest commit generation =3D 1 [junit4:junit4] 1> INFO - 2013-05-01 07:26:46.865; org.apache.solr.core.= RequestHandlers; created /admin/: org.apache.solr.handler.admin.AdminHandle= rs [junit4:junit4] 1> INFO - 2013-05-01 07:26:46.869; org.apache.solr.updat= e.processor.UpdateRequestProcessorChain; inserting DistributedUpdateProcess= orFactory into updateRequestProcessorChain "dedupe" [junit4:junit4] 1> INFO - 2013-05-01 07:26:46.870; org.apache.solr.updat= e.processor.UpdateRequestProcessorChain; inserting DistributedUpdateProcess= orFactory into updateRequestProcessorChain "stored_sig" [junit4:junit4] 1> INFO - 2013-05-01 07:26:46.871; org.apache.solr.updat= e.processor.UpdateRequestProcessorChain; inserting DistributedUpdateProcess= orFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit= " [junit4:junit4] 1> INFO - 2013-05-01 07:26:46.871; org.apache.solr.core.= SolrDeletionPolicy; SolrDeletionPolicy.onCommit: commits: num=3D1 [junit4:junit4] 1> =09commit{dir=3DMockDirWrapper(org.apache.lucene.store= .RAMDirectory@3647369c lockFactory=3Dorg.apache.lucene.store.NativeFSLockFa= ctory@d95664d),segFN=3Dsegments_1,generation=3D1} [junit4:junit4] 1> INFO - 2013-05-01 07:26:46.871; org.apache.solr.core.= RequestHandlers; created standard: solr.StandardRequestHandler [junit4:junit4] 1> INFO - 2013-05-01 07:26:46.872; org.apache.solr.schem= a.OpenExchangeRatesOrgProvider; Initialized with rates=3Dopen-exchange-rate= s.json, refreshInterval=3D1440. [junit4:junit4] 1> INFO - 2013-05-01 07:26:46.872; org.apache.solr.core.= SolrDeletionPolicy; newest commit generation =3D 1 [junit4:junit4] 1> INFO - 2013-05-01 07:26:46.873; org.apache.solr.core.= RequestHandlers; created /get: solr.RealTimeGetHandler [junit4:junit4] 1> INFO - 2013-05-01 07:26:46.874; org.apache.solr.core.= RequestHandlers; adding lazy requestHandler: solr.ReplicationHandler [junit4:junit4] 1> INFO - 2013-05-01 07:26:46.875; org.apache.solr.core.= RequestHandlers; created /replication: solr.ReplicationHandler [junit4:junit4] 1> INFO - 2013-05-01 07:26:46.875; org.apache.solr.core.= RequestHandlers; created /update: solr.UpdateRequestHandler [junit4:junit4] 1> INFO - 2013-05-01 07:26:46.876; org.apache.solr.core.= RequestHandlers; created /admin/: org.apache.solr.handler.admin.AdminHandle= rs [junit4:junit4] 1> INFO - 2013-05-01 07:26:46.878; org.apache.solr.updat= e.processor.UpdateRequestProcessorChain; inserting DistributedUpdateProcess= orFactory into updateRequestProcessorChain "dedupe" [junit4:junit4] 1> INFO - 2013-05-01 07:26:46.879; org.apache.solr.updat= e.processor.UpdateRequestProcessorChain; inserting DistributedUpdateProcess= orFactory into updateRequestProcessorChain "stored_sig" [junit4:junit4] 1> INFO - 2013-05-01 07:26:46.880; org.apache.solr.updat= e.processor.UpdateRequestProcessorChain; inserting DistributedUpdateProcess= orFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit= " [junit4:junit4] 1> INFO - 2013-05-01 07:26:46.881; org.apache.solr.schem= a.IndexSchema; unique key field: id [junit4:junit4] 1> INFO - 2013-05-01 07:26:46.882; org.apache.solr.schem= a.FileExchangeRateProvider; Reloading exchange rates from file currency.xml [junit4:junit4] 1> INFO - 2013-05-01 07:26:46.882; org.apache.solr.core.= RequestHandlers; created standard: solr.StandardRequestHandler [junit4:junit4] 1> INFO - 2013-05-01 07:26:46.881; org.apache.solr.schem= a.OpenExchangeRatesOrgProvider; Reloading exchange rates from open-exchange= -rates.json [junit4:junit4] 1> INFO - 2013-05-01 07:26:46.884; org.apache.solr.core.= RequestHandlers; created /get: solr.RealTimeGetHandler [junit4:junit4] 1> INFO - 2013-05-01 07:26:46.884; org.apache.solr.core.= RequestHandlers; adding lazy requestHandler: solr.ReplicationHandler [junit4:junit4] 1> INFO - 2013-05-01 07:26:46.885; org.apache.solr.schem= a.OpenExchangeRatesOrgProvider; Initialized with rates=3Dopen-exchange-rate= s.json, refreshInterval=3D1440. [junit4:junit4] 1> INFO - 2013-05-01 07:26:46.885; org.apache.solr.core.= RequestHandlers; created /replication: solr.ReplicationHandler [junit4:junit4] 1> WARN - 2013-05-01 07:26:46.885; org.apache.solr.schem= a.OpenExchangeRatesOrgProvider$OpenExchangeRates; Unknown key IMPORTANT NOT= E [junit4:junit4] 1> INFO - 2013-05-01 07:26:46.886; org.apache.solr.core.= RequestHandlers; created /update: solr.UpdateRequestHandler [junit4:junit4] 1> WARN - 2013-05-01 07:26:46.886; org.apache.solr.schem= a.OpenExchangeRatesOrgProvider$OpenExchangeRates; Expected key, got STRING [junit4:junit4] 1> INFO - 2013-05-01 07:26:46.887; org.apache.solr.core.= RequestHandlers; created /admin/: org.apache.solr.handler.admin.AdminHandle= rs [junit4:junit4] 1> INFO - 2013-05-01 07:26:46.888; org.apache.solr.schem= a.OpenExchangeRatesOrgProvider; Reloading exchange rates from open-exchange= -rates.json [junit4:junit4] 1> WARN - 2013-05-01 07:26:46.890; org.apache.solr.schem= a.OpenExchangeRatesOrgProvider$OpenExchangeRates; Unknown key IMPORTANT NOT= E [junit4:junit4] 1> WARN - 2013-05-01 07:26:46.891; org.apache.solr.schem= a.OpenExchangeRatesOrgProvider$OpenExchangeRates; Expected key, got STRING [junit4:junit4] 1> INFO - 2013-05-01 07:26:46.892; org.apache.solr.core.= SolrCore; org.apache.solr.core.MockDirectoryFactory [junit4:junit4] 1> INFO - 2013-05-01 07:26:46.892; org.apache.solr.handl= er.loader.XMLLoader; xsltCacheLifetimeSeconds=3D60 [junit4:junit4] 1> INFO - 2013-05-01 07:26:46.892; org.apache.solr.core.= SolrCore; [awholynewcollection_0_shard1_replica1] Opening new SolrCore at /= usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-java7/solr/b= uild/solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkT= est-controljetty-1367393193679/awholynewcollection_0_shard1_replica1/, data= Dir=3D/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-java7= /solr/build/solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistrib= utedZkTest-controljetty-1367393193679/awholynewcollection_0_shard1_replica1= /data/ [junit4:junit4] 1> INFO - 2013-05-01 07:26:46.892; org.apache.solr.handl= er.loader.XMLLoader; xsltCacheLifetimeSeconds=3D60 [junit4:junit4] 1> INFO - 2013-05-01 07:26:46.893; org.apache.solr.handl= er.loader.XMLLoader; xsltCacheLifetimeSeconds=3D60 [junit4:junit4] 1> INFO - 2013-05-01 07:26:46.893; org.apache.solr.core.= JmxMonitoredMap; JMX monitoring is enabled. Adding Solr mbeans to JMX Serve= r: com.sun.jmx.mbeanserver.JmxMBeanServer@342371e7 [junit4:junit4] 1> INFO - 2013-05-01 07:26:46.893; org.apache.solr.handl= er.loader.XMLLoader; xsltCacheLifetimeSeconds=3D60 [junit4:junit4] 1> INFO - 2013-05-01 07:26:46.895; org.apache.solr.core.= SolrCore; org.apache.solr.core.MockDirectoryFactory [junit4:junit4] 1> INFO - 2013-05-01 07:26:46.897; org.apache.solr.core.= CachingDirectoryFactory; return new directory for /usr/home/hudson/hudson-s= lave/workspace/Lucene-Solr-Tests-trunk-java7/solr/build/solr-core/test/J1/.= /org.apache.solr.cloud.CollectionsAPIDistributedZkTest-controljetty-1367393= 193679/awholynewcollection_0_shard1_replica1/data [junit4:junit4] 1> INFO - 2013-05-01 07:26:46.897; org.apache.solr.core.= SolrCore; New index directory detected: old=3Dnull new=3D/usr/home/hudson/h= udson-slave/workspace/Lucene-Solr-Tests-trunk-java7/solr/build/solr-core/te= st/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-controljetty-= 1367393193679/awholynewcollection_0_shard1_replica1/data/index/ [junit4:junit4] 1> INFO - 2013-05-01 07:26:46.898; org.apache.solr.searc= h.SolrIndexSearcher; Opening Searcher@bd3c47f main [junit4:junit4] 1> INFO - 2013-05-01 07:26:46.898; org.apache.solr.searc= h.SolrIndexSearcher; Opening Searcher@5099059d main [junit4:junit4] 1> INFO - 2013-05-01 07:26:46.899; org.apache.solr.updat= e.UpdateHandler; Clearing tlog files, tlogDir=3D/usr/home/hudson/hudson-sla= ve/workspace/Lucene-Solr-Tests-trunk-java7/solr/build/solr-core/test/J1/./o= rg.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1367393199177/a= wholynewcollection_0_shard3_replica2/data/tlog [junit4:junit4] 1> WARN - 2013-05-01 07:26:46.898; org.apache.solr.core.= SolrCore; [awholynewcollection_0_shard1_replica1] Solr index directory '/us= r/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-java7/solr/bui= ld/solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTes= t-controljetty-1367393193679/awholynewcollection_0_shard1_replica1/data/ind= ex' doesn't exist. Creating new index... [junit4:junit4] 1> INFO - 2013-05-01 07:26:46.900; org.apache.solr.schem= a.IndexSchema; default search field in schema is text [junit4:junit4] 1> INFO - 2013-05-01 07:26:46.900; org.apache.solr.searc= h.SolrIndexSearcher; Opening Searcher@25a7ded1 main [junit4:junit4] 1> INFO - 2013-05-01 07:26:46.899; org.apache.solr.updat= e.UpdateHandler; Clearing tlog files, tlogDir=3D/usr/home/hudson/hudson-sla= ve/workspace/Lucene-Solr-Tests-trunk-java7/solr/build/solr-core/test/J1/./o= rg.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty1-1367393194339/a= wholynewcollection_0_shard3_replica3/data/tlog [junit4:junit4] 1> INFO - 2013-05-01 07:26:46.899; org.apache.solr.schem= a.IndexSchema; default search field in schema is text [junit4:junit4] 1> INFO - 2013-05-01 07:26:46.902; org.apache.solr.updat= e.UpdateHandler; Clearing tlog files, tlogDir=3D/usr/home/hudson/hudson-sla= ve/workspace/Lucene-Solr-Tests-trunk-java7/solr/build/solr-core/test/J1/./o= rg.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty2-1367393195983/a= wholynewcollection_0_shard3_replica1/data/tlog [junit4:junit4] 1> INFO - 2013-05-01 07:26:46.901; org.apache.solr.schem= a.FileExchangeRateProvider; Reloading exchange rates from file currency.xml [junit4:junit4] 1> INFO - 2013-05-01 07:26:46.901; org.apache.solr.updat= e.CommitTracker; Hard AutoCommit: disabled [junit4:junit4] 1> INFO - 2013-05-01 07:26:46.901; org.apache.solr.core.= CachingDirectoryFactory; return new directory for /usr/home/hudson/hudson-s= lave/workspace/Lucene-Solr-Tests-trunk-java7/solr/build/solr-core/test/J1/.= /org.apache.solr.cloud.CollectionsAPIDistributedZkTest-controljetty-1367393= 193679/awholynewcollection_0_shard1_replica1/data/index [junit4:junit4] 1> INFO - 2013-05-01 07:26:46.905; org.apache.solr.updat= e.CommitTracker; Hard AutoCommit: disabled [junit4:junit4] 1> INFO - 2013-05-01 07:26:46.901; org.apache.solr.searc= h.SolrIndexSearcher; Opening Searcher@63e99757 main [junit4:junit4] 1> INFO - 2013-05-01 07:26:46.905; org.apache.solr.updat= e.CommitTracker; Soft AutoCommit: disabled [junit4:junit4] 1> INFO - 2013-05-01 07:26:46.905; org.apache.solr.schem= a.IndexSchema; unique key field: id [junit4:junit4] 1> INFO - 2013-05-01 07:26:46.904; org.apache.solr.updat= e.CommitTracker; Soft AutoCommit: disabled [junit4:junit4] 1> INFO - 2013-05-01 07:26:46.903; org.apache.solr.updat= e.CommitTracker; Hard AutoCommit: disabled [junit4:junit4] 1> INFO - 2013-05-01 07:26:46.906; org.apache.solr.updat= e.UpdateHandler; Clearing tlog files, tlogDir=3D/usr/home/hudson/hudson-sla= ve/workspace/Lucene-Solr-Tests-trunk-java7/solr/build/solr-core/test/J1/./o= rg.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty1-1367393194339/a= wholynewcollection_0_shard2_replica1/data/tlog [junit4:junit4] 1> INFO - 2013-05-01 07:26:46.908; org.apache.solr.schem= a.FileExchangeRateProvider; Reloading exchange rates from file currency.xml [junit4:junit4] 1> INFO - 2013-05-01 07:26:46.908; org.apache.solr.updat= e.CommitTracker; Soft AutoCommit: disabled [junit4:junit4] 1> INFO - 2013-05-01 07:26:46.909; org.apache.solr.core.= SolrDeletionPolicy; SolrDeletionPolicy.onCommit: commits: num=3D1 [junit4:junit4] 1> =09commit{dir=3DMockDirWrapper(RateLimitedDirectoryWra= pper(org.apache.lucene.store.RAMDirectory@78db3b1f lockFactory=3Dorg.apache= .lucene.store.NativeFSLockFactory@7b0f9a5c)),segFN=3Dsegments_1,generation= =3D1} [junit4:junit4] 1> INFO - 2013-05-01 07:26:46.909; org.apache.solr.schem= a.IndexSchema; unique key field: id [junit4:junit4] 1> INFO - 2013-05-01 07:26:46.911; org.apache.solr.core.= SolrCore; [awholynewcollection_0_shard3_replica1] Registered new searcher S= earcher@25a7ded1 main{StandardDirectoryReader(segments_1:1)} [junit4:junit4] 1> INFO - 2013-05-01 07:26:46.911; org.apache.solr.core.= SolrCore; [awholynewcollection_0_shard3_replica2] Registered new searcher S= earcher@bd3c47f main{StandardDirectoryReader(segments_1:1)} [junit4:junit4] 1> INFO - 2013-05-01 07:26:46.910; org.apache.solr.schem= a.FileExchangeRateProvider; Reloading exchange rates from file currency.xml [junit4:junit4] 1> INFO - 2013-05-01 07:26:46.910; org.apache.solr.core.= SolrDeletionPolicy; newest commit generation =3D 1 [junit4:junit4] 1> INFO - 2013-05-01 07:26:46.910; org.apache.solr.updat= e.CommitTracker; Hard AutoCommit: disabled [junit4:junit4] 1> INFO - 2013-05-01 07:26:46.913; org.apache.solr.core.= SolrCore; [awholynewcollection_0_shard3_replica3] Registered new searcher S= earcher@5099059d main{StandardDirectoryReader(segments_1:1)} [junit4:junit4] 1> INFO - 2013-05-01 07:26:46.913; org.apache.solr.updat= e.CommitTracker; Soft AutoCommit: disabled [junit4:junit4] 1> INFO - 2013-05-01 07:26:46.914; org.apache.solr.cloud= .ZkController; publishing core=3Dawholynewcollection_0_shard3_replica1 stat= e=3Ddown [junit4:junit4] 1> INFO - 2013-05-01 07:26:46.914; org.apache.solr.cloud= .ZkController; publishing core=3Dawholynewcollection_0_shard3_replica2 stat= e=3Ddown [junit4:junit4] 1> INFO - 2013-05-01 07:26:46.916; org.apache.solr.cloud= .ZkController; publishing core=3Dawholynewcollection_0_shard3_replica3 stat= e=3Ddown [junit4:junit4] 1> INFO - 2013-05-01 07:26:46.916; org.apache.solr.updat= e.processor.UpdateRequestProcessorChain; inserting DistributedUpdateProcess= orFactory into updateRequestProcessorChain "dedupe" [junit4:junit4] 1> INFO - 2013-05-01 07:26:46.917; org.apache.solr.updat= e.processor.UpdateRequestProcessorChain; inserting DistributedUpdateProcess= orFactory into updateRequestProcessorChain "stored_sig" [junit4:junit4] 1> INFO - 2013-05-01 07:26:46.917; org.apache.solr.core.= SolrCore; [awholynewcollection_0_shard2_replica1] Registered new searcher S= earcher@63e99757 main{StandardDirectoryReader(segments_1:1)} [junit4:junit4] 1> INFO - 2013-05-01 07:26:46.918; org.apache.solr.updat= e.processor.UpdateRequestProcessorChain; inserting DistributedUpdateProcess= orFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit= " [junit4:junit4] 1> INFO - 2013-05-01 07:26:46.919; org.apache.solr.core.= RequestHandlers; created standard: solr.StandardRequestHandler [junit4:junit4] 1> INFO - 2013-05-01 07:26:46.919; org.apache.solr.core.= RequestHandlers; created /get: solr.RealTimeGetHandler [junit4:junit4] 1> INFO - 2013-05-01 07:26:46.920; org.apache.solr.core.= RequestHandlers; adding lazy requestHandler: solr.ReplicationHandler [junit4:junit4] 1> INFO - 2013-05-01 07:26:46.919; org.apache.solr.cloud= .ZkController; publishing core=3Dawholynewcollection_0_shard2_replica1 stat= e=3Ddown [junit4:junit4] 1> INFO - 2013-05-01 07:26:46.920; org.apache.solr.core.= RequestHandlers; created /replication: solr.ReplicationHandler [junit4:junit4] 1> INFO - 2013-05-01 07:26:46.921; org.apache.solr.core.= RequestHandlers; created /update: solr.UpdateRequestHandler [junit4:junit4] 1> INFO - 2013-05-01 07:26:46.922; org.apache.solr.core.= RequestHandlers; created /admin/: org.apache.solr.handler.admin.AdminHandle= rs [junit4:junit4] 1> INFO - 2013-05-01 07:26:46.924; org.apache.solr.schem= a.OpenExchangeRatesOrgProvider; Reloading exchange rates from open-exchange= -rates.json [junit4:junit4] 1> WARN - 2013-05-01 07:26:46.933; org.apache.solr.schem= a.OpenExchangeRatesOrgProvider$OpenExchangeRates; Unknown key IMPORTANT NOT= E [junit4:junit4] 1> WARN - 2013-05-01 07:26:46.934; org.apache.solr.schem= a.OpenExchangeRatesOrgProvider$OpenExchangeRates; Expected key, got STRING [junit4:junit4] 1> INFO - 2013-05-01 07:26:46.934; org.apache.solr.schem= a.OpenExchangeRatesOrgProvider; Reloading exchange rates from open-exchange= -rates.json [junit4:junit4] 1> WARN - 2013-05-01 07:26:46.936; org.apache.solr.schem= a.OpenExchangeRatesOrgProvider$OpenExchangeRates; Unknown key IMPORTANT NOT= E [junit4:junit4] 1> WARN - 2013-05-01 07:26:46.937; org.apache.solr.schem= a.OpenExchangeRatesOrgProvider$OpenExchangeRates; Expected key, got STRING [junit4:junit4] 1> INFO - 2013-05-01 07:26:46.937; org.apache.solr.schem= a.OpenExchangeRatesOrgProvider; Reloading exchange rates from open-exchange= -rates.json [junit4:junit4] 1> INFO - 2013-05-01 07:26:46.938; org.apache.solr.core.= SolrCore; org.apache.solr.core.MockDirectoryFactory [junit4:junit4] 1> INFO - 2013-05-01 07:26:46.937; org.apache.solr.handl= er.loader.XMLLoader; xsltCacheLifetimeSeconds=3D60 [junit4:junit4] 1> INFO - 2013-05-01 07:26:46.939; org.apache.solr.core.= SolrCore; [awholynewcollection_0_shard1_replica3] Opening new SolrCore at /= usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-java7/solr/b= uild/solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkT= est-jetty4-1367393199177/awholynewcollection_0_shard1_replica3/, dataDir=3D= /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-java7/solr/= build/solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZk= Test-jetty4-1367393199177/awholynewcollection_0_shard1_replica3/data/ [junit4:junit4] 1> WARN - 2013-05-01 07:26:46.940; org.apache.solr.schem= a.OpenExchangeRatesOrgProvider$OpenExchangeRates; Unknown key IMPORTANT NOT= E [junit4:junit4] 1> INFO - 2013-05-01 07:26:46.940; org.apache.solr.core.= JmxMonitoredMap; JMX monitoring is enabled. Adding Solr mbeans to JMX Serve= r: com.sun.jmx.mbeanserver.JmxMBeanServer@342371e7 [junit4:junit4] 1> WARN - 2013-05-01 07:26:46.941; org.apache.solr.schem= a.OpenExchangeRatesOrgProvider$OpenExchangeRates; Expected key, got STRING [junit4:junit4] 1> INFO - 2013-05-01 07:26:46.942; org.apache.solr.core.= SolrCore; org.apache.solr.core.MockDirectoryFactory [junit4:junit4] 1> INFO - 2013-05-01 07:26:46.942; org.apache.solr.schem= a.OpenExchangeRatesOrgProvider; Reloading exchange rates from open-exchange= -rates.json [junit4:junit4] 1> INFO - 2013-05-01 07:26:46.943; org.apache.solr.core.= CachingDirectoryFactory; return new directory for /usr/home/hudson/hudson-s= lave/workspace/Lucene-Solr-Tests-trunk-java7/solr/build/solr-core/test/J1/.= /org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1367393199177= /awholynewcollection_0_shard1_replica3/data [junit4:junit4] 1> INFO - 2013-05-01 07:26:46.944; org.apache.solr.core.= SolrCore; New index directory detected: old=3Dnull new=3D/usr/home/hudson/h= udson-slave/workspace/Lucene-Solr-Tests-trunk-java7/solr/build/solr-core/te= st/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-136739= 3199177/awholynewcollection_0_shard1_replica3/data/index/ [junit4:junit4] 1> WARN - 2013-05-01 07:26:46.944; org.apache.solr.schem= a.OpenExchangeRatesOrgProvider$OpenExchangeRates; Unknown key IMPORTANT NOT= E [junit4:junit4] 1> WARN - 2013-05-01 07:26:46.945; org.apache.solr.schem= a.OpenExchangeRatesOrgProvider$OpenExchangeRates; Expected key, got STRING [junit4:junit4] 1> INFO - 2013-05-01 07:26:46.946; org.apache.solr.schem= a.FileExchangeRateProvider; Reloading exchange rates from file currency.xml [junit4:junit4] 1> INFO - 2013-05-01 07:26:46.945; org.apache.solr.searc= h.SolrIndexSearcher; Opening Searcher@5b9acc72 main [junit4:junit4] 1> WARN - 2013-05-01 07:26:46.945; org.apache.solr.core.= SolrCore; [awholynewcollection_0_shard1_replica3] Solr index directory '/us= r/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-java7/solr/bui= ld/solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTes= t-jetty4-1367393199177/awholynewcollection_0_shard1_replica3/data/index' do= esn't exist. Creating new index... [junit4:junit4] 1> INFO - 2013-05-01 07:26:46.948; org.apache.solr.updat= e.UpdateHandler; Clearing tlog files, tlogDir=3D/usr/home/hudson/hudson-sla= ve/workspace/Lucene-Solr-Tests-trunk-java7/solr/build/solr-core/test/J1/./o= rg.apache.solr.cloud.CollectionsAPIDistributedZkTest-controljetty-136739319= 3679/awholynewcollection_0_shard1_replica1/data/tlog [junit4:junit4] 1> INFO - 2013-05-01 07:26:46.946; org.apache.solr.core.= SolrCore; org.apache.solr.core.MockDirectoryFactory [junit4:junit4] 1> INFO - 2013-05-01 07:26:46.946; org.apache.solr.schem= a.FileExchangeRateProvider; Reloading exchange rates from file currency.xml [junit4:junit4] 1> INFO - 2013-05-01 07:26:46.949; org.apache.solr.core.= SolrCore; [awholynewcollection_0_shard2_replica2] Opening new SolrCore at /= usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-java7/solr/b= uild/solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkT= est-jetty3-1367393197576/awholynewcollection_0_shard2_replica2/, dataDir=3D= /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-java7/solr/= build/solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZk= Test-jetty3-1367393197576/awholynewcollection_0_shard2_replica2/data/ [junit4:junit4] 1> INFO - 2013-05-01 07:26:46.948; org.apache.solr.core.= CachingDirectoryFactory; return new directory for /usr/home/hudson/hudson-s= lave/workspace/Lucene-Solr-Tests-trunk-java7/solr/build/solr-core/test/J1/.= /org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1367393199177= /awholynewcollection_0_shard1_replica3/data/index [junit4:junit4] 1> INFO - 2013-05-01 07:26:46.951; org.apache.solr.core.= JmxMonitoredMap; JMX monitoring is enabled. Adding Solr mbeans to JMX Serve= r: com.sun.jmx.mbeanserver.JmxMBeanServer@342371e7 [junit4:junit4] 1> INFO - 2013-05-01 07:26:46.950; org.apache.solr.updat= e.CommitTracker; Hard AutoCommit: disabled [junit4:junit4] 1> INFO - 2013-05-01 07:26:46.952; org.apache.solr.core.= SolrCore; org.apache.solr.core.MockDirectoryFactory [junit4:junit4] 1> INFO - 2013-05-01 07:26:46.953; org.apache.solr.updat= e.CommitTracker; Soft AutoCommit: disabled [junit4:junit4] 1> INFO - 2013-05-01 07:26 [...truncated too long message...] ) [junit4:junit4] > =09at org.apache.solr.cloud.AbstractDistribZkTestBase.= waitForRecoveriesToFinish(AbstractDistribZkTestBase.java:131) [junit4:junit4] > =09at org.apache.solr.cloud.AbstractDistribZkTestBase.= waitForRecoveriesToFinish(AbstractDistribZkTestBase.java:126) [junit4:junit4] > =09at org.apache.solr.cloud.CollectionsAPIDistributedZ= kTest.testCollectionsAPI(CollectionsAPIDistributedZkTest.java:511) [junit4:junit4] > =09at org.apache.solr.cloud.CollectionsAPIDistributedZ= kTest.doTest(CollectionsAPIDistributedZkTest.java:145) [junit4:junit4] > =09at org.apache.solr.BaseDistributedSearchTestCase.te= stDistribSearch(BaseDistributedSearchTestCase.java:815) [junit4:junit4] > =09at java.lang.Thread.run(Thread.java:722) [junit4:junit4] 1> INFO - 2013-05-01 07:31:08.727; org.apache.solr.SolrT= estCaseJ4; ###deleteCore [junit4:junit4] 2> 275373 T1633 ccr.ThreadLeakControl.checkThreadLeaks WA= RNING Will linger awaiting termination of 2 leaked thread(s). [junit4:junit4] 1> WARN - 2013-05-01 07:31:09.871; org.apache.solr.cloud= .LeaderElector$1;=20 [junit4:junit4] 1> org.apache.zookeeper.KeeperException$SessionExpiredExc= eption: KeeperErrorCode =3D Session expired for /collections/awholynewcolle= ction_1/leader_elect/shard3/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] 1> WARN - 2013-05-01 07:31:09.872; org.apache.solr.cloud= .LeaderElector$1;=20 [junit4:junit4] 1> org.apache.zookeeper.KeeperException$SessionExpiredExc= eption: KeeperErrorCode =3D Session expired for /collections/awholynewcolle= ction_1/leader_elect/shard4/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] 1> INFO - 2013-05-01 07:31:09.872; org.apache.solr.commo= n.cloud.ZkStateReader$2; A cluster state change: WatchedEvent state:SyncCon= nected type:NodeChildrenChanged path:/live_nodes, has occurred - updating..= . (live nodes size: 1) [junit4:junit4] 1> WARN - 2013-05-01 07:31:09.873; org.apache.solr.commo= n.cloud.ZkStateReader$2; ZooKeeper watch triggered, but Solr cannot talk to= ZK [junit4:junit4] 1> WARN - 2013-05-01 07:31:09.873; org.apache.solr.commo= n.cloud.ZkStateReader$3; ZooKeeper watch triggered, but Solr cannot talk to= ZK [junit4:junit4] 1> WARN - 2013-05-01 07:31:09.873; org.apache.solr.cloud= .LeaderElector$1;=20 [junit4:junit4] 1> org.apache.zookeeper.KeeperException$SessionExpiredExc= eption: KeeperErrorCode =3D Session expired for /collections/awholynewcolle= ction_1/leader_elect/shard2/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=3DLucene42: {timestamp=3D= Pulsing41(freqCutoff=3D12 minBlockSize=3D22 maxBlockSize=3D79), range_facet= _l=3DPulsing41(freqCutoff=3D12 minBlockSize=3D22 maxBlockSize=3D79), id=3DP= ostingsFormat(name=3DLucene41WithOrds), range_facet_sl=3DPostingsFormat(nam= e=3DLucene41WithOrds), a_t=3DPulsing41(freqCutoff=3D12 minBlockSize=3D22 ma= xBlockSize=3D79), text=3DPostingsFormat(name=3DMockRandom), range_facet_si= =3DPulsing41(freqCutoff=3D12 minBlockSize=3D22 maxBlockSize=3D79), _version= _=3DPostingsFormat(name=3DMemory doPackFST=3D false), other_tl1=3DPostingsF= ormat(name=3DMemory doPackFST=3D false), multiDefault=3DPulsing41(freqCutof= f=3D12 minBlockSize=3D22 maxBlockSize=3D79), a_si=3DPostingsFormat(name=3DM= emory doPackFST=3D false), intDefault=3DPostingsFormat(name=3DMemory doPack= FST=3D false)}, docValues:{timestamp=3DDocValuesFormat(name=3DDisk)}, sim= =3DDefaultSimilarity, locale=3Dro, timezone=3DEurope/Malta [junit4:junit4] 2> NOTE: FreeBSD 9.0-RELEASE amd64/Oracle Corporation 1.7= .0_17 (64-bit)/cpus=3D16,threads=3D4,free=3D264010704,total=3D536870912 [junit4:junit4] 2> NOTE: All tests run in this JVM: [CurrencyFieldOpenExc= hangeTest, DisMaxRequestHandlerTest, XmlUpdateRequestHandlerTest, TestUpdat= e, StatsComponentTest, SuggesterWFSTTest, IndexReaderFactoryTest, TestField= TypeResource, TestCloudManagedSchemaAddField, TestDistributedSearch, MultiT= ermTest, TestFieldResource, TestSerializedLuceneMatchVersion, TestLazyCores= , TestPropInject, PingRequestHandlerTest, TestZkChroot, TestSolrXMLSerializ= er, TestFieldTypeCollectionResource, IndexBasedSpellCheckerTest, DateMathPa= rserTest, TestCoreDiscovery, TestCSVLoader, NoCacheHeaderTest, DocumentAnal= ysisRequestHandlerTest, TestLuceneMatchVersion, TestNumberUtils, TestPartia= lUpdateDeduplication, ConvertedLegacyTest, TestBinaryResponseWriter, IndexS= chemaRuntimeFieldTest, TestFoldingMultitermQuery, UniqFieldsUpdateProcessor= FactoryTest, TestPostingsSolrHighlighter, TestSolr4Spatial, TestRandomFacet= ing, TestBinaryField, SortByFunctionTest, SolrCoreCheckLockOnStartupTest, T= estLMJelinekMercerSimilarityFactory, DirectUpdateHandlerTest, TestArbitrary= IndexDir, SpellPossibilityIteratorTest, RequiredFieldsTest, AliasIntegratio= nTest, BadCopyFieldTest, TestSchemaVersionResource, BasicZkTest, FileUtilsT= est, TestDistributedGrouping, BasicDistributedZk2Test, TestIndexingPerforma= nce, TestOmitPositions, TestBM25SimilarityFactory, TestManagedSchemaFieldRe= source, SolrRequestParserTest, TestHashPartitioner, SolrPluginUtilsTest, Te= stAtomicUpdateErrorCases, TestQueryTypes, SpellCheckCollatorTest, DOMUtilTe= st, URLClassifyProcessorTest, TestStressLucene, HardAutoCommitTest, TimeZon= eUtilsTest, BadIndexSchemaTest, TestMultiCoreConfBootstrap, TestElisionMult= itermQuery, SolrTestCaseJ4Test, ClusterStateTest, CollectionsAPIDistributed= ZkTest] [junit4:junit4] Completed on J1 in 276.66s, 1 test, 1 failure <<< FAILURES! [...truncated 474 lines...] BUILD FAILED /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-java7/build= .xml:378: The following error occurred while executing this line: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-java7/build= .xml:358: The following error occurred while executing this line: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-java7/build= .xml:39: The following error occurred while executing this line: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-java7/solr/= build.xml:181: The following error occurred while executing this line: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-java7/solr/= common-build.xml:437: The following error occurred while executing this lin= e: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-java7/lucen= e/common-build.xml:1240: The following error occurred while executing this = line: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-java7/lucen= e/common-build.xml:884: There were test failures: 293 suites, 1219 tests, 1= failure, 27 ignored (8 assumptions) Total time: 53 minutes 2 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_6767_863640653.1367394252654 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_6767_863640653.1367394252654--