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 EAC77108C1 for ; Wed, 10 Apr 2013 08:54:34 +0000 (UTC) Received: (qmail 59247 invoked by uid 500); 10 Apr 2013 08:54:33 -0000 Delivered-To: apmail-lucene-dev-archive@lucene.apache.org Received: (qmail 58888 invoked by uid 500); 10 Apr 2013 08:54:29 -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 58854 invoked by uid 99); 10 Apr 2013 08:54:27 -0000 Received: from athena.apache.org (HELO athena.apache.org) (140.211.11.136) by apache.org (qpsmtpd/0.29) with ESMTP; Wed, 10 Apr 2013 08:54:27 +0000 X-ASF-Spam-Status: No, hits=0.0 required=5.0 tests=NORMAL_HTTP_TO_IP,SPF_PASS,WEIRD_PORT X-Spam-Check-By: apache.org Received-SPF: pass (athena.apache.org: domain of jenkins@thetaphi.de designates 188.138.97.18 as permitted sender) Received: from [188.138.97.18] (HELO mail.sd-datasolutions.de) (188.138.97.18) by apache.org (qpsmtpd/0.29) with ESMTP; Wed, 10 Apr 2013 08:54:18 +0000 Received: from serv1 (localhost.localdomain [127.0.0.1]) by mail.sd-datasolutions.de (Postfix) with ESMTP id 6CDDD14AA031; Wed, 10 Apr 2013 08:53:56 +0000 (UTC) Date: Wed, 10 Apr 2013 08:53:36 +0000 (UTC) From: Policeman Jenkins Server To: dev@lucene.apache.org, rmuir@apache.org, erick@apache.org, simonw@apache.org, shaie@apache.org, shalin@apache.org, yonik@apache.org, mikemccand@apache.org, markrmiller@apache.org Message-ID: <59821128.47.1365584036362.JavaMail.jenkins@serv1.sd-datasolutions.de> Subject: [JENKINS] Lucene-Solr-trunk-Windows (32bit/jdk1.7.0_17) - Build # 2723 - Failure! MIME-Version: 1.0 Content-Type: multipart/mixed; boundary="----=_Part_46_1496055095.1365584016500" X-Jenkins-Job: Lucene-Solr-trunk-Windows X-Jenkins-Result: FAILURE X-Virus-Checked: Checked by ClamAV on apache.org ------=_Part_46_1496055095.1365584016500 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: quoted-printable Build: http://jenkins.thetaphi.de/job/Lucene-Solr-trunk-Windows/2723/ Java: 32bit/jdk1.7.0_17 -server -XX:+UseConcMarkSweepGC 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([D89849C56E10B1F9:597EC7DD194FD1C5]= :0) =09at org.junit.Assert.fail(Assert.java:93) =09at org.apache.solr.cloud.AbstractDistribZkTestBase.waitForRecoveriesToFi= nish(AbstractDistribZkTestBase.java:173) =09at org.apache.solr.cloud.AbstractDistribZkTestBase.waitForRecoveriesToFi= nish(AbstractDistribZkTestBase.java:131) =09at org.apache.solr.cloud.AbstractDistribZkTestBase.waitForRecoveriesToFi= nish(AbstractDistribZkTestBase.java:126) =09at org.apache.solr.cloud.CollectionsAPIDistributedZkTest.testCollections= API(CollectionsAPIDistributedZkTest.java:483) =09at org.apache.solr.cloud.CollectionsAPIDistributedZkTest.doTest(Collecti= onsAPIDistributedZkTest.java:146) =09at org.apache.solr.BaseDistributedSearchTestCase.testDistribSearch(BaseD= istributedSearchTestCase.java:806) =09at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method) =09at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.= java:57) =09at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAcces= sorImpl.java:43) =09at java.lang.reflect.Method.invoke(Method.java: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 9200 lines...] [junit4:junit4] Suite: org.apache.solr.cloud.CollectionsAPIDistributedZkTes= t [junit4:junit4] 1> INFO - 2013-04-10 08:24:05.565; org.apache.solr.BaseD= istributedSearchTestCase; Setting hostContext system property: / [junit4:junit4] 1> INFO - 2013-04-10 08:24:05.570; org.apache.solr.SolrT= estCaseJ4; ###Starting testDistribSearch [junit4:junit4] 1> INFO - 2013-04-10 08:24:05.573; org.apache.solr.cloud= .ZkTestServer; STARTING ZK TEST SERVER [junit4:junit4] 1> client port:0.0.0.0/0.0.0.0:0 [junit4:junit4] 1> INFO - 2013-04-10 08:24:05.574; org.apache.solr.cloud= .ZkTestServer$ZKServerMain; Starting server [junit4:junit4] 1> INFO - 2013-04-10 08:24:05.687; org.apache.solr.cloud= .ZkTestServer; start zk server on port:50431 [junit4:junit4] 1> INFO - 2013-04-10 08:24:05.688; org.apache.solr.commo= n.cloud.ConnectionManager; Waiting for client to connect to ZooKeeper [junit4:junit4] 1> INFO - 2013-04-10 08:24:05.710; org.apache.solr.commo= n.cloud.ConnectionManager; Watcher org.apache.solr.common.cloud.ConnectionM= anager@a7741d name:ZooKeeperConnection Watcher:127.0.0.1:50431 got event Wa= tchedEvent state:SyncConnected type:None path:null path:null type:None [junit4:junit4] 1> INFO - 2013-04-10 08:24:05.710; org.apache.solr.commo= n.cloud.ConnectionManager; Client is connected to ZooKeeper [junit4:junit4] 1> INFO - 2013-04-10 08:24:05.710; org.apache.solr.commo= n.cloud.SolrZkClient; makePath: /solr [junit4:junit4] 1> INFO - 2013-04-10 08:24:05.722; org.apache.solr.commo= n.cloud.ConnectionManager; Waiting for client to connect to ZooKeeper [junit4:junit4] 1> INFO - 2013-04-10 08:24:05.726; org.apache.solr.commo= n.cloud.ConnectionManager; Watcher org.apache.solr.common.cloud.ConnectionM= anager@d753c7 name:ZooKeeperConnection Watcher:127.0.0.1:50431/solr got eve= nt WatchedEvent state:SyncConnected type:None path:null path:null type:None [junit4:junit4] 1> INFO - 2013-04-10 08:24:05.726; org.apache.solr.commo= n.cloud.ConnectionManager; Client is connected to ZooKeeper [junit4:junit4] 1> INFO - 2013-04-10 08:24:05.726; org.apache.solr.commo= n.cloud.SolrZkClient; makePath: /collections/collection1 [junit4:junit4] 1> INFO - 2013-04-10 08:24:05.735; org.apache.solr.commo= n.cloud.SolrZkClient; makePath: /collections/collection1/shards [junit4:junit4] 1> INFO - 2013-04-10 08:24:05.740; org.apache.solr.commo= n.cloud.SolrZkClient; makePath: /collections/control_collection [junit4:junit4] 1> INFO - 2013-04-10 08:24:05.746; org.apache.solr.commo= n.cloud.SolrZkClient; makePath: /collections/control_collection/shards [junit4:junit4] 1> INFO - 2013-04-10 08:24:05.762; org.apache.solr.cloud= .AbstractZkTestCase; put C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-= Windows\solr\build\solr-core\test-files\solr\collection1\conf\solrconfig-tl= og.xml to /configs/conf1/solrconfig.xml [junit4:junit4] 1> INFO - 2013-04-10 08:24:05.762; org.apache.solr.commo= n.cloud.SolrZkClient; makePath: /configs/conf1/solrconfig.xml [junit4:junit4] 1> INFO - 2013-04-10 08:24:05.783; org.apache.solr.cloud= .AbstractZkTestCase; put C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-= Windows\solr\build\solr-core\test-files\solr\collection1\conf\schema.xml to= /configs/conf1/schema.xml [junit4:junit4] 1> INFO - 2013-04-10 08:24:05.783; org.apache.solr.commo= n.cloud.SolrZkClient; makePath: /configs/conf1/schema.xml [junit4:junit4] 1> INFO - 2013-04-10 08:24:05.794; org.apache.solr.cloud= .AbstractZkTestCase; put C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-= Windows\solr\build\solr-core\test-files\solr\collection1\conf\stopwords.txt= to /configs/conf1/stopwords.txt [junit4:junit4] 1> INFO - 2013-04-10 08:24:05.796; org.apache.solr.commo= n.cloud.SolrZkClient; makePath: /configs/conf1/stopwords.txt [junit4:junit4] 1> INFO - 2013-04-10 08:24:05.813; org.apache.solr.cloud= .AbstractZkTestCase; put C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-= Windows\solr\build\solr-core\test-files\solr\collection1\conf\protwords.txt= to /configs/conf1/protwords.txt [junit4:junit4] 1> INFO - 2013-04-10 08:24:05.814; org.apache.solr.commo= n.cloud.SolrZkClient; makePath: /configs/conf1/protwords.txt [junit4:junit4] 1> INFO - 2013-04-10 08:24:05.837; org.apache.solr.cloud= .AbstractZkTestCase; put C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-= Windows\solr\build\solr-core\test-files\solr\collection1\conf\currency.xml = to /configs/conf1/currency.xml [junit4:junit4] 1> INFO - 2013-04-10 08:24:05.838; org.apache.solr.commo= n.cloud.SolrZkClient; makePath: /configs/conf1/currency.xml [junit4:junit4] 1> INFO - 2013-04-10 08:24:05.853; org.apache.solr.cloud= .AbstractZkTestCase; put C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-= Windows\solr\build\solr-core\test-files\solr\collection1\conf\open-exchange= -rates.json to /configs/conf1/open-exchange-rates.json [junit4:junit4] 1> INFO - 2013-04-10 08:24:05.853; org.apache.solr.commo= n.cloud.SolrZkClient; makePath: /configs/conf1/open-exchange-rates.json [junit4:junit4] 1> INFO - 2013-04-10 08:24:05.892; org.apache.solr.cloud= .AbstractZkTestCase; put C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-= Windows\solr\build\solr-core\test-files\solr\collection1\conf\mapping-ISOLa= tin1Accent.txt to /configs/conf1/mapping-ISOLatin1Accent.txt [junit4:junit4] 1> INFO - 2013-04-10 08:24:05.892; org.apache.solr.commo= n.cloud.SolrZkClient; makePath: /configs/conf1/mapping-ISOLatin1Accent.txt [junit4:junit4] 1> INFO - 2013-04-10 08:24:05.913; org.apache.solr.cloud= .AbstractZkTestCase; put C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-= Windows\solr\build\solr-core\test-files\solr\collection1\conf\old_synonyms.= txt to /configs/conf1/old_synonyms.txt [junit4:junit4] 1> INFO - 2013-04-10 08:24:05.913; org.apache.solr.commo= n.cloud.SolrZkClient; makePath: /configs/conf1/old_synonyms.txt [junit4:junit4] 1> INFO - 2013-04-10 08:24:05.946; org.apache.solr.cloud= .AbstractZkTestCase; put C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-= Windows\solr\build\solr-core\test-files\solr\collection1\conf\synonyms.txt = to /configs/conf1/synonyms.txt [junit4:junit4] 1> INFO - 2013-04-10 08:24:05.947; org.apache.solr.commo= n.cloud.SolrZkClient; makePath: /configs/conf1/synonyms.txt [junit4:junit4] 1> INFO - 2013-04-10 08:24:06.710; org.eclipse.jetty.ser= ver.Server; jetty-8.1.8.v20121106 [junit4:junit4] 1> INFO - 2013-04-10 08:24:06.717; org.eclipse.jetty.ser= ver.AbstractConnector; Started SelectChannelConnector@127.0.0.1:50438 [junit4:junit4] 1> INFO - 2013-04-10 08:24:06.719; org.apache.solr.servl= et.SolrDispatchFilter; SolrDispatchFilter.init() [junit4:junit4] 1> INFO - 2013-04-10 08:24:06.719; org.apache.solr.core.= SolrResourceLoader; JNDI not configured for solr (NoInitialContextEx) [junit4:junit4] 1> INFO - 2013-04-10 08:24:06.719; org.apache.solr.core.= SolrResourceLoader; using system property solr.solr.home: C:\Users\JenkinsS= lave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org= .apache.solr.cloud.CollectionsAPIDistributedZkTest-controljetty-13655822459= 91 [junit4:junit4] 1> INFO - 2013-04-10 08:24:06.720; org.apache.solr.core.= CoreContainer$Initializer; looking for solr config file: C:\Users\JenkinsSl= ave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.= apache.solr.cloud.CollectionsAPIDistributedZkTest-controljetty-136558224599= 1\solr.xml [junit4:junit4] 1> INFO - 2013-04-10 08:24:06.720; org.apache.solr.core.= CoreContainer; New CoreContainer 16847039 [junit4:junit4] 1> INFO - 2013-04-10 08:24:06.720; org.apache.solr.core.= CoreContainer; Loading CoreContainer using Solr Home: 'C:\Users\JenkinsSlav= e\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.ap= ache.solr.cloud.CollectionsAPIDistributedZkTest-controljetty-1365582245991\= ' [junit4:junit4] 1> INFO - 2013-04-10 08:24:06.721; org.apache.solr.core.= SolrResourceLoader; new SolrResourceLoader for directory: 'C:\Users\Jenkins= Slave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\or= g.apache.solr.cloud.CollectionsAPIDistributedZkTest-controljetty-1365582245= 991\' [junit4:junit4] 1> INFO - 2013-04-10 08:24:06.797; org.apache.solr.handl= er.component.HttpShardHandlerFactory; Setting socketTimeout to: 120000 [junit4:junit4] 1> INFO - 2013-04-10 08:24:06.797; org.apache.solr.handl= er.component.HttpShardHandlerFactory; Setting urlScheme to: http:// [junit4:junit4] 1> INFO - 2013-04-10 08:24:06.797; org.apache.solr.handl= er.component.HttpShardHandlerFactory; Setting connTimeout to: 15000 [junit4:junit4] 1> INFO - 2013-04-10 08:24:06.797; org.apache.solr.handl= er.component.HttpShardHandlerFactory; Setting maxConnectionsPerHost to: 20 [junit4:junit4] 1> INFO - 2013-04-10 08:24:06.798; org.apache.solr.handl= er.component.HttpShardHandlerFactory; Setting corePoolSize to: 0 [junit4:junit4] 1> INFO - 2013-04-10 08:24:06.798; org.apache.solr.handl= er.component.HttpShardHandlerFactory; Setting maximumPoolSize to: 214748364= 7 [junit4:junit4] 1> INFO - 2013-04-10 08:24:06.799; org.apache.solr.handl= er.component.HttpShardHandlerFactory; Setting maxThreadIdleTime to: 5 [junit4:junit4] 1> INFO - 2013-04-10 08:24:06.799; org.apache.solr.handl= er.component.HttpShardHandlerFactory; Setting sizeOfQueue to: -1 [junit4:junit4] 1> INFO - 2013-04-10 08:24:06.800; org.apache.solr.handl= er.component.HttpShardHandlerFactory; Setting fairnessPolicy to: false [junit4:junit4] 1> INFO - 2013-04-10 08:24:06.801; org.apache.solr.clien= t.solrj.impl.HttpClientUtil; Creating new http client, config:maxConnection= sPerHost=3D20&maxConnections=3D10000&socketTimeout=3D120000&connTimeout=3D1= 5000&retry=3Dfalse [junit4:junit4] 1> INFO - 2013-04-10 08:24:06.817; org.apache.solr.core.= CoreContainer; Registering Log Listener [junit4:junit4] 1> INFO - 2013-04-10 08:24:06.841; org.apache.solr.core.= CoreContainer; Zookeeper client=3D127.0.0.1:50431/solr [junit4:junit4] 1> INFO - 2013-04-10 08:24:06.841; org.apache.solr.cloud= .ZkController; zkHost includes chroot [junit4:junit4] 1> INFO - 2013-04-10 08:24:06.843; org.apache.solr.commo= n.cloud.ConnectionManager; Waiting for client to connect to ZooKeeper [junit4:junit4] 1> INFO - 2013-04-10 08:24:06.862; org.apache.solr.commo= n.cloud.ConnectionManager; Watcher org.apache.solr.common.cloud.ConnectionM= anager@11efe14 name:ZooKeeperConnection Watcher:127.0.0.1:50431 got event W= atchedEvent state:SyncConnected type:None path:null path:null type:None [junit4:junit4] 1> INFO - 2013-04-10 08:24:06.863; org.apache.solr.commo= n.cloud.ConnectionManager; Client is connected to ZooKeeper [junit4:junit4] 1> INFO - 2013-04-10 08:24:06.875; org.apache.solr.clien= t.solrj.impl.HttpClientUtil; Creating new http client, config:maxConnection= s=3D500&maxConnectionsPerHost=3D16&socketTimeout=3D120000&connTimeout=3D150= 00 [junit4:junit4] 1> INFO - 2013-04-10 08:24:06.885; org.apache.solr.commo= n.cloud.ConnectionManager; Waiting for client to connect to ZooKeeper [junit4:junit4] 1> INFO - 2013-04-10 08:24:06.897; org.apache.solr.commo= n.cloud.ConnectionManager; Watcher org.apache.solr.common.cloud.ConnectionM= anager@189d6d9 name:ZooKeeperConnection Watcher:127.0.0.1:50431/solr got ev= ent WatchedEvent state:SyncConnected type:None path:null path:null type:Non= e [junit4:junit4] 1> INFO - 2013-04-10 08:24:06.897; org.apache.solr.commo= n.cloud.ConnectionManager; Client is connected to ZooKeeper [junit4:junit4] 1> INFO - 2013-04-10 08:24:06.909; org.apache.solr.commo= n.cloud.SolrZkClient; makePath: /overseer/queue [junit4:junit4] 1> INFO - 2013-04-10 08:24:06.919; org.apache.solr.commo= n.cloud.SolrZkClient; makePath: /overseer/collection-queue-work [junit4:junit4] 1> INFO - 2013-04-10 08:24:06.935; org.apache.solr.commo= n.cloud.SolrZkClient; makePath: /live_nodes [junit4:junit4] 1> INFO - 2013-04-10 08:24:06.947; org.apache.solr.cloud= .ZkController; Register node as live in ZooKeeper:/live_nodes/127.0.0.1:504= 38_ [junit4:junit4] 1> INFO - 2013-04-10 08:24:06.952; org.apache.solr.commo= n.cloud.SolrZkClient; makePath: /live_nodes/127.0.0.1:50438_ [junit4:junit4] 1> INFO - 2013-04-10 08:24:06.967; org.apache.solr.commo= n.cloud.SolrZkClient; makePath: /overseer_elect/election [junit4:junit4] 1> INFO - 2013-04-10 08:24:06.984; org.apache.solr.commo= n.cloud.SolrZkClient; makePath: /overseer_elect/leader [junit4:junit4] 1> INFO - 2013-04-10 08:24:06.998; org.apache.solr.cloud= .Overseer; Overseer (id=3D89494798046396419-127.0.0.1:50438_-n_0000000000) = starting [junit4:junit4] 1> INFO - 2013-04-10 08:24:07.015; org.apache.solr.commo= n.cloud.SolrZkClient; makePath: /overseer/queue-work [junit4:junit4] 1> INFO - 2013-04-10 08:24:07.026; org.apache.solr.cloud= .OverseerCollectionProcessor; Process current queue of collection creations [junit4:junit4] 1> INFO - 2013-04-10 08:24:07.027; org.apache.solr.commo= n.cloud.SolrZkClient; makePath: /clusterstate.json [junit4:junit4] 1> INFO - 2013-04-10 08:24:07.034; org.apache.solr.commo= n.cloud.SolrZkClient; makePath: /aliases.json [junit4:junit4] 1> INFO - 2013-04-10 08:24:07.043; org.apache.solr.commo= n.cloud.ZkStateReader; Updating cluster state from ZooKeeper...=20 [junit4:junit4] 1> INFO - 2013-04-10 08:24:07.048; org.apache.solr.cloud= .Overseer$ClusterStateUpdater; Starting to work on the main queue [junit4:junit4] 1> INFO - 2013-04-10 08:24:07.053; org.apache.solr.servl= et.SolrDispatchFilter; user.dir=3DC:\Users\JenkinsSlave\workspace\Lucene-So= lr-trunk-Windows\solr\build\solr-core\test\J0 [junit4:junit4] 1> INFO - 2013-04-10 08:24:07.054; org.apache.solr.servl= et.SolrDispatchFilter; SolrDispatchFilter.init() done [junit4:junit4] 1> INFO - 2013-04-10 08:24:07.054; org.apache.solr.clien= t.solrj.impl.HttpClientUtil; Creating new http client, config:maxConnection= s=3D128&maxConnectionsPerHost=3D32&followRedirects=3Dfalse [junit4:junit4] 1> INFO - 2013-04-10 08:24:07.058; org.apache.solr.clien= t.solrj.impl.HttpClientUtil; Creating new http client, config: [junit4:junit4] 1> INFO - 2013-04-10 08:24:07.062; org.apache.solr.commo= n.cloud.ConnectionManager; Waiting for client to connect to ZooKeeper [junit4:junit4] 1> INFO - 2013-04-10 08:24:07.070; org.apache.solr.commo= n.cloud.ConnectionManager; Watcher org.apache.solr.common.cloud.ConnectionM= anager@6a3b00 name:ZooKeeperConnection Watcher:127.0.0.1:50431/solr got eve= nt WatchedEvent state:SyncConnected type:None path:null path:null type:None [junit4:junit4] 1> INFO - 2013-04-10 08:24:07.071; org.apache.solr.commo= n.cloud.ConnectionManager; Client is connected to ZooKeeper [junit4:junit4] 1> INFO - 2013-04-10 08:24:07.074; org.apache.solr.commo= n.cloud.ZkStateReader; Updating cluster state from ZooKeeper...=20 [junit4:junit4] 1> INFO - 2013-04-10 08:24:07.078; org.apache.solr.cloud= .ChaosMonkey; monkey: init - expire sessions:true cause connection loss:tru= e [junit4:junit4] 1> INFO - 2013-04-10 08:24:07.766; org.eclipse.jetty.ser= ver.Server; jetty-8.1.8.v20121106 [junit4:junit4] 1> INFO - 2013-04-10 08:24:07.776; org.eclipse.jetty.ser= ver.AbstractConnector; Started SelectChannelConnector@127.0.0.1:50450 [junit4:junit4] 1> INFO - 2013-04-10 08:24:07.777; org.apache.solr.servl= et.SolrDispatchFilter; SolrDispatchFilter.init() [junit4:junit4] 1> INFO - 2013-04-10 08:24:07.778; org.apache.solr.core.= SolrResourceLoader; JNDI not configured for solr (NoInitialContextEx) [junit4:junit4] 1> INFO - 2013-04-10 08:24:07.778; org.apache.solr.core.= SolrResourceLoader; using system property solr.solr.home: C:\Users\JenkinsS= lave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org= .apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty1-1365582247078 [junit4:junit4] 1> INFO - 2013-04-10 08:24:07.778; org.apache.solr.core.= CoreContainer$Initializer; looking for solr config file: C:\Users\JenkinsSl= ave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.= apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty1-1365582247078\solr= .xml [junit4:junit4] 1> INFO - 2013-04-10 08:24:07.779; org.apache.solr.core.= CoreContainer; New CoreContainer 23939827 [junit4:junit4] 1> INFO - 2013-04-10 08:24:07.779; org.apache.solr.core.= CoreContainer; Loading CoreContainer using Solr Home: 'C:\Users\JenkinsSlav= e\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.ap= ache.solr.cloud.CollectionsAPIDistributedZkTest-jetty1-1365582247078\' [junit4:junit4] 1> INFO - 2013-04-10 08:24:07.780; org.apache.solr.core.= SolrResourceLoader; new SolrResourceLoader for directory: 'C:\Users\Jenkins= Slave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\or= g.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty1-1365582247078\' [junit4:junit4] 1> INFO - 2013-04-10 08:24:07.843; org.apache.solr.handl= er.component.HttpShardHandlerFactory; Setting socketTimeout to: 120000 [junit4:junit4] 1> INFO - 2013-04-10 08:24:07.843; org.apache.solr.handl= er.component.HttpShardHandlerFactory; Setting urlScheme to: http:// [junit4:junit4] 1> INFO - 2013-04-10 08:24:07.844; org.apache.solr.handl= er.component.HttpShardHandlerFactory; Setting connTimeout to: 15000 [junit4:junit4] 1> INFO - 2013-04-10 08:24:07.845; org.apache.solr.handl= er.component.HttpShardHandlerFactory; Setting maxConnectionsPerHost to: 20 [junit4:junit4] 1> INFO - 2013-04-10 08:24:07.845; org.apache.solr.handl= er.component.HttpShardHandlerFactory; Setting corePoolSize to: 0 [junit4:junit4] 1> INFO - 2013-04-10 08:24:07.845; org.apache.solr.handl= er.component.HttpShardHandlerFactory; Setting maximumPoolSize to: 214748364= 7 [junit4:junit4] 1> INFO - 2013-04-10 08:24:07.846; org.apache.solr.handl= er.component.HttpShardHandlerFactory; Setting maxThreadIdleTime to: 5 [junit4:junit4] 1> INFO - 2013-04-10 08:24:07.846; org.apache.solr.handl= er.component.HttpShardHandlerFactory; Setting sizeOfQueue to: -1 [junit4:junit4] 1> INFO - 2013-04-10 08:24:07.847; org.apache.solr.handl= er.component.HttpShardHandlerFactory; Setting fairnessPolicy to: false [junit4:junit4] 1> INFO - 2013-04-10 08:24:07.848; org.apache.solr.clien= t.solrj.impl.HttpClientUtil; Creating new http client, config:maxConnection= sPerHost=3D20&maxConnections=3D10000&socketTimeout=3D120000&connTimeout=3D1= 5000&retry=3Dfalse [junit4:junit4] 1> INFO - 2013-04-10 08:24:07.864; org.apache.solr.core.= CoreContainer; Registering Log Listener [junit4:junit4] 1> INFO - 2013-04-10 08:24:07.891; org.apache.solr.core.= CoreContainer; Zookeeper client=3D127.0.0.1:50431/solr [junit4:junit4] 1> INFO - 2013-04-10 08:24:07.891; org.apache.solr.cloud= .ZkController; zkHost includes chroot [junit4:junit4] 1> INFO - 2013-04-10 08:24:07.895; org.apache.solr.commo= n.cloud.ConnectionManager; Waiting for client to connect to ZooKeeper [junit4:junit4] 1> INFO - 2013-04-10 08:24:07.916; org.apache.solr.commo= n.cloud.ConnectionManager; Watcher org.apache.solr.common.cloud.ConnectionM= anager@1fda7e1 name:ZooKeeperConnection Watcher:127.0.0.1:50431 got event W= atchedEvent state:SyncConnected type:None path:null path:null type:None [junit4:junit4] 1> INFO - 2013-04-10 08:24:07.917; org.apache.solr.commo= n.cloud.ConnectionManager; Client is connected to ZooKeeper [junit4:junit4] 1> INFO - 2013-04-10 08:24:07.928; org.apache.solr.clien= t.solrj.impl.HttpClientUtil; Creating new http client, config:maxConnection= s=3D500&maxConnectionsPerHost=3D16&socketTimeout=3D120000&connTimeout=3D150= 00 [junit4:junit4] 1> INFO - 2013-04-10 08:24:07.937; org.apache.solr.commo= n.cloud.ConnectionManager; Waiting for client to connect to ZooKeeper [junit4:junit4] 1> INFO - 2013-04-10 08:24:07.967; org.apache.solr.commo= n.cloud.ConnectionManager; Watcher org.apache.solr.common.cloud.ConnectionM= anager@1894e52 name:ZooKeeperConnection Watcher:127.0.0.1:50431/solr got ev= ent WatchedEvent state:SyncConnected type:None path:null path:null type:Non= e [junit4:junit4] 1> INFO - 2013-04-10 08:24:07.968; org.apache.solr.commo= n.cloud.ConnectionManager; Client is connected to ZooKeeper [junit4:junit4] 1> INFO - 2013-04-10 08:24:08.010; org.apache.solr.commo= n.cloud.ZkStateReader; Updating cluster state from ZooKeeper...=20 [junit4:junit4] 1> INFO - 2013-04-10 08:24:09.021; org.apache.solr.cloud= .ZkController; Register node as live in ZooKeeper:/live_nodes/127.0.0.1:504= 50_ [junit4:junit4] 1> INFO - 2013-04-10 08:24:09.032; org.apache.solr.commo= n.cloud.SolrZkClient; makePath: /live_nodes/127.0.0.1:50450_ [junit4:junit4] 1> INFO - 2013-04-10 08:24:09.041; org.apache.solr.commo= n.cloud.ZkStateReader$3; Updating live nodes... (2) [junit4:junit4] 1> INFO - 2013-04-10 08:24:09.041; org.apache.solr.commo= n.cloud.ZkStateReader$3; Updating live nodes... (2) [junit4:junit4] 1> INFO - 2013-04-10 08:24:09.042; org.apache.solr.commo= n.cloud.ZkStateReader$3; Updating live nodes... (2) [junit4:junit4] 1> INFO - 2013-04-10 08:24:09.051; org.apache.solr.servl= et.SolrDispatchFilter; user.dir=3DC:\Users\JenkinsSlave\workspace\Lucene-So= lr-trunk-Windows\solr\build\solr-core\test\J0 [junit4:junit4] 1> INFO - 2013-04-10 08:24:09.051; org.apache.solr.servl= et.SolrDispatchFilter; SolrDispatchFilter.init() done [junit4:junit4] 1> INFO - 2013-04-10 08:24:09.052; org.apache.solr.clien= t.solrj.impl.HttpClientUtil; Creating new http client, config:maxConnection= s=3D128&maxConnectionsPerHost=3D32&followRedirects=3Dfalse [junit4:junit4] 1> INFO - 2013-04-10 08:24:09.530; org.eclipse.jetty.ser= ver.Server; jetty-8.1.8.v20121106 [junit4:junit4] 1> INFO - 2013-04-10 08:24:09.534; org.eclipse.jetty.ser= ver.AbstractConnector; Started SelectChannelConnector@127.0.0.1:50459 [junit4:junit4] 1> INFO - 2013-04-10 08:24:09.534; org.apache.solr.servl= et.SolrDispatchFilter; SolrDispatchFilter.init() [junit4:junit4] 1> INFO - 2013-04-10 08:24:09.535; org.apache.solr.core.= SolrResourceLoader; JNDI not configured for solr (NoInitialContextEx) [junit4:junit4] 1> INFO - 2013-04-10 08:24:09.535; org.apache.solr.core.= SolrResourceLoader; using system property solr.solr.home: C:\Users\JenkinsS= lave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org= .apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty2-1365582249056 [junit4:junit4] 1> INFO - 2013-04-10 08:24:09.536; org.apache.solr.core.= CoreContainer$Initializer; looking for solr config file: C:\Users\JenkinsSl= ave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.= apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty2-1365582249056\solr= .xml [junit4:junit4] 1> INFO - 2013-04-10 08:24:09.536; org.apache.solr.core.= CoreContainer; New CoreContainer 26052380 [junit4:junit4] 1> INFO - 2013-04-10 08:24:09.536; org.apache.solr.core.= CoreContainer; Loading CoreContainer using Solr Home: 'C:\Users\JenkinsSlav= e\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.ap= ache.solr.cloud.CollectionsAPIDistributedZkTest-jetty2-1365582249056\' [junit4:junit4] 1> INFO - 2013-04-10 08:24:09.537; org.apache.solr.core.= SolrResourceLoader; new SolrResourceLoader for directory: 'C:\Users\Jenkins= Slave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\or= g.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty2-1365582249056\' [junit4:junit4] 1> INFO - 2013-04-10 08:24:09.598; org.apache.solr.handl= er.component.HttpShardHandlerFactory; Setting socketTimeout to: 120000 [junit4:junit4] 1> INFO - 2013-04-10 08:24:09.599; org.apache.solr.handl= er.component.HttpShardHandlerFactory; Setting urlScheme to: http:// [junit4:junit4] 1> INFO - 2013-04-10 08:24:09.599; org.apache.solr.handl= er.component.HttpShardHandlerFactory; Setting connTimeout to: 15000 [junit4:junit4] 1> INFO - 2013-04-10 08:24:09.599; org.apache.solr.handl= er.component.HttpShardHandlerFactory; Setting maxConnectionsPerHost to: 20 [junit4:junit4] 1> INFO - 2013-04-10 08:24:09.600; org.apache.solr.handl= er.component.HttpShardHandlerFactory; Setting corePoolSize to: 0 [junit4:junit4] 1> INFO - 2013-04-10 08:24:09.600; org.apache.solr.handl= er.component.HttpShardHandlerFactory; Setting maximumPoolSize to: 214748364= 7 [junit4:junit4] 1> INFO - 2013-04-10 08:24:09.600; org.apache.solr.handl= er.component.HttpShardHandlerFactory; Setting maxThreadIdleTime to: 5 [junit4:junit4] 1> INFO - 2013-04-10 08:24:09.601; org.apache.solr.handl= er.component.HttpShardHandlerFactory; Setting sizeOfQueue to: -1 [junit4:junit4] 1> INFO - 2013-04-10 08:24:09.601; org.apache.solr.handl= er.component.HttpShardHandlerFactory; Setting fairnessPolicy to: false [junit4:junit4] 1> INFO - 2013-04-10 08:24:09.601; org.apache.solr.clien= t.solrj.impl.HttpClientUtil; Creating new http client, config:maxConnection= sPerHost=3D20&maxConnections=3D10000&socketTimeout=3D120000&connTimeout=3D1= 5000&retry=3Dfalse [junit4:junit4] 1> INFO - 2013-04-10 08:24:09.615; org.apache.solr.core.= CoreContainer; Registering Log Listener [junit4:junit4] 1> INFO - 2013-04-10 08:24:09.639; org.apache.solr.core.= CoreContainer; Zookeeper client=3D127.0.0.1:50431/solr [junit4:junit4] 1> INFO - 2013-04-10 08:24:09.639; org.apache.solr.cloud= .ZkController; zkHost includes chroot [junit4:junit4] 1> INFO - 2013-04-10 08:24:09.641; org.apache.solr.commo= n.cloud.ConnectionManager; Waiting for client to connect to ZooKeeper [junit4:junit4] 1> INFO - 2013-04-10 08:24:09.661; org.apache.solr.commo= n.cloud.ConnectionManager; Watcher org.apache.solr.common.cloud.ConnectionM= anager@176c13c name:ZooKeeperConnection Watcher:127.0.0.1:50431 got event W= atchedEvent state:SyncConnected type:None path:null path:null type:None [junit4:junit4] 1> INFO - 2013-04-10 08:24:09.662; org.apache.solr.commo= n.cloud.ConnectionManager; Client is connected to ZooKeeper [junit4:junit4] 1> INFO - 2013-04-10 08:24:09.685; 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> WARN - 2013-04-10 08:24:09.685; org.apache.zookeeper.= server.NIOServerCnxn; caught end of stream exception [junit4:junit4] 1> EndOfStreamException: Unable to read additional data f= rom client sessionid 0x13df30b6ecd0007, likely client has closed socket [junit4:junit4] 1> =09at org.apache.zookeeper.server.NIOServerCnxn.doIO(N= IOServerCnxn.java:220) [junit4:junit4] 1> =09at org.apache.zookeeper.server.NIOServerCnxnFactory= .run(NIOServerCnxnFactory.java:208) [junit4:junit4] 1> =09at java.lang.Thread.run(Thread.java:722) [junit4:junit4] 1> INFO - 2013-04-10 08:24:09.694; org.apache.solr.commo= n.cloud.ConnectionManager; Waiting for client to connect to ZooKeeper [junit4:junit4] 1> INFO - 2013-04-10 08:24:09.698; org.apache.solr.commo= n.cloud.ConnectionManager; Watcher org.apache.solr.common.cloud.ConnectionM= anager@148804b name:ZooKeeperConnection Watcher:127.0.0.1:50431/solr got ev= ent WatchedEvent state:SyncConnected type:None path:null path:null type:Non= e [junit4:junit4] 1> INFO - 2013-04-10 08:24:09.698; org.apache.solr.commo= n.cloud.ConnectionManager; Client is connected to ZooKeeper [junit4:junit4] 1> INFO - 2013-04-10 08:24:09.708; org.apache.solr.commo= n.cloud.ZkStateReader; Updating cluster state from ZooKeeper...=20 [junit4:junit4] 1> INFO - 2013-04-10 08:24:10.717; org.apache.solr.cloud= .ZkController; Register node as live in ZooKeeper:/live_nodes/127.0.0.1:504= 59_ [junit4:junit4] 1> INFO - 2013-04-10 08:24:10.734; org.apache.solr.commo= n.cloud.SolrZkClient; makePath: /live_nodes/127.0.0.1:50459_ [junit4:junit4] 1> INFO - 2013-04-10 08:24:10.741; org.apache.solr.commo= n.cloud.ZkStateReader$3; Updating live nodes... (3) [junit4:junit4] 1> INFO - 2013-04-10 08:24:10.741; org.apache.solr.commo= n.cloud.ZkStateReader$3; Updating live nodes... (3) [junit4:junit4] 1> INFO - 2013-04-10 08:24:10.742; org.apache.solr.commo= n.cloud.ZkStateReader$3; Updating live nodes... (3) [junit4:junit4] 1> INFO - 2013-04-10 08:24:10.742; org.apache.solr.commo= n.cloud.ZkStateReader$3; Updating live nodes... (3) [junit4:junit4] 1> INFO - 2013-04-10 08:24:10.751; org.apache.solr.servl= et.SolrDispatchFilter; user.dir=3DC:\Users\JenkinsSlave\workspace\Lucene-So= lr-trunk-Windows\solr\build\solr-core\test\J0 [junit4:junit4] 1> INFO - 2013-04-10 08:24:10.751; org.apache.solr.servl= et.SolrDispatchFilter; SolrDispatchFilter.init() done [junit4:junit4] 1> INFO - 2013-04-10 08:24:10.751; org.apache.solr.clien= t.solrj.impl.HttpClientUtil; Creating new http client, config:maxConnection= s=3D128&maxConnectionsPerHost=3D32&followRedirects=3Dfalse [junit4:junit4] 1> INFO - 2013-04-10 08:24:11.204; org.eclipse.jetty.ser= ver.Server; jetty-8.1.8.v20121106 [junit4:junit4] 1> INFO - 2013-04-10 08:24:11.208; org.eclipse.jetty.ser= ver.AbstractConnector; Started SelectChannelConnector@127.0.0.1:50468 [junit4:junit4] 1> INFO - 2013-04-10 08:24:11.210; org.apache.solr.servl= et.SolrDispatchFilter; SolrDispatchFilter.init() [junit4:junit4] 1> INFO - 2013-04-10 08:24:11.210; org.apache.solr.core.= SolrResourceLoader; JNDI not configured for solr (NoInitialContextEx) [junit4:junit4] 1> INFO - 2013-04-10 08:24:11.211; org.apache.solr.core.= SolrResourceLoader; using system property solr.solr.home: C:\Users\JenkinsS= lave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org= .apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty3-1365582250756 [junit4:junit4] 1> INFO - 2013-04-10 08:24:11.211; org.apache.solr.core.= CoreContainer$Initializer; looking for solr config file: C:\Users\JenkinsSl= ave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.= apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty3-1365582250756\solr= .xml [junit4:junit4] 1> INFO - 2013-04-10 08:24:11.212; org.apache.solr.core.= CoreContainer; New CoreContainer 4742898 [junit4:junit4] 1> INFO - 2013-04-10 08:24:11.212; org.apache.solr.core.= CoreContainer; Loading CoreContainer using Solr Home: 'C:\Users\JenkinsSlav= e\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.ap= ache.solr.cloud.CollectionsAPIDistributedZkTest-jetty3-1365582250756\' [junit4:junit4] 1> INFO - 2013-04-10 08:24:11.212; org.apache.solr.core.= SolrResourceLoader; new SolrResourceLoader for directory: 'C:\Users\Jenkins= Slave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\or= g.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty3-1365582250756\' [junit4:junit4] 1> INFO - 2013-04-10 08:24:11.273; org.apache.solr.handl= er.component.HttpShardHandlerFactory; Setting socketTimeout to: 120000 [junit4:junit4] 1> INFO - 2013-04-10 08:24:11.274; org.apache.solr.handl= er.component.HttpShardHandlerFactory; Setting urlScheme to: http:// [junit4:junit4] 1> INFO - 2013-04-10 08:24:11.274; org.apache.solr.handl= er.component.HttpShardHandlerFactory; Setting connTimeout to: 15000 [junit4:junit4] 1> INFO - 2013-04-10 08:24:11.274; org.apache.solr.handl= er.component.HttpShardHandlerFactory; Setting maxConnectionsPerHost to: 20 [junit4:junit4] 1> INFO - 2013-04-10 08:24:11.275; org.apache.solr.handl= er.component.HttpShardHandlerFactory; Setting corePoolSize to: 0 [junit4:junit4] 1> INFO - 2013-04-10 08:24:11.275; org.apache.solr.handl= er.component.HttpShardHandlerFactory; Setting maximumPoolSize to: 214748364= 7 [junit4:junit4] 1> INFO - 2013-04-10 08:24:11.275; org.apache.solr.handl= er.component.HttpShardHandlerFactory; Setting maxThreadIdleTime to: 5 [junit4:junit4] 1> INFO - 2013-04-10 08:24:11.277; org.apache.solr.handl= er.component.HttpShardHandlerFactory; Setting sizeOfQueue to: -1 [junit4:junit4] 1> INFO - 2013-04-10 08:24:11.277; org.apache.solr.handl= er.component.HttpShardHandlerFactory; Setting fairnessPolicy to: false [junit4:junit4] 1> INFO - 2013-04-10 08:24:11.277; org.apache.solr.clien= t.solrj.impl.HttpClientUtil; Creating new http client, config:maxConnection= sPerHost=3D20&maxConnections=3D10000&socketTimeout=3D120000&connTimeout=3D1= 5000&retry=3Dfalse [junit4:junit4] 1> INFO - 2013-04-10 08:24:11.292; org.apache.solr.core.= CoreContainer; Registering Log Listener [junit4:junit4] 1> INFO - 2013-04-10 08:24:11.323; org.apache.solr.core.= CoreContainer; Zookeeper client=3D127.0.0.1:50431/solr [junit4:junit4] 1> INFO - 2013-04-10 08:24:11.324; org.apache.solr.cloud= .ZkController; zkHost includes chroot [junit4:junit4] 1> INFO - 2013-04-10 08:24:11.326; org.apache.solr.commo= n.cloud.ConnectionManager; Waiting for client to connect to ZooKeeper [junit4:junit4] 1> INFO - 2013-04-10 08:24:11.344; org.apache.solr.commo= n.cloud.ConnectionManager; Watcher org.apache.solr.common.cloud.ConnectionM= anager@16af0a9 name:ZooKeeperConnection Watcher:127.0.0.1:50431 got event W= atchedEvent state:SyncConnected type:None path:null path:null type:None [junit4:junit4] 1> INFO - 2013-04-10 08:24:11.345; org.apache.solr.commo= n.cloud.ConnectionManager; Client is connected to ZooKeeper [junit4:junit4] 1> INFO - 2013-04-10 08:24:11.350; org.apache.solr.clien= t.solrj.impl.HttpClientUtil; Creating new http client, config:maxConnection= s=3D500&maxConnectionsPerHost=3D16&socketTimeout=3D120000&connTimeout=3D150= 00 [junit4:junit4] 1> INFO - 2013-04-10 08:24:11.357; org.apache.solr.commo= n.cloud.ConnectionManager; Waiting for client to connect to ZooKeeper [junit4:junit4] 1> INFO - 2013-04-10 08:24:11.360; org.apache.solr.commo= n.cloud.ConnectionManager; Watcher org.apache.solr.common.cloud.ConnectionM= anager@1a2e804 name:ZooKeeperConnection Watcher:127.0.0.1:50431/solr got ev= ent WatchedEvent state:SyncConnected type:None path:null path:null type:Non= e [junit4:junit4] 1> INFO - 2013-04-10 08:24:11.361; org.apache.solr.commo= n.cloud.ConnectionManager; Client is connected to ZooKeeper [junit4:junit4] 1> INFO - 2013-04-10 08:24:11.369; org.apache.solr.commo= n.cloud.ZkStateReader; Updating cluster state from ZooKeeper...=20 [junit4:junit4] 1> INFO - 2013-04-10 08:24:12.380; org.apache.solr.cloud= .ZkController; Register node as live in ZooKeeper:/live_nodes/127.0.0.1:504= 68_ [junit4:junit4] 1> INFO - 2013-04-10 08:24:12.385; org.apache.solr.commo= n.cloud.SolrZkClient; makePath: /live_nodes/127.0.0.1:50468_ [junit4:junit4] 1> INFO - 2013-04-10 08:24:12.391; org.apache.solr.commo= n.cloud.ZkStateReader$3; Updating live nodes... (4) [junit4:junit4] 1> INFO - 2013-04-10 08:24:12.392; org.apache.solr.commo= n.cloud.ZkStateReader$3; Updating live nodes... (4) [junit4:junit4] 1> INFO - 2013-04-10 08:24:12.392; org.apache.solr.commo= n.cloud.ZkStateReader$3; Updating live nodes... (4) [junit4:junit4] 1> INFO - 2013-04-10 08:24:12.392; org.apache.solr.commo= n.cloud.ZkStateReader$3; Updating live nodes... (4) [junit4:junit4] 1> INFO - 2013-04-10 08:24:12.393; org.apache.solr.commo= n.cloud.ZkStateReader$3; Updating live nodes... (4) [junit4:junit4] 1> INFO - 2013-04-10 08:24:12.403; org.apache.solr.servl= et.SolrDispatchFilter; user.dir=3DC:\Users\JenkinsSlave\workspace\Lucene-So= lr-trunk-Windows\solr\build\solr-core\test\J0 [junit4:junit4] 1> INFO - 2013-04-10 08:24:12.404; org.apache.solr.servl= et.SolrDispatchFilter; SolrDispatchFilter.init() done [junit4:junit4] 1> INFO - 2013-04-10 08:24:12.404; org.apache.solr.clien= t.solrj.impl.HttpClientUtil; Creating new http client, config:maxConnection= s=3D128&maxConnectionsPerHost=3D32&followRedirects=3Dfalse [junit4:junit4] 1> INFO - 2013-04-10 08:24:12.837; org.eclipse.jetty.ser= ver.Server; jetty-8.1.8.v20121106 [junit4:junit4] 1> INFO - 2013-04-10 08:24:12.840; org.eclipse.jetty.ser= ver.AbstractConnector; Started SelectChannelConnector@127.0.0.1:50477 [junit4:junit4] 1> INFO - 2013-04-10 08:24:12.841; org.apache.solr.servl= et.SolrDispatchFilter; SolrDispatchFilter.init() [junit4:junit4] 1> INFO - 2013-04-10 08:24:12.841; org.apache.solr.core.= SolrResourceLoader; JNDI not configured for solr (NoInitialContextEx) [junit4:junit4] 1> INFO - 2013-04-10 08:24:12.842; org.apache.solr.core.= SolrResourceLoader; using system property solr.solr.home: C:\Users\JenkinsS= lave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org= .apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1365582252414 [junit4:junit4] 1> INFO - 2013-04-10 08:24:12.843; org.apache.solr.core.= CoreContainer$Initializer; looking for solr config file: C:\Users\JenkinsSl= ave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.= apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1365582252414\solr= .xml [junit4:junit4] 1> INFO - 2013-04-10 08:24:12.843; org.apache.solr.core.= CoreContainer; New CoreContainer 26259950 [junit4:junit4] 1> INFO - 2013-04-10 08:24:12.843; org.apache.solr.core.= CoreContainer; Loading CoreContainer using Solr Home: 'C:\Users\JenkinsSlav= e\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.ap= ache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1365582252414\' [junit4:junit4] 1> INFO - 2013-04-10 08:24:12.843; org.apache.solr.core.= SolrResourceLoader; new SolrResourceLoader for directory: 'C:\Users\Jenkins= Slave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\or= g.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1365582252414\' [junit4:junit4] 1> INFO - 2013-04-10 08:24:12.903; org.apache.solr.handl= er.component.HttpShardHandlerFactory; Setting socketTimeout to: 120000 [junit4:junit4] 1> INFO - 2013-04-10 08:24:12.903; org.apache.solr.handl= er.component.HttpShardHandlerFactory; Setting urlScheme to: http:// [junit4:junit4] 1> INFO - 2013-04-10 08:24:12.903; org.apache.solr.handl= er.component.HttpShardHandlerFactory; Setting connTimeout to: 15000 [junit4:junit4] 1> INFO - 2013-04-10 08:24:12.904; org.apache.solr.handl= er.component.HttpShardHandlerFactory; Setting maxConnectionsPerHost to: 20 [junit4:junit4] 1> INFO - 2013-04-10 08:24:12.904; org.apache.solr.handl= er.component.HttpShardHandlerFactory; Setting corePoolSize to: 0 [junit4:junit4] 1> INFO - 2013-04-10 08:24:12.904; org.apache.solr.handl= er.component.HttpShardHandlerFactory; Setting maximumPoolSize to: 214748364= 7 [junit4:junit4] 1> INFO - 2013-04-10 08:24:12.904; org.apache.solr.handl= er.component.HttpShardHandlerFactory; Setting maxThreadIdleTime to: 5 [junit4:junit4] 1> INFO - 2013-04-10 08:24:12.904; org.apache.solr.handl= er.component.HttpShardHandlerFactory; Setting sizeOfQueue to: -1 [junit4:junit4] 1> INFO - 2013-04-10 08:24:12.905; org.apache.solr.handl= er.component.HttpShardHandlerFactory; Setting fairnessPolicy to: false [junit4:junit4] 1> INFO - 2013-04-10 08:24:12.905; org.apache.solr.clien= t.solrj.impl.HttpClientUtil; Creating new http client, config:maxConnection= sPerHost=3D20&maxConnections=3D10000&socketTimeout=3D120000&connTimeout=3D1= 5000&retry=3Dfalse [junit4:junit4] 1> INFO - 2013-04-10 08:24:12.919; org.apache.solr.core.= CoreContainer; Registering Log Listener [junit4:junit4] 1> INFO - 2013-04-10 08:24:12.948; org.apache.solr.core.= CoreContainer; Zookeeper client=3D127.0.0.1:50431/solr [junit4:junit4] 1> INFO - 2013-04-10 08:24:12.949; org.apache.solr.cloud= .ZkController; zkHost includes chroot [junit4:junit4] 1> INFO - 2013-04-10 08:24:12.952; org.apache.solr.commo= n.cloud.ConnectionManager; Waiting for client to connect to ZooKeeper [junit4:junit4] 1> INFO - 2013-04-10 08:24:12.965; org.apache.solr.commo= n.cloud.ConnectionManager; Watcher org.apache.solr.common.cloud.ConnectionM= anager@12f29f4 name:ZooKeeperConnection Watcher:127.0.0.1:50431 got event W= atchedEvent state:SyncConnected type:None path:null path:null type:None [junit4:junit4] 1> INFO - 2013-04-10 08:24:12.966; org.apache.solr.commo= n.cloud.ConnectionManager; Client is connected to ZooKeeper [junit4:junit4] 1> INFO - 2013-04-10 08:24:12.970; org.apache.solr.clien= t.solrj.impl.HttpClientUtil; Creating new http client, config:maxConnection= s=3D500&maxConnectionsPerHost=3D16&socketTimeout=3D120000&connTimeout=3D150= 00 [junit4:junit4] 1> INFO - 2013-04-10 08:24:12.977; org.apache.solr.commo= n.cloud.ConnectionManager; Waiting for client to connect to ZooKeeper [junit4:junit4] 1> INFO - 2013-04-10 08:24:12.980; org.apache.solr.commo= n.cloud.ConnectionManager; Watcher org.apache.solr.common.cloud.ConnectionM= anager@3242e7 name:ZooKeeperConnection Watcher:127.0.0.1:50431/solr got eve= nt WatchedEvent state:SyncConnected type:None path:null path:null type:None [junit4:junit4] 1> INFO - 2013-04-10 08:24:12.980; org.apache.solr.commo= n.cloud.ConnectionManager; Client is connected to ZooKeeper [junit4:junit4] 1> INFO - 2013-04-10 08:24:12.988; org.apache.solr.commo= n.cloud.ZkStateReader; Updating cluster state from ZooKeeper...=20 [junit4:junit4] 1> INFO - 2013-04-10 08:24:13.998; org.apache.solr.cloud= .ZkController; Register node as live in ZooKeeper:/live_nodes/127.0.0.1:504= 77_ [junit4:junit4] 1> INFO - 2013-04-10 08:24:14.012; org.apache.solr.commo= n.cloud.SolrZkClient; makePath: /live_nodes/127.0.0.1:50477_ [junit4:junit4] 1> INFO - 2013-04-10 08:24:14.020; org.apache.solr.commo= n.cloud.ZkStateReader$3; Updating live nodes... (5) [junit4:junit4] 1> INFO - 2013-04-10 08:24:14.020; org.apache.solr.commo= n.cloud.ZkStateReader$3; Updating live nodes... (5) [junit4:junit4] 1> INFO - 2013-04-10 08:24:14.021; org.apache.solr.commo= n.cloud.ZkStateReader$3; Updating live nodes... (5) [junit4:junit4] 1> INFO - 2013-04-10 08:24:14.021; org.apache.solr.commo= n.cloud.ZkStateReader$3; Updating live nodes... (5) [junit4:junit4] 1> INFO - 2013-04-10 08:24:14.021; org.apache.solr.commo= n.cloud.ZkStateReader$3; Updating live nodes... (5) [junit4:junit4] 1> INFO - 2013-04-10 08:24:14.021; org.apache.solr.commo= n.cloud.ZkStateReader$3; Updating live nodes... (5) [junit4:junit4] 1> INFO - 2013-04-10 08:24:14.032; org.apache.solr.servl= et.SolrDispatchFilter; user.dir=3DC:\Users\JenkinsSlave\workspace\Lucene-So= lr-trunk-Windows\solr\build\solr-core\test\J0 [junit4:junit4] 1> INFO - 2013-04-10 08:24:14.032; org.apache.solr.servl= et.SolrDispatchFilter; SolrDispatchFilter.init() done [junit4:junit4] 1> INFO - 2013-04-10 08:24:14.034; org.apache.solr.clien= t.solrj.impl.HttpClientUtil; Creating new http client, config:maxConnection= s=3D128&maxConnectionsPerHost=3D32&followRedirects=3Dfalse [junit4:junit4] 1> INFO - 2013-04-10 08:24:14.041; org.apache.solr.clien= t.solrj.impl.HttpClientUtil; Creating new http client, config:maxConnection= s=3D128&maxConnectionsPerHost=3D32&followRedirects=3Dfalse [junit4:junit4] 1> INFO - 2013-04-10 08:24:14.052; org.apache.solr.handl= er.admin.CollectionsHandler; Creating Collection : numShards=3D2&name=3Dnod= es_used_collection&replicationFactor=3D2&action=3DCREATE&wt=3Djavabin&versi= on=3D2 [junit4:junit4] 1> INFO - 2013-04-10 08:24:14.055; org.apache.solr.cloud= .DistributedQueue$LatchChildWatcher; Watcher fired on path: /overseer/colle= ction-queue-work state: SyncConnected type NodeChildrenChanged [junit4:junit4] 1> INFO - 2013-04-10 08:24:14.059; org.apache.solr.cloud= .OverseerCollectionProcessor; Overseer Collection Processor: Get the messag= e id:/overseer/collection-queue-work/qn-0000000000 message:{ [junit4:junit4] 1> "operation":"createcollection", [junit4:junit4] 1> "numShards":"2", [junit4:junit4] 1> "maxShardsPerNode":null, [junit4:junit4] 1> "createNodeSet":null, [junit4:junit4] 1> "name":"nodes_used_collection", [junit4:junit4] 1> "replicationFactor":"2"} [junit4:junit4] 1> INFO - 2013-04-10 08:24:14.060; 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:50477_ [junit4:junit4] 1> INFO - 2013-04-10 08:24:14.060; 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:50459_ [junit4:junit4] 1> INFO - 2013-04-10 08:24:14.061; 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:50450_ [junit4:junit4] 1> INFO - 2013-04-10 08:24:14.064; 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:50438_ [junit4:junit4] 1> INFO - 2013-04-10 08:24:14.066; org.apache.solr.core.= CoreContainer; Creating SolrCore 'nodes_used_collection_shard1_replica2' us= ing instanceDir: C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\= solr\build\solr-core\test\J0\.\org.apache.solr.cloud.CollectionsAPIDistribu= tedZkTest-jetty2-1365582249056\nodes_used_collection_shard1_replica2 [junit4:junit4] 1> INFO - 2013-04-10 08:24:14.067; org.apache.solr.cloud= .ZkController; Check for collection zkNode:nodes_used_collection [junit4:junit4] 1> INFO - 2013-04-10 08:24:14.066; org.apache.solr.core.= CoreContainer; Creating SolrCore 'nodes_used_collection_shard1_replica1' us= ing instanceDir: C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\= solr\build\solr-core\test\J0\.\org.apache.solr.cloud.CollectionsAPIDistribu= tedZkTest-jetty4-1365582252414\nodes_used_collection_shard1_replica1 [junit4:junit4] 1> INFO - 2013-04-10 08:24:14.068; org.apache.solr.cloud= .ZkController; Check for collection zkNode:nodes_used_collection [junit4:junit4] 1> INFO - 2013-04-10 08:24:14.067; org.apache.solr.core.= CoreContainer; Creating SolrCore 'nodes_used_collection_shard2_replica1' us= ing instanceDir: C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\= solr\build\solr-core\test\J0\.\org.apache.solr.cloud.CollectionsAPIDistribu= tedZkTest-jetty1-1365582247078\nodes_used_collection_shard2_replica1 [junit4:junit4] 1> INFO - 2013-04-10 08:24:14.069; org.apache.solr.cloud= .ZkController; Check for collection zkNode:nodes_used_collection [junit4:junit4] 1> INFO - 2013-04-10 08:24:14.068; org.apache.solr.core.= CoreContainer; Creating SolrCore 'nodes_used_collection_shard2_replica2' us= ing instanceDir: C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\= solr\build\solr-core\test\J0\.\org.apache.solr.cloud.CollectionsAPIDistribu= tedZkTest-controljetty-1365582245991\nodes_used_collection_shard2_replica2 [junit4:junit4] 1> INFO - 2013-04-10 08:24:14.070; org.apache.solr.cloud= .ZkController; Check for collection zkNode:nodes_used_collection [junit4:junit4] 1> INFO - 2013-04-10 08:24:14.070; org.apache.solr.cloud= .ZkController; Creating collection in ZooKeeper:nodes_used_collection [junit4:junit4] 1> INFO - 2013-04-10 08:24:14.069; org.apache.solr.cloud= .ZkController; Creating collection in ZooKeeper:nodes_used_collection [junit4:junit4] 1> INFO - 2013-04-10 08:24:14.071; org.apache.solr.cloud= .ZkController; Creating collection in ZooKeeper:nodes_used_collection [junit4:junit4] 1> INFO - 2013-04-10 08:24:14.072; org.apache.solr.cloud= .ZkController; Looking for collection configName [junit4:junit4] 1> INFO - 2013-04-10 08:24:14.071; org.apache.solr.cloud= .ZkController; Looking for collection configName [junit4:junit4] 1> INFO - 2013-04-10 08:24:14.070; org.apache.solr.cloud= .ZkController; Creating collection in ZooKeeper:nodes_used_collection [junit4:junit4] 1> INFO - 2013-04-10 08:24:14.073; org.apache.solr.cloud= .ZkController; Looking for collection configName [junit4:junit4] 1> INFO - 2013-04-10 08:24:14.071; org.apache.solr.cloud= .ZkController; Looking for collection configName [junit4:junit4] 1> INFO - 2013-04-10 08:24:14.075; org.apache.solr.cloud= .ZkController; Only one config set found in zk - using it:conf1 [junit4:junit4] 1> INFO - 2013-04-10 08:24:14.077; org.apache.solr.commo= n.cloud.SolrZkClient; makePath: /collections/nodes_used_collection [junit4:junit4] 1> INFO - 2013-04-10 08:24:14.078; org.apache.solr.cloud= .ZkController; Only one config set found in zk - using it:conf1 [junit4:junit4] 1> INFO - 2013-04-10 08:24:14.078; org.apache.solr.cloud= .ZkController; Only one config set found in zk - using it:conf1 [junit4:junit4] 1> INFO - 2013-04-10 08:24:14.079; org.apache.solr.commo= n.cloud.SolrZkClient; makePath: /collections/nodes_used_collection [junit4:junit4] 1> INFO - 2013-04-10 08:24:14.078; org.apache.solr.cloud= .ZkController; Only one config set found in zk - using it:conf1 [junit4:junit4] 1> INFO - 2013-04-10 08:24:14.080; org.apache.solr.commo= n.cloud.SolrZkClient; makePath: /collections/nodes_used_collection [junit4:junit4] 1> INFO - 2013-04-10 08:24:14.079; org.apache.solr.commo= n.cloud.SolrZkClient; makePath: /collections/nodes_used_collection [junit4:junit4] 1> INFO - 2013-04-10 08:24:14.089; org.apache.solr.cloud= .ZkController; Load collection config from:/collections/nodes_used_collecti= on [junit4:junit4] 1> INFO - 2013-04-10 08:24:14.090; org.apache.solr.cloud= .ZkController; Load collection config from:/collections/nodes_used_collecti= on [junit4:junit4] 1> INFO - 2013-04-10 08:24:14.091; org.apache.solr.cloud= .ZkController; Load collection config from:/collections/nodes_used_collecti= on [junit4:junit4] 1> INFO - 2013-04-10 08:24:14.092; org.apache.solr.cloud= .ZkController; Load collection config from:/collections/nodes_used_collecti= on [junit4:junit4] 1> INFO - 2013-04-10 08:24:14.097; org.apache.solr.core.= SolrResourceLoader; new SolrResourceLoader for directory: 'C:\Users\Jenkins= Slave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\or= g.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty2-1365582249056\no= des_used_collection_shard1_replica2\' [junit4:junit4] 1> INFO - 2013-04-10 08:24:14.097; org.apache.solr.core.= SolrResourceLoader; new SolrResourceLoader for directory: 'C:\Users\Jenkins= Slave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\or= g.apache.solr.cloud.CollectionsAPIDistributedZkTest-controljetty-1365582245= 991\nodes_used_collection_shard2_replica2\' [junit4:junit4] 1> INFO - 2013-04-10 08:24:14.098; org.apache.solr.core.= SolrResourceLoader; new SolrResourceLoader for directory: 'C:\Users\Jenkins= Slave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\or= g.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1365582252414\no= des_used_collection_shard1_replica1\' [junit4:junit4] 1> INFO - 2013-04-10 08:24:14.104; org.apache.solr.core.= SolrResourceLoader; new SolrResourceLoader for directory: 'C:\Users\Jenkins= Slave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\or= g.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty1-1365582247078\no= des_used_collection_shard2_replica1\' [junit4:junit4] 1> INFO - 2013-04-10 08:24:14.230; org.apache.solr.core.= SolrConfig; Using Lucene MatchVersion: LUCENE_50 [junit4:junit4] 1> INFO - 2013-04-10 08:24:14.241; org.apache.solr.core.= SolrConfig; Using Lucene MatchVersion: LUCENE_50 [junit4:junit4] 1> INFO - 2013-04-10 08:24:14.296; org.apache.solr.core.= SolrConfig; Using Lucene MatchVersion: LUCENE_50 [junit4:junit4] 1> INFO - 2013-04-10 08:24:14.395; org.apache.solr.core.= SolrConfig; Loaded SolrConfig: solrconfig.xml [junit4:junit4] 1> INFO - 2013-04-10 08:24:14.428; org.apache.solr.core.= SolrConfig; Loaded SolrConfig: solrconfig.xml [junit4:junit4] 1> INFO - 2013-04-10 08:24:14.438; org.apache.solr.core.= SolrConfig; Using Lucene MatchVersion: LUCENE_50 [junit4:junit4] 1> INFO - 2013-04-10 08:24:14.481; org.apache.solr.core.= SolrConfig; Loaded SolrConfig: solrconfig.xml [junit4:junit4] 1> INFO - 2013-04-10 08:24:14.483; org.apache.solr.schem= a.IndexSchema; Reading Solr Schema from schema.xml [junit4:junit4] 1> INFO - 2013-04-10 08:24:14.492; org.apache.solr.schem= a.IndexSchema; Reading Solr Schema from schema.xml [junit4:junit4] 1> INFO - 2013-04-10 08:24:14.502; org.apache.solr.schem= a.IndexSchema; Schema name=3Dtest [junit4:junit4] 1> INFO - 2013-04-10 08:24:14.511; org.apache.solr.schem= a.IndexSchema; Schema name=3Dtest [junit4:junit4] 1> INFO - 2013-04-10 08:24:14.574; org.apache.solr.core.= SolrConfig; Loaded SolrConfig: solrconfig.xml [junit4:junit4] 1> INFO - 2013-04-10 08:24:14.529; org.apache.solr.schem= a.IndexSchema; Reading Solr Schema from schema.xml [junit4:junit4] 1> INFO - 2013-04-10 08:24:14.666; org.apache.solr.schem= a.IndexSchema; Schema name=3Dtest [junit4:junit4] 1> INFO - 2013-04-10 08:24:14.710; org.apache.solr.schem= a.IndexSchema; Reading Solr Schema from schema.xml [junit4:junit4] 1> INFO - 2013-04-10 08:24:14.724; org.apache.solr.schem= a.IndexSchema; Schema name=3Dtest [junit4:junit4] 1> INFO - 2013-04-10 08:24:16.663; org.apache.solr.schem= a.OpenExchangeRatesOrgProvider; Initialized with rates=3Dopen-exchange-rate= s.json, refreshInterval=3D1440. [junit4:junit4] 1> INFO - 2013-04-10 08:24:16.715; org.apache.solr.schem= a.OpenExchangeRatesOrgProvider; Initialized with rates=3Dopen-exchange-rate= s.json, refreshInterval=3D1440. [junit4:junit4] 1> INFO - 2013-04-10 08:24:16.730; org.apache.solr.schem= a.IndexSchema; default search field in schema is text [junit4:junit4] 1> INFO - 2013-04-10 08:24:16.737; org.apache.solr.schem= a.IndexSchema; unique key field: id [junit4:junit4] 1> INFO - 2013-04-10 08:24:16.745; org.apache.solr.schem= a.IndexSchema; default search field in schema is text [junit4:junit4] 1> INFO - 2013-04-10 08:24:16.762; org.apache.solr.schem= a.IndexSchema; unique key field: id [junit4:junit4] 1> INFO - 2013-04-10 08:24:16.827; org.apache.solr.schem= a.FileExchangeRateProvider; Reloading exchange rates from file currency.xml [junit4:junit4] 1> INFO - 2013-04-10 08:24:16.840; org.apache.solr.schem= a.FileExchangeRateProvider; Reloading exchange rates from file currency.xml [junit4:junit4] 1> INFO - 2013-04-10 08:24:16.875; org.apache.solr.schem= a.FileExchangeRateProvider; Reloading exchange rates from file currency.xml [junit4:junit4] 1> INFO - 2013-04-10 08:24:16.942; org.apache.solr.schem= a.OpenExchangeRatesOrgProvider; Initialized with rates=3Dopen-exchange-rate= s.json, refreshInterval=3D1440. [junit4:junit4] 1> INFO - 2013-04-10 08:24:16.962; org.apache.solr.schem= a.IndexSchema; default search field in schema is text [junit4:junit4] 1> INFO - 2013-04-10 08:24:16.969; org.apache.solr.schem= a.IndexSchema; unique key field: id [junit4:junit4] 1> INFO - 2013-04-10 08:24:16.977; org.apache.solr.schem= a.FileExchangeRateProvider; Reloading exchange rates from file currency.xml [junit4:junit4] 1> INFO - 2013-04-10 08:24:16.969; org.apache.solr.schem= a.OpenExchangeRatesOrgProvider; Initialized with rates=3Dopen-exchange-rate= s.json, refreshInterval=3D1440. [junit4:junit4] 1> INFO - 2013-04-10 08:24:16.981; org.apache.solr.schem= a.OpenExchangeRatesOrgProvider; Reloading exchange rates from open-exchange= -rates.json [junit4:junit4] 1> INFO - 2013-04-10 08:24:16.991; org.apache.solr.schem= a.OpenExchangeRatesOrgProvider; Reloading exchange rates from open-exchange= -rates.json [junit4:junit4] 1> WARN - 2013-04-10 08:24:16.992; org.apache.solr.schem= a.OpenExchangeRatesOrgProvider$OpenExchangeRates; Unknown key IMPORTANT NOT= E [junit4:junit4] 1> WARN - 2013-04-10 08:24:16.994; org.apache.solr.schem= a.OpenExchangeRatesOrgProvider$OpenExchangeRates; Expected key, got STRING [junit4:junit4] 1> INFO - 2013-04-10 08:24:16.995; org.apache.solr.schem= a.OpenExchangeRatesOrgProvider; Reloading exchange rates from open-exchange= -rates.json [junit4:junit4] 1> INFO - 2013-04-10 08:24:16.996; org.apache.solr.schem= a.IndexSchema; default search field in schema is text [junit4:junit4] 1> WARN - 2013-04-10 08:24:16.999; org.apache.solr.schem= a.OpenExchangeRatesOrgProvider$OpenExchangeRates; Unknown key IMPORTANT NOT= E [junit4:junit4] 1> WARN - 2013-04-10 08:24:17.003; org.apache.solr.schem= a.OpenExchangeRatesOrgProvider$OpenExchangeRates; Expected key, got STRING [junit4:junit4] 1> INFO - 2013-04-10 08:24:17.003; org.apache.solr.schem= a.OpenExchangeRatesOrgProvider; Reloading exchange rates from open-exchange= -rates.json [junit4:junit4] 1> WARN - 2013-04-10 08:24:17.002; org.apache.solr.schem= a.OpenExchangeRatesOrgProvider$OpenExchangeRates; Unknown key IMPORTANT NOT= E [junit4:junit4] 1> WARN - 2013-04-10 08:24:17.005; org.apache.solr.schem= a.OpenExchangeRatesOrgProvider$OpenExchangeRates; Expected key, got STRING [junit4:junit4] 1> INFO - 2013-04-10 08:24:17.005; org.apache.solr.core.= SolrCore; org.apache.solr.core.MockDirectoryFactory [junit4:junit4] 1> INFO - 2013-04-10 08:24:17.007; org.apache.solr.core.= SolrCore; [nodes_used_collection_shard1_replica2] Opening new SolrCore at C= :\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-co= re\test\J0\.\org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty2-1= 365582249056\nodes_used_collection_shard1_replica2\, dataDir=3DC:\Users\Jen= kinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\= .\org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty2-136558224905= 6\nodes_used_collection_shard1_replica2\data\ [junit4:junit4] 1> INFO - 2013-04-10 08:24:17.007; org.apache.solr.core.= JmxMonitoredMap; JMX monitoring is enabled. Adding Solr mbeans to JMX Serve= r: com.sun.jmx.mbeanserver.JmxMBeanServer@ad0010 [junit4:junit4] 1> INFO - 2013-04-10 08:24:17.008; org.apache.solr.core.= SolrCore; org.apache.solr.core.MockDirectoryFactory [junit4:junit4] 1> INFO - 2013-04-10 08:24:17.009; org.apache.solr.core.= CachingDirectoryFactory; return new directory for C:\Users\JenkinsSlave\wor= kspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.= solr.cloud.CollectionsAPIDistributedZkTest-jetty2-1365582249056\nodes_used_= collection_shard1_replica2\data\ [junit4:junit4] 1> INFO - 2013-04-10 08:24:17.009; org.apache.solr.core.= SolrCore; New index directory detected: old=3Dnull new=3DC:\Users\JenkinsSl= ave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.= apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty2-1365582249056\node= s_used_collection_shard1_replica2\data\index/ [junit4:junit4] 1> WARN - 2013-04-10 08:24:17.010; org.apache.solr.core.= SolrCore; [nodes_used_collection_shard1_replica2] Solr index directory 'C:\= Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core= \test\J0\.\org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty2-136= 5582249056\nodes_used_collection_shard1_replica2\data\index' doesn't exist.= Creating new index... [junit4:junit4] 1> INFO - 2013-04-10 08:24:17.011; org.apache.solr.core.= CachingDirectoryFactory; return new directory for C:\Users\JenkinsSlave\wor= kspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.= solr.cloud.CollectionsAPIDistributedZkTest-jetty2-1365582249056\nodes_used_= collection_shard1_replica2\data\index [junit4:junit4] 1> INFO - 2013-04-10 08:24:17.017; org.apache.solr.schem= a.IndexSchema; unique key field: id [junit4:junit4] 1> INFO - 2013-04-10 08:24:17.026; org.apache.solr.core.= SolrDeletionPolicy; SolrDeletionPolicy.onCommit: commits:num=3D1 [junit4:junit4] 1> =09commit{dir=3DBaseDirectoryWrapper(org.apache.lucene= .store.RAMDirectory@1aacc4c lockFactory=3Dorg.apache.lucene.store.NativeFSL= ockFactory@1d462b2),segFN=3Dsegments_1,generation=3D1,filenames=3D[segments= _1] [junit4:junit4] 1> INFO - 2013-04-10 08:24:17.027; org.apache.solr.core.= SolrDeletionPolicy; newest commit =3D 1[segments_1] [junit4:junit4] 1> INFO - 2013-04-10 08:24:17.032; org.apache.solr.updat= e.processor.UpdateRequestProcessorChain; inserting DistributedUpdateProcess= orFactory into updateRequestProcessorChain "dedupe" [junit4:junit4] 1> INFO - 2013-04-10 08:24:17.032; org.apache.solr.updat= e.processor.UpdateRequestProcessorChain; inserting DistributedUpdateProcess= orFactory into updateRequestProcessorChain "stored_sig" [junit4:junit4] 1> INFO - 2013-04-10 08:24:17.034; org.apache.solr.updat= e.processor.UpdateRequestProcessorChain; inserting DistributedUpdateProcess= orFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit= " [junit4:junit4] 1> INFO - 2013-04-10 08:24:17.035; org.apache.solr.core.= RequestHandlers; created standard: solr.StandardRequestHandler [junit4:junit4] 1> INFO - 2013-04-10 08:24:17.037; org.apache.solr.core.= RequestHandlers; created /get: solr.RealTimeGetHandler [junit4:junit4] 1> INFO - 2013-04-10 08:24:17.037; org.apache.solr.core.= RequestHandlers; adding lazy requestHandler: solr.ReplicationHandler [junit4:junit4] 1> INFO - 2013-04-10 08:24:17.038; org.apache.solr.core.= RequestHandlers; created /replication: solr.ReplicationHandler [junit4:junit4] 1> INFO - 2013-04-10 08:24:17.039; org.apache.solr.core.= RequestHandlers; created /update: solr.UpdateRequestHandler [junit4:junit4] 1> INFO - 2013-04-10 08:24:17.040; org.apache.solr.core.= RequestHandlers; created /admin/: org.apache.solr.handler.admin.AdminHandle= rs [junit4:junit4] 1> WARN - 2013-04-10 08:24:17.041; org.apache.solr.schem= a.OpenExchangeRatesOrgProvider$OpenExchangeRates; Unknown key IMPORTANT NOT= E [junit4:junit4] 1> WARN - 2013-04-10 08:24:17.041; org.apache.solr.schem= a.OpenExchangeRatesOrgProvider$OpenExchangeRates; Expected key, got STRING [junit4:junit4] 1> INFO - 2013-04-10 08:24:17.043; org.apache.solr.core.= SolrCore; org.apache.solr.core.MockDirectoryFactory [junit4:junit4] 1> INFO - 2013-04-10 08:24:17.044; org.apache.solr.core.= SolrCore; [nodes_used_collection_shard1_replica1] Opening new SolrCore at C= :\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-co= re\test\J0\.\org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1= 365582252414\nodes_used_collection_shard1_replica1\, dataDir=3DC:\Users\Jen= kinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\= .\org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-136558225241= 4\nodes_used_collection_shard1_replica1\data\ [junit4:junit4] 1> INFO - 2013-04-10 08:24:17.044; org.apache.solr.core.= JmxMonitoredMap; JMX monitoring is enabled. Adding Solr mbeans to JMX Serve= r: com.sun.jmx.mbeanserver.JmxMBeanServer@ad0010 [junit4:junit4] 1> INFO - 2013-04-10 08:24:17.044; org.apache.solr.core.= SolrCore; org.apache.solr.core.MockDirectoryFactory [junit4:junit4] 1> INFO - 2013-04-10 08:24:17.045; org.apache.solr.core.= CachingDirectoryFactory; return new directory for C:\Users\JenkinsSlave\wor= kspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.= solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1365582252414\nodes_used_= collection_shard1_replica1\data\ [junit4:junit4] 1> INFO - 2013-04-10 08:24:17.046; org.apache.solr.core.= SolrCore; New index directory detected: old=3Dnull new=3DC:\Users\JenkinsSl= ave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.= apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1365582252414\node= s_used_collection_shard1_replica1\data\index/ [junit4:junit4] 1> WARN - 2013-04-10 08:24:17.046; org.apache.solr.core.= SolrCore; [nodes_used_collection_shard1_replica1] Solr index directory 'C:\= Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core= \test\J0\.\org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-136= 5582252414\nodes_used_collection_shard1_replica1\data\index' doesn't exist.= Creating new index... [junit4:junit4] 1> INFO - 2013-04-10 08:24:17.047; org.apache.solr.core.= CachingDirectoryFactory; return new directory for C:\Users\JenkinsSlave\wor= kspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.= solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1365582252414\nodes_used_= collection_shard1_replica1\data\index [junit4:junit4] 1> INFO - 2013-04-10 08:24:17.060; org.apache.solr.handl= er.loader.XMLLoader; xsltCacheLifetimeSeconds=3D60 [junit4:junit4] 1> INFO - 2013-04-10 08:24:17.092; org.apache.solr.core.= SolrDeletionPolicy; SolrDeletionPolicy.onCommit: commits:num=3D1 [junit4:junit4] 1> =09commit{dir=3DBaseDirectoryWrapper(org.apache.lucene= .store.RAMDirectory@112c7d3 lockFactory=3Dorg.apache.lucene.store.NativeFSL= ockFactory@11c643e),segFN=3Dsegments_1,generation=3D1,filenames=3D[segments= _1] [junit4:junit4] 1> INFO - 2013-04-10 08:24:17.093; org.apache.solr.core.= SolrDeletionPolicy; newest commit =3D 1[segments_1] [junit4:junit4] 1> INFO - 2013-04-10 08:24:17.093; org.apache.solr.searc= h.SolrIndexSearcher; Opening Searcher@1487c46 main [junit4:junit4] 1> INFO - 2013-04-10 08:24:17.096; org.apache.solr.updat= e.UpdateHandler; Clearing tlog files, tlogDir=3DC:\Users\JenkinsSlave\works= pace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.so= lr.cloud.CollectionsAPIDistributedZkTest-jetty2-1365582249056\nodes_used_co= llection_shard1_replica2\data\tlog [junit4:junit4] 1> INFO - 2013-04-10 08:24:17.105; org.apache.solr.schem= a.FileExchangeRateProvider; Reloading exchange rates from file currency.xml [junit4:junit4] 1> INFO - 2013-04-10 08:24:17.115; org.apache.solr.schem= a.FileExchangeRateProvider; Reloading exchange rates from file currency.xml [junit4:junit4] 1> INFO - 2013-04-10 08:24:17.125; org.apache.solr.schem= a.FileExchangeRateProvider; Reloading exchange rates from file currency.xml [junit4:junit4] 1> INFO - 2013-04-10 08:24:17.128; org.apache.solr.schem= a.FileExchangeRateProvider; Reloading exchange rates from file currency.xml [junit4:junit4] 1> INFO - 2013-04-10 08:24:17.136; org.apache.solr.schem= a.OpenExchangeRatesOrgProvider; Reloading exchange rates from open-exchange= -rates.json [junit4:junit4] 1> INFO - 2013-04-10 08:24:17.139; org.apache.solr.schem= a.OpenExchangeRatesOrgProvider; Reloading exchange rates from open-exchange= -rates.json [junit4:junit4] 1> WARN - 2013-04-10 08:24:17.141; org.apache.solr.schem= a.OpenExchangeRatesOrgProvider$OpenExchangeRates; Unknown key IMPORTANT NOT= E [junit4:junit4] 1> WARN - 2013-04-10 08:24:17.141; org.apache.solr.schem= a.OpenExchangeRatesOrgProvider$OpenExchangeRates; Expected key, got STRING [junit4:junit4] 1> INFO - 2013-04-10 08:24:17.141; org.apache.solr.schem= a.OpenExchangeRatesOrgProvider; Reloading exchange rates from open-exchange= -rates.json [junit4:junit4] 1> WARN - 2013-04-10 08:24:17.142; org.apache.solr.schem= a.OpenExchangeRatesOrgProvider$OpenExchangeRates; Unknown key IMPORTANT NOT= E [junit4:junit4] 1> WARN - 2013-04-10 08:24:17.142; org.apache.solr.schem= a.OpenExchangeRatesOrgProvider$OpenExchangeRates; Expected key, got STRING [junit4:junit4] 1> INFO - 2013-04-10 08:24:17.143; org.apache.solr.schem= a.OpenExchangeRatesOrgProvider; Reloading exchange rates from open-exchange= -rates.json [junit4:junit4] 1> WARN - 2013-04-10 08:24:17.152; org.apache.solr.schem= a.OpenExchangeRatesOrgProvider$OpenExchangeRates; Unknown key IMPORTANT NOT= E [junit4:junit4] 1> WARN - 2013-04-10 08:24:17.152; org.apache.solr.schem= a.OpenExchangeRatesOrgProvider$OpenExchangeRates; Expected key, got STRING [junit4:junit4] 1> INFO - 2013-04-10 08:24:17.153; org.apache.solr.core.= SolrCore; org.apache.solr.core.MockDirectoryFactory [junit4:junit4] 1> INFO - 2013-04-10 08:24:17.153; org.apache.solr.core.= SolrCore; [nodes_used_collection_shard2_replica1] Opening new SolrCore at C= :\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-co= re\test\J0\.\org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty1-1= 365582247078\nodes_used_collection_shard2_replica1\, dataDir=3DC:\Users\Jen= kinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\= .\org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty1-136558224707= 8\nodes_used_collection_shard2_replica1\data\ [junit4:junit4] 1> INFO - 2013-04-10 08:24:17.153; org.apache.solr.core.= JmxMonitoredMap; JMX monitoring is enabled. Adding Solr mbeans to JMX Serve= r: com.sun.jmx.mbeanserver.JmxMBeanServer@ad0010 [junit4:junit4] 1> INFO - 2013-04-10 08:24:17.154; org.apache.solr.core.= SolrCore; org.apache.solr.core.MockDirectoryFactory [junit4:junit4] 1> INFO - 2013-04-10 08:24:17.156; org.apache.solr.core.= CachingDirectoryFactory; return new directory for C:\Users\JenkinsSlave\wor= kspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.= solr.cloud.CollectionsAPIDistributedZkTest-jetty1-1365582247078\nodes_used_= collection_shard2_replica1\data\ [junit4:junit4] 1> INFO - 2013-04-10 08:24:17.157; org.apache.solr.core.= SolrCore; New index directory detected: old=3Dnull new=3DC:\Users\JenkinsSl= ave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.= apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty1-1365582247078\node= s_used_collection_shard2_replica1\data\index/ [junit4:junit4] 1> WARN - 2013-04-10 08:24:17.157; org.apache.solr.core.= SolrCore; [nodes_used_collection_shard2_replica1] Solr index directory 'C:\= Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core= \test\J0\.\org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty1-136= 5582247078\nodes_used_collection_shard2_replica1\data\index' doesn't exist.= Creating new index... [junit4:junit4] 1> INFO - 2013-04-10 08:24:17.158; org.apache.solr.updat= e.processor.UpdateRequestProcessorChain; inserting DistributedUpdateProcess= orFactory into updateRequestProcessorChain "dedupe" [junit4:junit4] 1> INFO - 2013-04-10 08:24:17.158; org.apache.solr.updat= e.processor.UpdateRequestProcessorChain; inserting DistributedUpdateProcess= orFactory into updateRequestProcessorChain "stored_sig" [junit4:junit4] 1> INFO - 2013-04-10 08:24:17.153; org.apache.solr.updat= e.CommitTracker; Hard AutoCommit: disabled [junit4:junit4] 1> INFO - 2013-04-10 08:24:17.160; org.apache.solr.updat= e.CommitTracker; Soft AutoCommit: disabled [junit4:junit4] 1> INFO - 2013-04-10 08:24:17.159; org.apache.solr.updat= e.processor.UpdateRequestProcessorChain; inserting DistributedUpdateProcess= orFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit= " [junit4:junit4] 1> WARN - 2013-04-10 08:24:17.160; org.apache.solr.schem= a.OpenExchangeRatesOrgProvider$OpenExchangeRates; Unknown key IMPORTANT NOT= E [junit4:junit4] 1> INFO - 2013-04-10 08:24:17.161; org.apache.solr.core.= RequestHandlers; created standard: solr.StandardRequestHandler [junit4:junit4] 1> INFO - 2013-04-10 08:24:17.158; org.apache.solr.core.= CachingDirectoryFactory; return new directory for C:\Users\JenkinsSlave\wor= kspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.= solr.cloud.CollectionsAPIDistributedZkTest-jetty1-1365582247078\nodes_used_= collection_shard2_replica1\data\index [junit4:junit4] 1> INFO - 2013-04-10 08:24:17.162; org.apache.solr.core.= RequestHandlers; created /get: solr.RealTimeGetHandler [junit4:junit4] 1> INFO - 2013-04-10 08:24:17.162; org.apache.solr.core.= RequestHandlers; adding lazy requestHandler: solr.ReplicationHandler [junit4:junit4] 1> INFO - 2013-04-10 08:24:17.162; org.apache.solr.core.= RequestHandlers; created /replication: solr.ReplicationHandler [junit4:junit4] 1> INFO - 2013-04-10 08:24:17.164; org.apache.solr.core.= RequestHandlers; created /update: solr.UpdateRequestHandler [junit4:junit4] 1> INFO - 2013-04-10 08:24:17.165; org.apache.solr.core.= RequestHandlers; created /admin/: org.apache.solr.handler.admin.AdminHandle= rs [junit4:junit4] 1> WARN - 2013-04-10 08:24:17.161; org.apache.solr.schem= a.OpenExchangeRatesOrgProvider$OpenExchangeRates; Expected key, got STRING [junit4:junit4] 1> INFO - 2013-04-10 08:24:17.166; org.apache.solr.core.= SolrCore; org.apache.solr.core.MockDirectoryFactory [junit4:junit4] 1> INFO - 2013-04-10 08:24:17.167; org.apache.solr.core.= SolrCore; [nodes_used_collection_shard2_replica2] Opening new SolrCore at C= :\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-co= re\test\J0\.\org.apache.solr.cloud.CollectionsAPIDistributedZkTest-controlj= etty-1365582245991\nodes_used_collection_shard2_replica2\, dataDir=3DC:\Use= rs\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\te= st\J0\.\org.apache.solr.cloud.CollectionsAPIDistributedZkTest-controljetty-= 1365582245991\nodes_used_collection_shard2_replica2\data\ [junit4:junit4] 1> INFO - 2013-04-10 08:24:17.167; org.apache.solr.core.= JmxMonitoredMap; JMX monitoring is enabled. Adding Solr mbeans to JMX Serve= r: com.sun.jmx.mbeanserver.JmxMBeanServer@ad0010 [junit4:junit4] 1> INFO - 2013-04-10 08:24:17.168; org.apache.solr.core.= SolrCore; org.apache.solr.core.MockDirectoryFactory [junit4:junit4] 1> INFO - 2013-04-10 08:24:17.170; org.apache.solr.core.= CachingDirectoryFactory; return new directory for C:\Users\JenkinsSlave\wor= kspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.= solr.cloud.CollectionsAPIDistributedZkTest-controljetty-1365582245991\nodes= _used_collection_shard2_replica2\data\ [junit4:junit4] 1> INFO - 2013-04-10 08:24:17.170; org.apache.solr.core.= SolrCore; New index directory detected: old=3Dnull new=3DC:\Users\JenkinsSl= ave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.= apache.solr.cloud.CollectionsAPIDistributedZkTest-controljetty-136558224599= 1\nodes_used_collection_shard2_replica2\data\index/ [junit4:junit4] 1> WARN - 2013-04-10 08:24:17.170; org.apache.solr.core.= SolrCore; [nodes_used_collection_shard2_replica2] Solr index directory 'C:\= Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core= \test\J0\.\org.apache.solr.cloud.CollectionsAPIDistributedZkTest-controljet= ty-1365582245991\nodes_used_collection_shard2_replica2\data\index' doesn't = exist. Creating new index... [junit4:junit4] 1> INFO - 2013-04-10 08:24:17.171; org.apache.solr.core.= CachingDirectoryFactory; return new directory for C:\Users\JenkinsSlave\wor= kspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.= solr.cloud.CollectionsAPIDistributedZkTest-controljetty-1365582245991\nodes= _used_collection_shard2_replica2\data\index [junit4:junit4] 1> INFO - 2013-04-10 08:24:17.179; org.apache.solr.cloud= .ZkController; publishing core=3Dnodes_used_collection_shard1_replica2 stat= e=3Ddown [junit4:junit4] 1> INFO - 2013-04-10 08:24:17.181; org.apache.solr.handl= er.loader.XMLLoader; xsltCacheLifetimeSeconds=3D60 [junit4:junit4] 1> INFO - 2013-04-10 08:24:17.184; org.apache.solr.core.= SolrCore; [nodes_used_collection_shard1_replica2] Registered new searcher S= earcher@1487c46 main{StandardDirectoryReader(segments_1:1)} [junit4:junit4] 1> INFO - 2013-04-10 08:24:17.193; org.apache.solr.searc= h.SolrIndexSearcher; Opening Searcher@18837fa main [junit4:junit4] 1> INFO - 2013-04-10 08:24:17.194; org.apache.solr.updat= e.UpdateHandler; Clearing tlog files, tlogDir=3DC:\Users\JenkinsSlave\works= pace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.so= lr.cloud.CollectionsAPIDistributedZkTest-jetty4-1365582252414\nodes_used_co= llection_shard1_replica1\data\tlog [junit4:junit4] 1> INFO - 2013-04-10 08:24:17.194; org.apache.solr.core.= SolrDeletionPolicy; SolrDeletionPolicy.onCommit: commits:num=3D1 [junit4:junit4] 1> =09commit{dir=3DBaseDirectoryWrapper(org.apache.lucene= .store.RAMDirectory@1bae7f6 lockFactory=3Dorg.apache.lucene.store.NativeFSL= ockFactory@3e0df8),segFN=3Dsegments_1,generation=3D1,filenames=3D[segments_= 1] [junit4:junit4] 1> INFO - 2013-04-10 08:24:17.195; org.apache.solr.core.= SolrDeletionPolicy; newest commit =3D 1[segments_1] [junit4:junit4] 1> INFO - 2013-04-10 08:24:17.198; org.apache.solr.updat= e.CommitTracker; Hard AutoCommit: disabled [junit4:junit4] 1> INFO - 2013-04-10 08:24:17.199; org.apache.solr.updat= e.CommitTracker; Soft AutoCommit: disabled [junit4:junit4] 1> INFO - 2013-04-10 08:24:17.201; org.apache.solr.updat= e.processor.UpdateRequestProcessorChain; inserting DistributedUpdateProcess= orFactory into updateRequestProcessorChain "dedupe" [junit4:junit4] 1> INFO - 2013-04-10 08:24:17.202; org.apache.solr.updat= e.processor.UpdateRequestProcessorChain; inserting DistributedUpdateProcess= orFactory into updateRequestProcessorChain "stored_sig" [junit4:junit4] 1> INFO - 2013-04-10 08:24:17.203; org.apache.solr.updat= e.processor.UpdateRequestProcessorChain; inserting DistributedUpdateProcess= orFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit= " [junit4:junit4] 1> INFO - 2013-04-10 08:24:17.205; org.apache.solr.core.= RequestHandlers; created standard: solr.StandardRequestHandler [junit4:junit4] 1> INFO - 2013-04-10 08:24:17.205; org.apache.solr.cloud= .ZkController; publishing core=3Dnodes_used_collection_shard1_replica1 stat= e=3Ddown [junit4:junit4] 1> INFO - 2013-04-10 08:24:17.206; org.apache.solr.core.= RequestHandlers; created /get: solr.RealTimeGetHandler [junit4:junit4] 1> INFO - 2013-04-10 08:24:17.207; org.apache.solr.core.= RequestHandlers; adding lazy requestHandler: solr.ReplicationHandler [junit4:junit4] 1> INFO - 2013-04-10 08:24:17.208; org.apache.solr.core.= RequestHandlers; created /replication: solr.ReplicationHandler [junit4:junit4] 1> INFO - 2013-04-10 08:24:17.209; org.apache.solr.core.= SolrDeletionPolicy; SolrDeletionPolicy.onCommit: commits:num=3D1 [junit4:junit4] 1> =09commit{dir=3DBaseDirectoryWrapper(org.apache.lucene= .store.RAMDirectory@b9ca1a lockFactory=3Dorg.apache.lucene.store.NativeFSLo= ckFactory@16ff7c3),segFN=3Dsegments_1,generation=3D1,filenames=3D[segments_= 1] [junit4:junit4] 1> INFO - 2013-04-10 08:24:17.209; org.apache.solr.core.= SolrDeletionPolicy; newest commit =3D 1[segments_1] [junit4:junit4] 1> INFO - 2013-04-10 08:24:17.207; org.apache.solr.core.= SolrCore; [nodes_used_collection_shard1_replica1] Registered new searcher S= earcher@18837fa main{StandardDirectoryReader(segments_1:1)} [junit4:junit4] 1> INFO - 2013-04-10 08:24:17.209; org.apache.solr.core.= RequestHandlers; created /update: solr.UpdateRequestHandler [junit4:junit4] 1> INFO - 2013-04-10 08:24:17.212; org.apache.solr.core.= RequestHandlers; created /admin/: org.apache.solr.handler.admin.AdminHandle= rs [junit4:junit4] 1> INFO - 2013-04-10 08:24:17.217; org.apache.solr.updat= e.processor.UpdateRequestProcessorChain; inserting DistributedUpdateProcess= orFactory into updateRequestProcessorChain "dedupe" [junit4:junit4] 1> INFO - 2013-04-10 08:24:17.218; org.apache.solr.updat= e.processor.UpdateRequestProcessorChain; inserting DistributedUpdateProcess= orFactory into updateRequestProcessorChain "stored_sig" [junit4:junit4] 1> INFO - 2013-04-10 08:24:17.219; org.apache.solr.updat= e.processor.UpdateRequestProcessorChain; inserting DistributedUpdateProcess= orFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit= " [junit4:junit4] 1> INFO - 2013-04-10 08:24:17.220; org.apache.solr.core.= RequestHandlers; created standard: solr.StandardRequestHandler [junit4:junit4] 1> INFO - 2013-04-10 08:24:17.221; org.apache.solr.core.= RequestHandlers; created /get: solr.RealTimeGetHandler [junit4:junit4] 1> INFO - 2013-04-10 08:24:17.221; org.apache.solr.core.= RequestHandlers; adding lazy requestHandler: solr.ReplicationHandler [junit4:junit4] 1> INFO - 2013-04-10 08:24:17.221; org.apache.solr.core.= RequestHandlers; created /replication: solr.ReplicationHandler [junit4:junit4] 1> INFO - 2013-04-10 08:24:17.222; org.apache.solr.core.= RequestHandlers; created /update: solr.UpdateRequestHandler [junit4:junit4] 1> INFO - 2013-04-10 08:24:17.224; org.apache.solr.core.= RequestHandlers; created /admin/: org.apache.solr.handler.admin.AdminHandle= rs [junit4:junit4] 1> INFO - 2013-04-10 08:24:17.225; org.apache.solr.handl= er.loader.XMLLoader; xsltCacheLifetimeSeconds=3D60 [junit4:junit4] 1> INFO - 2013-04-10 08:24:17.227; org.apache.solr.handl= er.loader.XMLLoader; xsltCacheLifetimeSeconds=3D60 [junit4:junit4] 1> INFO - 2013-04-10 08:24:17.234; org.apache.solr.searc= h.SolrIndexSearcher; Opening Searcher@fff024 main [junit4:junit4] 1> INFO - 2013-04-10 08:24:17.234; org.apache.solr.searc= h.SolrIndexSearcher; Opening Searcher@15a9978 main [junit4:junit4] 1> INFO - 2013-04-10 08:24:17.235; org.apache.solr.updat= e.UpdateHandler; Clearing tlog files, tlogDir=3DC:\Users\JenkinsSlave\works= pace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.so= lr.cloud.CollectionsAPIDistributedZkTest-jetty1-1365582247078\nodes_used_co= llection_shard2_replica1\data\tlog [junit4:junit4] 1> INFO - 2013-04-10 08:24:17.235; org.apache.solr.updat= e.UpdateHandler; Clearing tlog files, tlogDir=3DC:\Users\JenkinsSlave\works= pace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.so= lr.cloud.CollectionsAPIDistributedZkTest-controljetty-1365582245991\nodes_u= sed_collection_shard2_replica2\data\tlog [junit4:junit4] 1> INFO - 2013-04-10 08:24:17.237; org.apache.solr.updat= e.CommitTracker; Hard AutoCommit: disabled [junit4:junit4] 1> INFO - 2013-04-10 08:24:17.237; org.apache.solr.updat= e.CommitTracker; Soft AutoCommit: disabled [junit4:junit4] 1> INFO - 2013-04-10 08:24:17.237; org.apache.solr.updat= e.CommitTracker; Hard AutoCommit: disabled [junit4:junit4] 1> INFO - 2013-04-10 08:24:17.239; org.apache.solr.updat= e.CommitTracker; Soft AutoCommit: disabled [junit4:junit4] 1> INFO - 2013-04-10 08:24:17.242; org.apache.solr.cloud= .ZkController; publishing core=3Dnodes_used_collection_shard2_replica2 stat= e=3Ddown [junit4:junit4] 1> INFO - 2013-04-10 08:24:17.243; org.apache.solr.core.= SolrCore; [nodes_used_collection_shard2_replica1] Registered new searcher S= earcher@fff024 main{StandardDirectoryReader(segments_1:1)} [junit4:junit4] 1> INFO - 2013-04-10 08:24:17.244; org.apache.solr.core.= SolrCore; [nodes_used_collection_shard2_replica2] Registered new searcher S= earcher@15a9978 main{StandardDirectoryReader(segments_1:1)} [junit4:junit4] 1> INFO - 2013-04-10 08:24:17.244; org.apache.solr.cloud= .ZkController; publishing core=3Dnodes_used_collection_shard2_replica1 stat= e=3Ddown [junit4:junit4] 1> INFO - 2013-04-10 08:24:18.134; org.apache.solr.commo= n.cloud.ZkStateReader; Updating cloud state from ZooKeeper...=20 [junit4:junit4] 1> INFO - 2013-04-10 08:24:18.136; 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:50459_", [junit4:junit4] 1> "base_url":"http://127.0.0.1:50459"} [junit4:junit4] 1> INFO - 2013-04-10 08:24:18.136; org.apache.solr.cloud= .Overseer$ClusterStateUpdater; Create collection nodes_used_collection with= numShards 2 [junit4:junit4] 1> INFO - 2013-04-10 08:24:18.144; 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:50477_", [junit4:junit4] 1> "base_url":"http://127.0.0.1:50477"} [junit4:junit4] 1> INFO - 2013-04-10 08:24:18.151; 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:50438_", [junit4:junit4] 1> "base_url":"http://127.0.0.1:50438"} [junit4:junit4] 1> INFO - 2013-04-10 08:24:18.158; 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:50450_", [junit4:junit4] 1> "base_url":"http://127.0.0.1:50450"} [junit4:junit4] 1> INFO - 2013-04-10 08:24:18.167; org.apache.solr.commo= n.cloud.ZkStateReader$2; A cluster state change: WatchedEvent state:SyncCon= nected type:NodeDataChanged path:/clusterstate.json, has occurred - updatin= g... (live nodes size: 5) [junit4:junit4] 1> INFO - 2013-04-10 08:24:18.168; org.apache.solr.commo= n.cloud.ZkStateReader$2; A cluster state change: WatchedEvent state:SyncCon= nected type:NodeDataChanged path:/clusterstate.json, has occurred - updatin= g... (live nodes size: 5) [junit4:junit4] 1> INFO - 2013-04-10 08:24:18.168; org.apache.solr.commo= n.cloud.ZkStateReader$2; A cluster state change: WatchedEvent state:SyncCon= nected type:NodeDataChanged path:/clusterstate.json, has occurred - updatin= g... (live nodes size: 5) [junit4:junit4] 1> INFO - 2013-04-10 08:24:18.168; org.apache.solr.commo= n.cloud.ZkStateReader$2; A cluster state change: WatchedEvent state:SyncCon= nected type:NodeDataChanged path:/clusterstate.json, has occurred - updatin= g... (live nodes size: 5) [junit4:junit4] 1> INFO - 2013-04-10 08:24:18.168; org.apache.solr.commo= n.cloud.ZkStateReader$2; A cluster state change: WatchedEvent state:SyncCon= nected type:NodeDataChanged path:/clusterstate.json, has occurred - updatin= g... (live nodes size: 5) [junit4:junit4] 1> INFO - 2013-04-10 08:24:18.168; org.apache.solr.commo= n.cloud.ZkStateReader$2; A cluster state change: WatchedEvent state:SyncCon= nected type:NodeDataChanged path:/clusterstate.json, has occurred - updatin= g... (live nodes size: 5) [junit4:junit4] 1> INFO - 2013-04-10 08:24:18.203; org.apache.solr.core.= CoreContainer; registering core: nodes_used_collection_shard2_replica2 [junit4:junit4] 1> INFO - 2013-04-10 08:24:18.203; org.apache.solr.cloud= .ZkController; Register replica - core:nodes_used_collection_shard2_replica= 2 address:http://127.0.0.1:50438 collection:nodes_used_collection shard:sha= rd2 [junit4:junit4] 1> INFO - 2013-04-10 08:24:18.204; org.apache.solr.core.= CoreContainer; registering core: nodes_used_collection_shard2_replica1 [junit4:junit4] 1> INFO - 2013-04-10 08:24:18.204; org.apache.solr.cloud= .ZkController; Register replica - core:nodes_used_collection_shard2_replica= 1 address:http://127.0.0.1:50450 collection:nodes_used_collection shard:sha= rd2 [junit4:junit4] 1> INFO - 2013-04-10 08:24:18.204; org.apache.solr.commo= n.cloud.SolrZkClient; makePath: /collections/nodes_used_collection/leader_e= lect/shard2/election [junit4:junit4] 1> INFO - 2013-04-10 08:24:18.206; org.apache.solr.commo= n.cloud.SolrZkClient; makePath: /collections/nodes_used_collection/leader_e= lect/shard2/election [junit4:junit4] 1> INFO - 2013-04-10 08:24:18.224; org.apache.solr.cloud= .ShardLeaderElectionContext; Running the leader process. [junit4:junit4] 1> INFO - 2013-04-10 08:24:18.229; org.apache.solr.cloud= .ShardLeaderElectionContext; Enough replicas found to continue. [junit4:junit4] 1> INFO - 2013-04-10 08:24:18.229; org.apache.solr.cloud= .ShardLeaderElectionContext; I may be the new leader - try and sync [junit4:junit4] 1> INFO - 2013-04-10 08:24:18.229; org.apache.solr.cloud= .SyncStrategy; Sync replicas to http://127.0.0.1:50450/nodes_used_collectio= n_shard2_replica1/ [junit4:junit4] 1> INFO - 2013-04-10 08:24:18.230; org.apache.solr.updat= e.PeerSync; PeerSync: core=3Dnodes_used_collection_shard2_replica1 url=3Dht= tp://127.0.0.1:50450 START replicas=3D[http://127.0.0.1:50438/nodes_used_co= llection_shard2_replica2/] nUpdates=3D100 [junit4:junit4] 1> INFO - 2013-04-10 08:24:18.231; org.apache.solr.updat= e.PeerSync; PeerSync: core=3Dnodes_used_collection_shard2_replica1 url=3Dht= tp://127.0.0.1:50450 DONE. We have no versions. sync failed. [junit4:junit4] 1> INFO - 2013-04-10 08:24:18.231; org.apache.solr.cloud= .SyncStrategy; Leader's attempt to sync with shard failed, moving to the ne= xt canidate [junit4:junit4] 1> INFO - 2013-04-10 08:24:18.231; org.apache.solr.cloud= .ShardLeaderElectionContext; We failed sync, but we have no versions - we c= an't sync in that case - we were active before, so become leader anyway [junit4:junit4] 1> INFO - 2013-04-10 08:24:18.232; org.apache.solr.cloud= .ShardLeaderElectionContext; I am the new leader: http://127.0.0.1:50450/no= des_used_collection_shard2_replica1/ [junit4:junit4] 1> INFO - 2013-04-10 08:24:18.232; org.apache.solr.commo= n.cloud.SolrZkClient; makePath: /collections/nodes_used_collection/leaders/= shard2 [junit4:junit4] 1> INFO - 2013-04-10 08:24:18.242; org.apache.solr.core.= SolrCore; [nodes_used_collection_shard2_replica2] webapp=3D path=3D/get par= ams=3D{getVersions=3D100&distrib=3Dfalse&wt=3Djavabin&qt=3D/get&version=3D2= } status=3D0 QTime=3D2=20 [junit4:junit4] 1> INFO - 2013-04-10 08:24:19.071; org.apache.solr.core.= CoreContainer; registering core: nodes_used_collection_shard1_replica2 [junit4:junit4] 1> INFO - 2013-04-10 08:24:19.071; org.apache.solr.cloud= .ZkController; Register replica - core:nodes_used_collection_shard1_replica= 2 address:http://127.0.0.1:50459 collection:nodes_used_collection shard:sha= rd1 [junit4:junit4] 1> INFO - 2013-04-10 08:24:19.072; org.apache.solr.commo= n.cloud.SolrZkClient; makePath: /collections/nodes_used_collection/leader_e= lect/shard1/election [junit4:junit4] 1> INFO - 2013-04-10 08:24:19.078; org.apache.solr.core.= CoreContainer; registering core: nodes_used_collection_shard1_replica1 [junit4:junit4] 1> INFO - 2013-04-10 08:24:19.078; org.apache.solr.cloud= .ZkController; Register replica - core:nodes_used_collection_shard1_replica= 1 address:http://127.0.0.1:50477 collection:nodes_used_collection shard:sha= rd1 [junit4:junit4] 1> INFO - 2013-04-10 08:24:19.083; org.apache.solr.commo= n.cloud.SolrZkClient; makePath: /collections/nodes_used_collection/leader_e= lect/shard1/election [junit4:junit4] 1> INFO - 2013-04-10 08:24:19.090; org.apache.solr.cloud= .ShardLeaderElectionContext; Running the leader process. [junit4:junit4] 1> INFO - 2013-04-10 08:24:19.097; org.apache.solr.cloud= .ShardLeaderElectionContext; Enough replicas found to continue. [junit4:junit4] 1> INFO - 2013-04-10 08:24:19.097; org.apache.solr.cloud= .ShardLeaderElectionContext; I may be the new leader - try and sync [junit4:junit4] 1> INFO - 2013-04-10 08:24:19.097; org.apache.solr.cloud= .SyncStrategy; Sync replicas to http://127.0.0.1:50459/nodes_used_collectio= n_shard1_replica2/ [junit4:junit4] 1> INFO - 2013-04-10 08:24:19.098; org.apache.solr.updat= e.PeerSync; PeerSync: core=3Dnodes_used_collection_shard1_replica2 url=3Dht= tp://127.0.0.1:50459 START replicas=3D[http://127.0.0.1:50477/nodes_used_co= llection_shard1_replica1/] nUpdates=3D100 [junit4:junit4] 1> INFO - 2013-04-10 08:24:19.099; org.apache.solr.updat= e.PeerSync; PeerSync: core=3Dnodes_used_collection_shard1_replica2 url=3Dht= tp://127.0.0.1:50459 DONE. We have no versions. sync failed. [junit4:junit4] 1> INFO - 2013-04-10 08:24:19.099; org.apache.solr.cloud= .SyncStrategy; Leader's attempt to sync with shard failed, moving to the ne= xt canidate [junit4:junit4] 1> INFO - 2013-04-10 08:24:19.100; org.apache.solr.cloud= .ShardLeaderElectionContext; We failed sync, but we have no versions - we c= an't sync in that case - we were active before, so become leader anyway [junit4:junit4] 1> INFO - 2013-04-10 08:24:19.100; org.apache.solr.cloud= .ShardLeaderElectionContext; I am the new leader: http://127.0.0.1:50459/no= des_used_collection_shard1_replica2/ [junit4:junit4] 1> INFO - 2013-04-10 08:24:19.100; org.apache.solr.commo= n.cloud.SolrZkClient; makePath: /collections/nodes_used_collection/leaders/= shard1 [junit4:junit4] 1> INFO - 2013-04-10 08:24:19.110; org.apache.solr.core.= SolrCore; [nodes_used_collection_shard1_replica1] webapp=3D path=3D/get par= ams=3D{getVersions=3D100&distrib=3Dfalse&wt=3Djavabin&qt=3D/get&version=3D2= } status=3D0 QTime=3D1=20 [junit4:junit4] 1> INFO - 2013-04-10 08:24:19.544; org.apache.solr.commo= n.cloud.ZkStateReader; Updating cloud state from ZooKeeper...=20 [junit4:junit4] 1> INFO - 2013-04-10 08:24:19.572; org.apache.solr.commo= n.cloud.ZkStateReader$2; A cluster state change: WatchedEvent state:SyncCon= nected type:NodeDataChanged path:/clusterstate.json, has occurred - updatin= g... (live nodes size: 5) [junit4:junit4] 1> INFO - 2013-04-10 08:24:19.572; org.apache.solr.commo= n.cloud.ZkStateReader$2; A cluster state change: WatchedEvent state:SyncCon= nected type:NodeDataChanged path:/clusterstate.json, has occurred - updatin= g... (live nodes size: 5) [junit4:junit4] 1> INFO - 2013-04-10 08:24:19.572; org.apache.solr.commo= n.cloud.ZkStateReader$2; A cluster state change: WatchedEvent state:SyncCon= nected type:NodeDataChanged path:/clusterstate.json, has occurred - updatin= g... (live nodes size: 5) [junit4:junit4] 1> INFO - 2013-04-10 08:24:19.572; org.apache.solr.commo= n.cloud.ZkStateReader$2; A cluster state change: WatchedEvent state:SyncCon= nected type:NodeDataChanged path:/clusterstate.json, has occurred - updatin= g... (live nodes size: 5) [junit4:junit4] 1> INFO - 2013-04-10 08:24:19.572; org.apache.solr.commo= n.cloud.ZkStateReader$2; A cluster state change: WatchedEvent state:SyncCon= nected type:NodeDataChanged path:/clusterstate.json, has occurred - updatin= g... (live nodes size: 5) [junit4:junit4] 1> INFO - 2013-04-10 08:24:19.572; org.apache.solr.commo= n.cloud.ZkStateReader$2; A cluster state change: WatchedEvent state:SyncCon= nected type:NodeDataChanged path:/clusterstate.json, has occurred - updatin= g... (live nodes size: 5) [junit4:junit4] 1> INFO - 2013-04-10 08:24:19.580; org.apache.solr.cloud= .ZkController; We are http://127.0.0.1:50450/nodes_used_collection_shard2_r= eplica1/ and leader is http://127.0.0.1:50450/nodes_used_collection_shard2_= replica1/ [junit4:junit4] 1> INFO - 2013-04-10 08:24:19.580; org.apache.solr.cloud= .ZkController; No LogReplay needed for core=3Dnodes_used_collection_shard2_= replica1 baseURL=3Dhttp://127.0.0.1:50450 [junit4:junit4] 1> INFO - 2013-04-10 08:24:19.580; org.apache.solr.cloud= .ZkController; I am the leader, no recovery necessary [junit4:junit4] 1> INFO - 2013-04-10 08:24:19.580; org.apache.solr.cloud= .ZkController; publishing core=3Dnodes_used_collection_shard2_replica1 stat= e=3Dactive [junit4:junit4] 1> INFO - 2013-04-10 08:24:19.582; org.apache.solr.commo= n.cloud.ZkStateReader; Updating cloud state from ZooKeeper...=20 [junit4:junit4] 1> INFO - 2013-04-10 08:24:19.583; org.apache.solr.core.= CoreContainer; Persisting cores config to C:\Users\JenkinsSlave\workspace\L= ucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.clo= ud.CollectionsAPIDistributedZkTest-jetty1-1365582247078\solr.xml [junit4:junit4] 1> INFO - 2013-04-10 08:24:19.599; org.apache.solr.core.= SolrXMLSerializer; Persisting cores config to C:\Users\JenkinsSlave\workspa= ce\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr= .cloud.CollectionsAPIDistributedZkTest-jetty1-1365582247078\solr.xml [junit4:junit4] 1> INFO - 2013-04-10 08:24:19.604; 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=3D5537=20 [junit4:junit4] 1> INFO - 2013-04-10 08:24:19.616; org.apache.solr.cloud= .ZkController; We are http://127.0.0.1:50459/nodes_used_collection_shard1_r= eplica2/ and leader is http://127.0.0.1:50459/nodes_used_collection_shard1_= replica2/ [junit4:junit4] 1> INFO - 2013-04-10 08:24:19.616; org.apache.solr.cloud= .ZkController; No LogReplay needed for core=3Dnodes_used_collection_shard1_= replica2 baseURL=3Dhttp://127.0.0.1:50459 [junit4:junit4] 1> INFO - 2013-04-10 08:24:19.616; org.apache.solr.cloud= .ZkController; I am the leader, no recovery necessary [junit4:junit4] 1> INFO - 2013-04-10 08:24:19.616; org.apache.solr.cloud= .ZkController; publishing core=3Dnodes_used_collection_shard1_replica2 stat= e=3Dactive [junit4:junit4] 1> INFO - 2013-04-10 08:24:19.619; org.apache.solr.commo= n.cloud.ZkStateReader; Updating cloud state from ZooKeeper...=20 [junit4:junit4] 1> INFO - 2013-04-10 08:24:19.621; org.apache.solr.core.= CoreContainer; Persisting cores config to C:\Users\JenkinsSlave\workspace\L= ucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.clo= ud.CollectionsAPIDistributedZkTest-jetty2-1365582249056\solr.xml [junit4:junit4] 1> INFO - 2013-04-10 08:24:19.633; org.apache.solr.core.= SolrXMLSerializer; Persisting cores config to C:\Users\JenkinsSlave\workspa= ce\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr= .cloud.CollectionsAPIDistributedZkTest-jetty2-1365582249056\solr.xml [junit4:junit4] 1> INFO - 2013-04-10 08:24:19.638; org.apache.solr.cloud= .ZkController; We are http://127.0.0.1:50438/nodes_used_collection_shard2_r= eplica2/ and leader is http://127.0.0.1:50450/nodes_used_collection_shard2_= replica1/ [junit4:junit4] 1> INFO - 2013-04-10 08:24:19.638; org.apache.solr.cloud= .ZkController; No LogReplay needed for core=3Dnodes_used_collection_shard2_= replica2 baseURL=3Dhttp://127.0.0.1:50438 [junit4:junit4] 1> INFO - 2013-04-10 08:24:19.638; org.apache.solr.cloud= .ZkController; Core needs to recover:nodes_used_collection_shard2_replica2 [junit4:junit4] 1> INFO - 2013-04-10 08:24:19.640; org.apache.solr.updat= e.DefaultSolrCoreState; Running recovery - first canceling any ongoing reco= very [junit4:junit4] 1> INFO - 2013-04-10 08:24:19.638; 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=3D5572=20 [junit4:junit4] 1> INFO - 2013-04-10 08:24:19.641; org.apache.solr.cloud= .RecoveryStrategy; Starting recovery process. core=3Dnodes_used_collection= _shard2_replica2 recoveringAfterStartup=3Dtrue [junit4:junit4] 1> INFO - 2013-04-10 08:24:19.641; org.apache.solr.cloud= .RecoveryStrategy; ###### startupVersions=3D[] [junit4:junit4] 1> INFO - 2013-04-10 08:24:19.642; org.apache.solr.cloud= .ZkController; publishing core=3Dnodes_used_collection_shard2_replica2 stat= e=3Drecovering [junit4:junit4] 1> INFO - 2013-04-10 08:24:19.642; org.apache.solr.commo= n.cloud.ZkStateReader; Updating cloud state from ZooKeeper...=20 [junit4:junit4] 1> INFO - 2013-04-10 08:24:19.645; org.apache.solr.clien= t.solrj.impl.HttpClientUtil; Creating new http client, config:maxConnection= s=3D128&maxConnectionsPerHost=3D32&followRedirects=3Dfalse [junit4:junit4] 1> INFO - 2013-04-10 08:24:19.646; org.apache.solr.core.= CoreContainer; Persisting cores config to C:\Users\JenkinsSlave\workspace\L= ucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.clo= ud.CollectionsAPIDistributedZkTest-controljetty-1365582245991\solr.xml [junit4:junit4] 1> INFO - 2013-04-10 08:24:19.656; org.apache.solr.handl= er.admin.CoreAdminHandler; Going to wait for coreNodeName: 127.0.0.1:50438_= _nodes_used_collection_shard2_replica2, state: recovering, checkLive: true,= onlyIfLeader: true [junit4:junit4] 1> INFO - 2013-04-10 08:24:19.662; org.apache.solr.core.= SolrXMLSerializer; Persisting cores config to C:\Users\JenkinsSlave\workspa= ce\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr= .cloud.CollectionsAPIDistributedZkTest-controljetty-1365582245991\solr.xml [junit4:junit4] 1> INFO - 2013-04-10 08:24:19.666; 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=3D5598=20 [junit4:junit4] 1> INFO - 2013-04-10 08:24:20.004; org.apache.solr.cloud= .ZkController; We are http://127.0.0.1:50477/nodes_used_collection_shard1_r= eplica1/ and leader is http://127.0.0.1:50459/nodes_used_collection_shard1_= replica2/ [junit4:junit4] 1> INFO - 2013-04-10 08:24:20.004; org.apache.solr.cloud= .ZkController; No LogReplay needed for core=3Dnodes_used_collection_shard1_= replica1 baseURL=3Dhttp://127.0.0.1:50477 [junit4:junit4] 1> INFO - 2013-04-10 08:24:20.004; org.apache.solr.cloud= .ZkController; Core needs to recover:nodes_used_collection_shard1_replica1 [junit4:junit4] 1> INFO - 2013-04-10 08:24:20.004; org.apache.solr.updat= e.DefaultSolrCoreState; Running recovery - first canceling any ongoing reco= very [junit4:junit4] 1> INFO - 2013-04-10 08:24:20.005; org.apache.solr.cloud= .RecoveryStrategy; Starting recovery process. core=3Dnodes_used_collection= _shard1_replica1 recoveringAfterStartup=3Dtrue [junit4:junit4] 1> INFO - 2013-04-10 08:24:20.005; org.apache.solr.cloud= .RecoveryStrategy; ###### startupVersions=3D[] [junit4:junit4] 1> INFO - 2013-04-10 08:24:20.006; org.apache.solr.commo= n.cloud.ZkStateReader; Updating cloud state from ZooKeeper...=20 [junit4:junit4] 1> INFO - 2013-04-10 08:24:20.006; org.apache.solr.cloud= .ZkController; publishing core=3Dnodes_used_collection_shard1_replica1 stat= e=3Drecovering [junit4:junit4] 1> INFO - 2013-04-10 08:24:20.007; org.apache.solr.core.= CoreContainer; Persisting cores config to C:\Users\JenkinsSlave\workspace\L= ucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.clo= ud.CollectionsAPIDistributedZkTest-jetty4-1365582252414\solr.xml [junit4:junit4] 1> INFO - 2013-04-10 08:24:20.009; org.apache.solr.clien= t.solrj.impl.HttpClientUtil; Creating new http client, config:maxConnection= s=3D128&maxConnectionsPerHost=3D32&followRedirects=3Dfalse [junit4:junit4] 1> INFO - 2013-04-10 08:24:20.019; org.apache.solr.handl= er.admin.CoreAdminHandler; Going to wait for coreNodeName: 127.0.0.1:50477_= _nodes_used_collection_shard1_replica1, state: recovering, checkLive: true,= onlyIfLeader: true [junit4:junit4] 1> INFO - 2013-04-10 08:24:20.020; org.apache.solr.core.= SolrXMLSerializer; Persisting cores config to C:\Users\JenkinsSlave\workspa= ce\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr= .cloud.CollectionsAPIDistributedZkTest-jetty4-1365582252414\solr.xml [junit4:junit4] 1> INFO - 2013-04-10 08:24:20.025; 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=3D5959=20 [junit4:junit4] 1> INFO - 2013-04-10 08:24:20.026; org.apache.solr.cloud= .OverseerCollectionProcessor; Finished create command on all shards for col= lection: nodes_used_collection [junit4:junit4] 1> INFO - 2013-04-10 08:24:20.029; org.apache.solr.cloud= .DistributedQueue$LatchChildWatcher; Watcher fired on path: /overseer/colle= ction-queue-work/qnr-0000000000 state: SyncConnected type NodeDataChanged [junit4:junit4] 1> INFO - 2013-04-10 08:24:20.031; org.apache.solr.cloud= .DistributedQueue$LatchChildWatcher; Watcher fired on path: /overseer/colle= ction-queue-work state: SyncConnected type NodeChildrenChanged [junit4:junit4] 1> INFO - 2013-04-10 08:24:20.032; 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=3D5537},core=3Dnodes_used_collect= ion_shard2_replica1,saved=3DC:\Users\JenkinsSlave\workspace\Lucene-Solr-tru= nk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.Collections= APIDistributedZkTest-jetty1-1365582247078\solr.xml},null=3D{responseHeader= =3D{status=3D0,QTime=3D5572},core=3Dnodes_used_collection_shard1_replica2,s= aved=3DC:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build= \solr-core\test\J0\.\org.apache.solr.cloud.CollectionsAPIDistributedZkTest-= jetty2-1365582249056\solr.xml},null=3D{responseHeader=3D{status=3D0,QTime= =3D5598},core=3Dnodes_used_collection_shard2_replica2,saved=3DC:\Users\Jenk= insSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.= \org.apache.solr.cloud.CollectionsAPIDistributedZkTest-controljetty-1365582= 245991\solr.xml},null=3D{responseHeader=3D{status=3D0,QTime=3D5959},core=3D= nodes_used_collection_shard1_replica1,saved=3DC:\Users\JenkinsSlave\workspa= ce\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr= .cloud.CollectionsAPIDistributedZkTest-jetty4-1365582252414\solr.xml}}} [junit4:junit4] 1> INFO - 2013-04-10 08:24:20.034; 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=3D5982=20 [junit4:junit4] 1> INFO - 2013-04-10 08:24:20.035; org.apache.solr.clien= t.solrj.impl.HttpClientUtil; Creating new http client, config: [junit4:junit4] 1> INFO - 2013-04-10 08:24:20.036; org.apache.solr.commo= n.cloud.ConnectionManager; Waiting for client to connect to ZooKeeper [junit4:junit4] 1> INFO - 2013-04-10 08:24:20.040; org.apache.solr.commo= n.cloud.ConnectionManager; Watcher org.apache.solr.common.cloud.ConnectionM= anager@1ddcbd5 name:ZooKeeperConnection Watcher:127.0.0.1:50431/solr got ev= ent WatchedEvent state:SyncConnected type:None path:null path:null type:Non= e [junit4:junit4] 1> INFO - 2013-04-10 08:24:20.040; org.apache.solr.commo= n.cloud.ConnectionManager; Client is connected to ZooKeeper [junit4:junit4] 1> INFO - 2013-04-10 08:24:20.042; org.apache.solr.commo= n.cloud.ZkStateReader; Updating cluster state from ZooKeeper...=20 [junit4:junit4] 1> INFO - 2013-04-10 08:24:20.046; org.apache.solr.clien= t.solrj.impl.HttpClientUtil; Creating new http client, config: [junit4:junit4] 1> INFO - 2013-04-10 08:24:20.053; org.apache.solr.commo= n.cloud.ConnectionManager; Waiting for client to connect to ZooKeeper [junit4:junit4] 1> INFO - 2013-04-10 08:24:20.056; org.apache.solr.commo= n.cloud.ConnectionManager; Watcher org.apache.solr.common.cloud.ConnectionM= anager@1c182de name:ZooKeeperConnection Watcher:127.0.0.1:50431/solr got ev= ent WatchedEvent state:SyncConnected type:None path:null path:null type:Non= e [junit4:junit4] 1> INFO - 2013-04-10 08:24:20.056; org.apache.solr.commo= n.cloud.ConnectionManager; Client is connected to ZooKeeper [junit4:junit4] 1> INFO - 2013-04-10 08:24:20.058; org.apache.solr.commo= n.cloud.ZkStateReader; Updating cluster state from ZooKeeper...=20 [junit4:junit4] 1> INFO - 2013-04-10 08:24:20.071; org.apache.solr.handl= er.admin.CollectionsHandler; Creating Collection : numShards=3D4&maxShardsP= erNode=3D5&name=3Dawholynewcollection_0&replicationFactor=3D5&action=3DCREA= TE&wt=3Djavabin&version=3D2 [junit4:junit4] 1> INFO - 2013-04-10 08:24:20.073; org.apache.solr.cloud= .DistributedQueue$LatchChildWatcher; Watcher fired on path: /overseer/colle= ction-queue-work state: SyncConnected type NodeChildrenChanged [junit4:junit4] 1> INFO - 2013-04-10 08:24:20.076; org.apache.solr.cloud= .DistributedQueue$LatchChildWatcher; Watcher fired on path: /overseer/colle= ction-queue-work state: SyncConnected type NodeChildrenChanged [junit4:junit4] 1> INFO - 2013-04-10 08:24:20.076; 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":"4", [junit4:junit4] 1> "maxShardsPerNode":"5", [junit4:junit4] 1> "createNodeSet":null, [junit4:junit4] 1> "name":"awholynewcollection_0", [junit4:junit4] 1> "replicationFactor":"5"} [junit4:junit4] 1> INFO - 2013-04-10 08:24:20.077; 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:50459_ [junit4:junit4] 1> INFO - 2013-04-10 08:24:20.077; 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:50477_ [junit4:junit4] 1> INFO - 2013-04-10 08:24:20.077; 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:50450_ [junit4:junit4] 1> INFO - 2013-04-10 08:24:20.077; org.apache.solr.cloud= .OverseerCollectionProcessor; Creating shard awholynewcollection_0_shard1_r= eplica4 as part of slice shard1 of collection awholynewcollection_0 on 127.= 0.0.1:50468_ [junit4:junit4] 1> INFO - 2013-04-10 08:24:20.077; org.apache.solr.cloud= .OverseerCollectionProcessor; Creating shard awholynewcollection_0_shard1_r= eplica5 as part of slice shard1 of collection awholynewcollection_0 on 127.= 0.0.1:50438_ [junit4:junit4] 1> INFO - 2013-04-10 08:24:20.078; 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:50459_ [junit4:junit4] 1> INFO - 2013-04-10 08:24:20.079; 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:50477_ [junit4:junit4] 1> INFO - 2013-04-10 08:24:20.080; org.apache.solr.core.= CoreContainer; Creating SolrCore 'awholynewcollection_0_shard1_replica2' us= ing instanceDir: C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\= solr\build\solr-core\test\J0\.\org.apache.solr.cloud.CollectionsAPIDistribu= tedZkTest-jetty4-1365582252414\awholynewcollection_0_shard1_replica2 [junit4:junit4] 1> INFO - 2013-04-10 08:24:20.082; org.apache.solr.cloud= .ZkController; Check for collection zkNode:awholynewcollection_0 [junit4:junit4] 1> INFO - 2013-04-10 08:24:20.083; org.apache.solr.core.= CoreContainer; Creating SolrCore 'awholynewcollection_0_shard2_replica2' us= ing instanceDir: C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\= solr\build\solr-core\test\J0\.\org.apache.solr.cloud.CollectionsAPIDistribu= tedZkTest-jetty4-1365582252414\awholynewcollection_0_shard2_replica2 [junit4:junit4] 1> INFO - 2013-04-10 08:24:20.083; org.apache.solr.cloud= .ZkController; Check for collection zkNode:awholynewcollection_0 [junit4:junit4] 1> INFO - 2013-04-10 08:24:20.080; org.apache.solr.core.= CoreContainer; Creating SolrCore 'awholynewcollection_0_shard1_replica4' us= ing instanceDir: C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\= solr\build\solr-core\test\J0\.\org.apache.solr.cloud.CollectionsAPIDistribu= tedZkTest-jetty3-1365582250756\awholynewcollection_0_shard1_replica4 [junit4:junit4] 1> INFO - 2013-04-10 08:24:20.084; org.apache.solr.cloud= .ZkController; Check for collection zkNode:awholynewcollection_0 [junit4:junit4] 1> INFO - 2013-04-10 08:24:20.085; org.apache.solr.cloud= .ZkController; Creating collection in ZooKeeper:awholynewcollection_0 [junit4:junit4] 1> INFO - 2013-04-10 08:24:20.085; org.apache.solr.cloud= .ZkController; Looking for collection configName [junit4:junit4] 1> INFO - 2013-04-10 08:24:20.080; org.apache.solr.core.= CoreContainer; Creating SolrCore 'awholynewcollection_0_shard1_replica3' us= ing instanceDir: C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\= solr\build\solr-core\test\J0\.\org.apache.solr.cloud.CollectionsAPIDistribu= tedZkTest-jetty1-1365582247078\awholynewcollection_0_shard1_replica3 [junit4:junit4] 1> INFO - 2013-04-10 08:24:20.086; org.apache.solr.cloud= .ZkController; Check for collection zkNode:awholynewcollection_0 [junit4:junit4] 1> INFO - 2013-04-10 08:24:20.079; org.apache.solr.core.= CoreContainer; Creating SolrCore 'awholynewcollection_0_shard1_replica1' us= ing instanceDir: C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\= solr\build\solr-core\test\J0\.\org.apache.solr.cloud.CollectionsAPIDistribu= tedZkTest-jetty2-1365582249056\awholynewcollection_0_shard1_replica1 [junit4:junit4] 1> INFO - 2013-04-10 08:24:20.087; org.apache.solr.cloud= .ZkController; Check for collection zkNode:awholynewcollection_0 [junit4:junit4] 1> INFO - 2013-04-10 08:24:20.085; org.apache.solr.cloud= .ZkController; Creating collection in ZooKeeper:awholynewcollection_0 [junit4:junit4] 1> INFO - 2013-04-10 08:24:20.087; org.apache.solr.cloud= .ZkController; Looking for collection configName [junit4:junit4] 1> INFO - 2013-04-10 08:24:20.084; org.apache.solr.cloud= .ZkController; Creating collection in ZooKeeper:awholynewcollection_0 [junit4:junit4] 1> INFO - 2013-04-10 08:24:20.083; org.apache.solr.core.= CoreContainer; Creating SolrCore 'awholynewcollection_0_shard1_replica5' us= ing instanceDir: C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\= solr\build\solr-core\test\J0\.\org.apache.solr.cloud.CollectionsAPIDistribu= tedZkTest-controljetty-1365582245991\awholynewcollection_0_shard1_replica5 [junit4:junit4] 1> INFO - 2013-04-10 08:24:20.088; org.apache.solr.cloud= .ZkController; Check for collection zkNode:awholynewcollection_0 [junit4:junit4] 1> INFO - 2013-04-10 08:24:20.081; 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:50450_ [junit4:junit4] 1> INFO - 2013-04-10 08:24:20.089; org.apache.solr.cloud= .OverseerCollectionProcessor; Creating shard awholynewcollection_0_shard2_r= eplica4 as part of slice shard2 of collection awholynewcollection_0 on 127.= 0.0.1:50468_ [junit4:junit4] 1> INFO - 2013-04-10 08:24:20.081; org.apache.solr.core.= CoreContainer; Creating SolrCore 'awholynewcollection_0_shard2_replica1' us= ing instanceDir: C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\= solr\build\solr-core\test\J0\.\org.apache.solr.cloud.CollectionsAPIDistribu= tedZkTest-jetty2-1365582249056\awholynewcollection_0_shard2_replica1 [junit4:junit4] 1> INFO - 2013-04-10 08:24:20.091; org.apache.solr.cloud= .OverseerCollectionProcessor; Creating shard awholynewcollection_0_shard2_r= eplica5 as part of slice shard2 of collection awholynewcollection_0 on 127.= 0.0.1:50438_ [junit4:junit4] 1> INFO - 2013-04-10 08:24:20.089; org.apache.solr.cloud= .ZkController; Only one config set found in zk - using it:conf1 [junit4:junit4] 1> INFO - 2013-04-10 08:24:20.091; org.apache.solr.commo= n.cloud.SolrZkClient; makePath: /collections/awholynewcollection_0 [junit4:junit4] 1> INFO - 2013-04-10 08:24:20.103; org.apache.solr.core.= CoreContainer; Creating SolrCore 'awholynewcollection_0_shard2_replica5' us= ing instanceDir: C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\= solr\build\solr-core\test\J0\.\org.apache.solr.cloud.CollectionsAPIDistribu= tedZkTest-controljetty-1365582245991\awholynewcollection_0_shard2_replica5 [junit4:junit4] 1> INFO - 2013-04-10 08:24:20.104; org.apache.solr.cloud= .ZkController; Check for collection zkNode:awholynewcollection_0 [junit4:junit4] 1> INFO - 2013-04-10 08:24:20.088; org.apache.solr.cloud= .ZkController; Looking for collection configName [junit4:junit4] 1> INFO - 2013-04-10 08:24:20.087; org.apache.solr.cloud= .ZkController; Creating collection in ZooKeeper:awholynewcollection_0 [junit4:junit4] 1> INFO - 2013-04-10 08:24:20.105; org.apache.solr.cloud= .ZkController; Looking for collection configName [junit4:junit4] 1> INFO - 2013-04-10 08:24:20.087; org.apache.solr.cloud= .ZkController; Creating collection in ZooKeeper:awholynewcollection_0 [junit4:junit4] 1> INFO - 2013-04-10 08:24:20.106; org.apache.solr.cloud= .ZkController; Looking for collection configName [junit4:junit4] 1> INFO - 2013-04-10 08:24:20.087; org.apache.solr.cloud= .ZkController; Only one config set found in zk - using it:conf1 [junit4:junit4] 1> INFO - 2013-04-10 08:24:20.107; org.apache.solr.commo= n.cloud.SolrZkClient; makePath: /collections/awholynewcollection_0 [junit4:junit4] 1> INFO - 2013-04-10 08:24:20.106; org.apache.solr.cloud= .ZkController; Creating collection in ZooKeeper:awholynewcollection_0 [junit4:junit4] 1> INFO - 2013-04-10 08:24:20.108; org.apache.solr.cloud= .ZkController; Looking for collection configName [junit4:junit4] 1> INFO - 2013-04-10 08:24:20.102; org.apache.solr.core.= CoreContainer; Creating SolrCore 'awholynewcollection_0_shard2_replica3' us= ing instanceDir: C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\= solr\build\solr-core\test\J0\.\org.apache.solr.cloud.CollectionsAPIDistribu= tedZkTest-jetty1-1365582247078\awholynewcollection_0_shard2_replica3 [junit4:junit4] 1> INFO - 2013-04-10 08:24:20.109; org.apache.solr.cloud= .ZkController; Check for collection zkNode:awholynewcollection_0 [junit4:junit4] 1> INFO - 2013-04-10 08:24:20.110; org.apache.solr.cloud= .ZkController; Only one config set found in zk - using it:conf1 [junit4:junit4] 1> INFO - 2013-04-10 08:24:20.110; org.apache.solr.commo= n.cloud.SolrZkClient; makePath: /collections/awholynewcollection_0 [junit4:junit4] 1> INFO - 2013-04-10 08:24:20.102; org.apache.solr.core.= CoreContainer; Creating SolrCore 'awholynewcollection_0_shard2_replica4' us= ing instanceDir: C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\= solr\build\solr-core\test\J0\.\org.apache.solr.cloud.CollectionsAPIDistribu= tedZkTest-jetty3-1365582250756\awholynewcollection_0_shard2_replica4 [junit4:junit4] 1> INFO - 2013-04-10 08:24:20.111; org.apache.solr.cloud= .ZkController; Check for collection zkNode:awholynewcollection_0 [junit4:junit4] 1> INFO - 2013-04-10 08:24:20.092; 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:50459_ [junit4:junit4] 1> INFO - 2013-04-10 08:24:20.113; org.apache.solr.commo= n.cloud.SolrZkClient; makePath: /collections/awholynewcollection_0 [junit4:junit4] 1> INFO - 2013-04-10 08:24:20.114; org.apache.solr.commo= n.cloud.SolrZkClient; makePath: /collections/awholynewcollection_0 [junit4:junit4] 1> INFO - 2013-04-10 08:24:20.114; 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:50477_ [junit4:junit4] 1> INFO - 2013-04-10 08:24:20.115; 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:50450_ [junit4:junit4] 1> INFO - 2013-04-10 08:24:20.091; org.apache.solr.cloud= .ZkController; Creating collection in ZooKeeper:awholynewcollection_0 [junit4:junit4] 1> INFO - 2013-04-10 08:24:20.115; org.apache.solr.cloud= .ZkController; Looking for collection configName [junit4:junit4] 1> INFO - 2013-04-10 08:24:20.116; org.apache.solr.cloud= .OverseerCollectionProcessor; Creating shard awholynewcollection_0_shard3_r= eplica4 as part of slice shard3 of collection awholynewcollection_0 on 127.= 0.0.1:50468_ [junit4:junit4] 1> INFO - 2013-04-10 08:24:20.117; org.apache.solr.core.= CoreContainer; Creating SolrCore 'awholynewcollection_0_shard3_replica1' us= ing instanceDir: C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\= solr\build\solr-core\test\J0\.\org.apache.solr.cloud.CollectionsAPIDistribu= tedZkTest-jetty2-1365582249056\awholynewcollection_0_shard3_replica1 [junit4:junit4] 1> INFO - 2013-04-10 08:24:20.117; org.apache.solr.cloud= .ZkController; Check for collection zkNode:awholynewcollection_0 [junit4:junit4] 1> INFO - 2013-04-10 08:24:20.117; org.apache.solr.cloud= .OverseerCollectionProcessor; Creating shard awholynewcollection_0_shard3_r= eplica5 as part of slice shard3 of collection awholynewcollection_0 on 127.= 0.0.1:50438_ [junit4:junit4] 1> INFO - 2013-04-10 08:24:20.118; org.apache.solr.cloud= .OverseerCollectionProcessor; Creating shard awholynewcollection_0_shard4_r= eplica1 as part of slice shard4 of collection awholynewcollection_0 on 127.= 0.0.1:50459_ [junit4:junit4] 1> INFO - 2013-04-10 08:24:20.118; org.apache.solr.cloud= .ZkController; Collection zkNode exists [junit4:junit4] 1> INFO - 2013-04-10 08:24:20.120; org.apache.solr.cloud= .ZkController; Load collection config from:/collections/awholynewcollection= _0 [junit4:junit4] 1> INFO - 2013-04-10 08:24:20.121; org.apache.solr.core.= CoreContainer; Creating SolrCore 'awholynewcollection_0_shard3_replica2' us= ing instanceDir: C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\= solr\build\solr-core\test\J0\.\org.apache.solr.cloud.CollectionsAPIDistribu= tedZkTest-jetty4-1365582252414\awholynewcollection_0_shard3_replica2 [junit4:junit4] 1> INFO - 2013-04-10 08:24:20.123; org.apache.solr.cloud= .ZkController; Check for collection zkNode:awholynewcollection_0 [junit4:junit4] 1> INFO - 2013-04-10 08:24:20.091; org.apache.solr.cloud= .ZkController; Check for collection zkNode:awholynewcollection_0 [junit4:junit4] 1> INFO - 2013-04-10 08:24:20.126; org.apache.solr.cloud= .ZkController; Load collection config from:/collections/awholynewcollection= _0 [junit4:junit4] 1> INFO - 2013-04-10 08:24:20.125; org.apache.solr.core.= CoreContainer; Creating SolrCore 'awholynewcollection_0_shard4_replica1' us= ing instanceDir: C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\= solr\build\solr-core\test\J0\.\org.apache.solr.cloud.CollectionsAPIDistribu= tedZkTest-jetty2-1365582249056\awholynewcollection_0_shard4_replica1 [junit4:junit4] 1> INFO - 2013-04-10 08:24:20.127; org.apache.solr.cloud= .ZkController; Load collection config from:/collections/awholynewcollection= _0 [junit4:junit4] 1> INFO - 2013-04-10 08:24:20.128; org.apache.solr.cloud= .ZkController; Collection zkNode exists [junit4:junit4] 1> INFO - 2013-04-10 08:24:20.129; org.apache.solr.cloud= .ZkController; Load collection config from:/collections/awholynewcollection= _0 [junit4:junit4] 1> INFO - 2013-04-10 08:24:20.124; org.apache.solr.core.= CoreContainer; Creating SolrCore 'awholynewcollection_0_shard3_replica5' us= ing instanceDir: C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\= solr\build\solr-core\test\J0\.\org.apache.solr.cloud.CollectionsAPIDistribu= tedZkTest-controljetty-1365582245991\awholynewcollection_0_shard3_replica5 [junit4:junit4] 1> INFO - 2013-04-10 08:24:20.130; org.apache.solr.cloud= .ZkController; Check for collection zkNode:awholynewcollection_0 [junit4:junit4] 1> INFO - 2013-04-10 08:24:20.124; org.apache.solr.commo= n.cloud.SolrZkClient; makePath: /collections/awholynewcollection_0 [junit4:junit4] 1> INFO - 2013-04-10 08:24:20.131; org.apache.solr.core.= SolrResourceLoader; new SolrResourceLoader for directory: 'C:\Users\Jenkins= Slave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\or= g.apache.solr.cloud.CollectionsAPIDistributedZkTest-controljetty-1365582245= 991\awholynewcollection_0_shard2_replica5\' [junit4:junit4] 1> INFO - 2013-04-10 08:24:20.124; org.apache.solr.cloud= .ZkController; Load collection config from:/collections/awholynewcollection= _0 [junit4:junit4] 1> INFO - 2013-04-10 08:24:20.134; org.apache.solr.cloud= .ZkController; Collection zkNode exists [junit4:junit4] 1> INFO - 2013-04-10 08:24:20.134; org.apache.solr.cloud= .ZkController; Load collection config from:/collections/awholynewcollection= _0 [junit4:junit4] 1> INFO - 2013-04-10 08:24:20.136; org.apache.solr.core.= SolrResourceLoader; new SolrResourceLoader for directory: 'C:\Users\Jenkins= Slave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\or= g.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty1-1365582247078\aw= holynewcollection_0_shard1_replica3\' [junit4:junit4] 1> INFO - 2013-04-10 08:24:20.123; org.apache.solr.core.= CoreContainer; Creating SolrCore 'awholynewcollection_0_shard3_replica3' us= ing instanceDir: C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\= solr\build\solr-core\test\J0\.\org.apache.solr.cloud.CollectionsAPIDistribu= tedZkTest-jetty1-1365582247078\awholynewcollection_0_shard3_replica3 [junit4:junit4] 1> INFO - 2013-04-10 08:24:20.138; org.apache.solr.cloud= .ZkController; Check for collection zkNode:awholynewcollection_0 [junit4:junit4] 1> INFO - 2013-04-10 08:24:20.123; org.apache.solr.core.= CoreContainer; Creating SolrCore 'awholynewcollection_0_shard3_replica4' us= ing instanceDir: C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\= solr\build\solr-core\test\J0\.\org.apache.solr.cloud.CollectionsAPIDistribu= tedZkTest-jetty3-1365582250756\awholynewcollection_0_shard3_replica4 [junit4:junit4] 1> INFO - 2013-04-10 08:24:20.142; org.apache.solr.cloud= .ZkController; Check for collection zkNode:awholynewcollection_0 [junit4:junit4] 1> INFO - 2013-04-10 08:24:20.145; org.apache.solr.core.= SolrResourceLoader; new SolrResourceLoader for directory: 'C:\Users\Jenkins= Slave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\or= g.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1365582252414\aw= holynewcollection_0_shard3_replica2\' [junit4:junit4] 1> INFO - 2013-04-10 08:24:20.119; org.apache.solr.cloud= .ZkController; Collection zkNode exists [junit4:junit4] 1> INFO - 2013-04-10 08:24:20.155; org.apache.solr.cloud= .ZkController; Load collection config from:/collections/awholynewcollection= _0 [junit4:junit4] 1> INFO - 2013-04-10 08:24:20.118; org.apache.solr.cloud= .ZkController; Load collection config from:/collections/awholynewcollection= _0 [junit4:junit4] 1> INFO - 2013-04-10 08:24:20.156; org.apache.solr.cloud= .ZkController; Collection zkNode exists [junit4:junit4] 1> INFO - 2013-04-10 08:24:20.158; org.apache.solr.cloud= .ZkController; Load collection config from:/collections/awholynewcollection= _0 [junit4:junit4] 1> INFO - 2013-04-10 08:24:20.158; org.apache.solr.cloud= .ZkController; Collection zkNode exists [junit4:junit4] 1> INFO - 2013-04-10 08:24:20.158; org.apache.solr.cloud= .ZkController; Load collection config from:/collections/awholynewcollection= _0 [junit4:junit4] 1> INFO - 2013-04-10 08:24:20.159; org.apache.solr.core.= SolrResourceLoader; new SolrResourceLoader for directory: 'C:\Users\Jenkins= Slave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\or= g.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty2-1365582249056\aw= holynewcollection_0_shard1_replica1\' [junit4:junit4] 1> INFO - 2013-04-10 08:24:20.118; org.apache.solr.cloud= .OverseerCollectionProcessor; Creating shard awholynewcollection_0_shard4_r= eplica2 as part of slice shard4 of collection awholynewcollection_0 on 127.= 0.0.1:50477_ [junit4:junit4] 1> INFO - 2013-04-10 08:24:20.113; org.apache.solr.cloud= .ZkController; Load collection config from:/collections/awholynewcollection= _0 [junit4:junit4] 1> INFO - 2013-04-10 08:24:20.172; org.apache.solr.cloud= .OverseerCollectionProcessor; Creating shard awholynewcollection_0_shard4_r= eplica3 as part of slice shard4 of collection awholynewcollection_0 on 127.= 0.0.1:50450_ [junit4:junit4] 1> INFO - 2013-04-10 08:24:20.173; org.apache.solr.cloud= .OverseerCollectionProcessor; Creating shard awholynewcollection_0_shard4_r= eplica4 as part of slice shard4 of collection awholynewcollection_0 on 127.= 0.0.1:50468_ [junit4:junit4] 1> INFO - 2013-04-10 08:24:20.174; org.apache.solr.cloud= .OverseerCollectionProcessor; Creating shard awholynewcollection_0_shard4_r= eplica5 as part of slice shard4 of collection awholynewcollection_0 on 127.= 0.0.1:50438_ [junit4:junit4] 1> INFO - 2013-04-10 08:24:20.179; org.apache.solr.core.= SolrResourceLoader; new SolrResourceLoader for directory: 'C:\Users\Jenkins= Slave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\or= g.apache.solr.cloud.CollectionsAPIDistributedZkTest-controljetty-1365582245= 991\awholynewcollection_0_shard3_replica5\' [junit4:junit4] 1> INFO - 2013-04-10 08:24:20.113; org.apache.solr.cloud= .ZkController; Collection zkNode exists [junit4:junit4] 1> INFO - 2013-04-10 08:24:20.181; org.apache.solr.cloud= .ZkController; Load collection config from:/collections/awholynewcollection= _0 [junit4:junit4] 1> INFO - 2013-04-10 08:24:20.182; org.apache.solr.cloud= .ZkController; Load collection config from:/collections/awholynewcollection= _0 [junit4:junit4] 1> INFO - 2013-04-10 08:24:20.110; org.apache.solr.cloud= .ZkController; Only one config set found in zk - using it:conf1 [junit4:junit4] 1> INFO - 2013-04-10 08:24:20.185; org.apache.solr.commo= n.cloud.SolrZkClient; makePath: /collections/awholynewcollection_0 [junit4:junit4] 1> INFO - 2013-04-10 08:24:20.186; org.apache.solr.core.= CoreContainer; Creating SolrCore 'awholynewcollection_0_shard4_replica2' us= ing instanceDir: C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\= solr\build\solr-core\test\J0\.\org.apache.solr.cloud.CollectionsAPIDistribu= tedZkTest-jetty4-1365582252414\awholynewcollection_0_shard4_replica2 [junit4:junit4] 1> INFO - 2013-04-10 08:24:20.231; org.apache.solr.cloud= .ZkController; Check for collection zkNode:awholynewcollection_0 [junit4:junit4] 1> INFO - 2013-04-10 08:24:20.130; org.apache.solr.core.= SolrResourceLoader; new SolrResourceLoader for directory: 'C:\Users\Jenkins= Slave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\or= g.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty3-1365582250756\aw= holynewcollection_0_shard2_replica4\' [junit4:junit4] 1> INFO - 2013-04-10 08:24:20.129; org.apache.solr.cloud= .ZkController; Collection zkNode exists [junit4:junit4] 1> INFO - 2013-04-10 08:24:20.241; org.apache.solr.cloud= .ZkController; Load collection config from:/collections/awholynewcollection= _0 [junit4:junit4] 1> INFO - 2013-04-10 08:24:20.242; org.apache.solr.core.= CoreContainer; Creating SolrCore 'awholynewcollection_0_shard4_replica4' us= ing instanceDir: C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\= solr\build\solr-core\test\J0\.\org.apache.solr.cloud.CollectionsAPIDistribu= tedZkTest-jetty3-1365582250756\awholynewcollection_0_shard4_replica4 [junit4:junit4] 1> INFO - 2013-04-10 08:24:20.243; org.apache.solr.cloud= .ZkController; Check for collection zkNode:awholynewcollection_0 [junit4:junit4] 1> INFO - 2013-04-10 08:24:20.243; org.apache.solr.core.= SolrResourceLoader; new SolrResourceLoader for directory: 'C:\Users\Jenkins= Slave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\or= g.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty1-1365582247078\aw= holynewcollection_0_shard2_replica3\' [junit4:junit4] 1> INFO - 2013-04-10 08:24:20.127; org.apache.solr.cloud= .ZkController; Check for collection zkNode:awholynewcollection_0 [junit4:junit4] 1> INFO - 2013-04-10 08:24:20.238; org.apache.solr.core.= SolrConfig; Using Lucene MatchVersion: LUCENE_50 [junit4:junit4] 1> INFO - 2013-04-10 08:24:20.245; org.apache.solr.cloud= .ZkController; Collection zkNode exists [junit4:junit4] 1> INFO - 2013-04-10 08:24:20.245; org.apache.solr.cloud= .ZkController; Load collection config from:/collections/awholynewcollection= _0 [junit4:junit4] 1> INFO - 2013-04-10 08:24:20.238; org.apache.solr.core.= SolrResourceLoader; new SolrResourceLoader for directory: 'C:\Users\Jenkins= Slave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\or= g.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty3-1365582250756\aw= holynewcollection_0_shard1_replica4\' [junit4:junit4] 1> INFO - 2013-04-10 08:24:20.230; org.apache.solr.core.= SolrResourceLoader; new SolrResourceLoader for directory: 'C:\Users\Jenkins= Slave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\or= g.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty3-1365582250756\aw= holynewcollection_0_shard3_replica4\' [junit4:junit4] 1> INFO - 2013-04-10 08:24:20.228; org.apache.solr.core.= SolrResourceLoader; new SolrResourceLoader for directory: 'C:\Users\Jenkins= Slave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\or= g.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1365582252414\aw= holynewcollection_0_shard2_replica2\' [junit4:junit4] 1> INFO - 2013-04-10 08:24:20.249; org.apache.solr.cloud= .ZkController; Collection zkNode exists [junit4:junit4] 1> INFO - 2013-04-10 08:24:20.263; org.apache.solr.cloud= .ZkController; Load collection config from:/collections/awholynewcollection= _0 [junit4:junit4] 1> INFO - 2013-04-10 08:24:20.264; org.apache.solr.cloud= .ZkController; Collection zkNode exists [junit4:junit4] 1> INFO - 2013-04-10 08:24:20.264; org.apache.solr.cloud= .ZkController; Load collection config from:/collections/awholynewcollection= _0 [junit4:junit4] 1> INFO - 2013-04-10 08:24:20.228; org.apache.solr.core.= SolrResourceLoader; new SolrResourceLoader for directory: 'C:\Users\Jenkins= Slave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\or= g.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty2-1365582249056\aw= holynewcollection_0_shard3_replica1\' [junit4:junit4] 1> INFO - 2013-04-10 08:24:20.227; org.apache.solr.core.= SolrResourceLoader; new SolrResourceLoader for directory: 'C:\Users\Jenkins= Slave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\or= g.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty1-1365582247078\aw= holynewcollection_0_shard3_replica3\' [junit4:junit4] 1> INFO - 2013-04-10 08:24:20.268; org.apache.solr.cloud= .ZkController; Load collection config from:/collections/awholynewcollection= _0 [junit4:junit4] 1> INFO - 2013-04-10 08:24:20.204; org.apache.solr.core.= CoreContainer; Creating SolrCore 'awholynewcollection_0_shard4_replica5' us= ing instanceDir: C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\= solr\build\solr-core\test\J0\.\org.apache.solr.cloud.CollectionsAPIDistribu= tedZkTest-controljetty-1365582245991\awholynewcollection_0_shard4_replica5 [junit4:junit4] 1> INFO - 2013-04-10 08:24:20.268; org.apache.solr.cloud= .ZkController; Check for collection zkNode:awholynewcollection_0 [junit4:junit4] 1> INFO - 2013-04-10 08:24:20.193; org.apache.solr.core.= CoreContainer; Creating SolrCore 'awholynewcollection_0_shard4_replica3' us= ing instanceDir: C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\= solr\build\solr-core\test\J0\.\org.apache.solr.cloud.CollectionsAPIDistribu= tedZkTest-jetty1-1365582247078\awholynewcollection_0_shard4_replica3 [junit4:junit4] 1> INFO - 2013-04-10 08:24:20.269; org.apache.solr.cloud= .ZkController; Check for collection zkNode:awholynewcollection_0 [junit4:junit4] 1> INFO - 2013-04-10 08:24:20.285; org.apache.solr.core.= SolrResourceLoader; new SolrResourceLoader for directory: 'C:\Users\Jenkins= Slave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\or= g.apache.solr.cloud.CollectionsAPIDistributedZkTest-controljetty-1365582245= 991\awholynewcollection_0_shard1_replica5\' [junit4:junit4] 1> INFO - 2013-04-10 08:24:20.285; org.apache.solr.core.= SolrResourceLoader; new SolrResourceLoader for directory: 'C:\Users\Jenkins= Slave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\or= g.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty2-1365582249056\aw= holynewcollection_0_shard2_replica1\' [junit4:junit4] 1> INFO - 2013-04-10 08:24:20.321; org.apache.solr.core.= SolrConfig; Using Lucene MatchVersion: LUCENE_50 [junit4:junit4] 1> INFO - 2013-04-10 08:24:20.340; org.apache.solr.cloud= .ZkController; Collection zkNode exists [junit4:junit4] 1> INFO - 2013-04-10 08:24:20.341; org.apache.solr.cloud= .ZkController; Load collection config from:/collections/awholynewcollection= _0 [junit4:junit4] 1> INFO - 2013-04-10 08:24:20.342; org.apache.solr.cloud= .ZkController; Collection zkNode exists [junit4:junit4] 1> INFO - 2013-04-10 08:24:20.342; org.apache.solr.cloud= .ZkController; Load collection config from:/collections/awholynewcollection= _0 [junit4:junit4] 1> INFO - 2013-04-10 08:24:20.359; org.apache.solr.core.= SolrConfig; Using Lucene MatchVersion: LUCENE_50 [junit4:junit4] 1> INFO - 2013-04-10 08:24:20.365; org.apache.solr.core.= SolrResourceLoader; new SolrResourceLoader for directory: 'C:\Users\Jenkins= Slave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\or= g.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1365582252414\aw= holynewcollection_0_shard1_replica2\' [junit4:junit4] 1> INFO - 2013-04-10 08:24:20.380; org.apache.solr.core.= SolrResourceLoader; new SolrResourceLoader for directory: 'C:\Users\Jenkins= Slave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\or= g.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty3-1365582250756\aw= holynewcollection_0_shard4_replica4\' [junit4:junit4] 1> INFO - 2013-04-10 08:24:20.381; org.apache.solr.core.= SolrResourceLoader; new SolrResourceLoader for directory: 'C:\Users\Jenkins= Slave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\or= g.apache.solr.cloud.CollectionsAPIDistributedZkTest-controljetty-1365582245= 991\awholynewcollection_0_shard4_replica5\' [junit4:junit4] 1> INFO - 2013-04-10 08:24:20.381; org.apache.solr.core.= SolrResourceLoader; new SolrResourceLoader for directory: 'C:\Users\Jenkins= Slave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\or= g.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1365582252414\aw= holynewcollection_0_shard4_replica2\' [junit4:junit4] 1> INFO - 2013-04-10 08:24:20.392; org.apache.solr.core.= SolrConfig; Using Lucene MatchVersion: LUCENE_50 [junit4:junit4] 1> INFO - 2013-04-10 08:24:20.418; org.apache.solr.core.= SolrResourceLoader; new SolrResourceLoader for directory: 'C:\Users\Jenkins= Slave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\or= g.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty2-1365582249056\aw= holynewcollection_0_shard4_replica1\' [junit4:junit4] 1> INFO - 2013-04-10 08:24:20.419; org.apache.solr.core.= SolrResourceLoader; new SolrResourceLoader for directory: 'C:\Users\Jenkins= Slave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\or= g.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty1-1365582247078\aw= holynewcollection_0_shard4_replica3\' [junit4:junit4] 1> INFO - 2013-04-10 08:24:20.453; org.apache.solr.core.= SolrConfig; Loaded SolrConfig: solrconfig.xml [junit4:junit4] 1> INFO - 2013-04-10 08:24:20.488; org.apache.solr.schem= a.IndexSchema; Reading Solr Schema from schema.xml [junit4:junit4] 1> INFO - 2013-04-10 08:24:20.510; org.apache.solr.schem= a.IndexSchema; Schema name=3Dtest [junit4:junit4] 1> INFO - 2013-04-10 08:24:20.527; org.apache.solr.core.= SolrConfig; Using Lucene MatchVersion: LUCENE_50 [junit4:junit4] 1> INFO - 2013-04-10 08:24:20.589; org.apache.solr.core.= SolrConfig; Using Lucene MatchVersion: LUCENE_50 [junit4:junit4] 1> INFO - 2013-04-10 08:24:20.603; org.apache.solr.core.= SolrConfig; Using Lucene MatchVersion: LUCENE_50 [junit4:junit4] 1> INFO - 2013-04-10 08:24:20.624; org.apache.solr.core.= SolrConfig; Using Lucene MatchVersion: LUCENE_50 [junit4:junit4] 1> INFO - 2013-04-10 08:24:20.813; org.apache.solr.core.= SolrConfig; Using Lucene MatchVersion: LUCENE_50 [junit4:junit4] 1> INFO - 2013-04-10 08:24:20.820; org.apache.solr.core.= SolrConfig; Loaded SolrConfig: solrconfig.xml [junit4:junit4] 1> INFO - 2013-04-10 08:24:20.845; org.apache.solr.schem= a.IndexSchema; Reading Solr Schema from schema.xml [junit4:junit4] 1> INFO - 2013-04-10 08:24:20.856; org.apache.solr.core.= SolrConfig; Loaded SolrConfig: solrconfig.xml [junit4:junit4] 1> INFO - 2013-04-10 08:24:20.877; org.apache.solr.schem= a.IndexSchema; Reading Solr Schema from schema.xml [junit4:junit4] 1> INFO - 2013-04-10 08:24:20.899; org.apache.solr.schem= a.IndexSchema; Schema name=3Dtest [junit4:junit4] 1> INFO - 2013-04-10 08:24:20.939; org.apache.solr.core.= SolrConfig; Loaded SolrConfig: solrconfig.xml [junit4:junit4] 1> INFO - 2013-04-10 08:24:20.945; org.apache.solr.core.= SolrConfig; Using Lucene MatchVersion: LUCENE_50 [junit4:junit4] 1> INFO - 2013-04-10 08:24:20.948; org.apache.solr.schem= a.IndexSchema; Schema name=3Dtest [junit4:junit4] 1> INFO - 2013-04-10 08:24:20.972; org.apache.solr.core.= SolrConfig; Loaded SolrConfig: solrconfig.xml [junit4:junit4] 1> INFO - 2013-04-10 08:24:20.987; org.apache.solr.core.= SolrConfig; Loaded SolrConfig: solrconfig.xml [junit4:junit4] 1> INFO - 2013-04-10 08:24:21.013; org.apache.solr.core.= SolrConfig; Using Lucene MatchVersion: LUCENE_50 [junit4:junit4] 1> INFO - 2013-04-10 08:24:21.093; org.apache.solr.core.= SolrConfig; Using Lucene MatchVersion: LUCENE_50 [junit4:junit4] 1> INFO - 2013-04-10 08:24:21.100; org.apache.solr.schem= a.IndexSchema; Reading Solr Schema from schema.xml [junit4:junit4] 1> INFO - 2013-04-10 08:24:21.109; org.apache.solr.schem= a.IndexSchema; Schema name=3Dtest [junit4:junit4] 1> INFO - 2013-04-10 08:24:21.114; org.apache.solr.core.= SolrConfig; Loaded SolrConfig: solrconfig.xml [junit4:junit4] 1> INFO - 2013-04-10 08:24:21.142; org.apache.solr.schem= a.IndexSchema; Reading Solr Schema from schema.xml [junit4:junit4] 1> INFO - 2013-04-10 08:24:21.183; org.apache.solr.core.= SolrConfig; Loaded SolrConfig: solrconfig.xml [junit4:junit4] 1> INFO - 2013-04-10 08:24:21.215; org.apache.solr.schem= a.IndexSchema; Reading Solr Schema from schema.xml [junit4:junit4] 1> INFO - 2013-04-10 08:24:21.218; org.apache.solr.schem= a.IndexSchema; Reading Solr Schema from schema.xml [junit4:junit4] 1> INFO - 2013-04-10 08:24:21.253; org.apache.solr.core.= SolrConfig; Using Lucene MatchVersion: LUCENE_50 [junit4:junit4] 1> INFO - 2013-04-10 08:24:21.291; org.apache.solr.commo= n.cloud.ZkStateReader; Updating cloud state from ZooKeeper...=20 [junit4:junit4] 1> INFO - 2013-04-10 08:24:21.292; org.apache.solr.schem= a.IndexSchema; Reading Solr Schema from schema.xml [junit4:junit4] 1> INFO - 2013-04-10 08:24:21.300; org.apache.solr.schem= a.IndexSchema; Schema name=3Dtest [junit4:junit4] 1> INFO - 2013-04-10 08:24:21.339; org.apache.solr.core.= SolrConfig; Using Lucene MatchVersion: LUCENE_50 [junit4:junit4] 1> INFO - 2013-04-10 08:24:21.341; org.apache.solr.core.= SolrConfig; Using Lucene MatchVersion: LUCENE_50 [junit4:junit4] 1> INFO - 2013-04-10 08:24:21.352; 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:50450__nodes_used_collec= tion_shard2_replica1", [junit4:junit4] 1> "numShards":"2", [junit4:junit4] 1> "shard":"shard2", [junit4:junit4] 1> "roles":null, [junit4:junit4] 1> "state":"active", [junit4:junit4] 1> "shard_state":"active", [junit4:junit4] 1> "core":"nodes_used_collection_shard2_replica1", [junit4:junit4] 1> "collection":"nodes_used_collection", [junit4:junit4] 1> "shard_range":null, [junit4:junit4] 1> "node_name":"127.0.0.1:50450_", [junit4:junit4] 1> "base_url":"http://127.0.0.1:50450"} [junit4:junit4] 1> INFO - 2013-04-10 08:24:21.394; org.apache.solr.schem= a.IndexSchema; Schema name=3Dtest [junit4:junit4] 1> INFO - 2013-04-10 08:24:21.438; org.apache.solr.core.= SolrConfig; Loaded SolrConfig: solrconfig.xml [junit4:junit4] 1> INFO - 2013-04-10 08:24:21.483; org.apache.solr.core.= SolrConfig; Using Lucene MatchVersion: LUCENE_50 [junit4:junit4] 1> INFO - 2013-04-10 08:24:21.548; org.apache.solr.core.= SolrConfig; Using Lucene MatchVersion: LUCENE_50 [junit4:junit4] 1> INFO - 2013-04-10 08:24:21.674; org.apache.solr.schem= a.IndexSchema; Reading Solr Schema from schema.xml [junit4:junit4] 1> INFO - 2013-04-10 08:24:21.688; org.apache.solr.core.= SolrConfig; Using Lucene MatchVersion: LUCENE_50 [junit4:junit4] 1> INFO - 2013-04-10 08:24:21.726; 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:50459__nodes_used_collec= tion_shard1_replica2", [junit4:junit4] 1> "numShards":"2", [junit4:junit4] 1> "shard":"shard1", [junit4:junit4] 1> "roles":null, [junit4:junit4] 1> "state":"active", [junit4:junit4] 1> "shard_state":"active", [junit4:junit4] 1> "core":"nodes_used_collection_shard1_replica2", [junit4:junit4] 1> "collection":"nodes_used_collection", [junit4:junit4] 1> "shard_range":null, [junit4:junit4] 1> "node_name":"127.0.0.1:50459_", [junit4:junit4] 1> "base_url":"http://127.0.0.1:50459"} [junit4:junit4] 1> INFO - 2013-04-10 08:24:21.743; org.apache.solr.core.= SolrConfig; Loaded SolrConfig: solrconfig.xml [junit4:junit4] 1> INFO - 2013-04-10 08:24:21.754; org.apache.solr.schem= a.IndexSchema; Schema name=3Dtest [junit4:junit4] 1> INFO - 2013-04-10 08:24:21.765; org.apache.solr.core.= SolrConfig; Loaded SolrConfig: solrconfig.xml [junit4:junit4] 1> INFO - 2013-04-10 08:24:21.781; org.apache.solr.core.= SolrConfig; Loaded SolrConfig: solrconfig.xml [junit4:junit4] 1> INFO - 2013-04-10 08:24:21.806; org.apache.solr.schem= a.IndexSchema; Schema name=3Dtest [junit4:junit4] 1> INFO - 2013-04-10 08:24:21.875; org.apache.solr.schem= a.IndexSchema; Reading Solr Schema from schema.xml [junit4:junit4] 1> INFO - 2013-04-10 08:24:21.880; org.apache.solr.schem= a.IndexSchema; Schema name=3Dtest [junit4:junit4] 1> INFO - 2013-04-10 08:24:21.890; org.apache.solr.schem= a.IndexSchema; Schema name=3Dtest [junit4:junit4] 1> INFO - 2013-04-10 08:24:21.901; org.apache.solr.core.= SolrConfig; Using Lucene MatchVersion: LUCENE_50 [junit4:junit4] 1> INFO - 2013-04-10 08:24:21.927; org.apache.solr.schem= a.IndexSchema; Reading Solr Schema from schema.xml [junit4:junit4] 1> INFO - 2013-04-10 08:24:21.929; org.apache.solr.schem= a.IndexSchema; Reading Solr Schema from schema.xml [junit4:junit4] 1> INFO - 2013-04-10 08:24:22.009; org.apache.solr.core.= SolrConfig; Using Lucene MatchVersion: LUCENE_50 [junit4:junit4] 1> INFO - 2013-04-10 08:24:22.015; 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:50438__nodes_used_collec= tion_shard2_replica2", [junit4:junit4] 1> "numShards":"2", [junit4:junit4] 1> "shard":"shard2", [junit4:junit4] 1> "roles":null, [junit4:junit4] 1> "state":"recovering", [junit4:junit4] 1> "shard_state":"active", [junit4:junit4] 1> "core":"nodes_used_collection_shard2_replica2", [junit4:junit4] 1> "collection":"nodes_used_collection", [junit4:junit4] 1> "shard_range":null, [junit4:junit4] 1> "node_name":"127.0.0.1:50438_", [junit4:junit4] 1> "base_url":"http://127.0.0.1:50438"} [junit4:junit4] 1> INFO - 2013-04-10 08:24:22.037; 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:50477__nodes_used_collec= tion_shard1_replica1", [junit4:junit4] 1> "numShards":"2", [junit4:junit4] 1> "shard":"shard1", [junit4:junit4] 1> "roles":null, [junit4:junit4] 1> "state":"recovering", [junit4:junit4] 1> "shard_state":"active", [junit4:junit4] 1> "core":"nodes_used_collection_shard1_replica1", [junit4:junit4] 1> "collection":"nodes_used_collection", [junit4:junit4] 1> "shard_range":null, [junit4:junit4] 1> "node_name":"127.0.0.1:50477_", [junit4:junit4] 1> "base_url":"http://127.0.0.1:50477"} [junit4:junit4] 1> INFO - 2013-04-10 08:24:22.042; org.apache.solr.schem= a.IndexSchema; Schema name=3Dtest [junit4:junit4] 1> INFO - 2013-04-10 08:24:22.042; org.apache.solr.core.= SolrConfig; Loaded SolrConfig: solrconfig.xml [junit4:junit4] 1> INFO - 2013-04-10 08:24:22.048; org.apache.solr.schem= a.IndexSchema; Schema name=3Dtest [junit4:junit4] 1> INFO - 2013-04-10 08:24:22.049; org.apache.solr.schem= a.IndexSchema; Reading Solr Schema from schema.xml [junit4:junit4] 1> INFO - 2013-04-10 08:24:22.063; org.apache.solr.core.= SolrConfig; Loaded SolrConfig: solrconfig.xml [junit4:junit4] 1> INFO - 2013-04-10 08:24:22.074; org.apache.solr.core.= SolrConfig; Loaded SolrConfig: solrconfig.xml [junit4:junit4] 1> INFO - 2013-04-10 08:24:22.086; org.apache.solr.schem= a.IndexSchema; Schema name=3Dtest [junit4:junit4] 1> INFO - 2013-04-10 08:24:22.209; org.apache.solr.schem= a.IndexSchema; Reading Solr Schema from schema.xml [junit4:junit4] 1> INFO - 2013-04-10 08:24:22.213; org.apache.solr.schem= a.IndexSchema; Schema name=3Dtest [junit4:junit4] 1> INFO - 2013-04-10 08:24:22.270; org.apache.solr.schem= a.IndexSchema; Reading Solr Schema from schema.xml [junit4:junit4] 1> INFO - 2013-04-10 08:24:22.281; org.apache.solr.commo= n.cloud.ZkStateReader$2; A cluster state change: WatchedEvent state:SyncCon= nected type:NodeDataChanged path:/clusterstate.json, has occurred - updatin= g... (live nodes size: 5) [junit4:junit4] 1> INFO - 2013-04-10 08:24:22.281; org.apache.solr.commo= n.cloud.ZkStateReader$2; A cluster state change: WatchedEvent state:SyncCon= nected type:NodeDataChanged path:/clusterstate.json, has occurred - updatin= g... (live nodes size: 5) [junit4:junit4] 1> INFO - 2013-04-10 08:24:22.282; org.apache.solr.commo= n.cloud.ZkStateReader$2; A cluster state change: WatchedEvent state:SyncCon= nected type:NodeDataChanged path:/clusterstate.json, has occurred - updatin= g... (live nodes size: 5) [junit4:junit4] 1> INFO - 2013-04-10 08:24:22.282; org.apache.solr.commo= n.cloud.ZkStateReader$2; A cluster state change: WatchedEvent state:SyncCon= nected type:NodeDataChanged path:/clusterstate.json, has occurred - updatin= g... (live nodes size: 5) [junit4:junit4] 1> INFO - 2013-04-10 08:24:22.282; org.apache.solr.commo= n.cloud.ZkStateReader$2; A cluster state change: WatchedEvent state:SyncCon= nected type:NodeDataChanged path:/clusterstate.json, has occurred - updatin= g... (live nodes size: 5) [junit4:junit4] 1> INFO - 2013-04-10 08:24:22.282; org.apache.solr.commo= n.cloud.ZkStateReader$2; A cluster state change: WatchedEvent state:SyncCon= nected type:NodeDataChanged path:/clusterstate.json, has occurred - updatin= g... (live nodes size: 5) [junit4:junit4] 1> INFO - 2013-04-10 08:24:22.320; org.apache.solr.commo= n.cloud.ZkStateReader$2; A cluster state change: WatchedEvent state:SyncCon= nected type:NodeDataChanged path:/clusterstate.json, has occurred - updatin= g... (live nodes size: 5) [junit4:junit4] 1> INFO - 2013-04-10 08:24:22.320; org.apache.solr.commo= n.cloud.ZkStateReader$2; A cluster state change: WatchedEvent state:SyncCon= nected type:NodeDataChanged path:/clusterstate.json, has occurred - updatin= g... (live nodes size: 5) [junit4:junit4] 1> INFO - 2013-04-10 08:24:22.337; org.apache.solr.core.= SolrConfig; Loaded SolrConfig: solrconfig.xml [junit4:junit4] 1> INFO - 2013-04-10 08:24:22.409; org.apache.solr.schem= a.IndexSchema; Schema name=3Dtest [junit4:junit4] 1> INFO - 2013-04-10 08:24:22.438; org.apache.solr.schem= a.IndexSchema; Reading Solr Schema from schema.xml [junit4:junit4] 1> INFO - 2013-04-10 08:24:22.444; org.apache.solr.schem= a.IndexSchema; Schema name=3Dtest [junit4:junit4] 1> INFO - 2013-04-10 08:24:22.543; org.apache.solr.handl= er.admin.CoreAdminHandler; Waited coreNodeName: 127.0.0.1:50438__nodes_used= _collection_shard2_replica2, state: recovering, checkLive: true, onlyIfLead= er: true for: 3 seconds. [junit4:junit4] 1> INFO - 2013-04-10 08:24:22.543; org.apache.solr.servl= et.SolrDispatchFilter; [admin] webapp=3Dnull path=3D/admin/cores params=3D{= coreNodeName=3D127.0.0.1:50438__nodes_used_collection_shard2_replica2&state= =3Drecovering&nodeName=3D127.0.0.1:50438_&action=3DPREPRECOVERY&checkLive= =3Dtrue&core=3Dnodes_used_collection_shard2_replica1&wt=3Djavabin&onlyIfLea= der=3Dtrue&version=3D2} status=3D0 QTime=3D2887=20 [junit4:junit4] 1> INFO - 2013-04-10 08:24:22.556; org.apache.solr.core.= SolrConfig; Loaded SolrConfig: solrconfig.xml [junit4:junit4] 1> INFO - 2013-04-10 08:24:22.579; org.apache.solr.schem= a.IndexSchema; Reading Solr Schema from schema.xml [junit4:junit4] 1> INFO - 2013-04-10 08:24:22.748; org.apache.solr.core.= SolrConfig; Loaded SolrConfig: solrconfig.xml [junit4:junit4] 1> INFO - 2013-04-10 08:24:22.803; org.apache.solr.handl= er.admin.CoreAdminHandler; Waited coreNodeName: 127.0.0.1:50477__nodes_used= _collection_shard1_replica1, state: recovering, checkLive: true, onlyIfLead= er: true for: 3 seconds. [junit4:junit4] 1> INFO - 2013-04-10 08:24:22.803; org.apache.solr.servl= et.SolrDispatchFilter; [admin] webapp=3Dnull path=3D/admin/cores params=3D{= coreNodeName=3D127.0.0.1:50477__nodes_used_collection_shard1_replica1&state= =3Drecovering&nodeName=3D127.0.0.1:50477_&action=3DPREPRECOVERY&checkLive= =3Dtrue&core=3Dnodes_used_collection_shard1_replica2&wt=3Djavabin&onlyIfLea= der=3Dtrue&version=3D2} status=3D0 QTime=3D2784=20 [junit4:junit4] 1> INFO - 2013-04-10 08:24:22.817; org.apache.solr.schem= a.IndexSchema; Schema name=3Dtest [junit4:junit4] 1> INFO - 2013-04-10 08:24:22.891; org.apache.solr.schem= a.IndexSchema; Reading Solr Schema from schema.xml [junit4:junit4] 1> INFO - 2013-04-10 08:24:22.969; org.apache.solr.schem= a.IndexSchema; Schema name=3Dtest [junit4:junit4] 1> INFO - 2013-04-10 08:24:23.026; org.apache.solr.core.= SolrConfig; Loaded SolrConfig: solrconfig.xml [junit4:junit4] 1> INFO - 2013-04-10 08:24:23.032; org.apache.solr.schem= a.IndexSchema; Reading Solr Schema from schema.xml [junit4:junit4] 1> INFO - 2013-04-10 08:24:23.232; org.apache.solr.schem= a.IndexSchema; Schema name=3Dtest [junit4:junit4] 1> INFO - 2013-04-10 08:24:23.777; org.apache.solr.core.= SolrConfig; Loaded SolrConfig: solrconfig.xml [junit4:junit4] 1> INFO - 2013-04-10 08:24:23.854; org.apache.solr.schem= a.IndexSchema; Reading Solr Schema from schema.xml [junit4:junit4] 1> INFO - 2013-04-10 08:24:24.249; org.apache.solr.schem= a.IndexSchema; Schema name=3Dtest [junit4:junit4] 1> INFO - 2013-04-10 08:24:24.428; org.apache.solr.cloud= .RecoveryStrategy; Attempting to PeerSync from http://127.0.0.1:50450/nodes= _used_collection_shard2_replica1/ core=3Dnodes_used_collection_shard2_repli= ca2 - recoveringAfterStartup=3Dtrue [junit4:junit4] 1> INFO - 2013-04-10 08:24:24.428; org.apache.solr.updat= e.PeerSync; PeerSync: core=3Dnodes_used_collection_shard2_replica2 url=3Dht= tp://127.0.0.1:50438 START replicas=3D[http://127.0.0.1:50450/nodes_used_co= llection_shard2_replica1/] nUpdates=3D100 [junit4:junit4] 1> WARN - 2013-04-10 08:24:24.431; org.apache.solr.updat= e.PeerSync; no frame of reference to tell of we've missed updates [junit4:junit4] 1> INFO - 2013-04-10 08:24:24.432; org.apache.solr.cloud= .RecoveryStrategy; PeerSync Recovery was not successful - trying replicatio= n. core=3Dnodes_used_collection_shard2_replica2 [junit4:junit4] 1> INFO - 2013-04-10 08:24:24.432; org.apache.solr.cloud= .RecoveryStrategy; Starting Replication Recovery. core=3Dnodes_used_collect= ion_shard2_replica2 [junit4:junit4] 1> INFO - 2013-04-10 08:24:24.432; org.apache.solr.cloud= .RecoveryStrategy; Begin buffering updates. core=3Dnodes_used_collection_sh= ard2_replica2 [junit4:junit4] 1> INFO - 2013-04-10 08:24:24.432; org.apache.solr.updat= e.UpdateLog; Starting to buffer updates. FSUpdateLog{state=3DACTIVE, tlog= =3Dnull} [junit4:junit4] 1> INFO - 2013-04-10 08:24:24.432; org.apache.solr.cloud= .RecoveryStrategy; Attempting to replicate from http://127.0.0.1:50450/node= s_used_collection_shard2_replica1/. core=3Dnodes_used_collection_shard2_rep= lica2 [junit4:junit4] 1> INFO - 2013-04-10 08:24:24.432; org.apache.solr.clien= t.solrj.impl.HttpClientUtil; Creating new http client, config:maxConnection= s=3D128&maxConnectionsPerHost=3D32&followRedirects=3Dfalse [junit4:junit4] 1> INFO - 2013-04-10 08:24:24.573; org.apache.solr.core.= SolrCore; [nodes_used_collection_shard2_replica1] webapp=3D path=3D/get par= ams=3D{getVersions=3D100&distrib=3Dfalse&wt=3Djavabin&qt=3D/get&version=3D2= } status=3D0 QTime=3D1=20 [junit4:junit4] 1> INFO - 2013-04-10 08:24:24.587; org.apache.solr.updat= e.DirectUpdateHandler2; start commit{,optimize=3Dfalse,openSearcher=3Dfalse= ,waitSearcher=3Dtrue,expungeDeletes=3Dfalse,softCommit=3Dfalse,prepareCommi= t=3Dfalse} [junit4:junit4] 1> INFO - 2013-04-10 08:24:24.624; org.apache.solr.cloud= .RecoveryStrategy; Attempting to PeerSync from http://127.0.0.1:50459/nodes= _used_collection_shard1_replica2/ core=3Dnodes_used_collection_shard1_repli= ca1 - recoveringAfterStartup=3Dtrue [junit4:junit4] 1> INFO - 2013-04-10 08:24:24.624; org.apache.solr.updat= e.PeerSync; PeerSync: core=3Dnodes_used_collection_shard1_replica1 url=3Dht= tp://127.0.0.1:50477 START replicas=3D[http://127.0.0.1:50459/nodes_used_co= llection_shard1_replica2/] nUpdates=3D100 [junit4:junit4] 1> WARN - 2013-04-10 08:24:24.625; org.apache.solr.updat= e.PeerSync; no frame of reference to tell of we've missed updates [junit4:junit4] 1> INFO - 2013-04-10 08:24:24.625; org.apache.solr.cloud= .RecoveryStrategy; PeerSync Recovery was not successful - trying replicatio= n. core=3Dnodes_used_collection_shard1_replica1 [junit4:junit4] 1> INFO - 2013-04-10 08:24:24.625; org.apache.solr.cloud= .RecoveryStrategy; Starting Replication Recovery. core=3Dnodes_used_collect= ion_shard1_replica1 [junit4:junit4] 1> INFO - 2013-04-10 08:24:24.626; org.apache.solr.cloud= .RecoveryStrategy; Begin buffering updates. core=3Dnodes_used_collection_sh= ard1_replica1 [junit4:junit4] 1> INFO - 2013-04-10 08:24:24.626; org.apache.solr.updat= e.UpdateLog; Starting to buffer updates. FSUpdateLog{state=3DACTIVE, tlog= =3Dnull} [junit4:junit4] 1> INFO - 2013-04-10 08:24:24.626; org.apache.solr.cloud= .RecoveryStrategy; Attempting to replicate from http://127.0.0.1:50459/node= s_used_collection_shard1_replica2/. core=3Dnodes_used_collection_shard1_rep= lica1 [junit4:junit4] 1> INFO - 2013-04-10 08:24:24.626; org.apache.solr.clien= t.solrj.impl.HttpClientUtil; Creating new http client, config:maxConnection= s=3D128&maxConnectionsPerHost=3D32&followRedirects=3Dfalse [junit4:junit4] 1> INFO - 2013-04-10 08:24:24.641; org.apache.solr.core.= SolrDeletionPolicy; SolrDeletionPolicy.onInit: commits:num=3D1 [junit4:junit4] 1> =09commit{dir=3DBaseDirectoryWrapper(org.apache.lucene= .store.RAMDirectory@1bae7f6 lockFactory=3Dorg.apache.lucene.store.NativeFSL= ockFactory@3e0df8),segFN=3Dsegments_1,generation=3D1,filenames=3D[segments_= 1] [junit4:junit4] 1> INFO - 2013-04-10 08:24:24.645; org.apache.solr.core.= SolrDeletionPolicy; newest commit =3D 1[segments_1] [junit4:junit4] 1> INFO - 2013-04-10 08:24:24.646; org.apache.solr.core.= SolrDeletionPolicy; SolrDeletionPolicy.onCommit: commits:num=3D2 [junit4:junit4] 1> =09commit{dir=3DBaseDirectoryWrapper(org.apache.lucene= .store.RAMDirectory@1bae7f6 lockFactory=3Dorg.apache.lucene.store.NativeFSL= ockFactory@3e0df8),segFN=3Dsegments_1,generation=3D1,filenames=3D[segments_= 1] [junit4:junit4] 1> =09commit{dir=3DBaseDirectoryWrapper(org.apache.lucene= .store.RAMDirectory@1bae7f6 lockFactory=3Dorg.apache.lucene.store.NativeFSL= ockFactory@3e0df8),segFN=3Dsegments_2,generation=3D2,filenames=3D[segments_= 2] [junit4:junit4] 1> INFO - 2013-04-10 08:24:24.646; org.apache.solr.core.= SolrDeletionPolicy; newest commit =3D 2[segments_2] [junit4:junit4] 1> INFO - 2013-04-10 08:24:24.647; org.apache.solr.searc= h.SolrIndexSearcher; Opening Searcher@beb911 realtime [junit4:junit4] 1> INFO - 2013-04-10 08:24:24.647; org.apache.solr.updat= e.DirectUpdateHandler2; end_commit_flush [junit4:junit4] 1> INFO - 2013-04-10 08:24:24.647; org.apache.solr.updat= e.processor.LogUpdateProcessor; [nodes_used_collection_shard2_replica1] web= app=3D path=3D/update params=3D{waitSearcher=3Dtrue&openSearcher=3Dfalse&co= mmit=3Dtrue&wt=3Djavabin&commit_end_point=3Dtrue&version=3D2&softCommit=3Df= alse} {commit=3D} 0 61 [junit4:junit4] 1> INFO - 2013-04-10 08:24:24.649; org.apache.solr.handl= er.ReplicationHandler; Commits will be reserved for 10000 [junit4:junit4] 1> INFO - 2013-04-10 08:24:24.649; org.apache.solr.handl= er.SnapPuller; No value set for 'pollInterval'. Timer Task not started. [junit4:junit4] 1> INFO - 2013-04-10 08:24:24.653; org.apache.solr.handl= er.ReplicationHandler; Commits will be reserved for 10000 [junit4:junit4] 1> INFO - 2013-04-10 08:24:24.653; org.apache.solr.core.= SolrCore; [nodes_used_collection_shard2_replica1] webapp=3D path=3D/replica= tion params=3D{command=3Dindexversion&qt=3D/replication&wt=3Djavabin&versio= n=3D2} status=3D0 QTime=3D1=20 [junit4:junit4] 1> INFO - 2013-04-10 08:24:24.654; org.apache.solr.handl= er.SnapPuller; Master's generation: 2 [junit4:junit4] 1> INFO - 2013-04-10 08:24:24.654; org.apache.solr.handl= er.SnapPuller; Slave's generation: 1 [junit4:junit4] 1> INFO - 2013-04-10 08:24:24.654; org.apache.solr.handl= er.SnapPuller; Starting replication process [junit4:junit4] 1> INFO - 2013-04-10 08:24:24.714; org.apache.solr.core.= SolrCore; [nodes_used_collection_shard2_replica1] webapp=3D path=3D/replica= tion params=3D{command=3Dfilelist&qt=3D/replication&wt=3Djavabin&generation= =3D2&version=3D2} status=3D0 QTime=3D4=20 [junit4:junit4] 1> INFO - 2013-04-10 08:24:24.714; org.apache.solr.handl= er.SnapPuller; Number of files in latest index in master: 1 [junit4:junit4] 1> INFO - 2013-04-10 08:24:24.716; org.apache.solr.core.= CachingDirectoryFactory; return new directory for C:\Users\JenkinsSlave\wor= kspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.= solr.cloud.CollectionsAPIDistributedZkTest-controljetty-1365582245991\nodes= _used_collection_shard2_replica2\data\index.20130410162424714 [junit4:junit4] 1> INFO - 2013-04-10 08:24:24.716; org.apache.solr.handl= er.SnapPuller; Starting download to MockDirWrapper(org.apache.lucene.store.= RAMDirectory@cd1ccf lockFactory=3Dorg.apache.lucene.store.NativeFSLockFacto= ry@17d4550) fullCopy=3Dfalse [junit4:junit4] 1> INFO - 2013-04-10 08:24:24.739; org.apache.solr.updat= e.DirectUpdateHandler2; start commit{,optimize=3Dfalse,openSearcher=3Dfalse= ,waitSearcher=3Dtrue,expungeDeletes=3Dfalse,softCommit=3Dfalse,prepareCommi= t=3Dfalse} [junit4:junit4] 1> INFO - 2013-04-10 08:24:24.747; org.apache.solr.core.= SolrCore; [nodes_used_collection_shard2_replica1] webapp=3D path=3D/replica= tion params=3D{file=3Dsegments_2&command=3Dfilecontent&checksum=3Dtrue&wt= =3Dfilestream&qt=3D/replication&generation=3D2} status=3D0 QTime=3D0=20 [junit4:junit4] 1> INFO - 2013-04-10 08:24:24.749; org.apache.solr.handl= er.SnapPuller; Total time taken for download : 0 secs [junit4:junit4] 1> INFO - 2013-04-10 08:24:24.749; org.apache.solr.core.= SolrCore; [nodes_used_collection_shard1_replica2] webapp=3D path=3D/get par= ams=3D{getVersions=3D100&distrib=3Dfalse&wt=3Djavabin&qt=3D/get&version=3D2= } status=3D0 QTime=3D4=20 [junit4:junit4] 1> INFO - 2013-04-10 08:24:24.774; org.apache.solr.core.= SolrDeletionPolicy; SolrDeletionPolicy.onInit: commits:num=3D1 [junit4:junit4] 1> =09commit{dir=3DBaseDirectoryWrapper(org.apache.lucene= .store.RAMDirectory@1aacc4c lockFactory=3Dorg.apache.lucene.store.NativeFSL= ockFactory@1d462b2),segFN=3Dsegments_1,generation=3D1,filenames=3D[segments= _1] [junit4:junit4] 1> INFO - 2013-04-10 08:24:24.786; org.apache.solr.core.= SolrDeletionPolicy; newest commit =3D 1[segments_1] [junit4:junit4] 1> INFO - 2013-04-10 08:24:24.787; org.apache.solr.updat= e.DefaultSolrCoreState; Creating new IndexWriter... [junit4:junit4] 1> INFO - 2013-04-10 08:24:24.787; org.apache.solr.core.= SolrDeletionPolicy; SolrDeletionPolicy.onCommit: commits:num=3D2 [junit4:junit4] 1> =09commit{dir=3DBaseDirectoryWrapper(org.apache.lucene= .store.RAMDirectory@1aacc4c lockFactory=3Dorg.apache.lucene.store.NativeFSL= ockFactory@1d462b2),segFN=3Dsegments_1,generation=3D1,filenames=3D[segments= _1] [junit4:junit4] 1> =09commit{dir=3DBaseDirectoryWrapper(org.apache.lucene= .store.RAMDirectory@1aacc4c lockFactory=3Dorg.apache.lucene.store.NativeFSL= ockFactory@1d462b2),segFN=3Dsegments_2,generation=3D2,filenames=3D[segments= _2] [junit4:junit4] 1> INFO - 2013-04-10 08:24:24.788; org.apache.solr.core.= SolrDeletionPolicy; newest commit =3D 2[segments_2] [junit4:junit4] 1> INFO - 2013-04-10 08:24:24.788; org.apache.solr.searc= h.SolrIndexSearcher; Opening Searcher@140857d realtime [junit4:junit4] 1> INFO - 2013-04-10 08:24:24.788; org.apache.solr.updat= e.DirectUpdateHandler2; end_commit_flush [junit4:junit4] 1> INFO - 2013-04-10 08:24:24.789; org.apache.solr.updat= e.processor.LogUpdateProcessor; [nodes_used_collection_shard1_replica2] web= app=3D path=3D/update params=3D{waitSearcher=3Dtrue&openSearcher=3Dfalse&co= mmit=3Dtrue&wt=3Djavabin&commit_end_point=3Dtrue&version=3D2&softCommit=3Df= alse} {commit=3D} 0 51 [junit4:junit4] 1> INFO - 2013-04-10 08:24:24.787; org.apache.solr.updat= e.DefaultSolrCoreState; Waiting until IndexWriter is unused... core=3Dnodes= _used_collection_shard2_replica2 [junit4:junit4] 1> INFO - 2013-04-10 08:24:24.790; org.apache.solr.handl= er.ReplicationHandler; Commits will be reserved for 10000 [junit4:junit4] 1> INFO - 2013-04-10 08:24:24.792; org.apache.solr.handl= er.SnapPuller; No value set for 'pollInterval'. Timer Task not started. [junit4:junit4] 1> INFO - 2013-04-10 08:24:24.807; org.apache.solr.handl= er.ReplicationHandler; Commits will be reserved for 10000 [junit4:junit4] 1> INFO - 2013-04-10 08:24:24.808; org.apache.solr.core.= SolrCore; [nodes_used_collection_shard1_replica2] webapp=3D path=3D/replica= tion params=3D{command=3Dindexversion&qt=3D/replication&wt=3Djavabin&versio= n=3D2} status=3D0 QTime=3D2=20 [junit4:junit4] 1> INFO - 2013-04-10 08:24:24.809; org.apache.solr.handl= er.SnapPuller; Master's generation: 2 [junit4:junit4] 1> INFO - 2013-04-10 08:24:24.810; org.apache.solr.handl= er.SnapPuller; Slave's generation: 1 [junit4:junit4] 1> INFO - 2013-04-10 08:24:24.810; org.apache.solr.handl= er.SnapPuller; Starting replication process [junit4:junit4] 1> INFO - 2013-04-10 08:24:24.818; org.apache.solr.core.= SolrCore; [nodes_used_collection_shard1_replica2] webapp=3D path=3D/replica= tion params=3D{command=3Dfilelist&qt=3D/replication&wt=3Djavabin&generation= =3D2&version=3D2} status=3D0 QTime=3D5=20 [junit4:junit4] 1> INFO - 2013-04-10 08:24:24.838; org.apache.solr.handl= er.SnapPuller; Number of files in latest index in master: 1 [junit4:junit4] 1> INFO - 2013-04-10 08:24:24.835; org.apache.solr.core.= SolrDeletionPolicy; SolrDeletionPolicy.onInit: commits:num=3D2 [junit4:junit4] 1> =09commit{dir=3DBaseDirectoryWrapper(org.apache.lucene= .store.RAMDirectory@b9ca1a lockFactory=3Dorg.apache.lucene.store.NativeFSLo= ckFactory@16ff7c3),segFN=3Dsegments_1,generation=3D1,filenames=3D[segments_= 1] [junit4:junit4] 1> =09commit{dir=3DBaseDirectoryWrapper(org.apache.lucene= .store.RAMDirectory@b9ca1a lockFactory=3Dorg.apache.lucene.store.NativeFSLo= ckFactory@16ff7c3),segFN=3Dsegments_2,generation=3D2,filenames=3D[segments_= 2] [junit4:junit4] 1> INFO - 2013-04-10 08:24:24.874; org.apache.solr.core.= CachingDirectoryFactory; return new directory for C:\Users\JenkinsSlave\wor= kspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.= solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1365582252414\nodes_used_= collection_shard1_replica1\data\index.20130410162424838 [junit4:junit4] 1> INFO - 2013-04-10 08:24:24.931; org.apache.solr.handl= er.SnapPuller; Starting download to MockDirWrapper(org.apache.lucene.store.= RAMDirectory@1f437cd lockFactory=3Dorg.apache.lucene.store.NativeFSLockFact= ory@9fde78) fullCopy=3Dfalse [junit4:junit4] 1> INFO - 2013-04-10 08:24:24.889; org.apache.solr.core.= SolrDeletionPolicy; newest commit =3D 2[segments_2] [junit4:junit4] 1> INFO - 2013-04-10 08:24:24.932; org.apache.solr.updat= e.DefaultSolrCoreState; New IndexWriter is ready to be used. [junit4:junit4] 1> INFO - 2013-04-10 08:24:24.932; org.apache.solr.searc= h.SolrIndexSearcher; Opening Searcher@1644f58 main [junit4:junit4] 1> INFO - 2013-04-10 08:24:24.934; org.apache.solr.core.= SolrCore; [nodes_used_collection_shard1_replica2] webapp=3D path=3D/replica= tion params=3D{file=3Dsegments_2&command=3Dfilecontent&checksum=3Dtrue&wt= =3Dfilestream&qt=3D/replication&generation=3D2} status=3D0 QTime=3D0=20 [junit4:junit4] 1> INFO - 2013-04-10 08:24:24.937; org.apache.solr.handl= er.SnapPuller; Total time taken for download : 0 secs [junit4:junit4] 1> INFO - 2013-04-10 08:24:24.937; org.apache.solr.core.= SolrCore; [nodes_used_collection_shard2_replica2] Registered new searcher S= earcher@1644f58 main{StandardDirectoryReader(segments_2:1:nrt)} [junit4:junit4] 1> INFO - 2013-04-10 08:24:24.942; org.apache.solr.core.= CachingDirectoryFactory; looking to close C:\Users\JenkinsSlave\workspace\L= ucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.clo= ud.CollectionsAPIDistributedZkTest-controljetty-1365582245991\nodes_used_co= llection_shard2_replica2\data\index.20130410162424714 [CachedDir<>] [junit4:junit4] 1> INFO - 2013-04-10 08:24:24.942; org.apache.solr.core.= CachingDirectoryFactory; Closing directory: C:\Users\JenkinsSlave\workspace= \Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.c= loud.CollectionsAPIDistributedZkTest-controljetty-1365582245991\nodes_used_= collection_shard2_replica2\data\index.20130410162424714 [junit4:junit4] 1> INFO - 2013-04-10 08:24:24.943; org.apache.solr.core.= CachingDirectoryFactory; Removing directory before core close: C:\Users\Jen= kinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\= .\org.apache.solr.cloud.CollectionsAPIDistributedZkTest-controljetty-136558= 2245991\nodes_used_collection_shard2_replica2\data\index.20130410162424714 [junit4:junit4] 1> INFO - 2013-04-10 08:24:24.943; org.apache.solr.updat= e.DefaultSolrCoreState; Creating new IndexWriter... [junit4:junit4] 1> INFO - 2013-04-10 08:24:24.943; org.apache.solr.updat= e.DefaultSolrCoreState; Waiting until IndexWriter is unused... core=3Dnodes= _used_collection_shard1_replica1 [junit4:junit4] 1> INFO - 2013-04-10 08:24:24.943; org.apache.solr.cloud= .RecoveryStrategy; No replay needed. core=3Dnodes_used_collection_shard2_re= plica2 [junit4:junit4] 1> INFO - 2013-04-10 08:24:24.949; org.apache.solr.cloud= .RecoveryStrategy; Replication Recovery was successful - registering as Act= ive. core=3Dnodes_used_collection_shard2_replica2 [junit4:junit4] 1> INFO - 2013-04-10 08:24:24.949; org.apache.solr.cloud= .ZkController; publishing core=3Dnodes_used_collection_shard2_replica2 stat= e=3Dactive [junit4:junit4] 1> INFO - 2013-04-10 08:24:24.972; org.apache.solr.cloud= .RecoveryStrategy; Finished recovery process. core=3Dnodes_used_collection_= shard2_replica2 [junit4:junit4] 1> INFO - 2013-04-10 08:24:24.992; org.apache.solr.core.= SolrDeletionPolicy; SolrDeletionPolicy.onInit: commits:num=3D2 [junit4:junit4] 1> =09commit{dir=3DBaseDirectoryWrapper(org.apache.lucene= .store.RAMDirectory@112c7d3 lockFactory=3Dorg.apache.lucene.store.NativeFSL= ockFactory@11c643e),segFN=3Dsegments_1,generation=3D1,filenames=3D[segments= _1] [junit4:junit4] 1> =09commit{dir=3DBaseDirectoryWrapper(org.apache.lucene= .store.RAMDirectory@112c7d3 lockFactory=3Dorg.apache.lucene.store.NativeFSL= ockFactory@11c643e),segFN=3Dsegments_2,generation=3D2,filenames=3D[segments= _2] [junit4:junit4] 1> INFO - 2013-04-10 08:24:24.994; org.apache.solr.core.= SolrDeletionPolicy; newest commit =3D 2[segments_2] [junit4:junit4] 1> INFO - 2013-04-10 08:24:24.994; org.apache.solr.updat= e.DefaultSolrCoreState; New IndexWriter is ready to be used. [junit4:junit4] 1> INFO - 2013-04-10 08:24:24.994; org.apache.solr.searc= h.SolrIndexSearcher; Opening Searcher@1606037 main [junit4:junit4] 1> INFO - 2013-04-10 08:24:24.996; org.apache.solr.core.= SolrCore; [nodes_used_collection_shard1_replica1] Registered new searcher S= earcher@1606037 main{StandardDirectoryReader(segments_2:1:nrt)} [junit4:junit4] 1> INFO - 2013-04-10 08:24:24.997; org.apache.solr.core.= CachingDirectoryFactory; looking to close C:\Users\JenkinsSlave\workspace\L= ucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.clo= ud.CollectionsAPIDistributedZkTest-jetty4-1365582252414\nodes_used_collecti= on_shard1_replica1\data\index.20130410162424838 [CachedDir<>] [junit4:junit4] 1> INFO - 2013-04-10 08:24:24.998; org.apache.solr.core.= CachingDirectoryFactory; Closing directory: C:\Users\JenkinsSlave\workspace= \Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.c= loud.CollectionsAPIDistributedZkTest-jetty4-1365582252414\nodes_used_collec= tion_shard1_replica1\data\index.20130410162424838 [junit4:junit4] 1> INFO - 2013-04-10 08:24:24.999; org.apache.solr.core.= CachingDirectoryFactory; Removing directory before core close: C:\Users\Jen= kinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\= .\org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-136558225241= 4\nodes_used_collection_shard1_replica1\data\index.20130410162424838 [junit4:junit4] 1> INFO - 2013-04-10 08:24:24.999; org.apache.solr.cloud= .RecoveryStrategy; No replay needed. core=3Dnodes_used_collection_shard1_re= plica1 [junit4:junit4] 1> INFO - 2013-04-10 08:24:25.000; org.apache.solr.cloud= .RecoveryStrategy; Replication Recovery was successful - registering as Act= ive. core=3Dnodes_used_collection_shard1_replica1 [junit4:junit4] 1> INFO - 2013-04-10 08:24:25.000; org.apache.solr.cloud= .ZkController; publishing core=3Dnodes_used_collection_shard1_replica1 stat= e=3Dactive [junit4:junit4] 1> INFO - 2013-04-10 08:24:25.025; org.apache.solr.cloud= .RecoveryStrategy; Finished recovery process. core=3Dnodes_used_collection_= shard1_replica1 [junit4:junit4] 1> INFO - 2013-04-10 08:24:25.675; org.apache.solr.commo= n.cloud.ZkStateReader; Updating cloud state from ZooKeeper...=20 [junit4:junit4] 1> INFO - 2013-04-10 08:24:25.717; 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:50438__nodes_used_collec= tion_shard2_replica2", [junit4:junit4] 1> "numShards":"2", [junit4:junit4] 1> "shard":"shard2", [junit4:junit4] 1> "roles":null, [junit4:junit4] 1> "state":"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:50438_", [junit4:junit4] 1> "base_url":"http://127.0.0.1:50438"} [junit4:junit4] 1> INFO - 2013-04-10 08:24:26.248; 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:50477__nodes_used_collec= tion_shard1_replica1", [junit4:junit4] 1> "numShards":"2", [junit4:junit4] 1> "shard":"shard1", [junit4:junit4] 1> "roles":null, [junit4:junit4] 1> "state":"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:50477_", [junit4:junit4] 1> "base_url":"http://127.0.0.1:50477"} [junit4:junit4] 1> INFO - 2013-04-10 08:24:26.525; org.apache.solr.schem= a.OpenExchangeRatesOrgProvider; Initialized with rates=3Dopen-exchange-rate= s.json, refreshInterval=3D1440. [junit4:junit4] 1> INFO - 2013-04-10 08:24:26.538; org.apache.solr.commo= n.cloud.ZkStateReader$2; A cluster state change: WatchedEvent state:SyncCon= nected type:NodeDataChanged path:/clusterstate.json, has occurred - updatin= g... (live nodes size: 5) [junit4:junit4] 1> INFO - 2013-04-10 08:24:26.539; org.apache.solr.commo= n.cloud.ZkStateReader$2; A cluster state change: WatchedEvent state:SyncCon= nected type:NodeDataChanged path:/clusterstate.json, has occurred - updatin= g... (live nodes size: 5) [junit4:junit4] 1> INFO - 2013-04-10 08:24:26.539; org.apache.solr.commo= n.cloud.ZkStateReader$2; A cluster state change: WatchedEvent state:SyncCon= nected type:NodeDataChanged path:/clusterstate.json, has occurred - updatin= g... (live nodes size: 5) [junit4:junit4] 1> INFO - 2013-04-10 08:24:26.539; org.apache.solr.commo= n.cloud.ZkStateReader$2; A cluster state change: WatchedEvent state:SyncCon= nected type:NodeDataChanged path:/clusterstate.json, has occurred - updatin= g... (live nodes size: 5) [junit4:junit4] 1> INFO - 2013-04-10 08:24:26.539; org.apache.solr.commo= n.cloud.ZkStateReader$2; A cluster state change: WatchedEvent state:SyncCon= nected type:NodeDataChanged path:/clusterstate.json, has occurred - updatin= g... (live nodes size: 5) [junit4:junit4] 1> INFO - 2013-04-10 08:24:26.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-04-10 08:24:26.605; org.apache.solr.commo= n.cloud.ZkStateReader$2; A cluster state change: WatchedEvent state:SyncCon= nected type:NodeDataChanged path:/clusterstate.json, has occurred - updatin= g... (live nodes size: 5) [junit4:junit4] 1> INFO - 2013-04-10 08:24:26.605; org.apache.solr.commo= n.cloud.ZkStateReader$2; A cluster state change: WatchedEvent state:SyncCon= nected type:NodeDataChanged path:/clusterstate.json, has occurred - updatin= g... (live nodes size: 5) [junit4:junit4] 1> INFO - 2013-04-10 08:24:26.693; org.apache.solr.schem= a.IndexSchema; default search field in schema is text [junit4:junit4] 1> INFO - 2013-04-10 08:24:26.802; org.apache.solr.schem= a.IndexSchema; unique key field: id [junit4:junit4] 1> INFO - 2013-04-10 08:24:27.180; org.apache.solr.schem= a.FileExchangeRateProvider; Reloading exchange rates from file currency.xml [junit4:junit4] 1> INFO - 2013-04-10 08:24:27.242; org.apache.solr.schem= a.FileExchangeRateProvider; Reloading exchange rates from file currency.xml [junit4:junit4] 1> INFO - 2013-04-10 08:24:27.284; org.apache.solr.schem= a.OpenExchangeRatesOrgProvider; Reloading exchange rates from open-exchange= -rates.json [junit4:junit4] 1> WARN - 2013-04-10 08:24:27.347; org.apache.solr.schem= a.OpenExchangeRatesOrgProvider$OpenExchangeRates; Unknown key IMPORTANT NOT= E [junit4:junit4] 1> WARN - 2013-04-10 08:24:27.348; org.apache.solr.schem= a.OpenExchangeRatesOrgProvider$OpenExchangeRates; Expected key, got STRING [junit4:junit4] 1> INFO - 2013-04-10 08:24:27.348; org.apache.solr.schem= a.OpenExchangeRatesOrgProvider; Reloading exchange rates from open-exchange= -rates.json [junit4:junit4] 1> WARN - 2013-04-10 08:24:27.354; org.apache.solr.schem= a.OpenExchangeRatesOrgProvider$OpenExchangeRates; Unknown key IMPORTANT NOT= E [junit4:junit4] 1> WARN - 2013-04-10 08:24:27.354; org.apache.solr.schem= a.OpenExchangeRatesOrgProvider$OpenExchangeRates; Expected key, got STRING [junit4:junit4] 1> INFO - 2013-04-10 08:24:27.355; org.apache.solr.core.= SolrCore; org.apache.solr.core.MockDirectoryFactory [junit4:junit4] 1> INFO - 2013-04-10 08:24:27.356; org.apache.solr.core.= SolrCore; [awholynewcollection_0_shard1_replica1] Opening new SolrCore at C= :\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-co= re\test\J0\.\org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty2-1= 365582249056\awholynewcollection_0_shard1_replica1\, dataDir=3DC:\Users\Jen= kinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\= .\org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty2-136558224905= 6\awholynewcollection_0_shard1_replica1\data\ [junit4:junit4] 1> INFO - 2013-04-10 08:24:27.356; org.apache.solr.core.= JmxMonitoredMap; JMX monitoring is enabled. Adding Solr mbeans to JMX Serve= r: com.sun.jmx.mbeanserver.JmxMBeanServer@ad0010 [junit4:junit4] 1> INFO - 2013-04-10 08:24:27.357; org.apache.solr.core.= SolrCore; org.apache.solr.core.MockDirectoryFactory [junit4:junit4] 1> INFO - 2013-04-10 08:24:27.370; org.apache.solr.core.= CachingDirectoryFactory; return new directory for C:\Users\JenkinsSlave\wor= kspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.= solr.cloud.CollectionsAPIDistributedZkTest-jetty2-1365582249056\awholynewco= llection_0_shard1_replica1\data\ [junit4:junit4] 1> INFO - 2013-04-10 08:24:27.370; org.apache.solr.core.= SolrCore; New index directory detected: old=3Dnull new=3DC:\Users\JenkinsSl= ave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.= apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty2-1365582249056\awho= lynewcollection_0_shard1_replica1\data\index/ [junit4:junit4] 1> WARN - 2013-04-10 08:24:27.370; org.apache.solr.core.= SolrCore; [awholynewcollection_0_shard1_replica1] Solr index directory 'C:\= Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core= \test\J0\.\org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty2-136= 5582249056\awholynewcollection_0_shard1_replica1\data\index' doesn't exist.= Creating new index... [junit4:junit4] 1> INFO - 2013-04-10 08:24:27.371; org.apache.solr.core.= CachingDirectoryFactory; return new directory for C:\Users\JenkinsSlave\wor= kspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.= solr.cloud.CollectionsAPIDistributedZkTest-jetty2-1365582249056\awholynewco= llection_0_shard1_replica1\data\index [junit4:junit4] 1> INFO - 2013-04-10 08:24:27.420; org.apache.solr.core.= SolrDeletionPolicy; SolrDeletionPolicy.onCommit: commits:num=3D1 [junit4:junit4] 1> =09commit{dir=3DBaseDirectoryWrapper(org.apache.lucene= .store.RAMDirectory@13f91ed lockFactory=3Dorg.apache.lucene.store.NativeFSL= ockFactory@d4278c),segFN=3Dsegments_1,generation=3D1,filenames=3D[segments_= 1] [junit4:junit4] 1> INFO - 2013-04-10 08:24:27.420; org.apache.solr.core.= SolrDeletionPolicy; newest commit =3D 1[segments_1] [junit4:junit4] 1> INFO - 2013-04-10 08:24:27.426; org.apache.solr.updat= e.processor.UpdateRequestProcessorChain; inserting DistributedUpdateProcess= orFactory into updateRequestProcessorChain "dedupe" [junit4:junit4] 1> INFO - 2013-04-10 08:24:27.427; org.apache.solr.updat= e.processor.UpdateRequestProcessorChain; inserting DistributedUpdateProcess= orFactory into updateRequestProcessorChain "stored_sig" [junit4:junit4] 1> INFO - 2013-04-10 08:24:27.428; org.apache.solr.updat= e.processor.UpdateRequestProcessorChain; inserting DistributedUpdateProcess= orFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit= " [junit4:junit4] 1> INFO - 2013-04-10 08:24:27.428; org.apache.solr.core.= RequestHandlers; created standard: solr.StandardRequestHandler [junit4:junit4] 1> INFO - 2013-04-10 08:24:27.429; org.apache.solr.core.= RequestHandlers; created /get: solr.RealTimeGetHandler [junit4:junit4] 1> INFO - 2013-04-10 08:24:27.429; org.apache.solr.core.= RequestHandlers; adding lazy requestHandler: solr.ReplicationHandler [junit4:junit4] 1> INFO - 2013-04-10 08:24:27.430; org.apache.solr.core.= RequestHandlers; created /replication: solr.ReplicationHandler [junit4:junit4] 1> INFO - 2013-04-10 08:24:27.431; org.apache.solr.core.= RequestHandlers; created /update: solr.UpdateRequestHandler [junit4:junit4] 1> INFO - 2013-04-10 08:24:27.432; org.apache.solr.core.= RequestHandlers; created /admin/: org.apache.solr.handler.admin.AdminHandle= rs [junit4:junit4] 1> INFO - 2013-04-10 08:24:27.494; org.apache.solr.handl= er.loader.XMLLoader; xsltCacheLifetimeSeconds=3D60 [junit4:junit4] 1> INFO - 2013-04-10 08:24:27.781; org.apache.solr.searc= h.SolrIndexSearcher; Opening Searcher@ed4414 main [junit4:junit4] 1> INFO - 2013-04-10 08:24:27.782; org.apache.solr.updat= e.UpdateHandler; Clearing tlog files, tlogDir=3DC:\Users\JenkinsSlave\works= pace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.so= lr.cloud.CollectionsAPIDistributedZkTest-jetty2-1365582249056\awholynewcoll= ection_0_shard1_replica1\data\tlog [junit4:junit4] 1> INFO - 2013-04-10 08:24:27.783; org.apache.solr.updat= e.CommitTracker; Hard AutoCommit: disabled [junit4:junit4] 1> INFO - 2013-04-10 08:24:27.785; org.apache.solr.updat= e.CommitTracker; Soft AutoCommit: disabled [junit4:junit4] 1> INFO - 2013-04-10 08:24:27.825; org.apache.solr.cloud= .ZkController; publishing core=3Dawholynewcollection_0_shard1_replica1 stat= e=3Ddown [junit4:junit4] 1> INFO - 2013-04-10 08:24 [...truncated too long message...] getChildren(ZooKeeper.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-04-10 08:28:59.780; org.apache.solr.cloud= .LeaderElector$1;=20 [junit4:junit4] 1> org.apache.zookeeper.KeeperException$SessionExpiredExc= eption: KeeperErrorCode =3D Session expired for /collections/awholynewcolle= ction_0/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] 2> Creating dataDir: C:\Users\JenkinsSlave\workspace\Luce= ne-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\solrtest-CollectionsAP= IDistributedZkTest-1365582245572 [junit4:junit4] 2> !!!! WARNING: best effort to remove C:\Users\JenkinsSl= ave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.= apache.solr.cloud.CollectionsAPIDistributedZkTest-1365582245571\zookeeper\s= erver1\data\version-2\log.1 FAILED !!!!! [junit4:junit4] 2> !!!! WARNING: best effort to remove C:\Users\JenkinsSl= ave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.= apache.solr.cloud.CollectionsAPIDistributedZkTest-1365582245571\zookeeper\s= erver1\data\version-2 FAILED !!!!! [junit4:junit4] 2> !!!! WARNING: best effort to remove C:\Users\JenkinsSl= ave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.= apache.solr.cloud.CollectionsAPIDistributedZkTest-1365582245571\zookeeper\s= erver1\data FAILED !!!!! [junit4:junit4] 2> !!!! WARNING: best effort to remove C:\Users\JenkinsSl= ave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.= apache.solr.cloud.CollectionsAPIDistributedZkTest-1365582245571\zookeeper\s= erver1 FAILED !!!!! [junit4:junit4] 2> !!!! WARNING: best effort to remove C:\Users\JenkinsSl= ave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.= apache.solr.cloud.CollectionsAPIDistributedZkTest-1365582245571\zookeeper F= AILED !!!!! [junit4:junit4] 2> !!!! WARNING: best effort to remove C:\Users\JenkinsSl= ave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.= apache.solr.cloud.CollectionsAPIDistributedZkTest-1365582245571 FAILED !!!!= ! [junit4:junit4] 2> NOTE: reproduce with: ant test -Dtestcase=3DCollectio= nsAPIDistributedZkTest -Dtests.method=3DtestDistribSearch -Dtests.seed=3DD8= 9849C56E10B1F9 -Dtests.slow=3Dtrue -Dtests.locale=3Den_CA -Dtests.timezone= =3DSingapore -Dtests.file.encoding=3DCp1252 [junit4:junit4] FAILURE 294s | CollectionsAPIDistributedZkTest.testDistrib= Search <<< [junit4:junit4] > Throwable #1: java.lang.AssertionError: There are stil= l nodes recoverying - waited for 230 seconds [junit4:junit4] > =09at __randomizedtesting.SeedInfo.seed([D89849C56E10B= 1F9:597EC7DD194FD1C5]:0) [junit4:junit4] > =09at org.apache.solr.cloud.AbstractDistribZkTestBase.= waitForRecoveriesToFinish(AbstractDistribZkTestBase.java:173) [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:483) [junit4:junit4] > =09at org.apache.solr.cloud.CollectionsAPIDistributedZ= kTest.doTest(CollectionsAPIDistributedZkTest.java:146) [junit4:junit4] > =09at org.apache.solr.BaseDistributedSearchTestCase.te= stDistribSearch(BaseDistributedSearchTestCase.java:806) [junit4:junit4] > =09at java.lang.Thread.run(Thread.java:722) [junit4:junit4] 1> INFO - 2013-04-10 08:28:59.789; org.apache.solr.SolrT= estCaseJ4; ###deleteCore [junit4:junit4] 2> 294228 T2737 ccr.ThreadLeakControl.checkThreadLeaks WA= RNING Will linger awaiting termination of 1 leaked thread(s). [junit4:junit4] 2> NOTE: test params are: codec=3DLucene42: {timestamp=3D= PostingsFormat(name=3DNestedPulsing), range_facet_l=3DPostingsFormat(name= =3DNestedPulsing), id=3DPostingsFormat(name=3DAsserting), range_facet_sl=3D= PostingsFormat(name=3DAsserting), a_t=3DPostingsFormat(name=3DNestedPulsing= ), text=3DPostingsFormat(name=3DLucene41WithOrds), range_facet_si=3DPosting= sFormat(name=3DNestedPulsing), _version_=3DPostingsFormat(name=3DMockRandom= ), other_tl1=3DPostingsFormat(name=3DMockRandom), multiDefault=3DPostingsFo= rmat(name=3DNestedPulsing), a_si=3DPostingsFormat(name=3DMockRandom), intDe= fault=3DPostingsFormat(name=3DMockRandom)}, docValues:{timestamp=3DDocValue= sFormat(name=3DSimpleText)}, sim=3DDefaultSimilarity, locale=3Den_CA, timez= one=3DSingapore [junit4:junit4] 2> NOTE: Windows 7 6.1 x86/Oracle Corporation 1.7.0_17 (3= 2-bit)/cpus=3D2,threads=3D1,free=3D69729056,total=3D226455552 [junit4:junit4] 2> NOTE: All tests run in this JVM: [TestFieldTypeCollect= ionResource, CacheHeaderTest, BasicDistributedZk2Test, DistributedQueryElev= ationComponentTest, AnalysisAfterCoreReloadTest, TestHashPartitioner, Sugge= sterFSTTest, TestZkChroot, TestComponentsName, PeerSyncTest, TestJmxIntegra= tion, LukeRequestHandlerTest, TestSearchPerf, DateFieldTest, TestAnalyzedSu= ggestions, TestCoreContainer, TestCoreDiscovery, AliasIntegrationTest, Test= ReplicationHandler, FieldMutatingUpdateProcessorTest, TestLMJelinekMercerSi= milarityFactory, SolrIndexSplitterTest, RAMDirectoryFactoryTest, TestIndexS= earcher, BadComponentTest, SolrCmdDistributorTest, RegexBoostProcessorTest,= TestPhraseSuggestions, SolrIndexConfigTest, ZkNodePropsTest, SliceStateUpd= ateTest, SolrCoreTest, UUIDFieldTest, TestBM25SimilarityFactory, OpenCloseC= oreStressTest, HighlighterTest, TestSchemaNameResource, TestSolrQueryParser= DefaultOperatorResource, ResponseLogComponentTest, UpdateRequestProcessorFa= ctoryTest, TestManagedSchema, TestBadConfig, DOMUtilTest, LeaderElectionTes= t, TestLuceneMatchVersion, TestQueryUtils, TestSweetSpotSimilarityFactory, = TimeZoneUtilsTest, TestUtils, SimplePostToolTest, LeaderElectionIntegration= Test, CoreContainerCoreInitFailuresTest, TestQueryTypes, NotRequiredUniqueK= eyTest, TestSort, XmlUpdateRequestHandlerTest, SimpleFacetsTest, ChaosMonke= yShardSplitTest, SolrTestCaseJ4Test, TestSolrDeletionPolicy1, TestUpdate, T= estSolr4Spatial, MBeansHandlerTest, SpellPossibilityIteratorTest, MinimalSc= hemaTest, TestFastOutputStream, BinaryUpdateRequestHandlerTest, TestRTGBase= , CopyFieldTest, ZkSolrClientTest, OverseerCollectionProcessorTest, Require= dFieldsTest, PluginInfoTest, TestMultiCoreConfBootstrap, TestWordDelimiterF= ilterFactory, TestCloudManagedSchema, TestDocumentBuilder, TestFieldCollect= ionResource, DateMathParserTest, TermVectorComponentTest, TestStressReorder= , TestBinaryField, SearchHandlerTest, TestPluginEnable, TestFuzzyAnalyzedSu= ggestions, TestLRUCache, TestSchemaSimilarityResource, CollectionsAPIDistri= butedZkTest] [junit4:junit4] Completed in 295.47s, 1 test, 1 failure <<< FAILURES! [...truncated 605 lines...] BUILD FAILED C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\build.xml:375: Th= e following error occurred while executing this line: C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\build.xml:355: Th= e following error occurred while executing this line: C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\build.xml:39: The= following error occurred while executing this line: C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build.xml:18= 3: The following error occurred while executing this line: C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\common-build= .xml:438: The following error occurred while executing this line: C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\lucene\common-bui= ld.xml:1231: The following error occurred while executing this line: C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\lucene\common-bui= ld.xml:875: There were test failures: 287 suites, 1194 tests, 1 failure, 18= ignored (12 assumptions) Total time: 67 minutes 29 seconds Build step 'Invoke Ant' marked build as failure Archiving artifacts Recording test results Description set: Java: 32bit/jdk1.7.0_17 -server -XX:+UseConcMarkSweepGC Email was triggered for: Failure Sending email for trigger: Failure ------=_Part_46_1496055095.1365584016500 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_46_1496055095.1365584016500--