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 2290B10982 for ; Thu, 25 Apr 2013 01:10:47 +0000 (UTC) Received: (qmail 73885 invoked by uid 500); 25 Apr 2013 01:10:45 -0000 Delivered-To: apmail-lucene-dev-archive@lucene.apache.org Received: (qmail 73798 invoked by uid 500); 25 Apr 2013 01:10:45 -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 73789 invoked by uid 99); 25 Apr 2013 01:10:45 -0000 Received: from athena.apache.org (HELO athena.apache.org) (140.211.11.136) by apache.org (qpsmtpd/0.29) with ESMTP; Thu, 25 Apr 2013 01:10:45 +0000 X-ASF-Spam-Status: No, hits=1.0 required=5.0 tests=FRT_ADOBE2,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; Thu, 25 Apr 2013 01:10:34 +0000 Received: from serv1 (localhost.localdomain [127.0.0.1]) by mail.sd-datasolutions.de (Postfix) with ESMTP id B620C14AA07F; Thu, 25 Apr 2013 01:10:12 +0000 (UTC) Date: Thu, 25 Apr 2013 01:09:53 +0000 (UTC) From: Policeman Jenkins Server To: dev@lucene.apache.org, sarowe@gmail.com, uwe@thetaphi.de, dsmiley@apache.org, simonw@apache.org, markrmiller@apache.org, rmuir@apache.org, elyograg@apache.org, jpountz@apache.org, mikemccand@apache.org Message-ID: <747704920.141.1366852212734.JavaMail.jenkins@serv1.sd-datasolutions.de> In-Reply-To: <1572073338.71.1366657145217.JavaMail.jenkins@serv1.sd-datasolutions.de> References: <1572073338.71.1366657145217.JavaMail.jenkins@serv1.sd-datasolutions.de> Subject: [JENKINS] Lucene-Solr-trunk-Windows (32bit/jdk1.7.0_21) - Build # 2762 - Still Failing! MIME-Version: 1.0 Content-Type: multipart/mixed; boundary="----=_Part_140_1770855211.1366852193134" X-Jenkins-Job: Lucene-Solr-trunk-Windows X-Jenkins-Result: FAILURE X-Virus-Checked: Checked by ClamAV on apache.org ------=_Part_140_1770855211.1366852193134 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: quoted-printable Build: http://jenkins.thetaphi.de/job/Lucene-Solr-trunk-Windows/2762/ Java: 32bit/jdk1.7.0_21 -client -XX:+UseSerialGC 1 tests failed. REGRESSION: org.apache.solr.cloud.CollectionsAPIDistributedZkTest.testDist= ribSearch Error Message: Server at http://127.0.0.1:65483 returned non ok status:500, message:Server= Error Stack Trace: org.apache.solr.client.solrj.impl.HttpSolrServer$RemoteSolrException: Serve= r at http://127.0.0.1:65483 returned non ok status:500, message:Server Erro= r =09at __randomizedtesting.SeedInfo.seed([45FBF77FED4A7288:C41D79679A1512B4]= :0) =09at org.apache.solr.client.solrj.impl.HttpSolrServer.request(HttpSolrServ= er.java:385) =09at org.apache.solr.client.solrj.impl.HttpSolrServer.request(HttpSolrServ= er.java:180) =09at org.apache.solr.cloud.CollectionsAPIDistributedZkTest.deleteCollectio= nWithDownNodes(CollectionsAPIDistributedZkTest.java:206) =09at org.apache.solr.cloud.CollectionsAPIDistributedZkTest.doTest(Collecti= onsAPIDistributedZkTest.java:148) =09at org.apache.solr.BaseDistributedSearchTestCase.testDistribSearch(BaseD= istributedSearchTestCase.java:815) =09at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method) =09at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.= java:57) =09at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAcces= sorImpl.java:43) =09at java.lang.reflect.Method.invoke(Method.java:601) =09at com.carrotsearch.randomizedtesting.RandomizedRunner.invoke(Randomized= Runner.java:1559) =09at com.carrotsearch.randomizedtesting.RandomizedRunner.access$600(Random= izedRunner.java:79) =09at com.carrotsearch.randomizedtesting.RandomizedRunner$6.evaluate(Random= izedRunner.java:737) =09at com.carrotsearch.randomizedtesting.RandomizedRunner$7.evaluate(Random= izedRunner.java:773) =09at com.carrotsearch.randomizedtesting.RandomizedRunner$8.evaluate(Random= izedRunner.java:787) =09at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$= 1.evaluate(SystemPropertiesRestoreRule.java:53) =09at org.apache.lucene.util.TestRuleSetupTeardownChained$1.evaluate(TestRu= leSetupTeardownChained.java:50) =09at org.apache.lucene.util.TestRuleFieldCacheSanity$1.evaluate(TestRuleFi= eldCacheSanity.java:51) =09at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBef= oreAfterRule.java:46) =09at com.carrotsearch.randomizedtesting.rules.SystemPropertiesInvariantRul= e$1.evaluate(SystemPropertiesInvariantRule.java:55) =09at org.apache.lucene.util.TestRuleThreadAndTestName$1.evaluate(TestRuleT= hreadAndTestName.java:49) =09at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(Test= RuleIgnoreAfterMaxFailures.java:70) =09at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFai= lure.java:48) =09at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(St= atementAdapter.java:36) =09at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.= run(ThreadLeakControl.java:358) =09at com.carrotsearch.randomizedtesting.ThreadLeakControl.forkTimeoutingTa= sk(ThreadLeakControl.java:782) =09at com.carrotsearch.randomizedtesting.ThreadLeakControl$3.evaluate(Threa= dLeakControl.java:442) =09at com.carrotsearch.randomizedtesting.RandomizedRunner.runSingleTest(Ran= domizedRunner.java:746) =09at com.carrotsearch.randomizedtesting.RandomizedRunner$3.evaluate(Random= izedRunner.java:648) =09at com.carrotsearch.randomizedtesting.RandomizedRunner$4.evaluate(Random= izedRunner.java:682) =09at com.carrotsearch.randomizedtesting.RandomizedRunner$5.evaluate(Random= izedRunner.java:693) =09at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(St= atementAdapter.java:36) =09at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$= 1.evaluate(SystemPropertiesRestoreRule.java:53) =09at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBef= oreAfterRule.java:46) =09at org.apache.lucene.util.TestRuleStoreClassName$1.evaluate(TestRuleStor= eClassName.java:42) =09at com.carrotsearch.randomizedtesting.rules.SystemPropertiesInvariantRul= e$1.evaluate(SystemPropertiesInvariantRule.java:55) =09at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMeth= odsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:39) =09at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMeth= odsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:39) =09at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(St= atementAdapter.java:36) =09at org.apache.lucene.util.TestRuleAssertionsRequired$1.evaluate(TestRule= AssertionsRequired.java:43) =09at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFai= lure.java:48) =09at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(Test= RuleIgnoreAfterMaxFailures.java:70) =09at org.apache.lucene.util.TestRuleIgnoreTestSuites$1.evaluate(TestRuleIg= noreTestSuites.java:55) =09at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(St= atementAdapter.java:36) =09at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.= run(ThreadLeakControl.java:358) =09at java.lang.Thread.run(Thread.java:722) Build Log: [...truncated 9358 lines...] [junit4:junit4] Suite: org.apache.solr.cloud.CollectionsAPIDistributedZkTes= t [junit4:junit4] 1> INFO - 2013-04-24 20:49:46.867; org.apache.solr.BaseD= istributedSearchTestCase; Setting hostContext system property: / [junit4:junit4] 1> INFO - 2013-04-24 20:49:46.870; org.apache.solr.SolrT= estCaseJ4; ###Starting testDistribSearch [junit4:junit4] 1> INFO - 2013-04-24 20:49:46.874; 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-24 20:49:46.875; org.apache.solr.cloud= .ZkTestServer$ZKServerMain; Starting server [junit4:junit4] 1> INFO - 2013-04-24 20:49:46.963; org.apache.solr.cloud= .ZkTestServer; start zk server on port:65446 [junit4:junit4] 1> INFO - 2013-04-24 20:49:46.965; org.apache.solr.commo= n.cloud.ConnectionManager; Waiting for client to connect to ZooKeeper [junit4:junit4] 1> INFO - 2013-04-24 20:49:46.974; org.apache.solr.commo= n.cloud.ConnectionManager; Watcher org.apache.solr.common.cloud.ConnectionM= anager@b6dfe8 name:ZooKeeperConnection Watcher:127.0.0.1:65446 got event Wa= tchedEvent state:SyncConnected type:None path:null path:null type:None [junit4:junit4] 1> INFO - 2013-04-24 20:49:46.974; org.apache.solr.commo= n.cloud.ConnectionManager; Client is connected to ZooKeeper [junit4:junit4] 1> INFO - 2013-04-24 20:49:46.975; org.apache.solr.commo= n.cloud.SolrZkClient; makePath: /solr [junit4:junit4] 1> INFO - 2013-04-24 20:49:46.984; org.apache.solr.commo= n.cloud.ConnectionManager; Waiting for client to connect to ZooKeeper [junit4:junit4] 1> INFO - 2013-04-24 20:49:46.986; org.apache.solr.commo= n.cloud.ConnectionManager; Watcher org.apache.solr.common.cloud.ConnectionM= anager@1978c0 name:ZooKeeperConnection Watcher:127.0.0.1:65446/solr got eve= nt WatchedEvent state:SyncConnected type:None path:null path:null type:None [junit4:junit4] 1> INFO - 2013-04-24 20:49:46.987; org.apache.solr.commo= n.cloud.ConnectionManager; Client is connected to ZooKeeper [junit4:junit4] 1> INFO - 2013-04-24 20:49:46.987; org.apache.solr.commo= n.cloud.SolrZkClient; makePath: /collections/collection1 [junit4:junit4] 1> INFO - 2013-04-24 20:49:46.993; org.apache.solr.commo= n.cloud.SolrZkClient; makePath: /collections/collection1/shards [junit4:junit4] 1> INFO - 2013-04-24 20:49:46.999; org.apache.solr.commo= n.cloud.SolrZkClient; makePath: /collections/control_collection [junit4:junit4] 1> INFO - 2013-04-24 20:49:47.004; org.apache.solr.commo= n.cloud.SolrZkClient; makePath: /collections/control_collection/shards [junit4:junit4] 1> INFO - 2013-04-24 20:49:47.009; 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-24 20:49:47.009; org.apache.solr.commo= n.cloud.SolrZkClient; makePath: /configs/conf1/solrconfig.xml [junit4:junit4] 1> INFO - 2013-04-24 20:49:47.019; 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-24 20:49:47.020; org.apache.solr.commo= n.cloud.SolrZkClient; makePath: /configs/conf1/schema.xml [junit4:junit4] 1> INFO - 2013-04-24 20:49:47.026; 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-24 20:49:47.026; org.apache.solr.commo= n.cloud.SolrZkClient; makePath: /configs/conf1/stopwords.txt [junit4:junit4] 1> INFO - 2013-04-24 20:49:47.032; 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-24 20:49:47.032; org.apache.solr.commo= n.cloud.SolrZkClient; makePath: /configs/conf1/protwords.txt [junit4:junit4] 1> INFO - 2013-04-24 20:49:47.038; 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-24 20:49:47.039; org.apache.solr.commo= n.cloud.SolrZkClient; makePath: /configs/conf1/currency.xml [junit4:junit4] 1> INFO - 2013-04-24 20:49:47.045; 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-24 20:49:47.046; org.apache.solr.commo= n.cloud.SolrZkClient; makePath: /configs/conf1/open-exchange-rates.json [junit4:junit4] 1> INFO - 2013-04-24 20:49:47.055; 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-24 20:49:47.056; org.apache.solr.commo= n.cloud.SolrZkClient; makePath: /configs/conf1/mapping-ISOLatin1Accent.txt [junit4:junit4] 1> INFO - 2013-04-24 20:49:47.062; 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-24 20:49:47.063; org.apache.solr.commo= n.cloud.SolrZkClient; makePath: /configs/conf1/old_synonyms.txt [junit4:junit4] 1> INFO - 2013-04-24 20:49:47.068; 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-24 20:49:47.069; org.apache.solr.commo= n.cloud.SolrZkClient; makePath: /configs/conf1/synonyms.txt [junit4:junit4] 1> INFO - 2013-04-24 20:49:47.574; org.eclipse.jetty.ser= ver.Server; jetty-8.1.10.v20130312 [junit4:junit4] 1> INFO - 2013-04-24 20:49:47.582; org.eclipse.jetty.ser= ver.AbstractConnector; Started SelectChannelConnector@127.0.0.1:65453 [junit4:junit4] 1> INFO - 2013-04-24 20:49:47.583; org.apache.solr.servl= et.SolrDispatchFilter; SolrDispatchFilter.init() [junit4:junit4] 1> INFO - 2013-04-24 20:49:47.583; org.apache.solr.core.= SolrResourceLoader; JNDI not configured for solr (NoInitialContextEx) [junit4:junit4] 1> INFO - 2013-04-24 20:49:47.584; 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-13668509870= 76 [junit4:junit4] 1> INFO - 2013-04-24 20:49:47.584; 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-136685098707= 6\solr.xml [junit4:junit4] 1> INFO - 2013-04-24 20:49:47.584; org.apache.solr.core.= CoreContainer; New CoreContainer 31704725 [junit4:junit4] 1> INFO - 2013-04-24 20:49:47.585; 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-1366850987076\= ' [junit4:junit4] 1> INFO - 2013-04-24 20:49:47.585; 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-1366850987= 076\' [junit4:junit4] 1> INFO - 2013-04-24 20:49:47.717; org.apache.solr.core.= SolrCoreDiscoverer; Looking for cores in C:\Users\JenkinsSlave\workspace\Lu= cene-Solr-trunk-Windows\solr\build\solr-core\test\J0\org.apache.solr.cloud.= CollectionsAPIDistributedZkTest-controljetty-1366850987076 [junit4:junit4] 1> INFO - 2013-04-24 20:49:47.717; org.apache.solr.core.= SolrCoreDiscoverer; Looking for cores in C:\Users\JenkinsSlave\workspace\Lu= cene-Solr-trunk-Windows\solr\build\solr-core\test\J0\org.apache.solr.cloud.= CollectionsAPIDistributedZkTest-controljetty-1366850987076\collection1 [junit4:junit4] 1> INFO - 2013-04-24 20:49:47.720; org.apache.solr.core.= SolrCoreDiscoverer; Looking for cores in C:\Users\JenkinsSlave\workspace\Lu= cene-Solr-trunk-Windows\solr\build\solr-core\test\J0\org.apache.solr.cloud.= CollectionsAPIDistributedZkTest-controljetty-1366850987076\collection1\conf [junit4:junit4] 1> INFO - 2013-04-24 20:49:48.022; org.apache.solr.core.= SolrCoreDiscoverer; Looking for cores in C:\Users\JenkinsSlave\workspace\Lu= cene-Solr-trunk-Windows\solr\build\solr-core\test\J0\org.apache.solr.cloud.= CollectionsAPIDistributedZkTest-controljetty-1366850987076\collection1\conf= \xslt [junit4:junit4] 1> INFO - 2013-04-24 20:49:48.034; org.apache.solr.core.= SolrCoreDiscoverer; Looking for cores in C:\Users\JenkinsSlave\workspace\Lu= cene-Solr-trunk-Windows\solr\build\solr-core\test\J0\org.apache.solr.cloud.= CollectionsAPIDistributedZkTest-controljetty-1366850987076\collection1\lib [junit4:junit4] 1> INFO - 2013-04-24 20:49:48.040; org.apache.solr.core.= SolrCoreDiscoverer; Looking for cores in C:\Users\JenkinsSlave\workspace\Lu= cene-Solr-trunk-Windows\solr\build\solr-core\test\J0\org.apache.solr.cloud.= CollectionsAPIDistributedZkTest-controljetty-1366850987076\collection1\lib\= classes [junit4:junit4] 1> INFO - 2013-04-24 20:49:48.050; org.apache.solr.core.= SolrCoreDiscoverer; Discovered properties file C:\Users\JenkinsSlave\worksp= ace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.sol= r.cloud.CollectionsAPIDistributedZkTest-controljetty-1366850987076\conf\cor= e.properties, adding to cores [junit4:junit4] 1> INFO - 2013-04-24 20:49:48.080; org.apache.solr.handl= er.component.HttpShardHandlerFactory; Setting socketTimeout to: 0 [junit4:junit4] 1> INFO - 2013-04-24 20:49:48.081; org.apache.solr.handl= er.component.HttpShardHandlerFactory; Setting urlScheme to: http:// [junit4:junit4] 1> INFO - 2013-04-24 20:49:48.081; org.apache.solr.handl= er.component.HttpShardHandlerFactory; Setting connTimeout to: 0 [junit4:junit4] 1> INFO - 2013-04-24 20:49:48.082; org.apache.solr.handl= er.component.HttpShardHandlerFactory; Setting maxConnectionsPerHost to: 20 [junit4:junit4] 1> INFO - 2013-04-24 20:49:48.082; org.apache.solr.handl= er.component.HttpShardHandlerFactory; Setting corePoolSize to: 0 [junit4:junit4] 1> INFO - 2013-04-24 20:49:48.082; org.apache.solr.handl= er.component.HttpShardHandlerFactory; Setting maximumPoolSize to: 214748364= 7 [junit4:junit4] 1> INFO - 2013-04-24 20:49:48.082; org.apache.solr.handl= er.component.HttpShardHandlerFactory; Setting maxThreadIdleTime to: 5 [junit4:junit4] 1> INFO - 2013-04-24 20:49:48.083; org.apache.solr.handl= er.component.HttpShardHandlerFactory; Setting sizeOfQueue to: -1 [junit4:junit4] 1> INFO - 2013-04-24 20:49:48.084; org.apache.solr.handl= er.component.HttpShardHandlerFactory; Setting fairnessPolicy to: false [junit4:junit4] 1> INFO - 2013-04-24 20:49:48.085; org.apache.solr.clien= t.solrj.impl.HttpClientUtil; Creating new http client, config:maxConnection= sPerHost=3D20&maxConnections=3D10000&socketTimeout=3D0&connTimeout=3D0&retr= y=3Dfalse [junit4:junit4] 1> INFO - 2013-04-24 20:49:48.100; org.apache.solr.core.= CoreContainer; Registering Log Listener [junit4:junit4] 1> INFO - 2013-04-24 20:49:48.101; org.apache.solr.core.= ZkContainer; Zookeeper client=3D127.0.0.1:65446/solr [junit4:junit4] 1> INFO - 2013-04-24 20:49:48.102; org.apache.solr.cloud= .ZkController; zkHost includes chroot [junit4:junit4] 1> INFO - 2013-04-24 20:49:48.104; org.apache.solr.commo= n.cloud.ConnectionManager; Waiting for client to connect to ZooKeeper [junit4:junit4] 1> INFO - 2013-04-24 20:49:48.122; org.apache.solr.commo= n.cloud.ConnectionManager; Watcher org.apache.solr.common.cloud.ConnectionM= anager@196446a name:ZooKeeperConnection Watcher:127.0.0.1:65446 got event W= atchedEvent state:SyncConnected type:None path:null path:null type:None [junit4:junit4] 1> INFO - 2013-04-24 20:49:48.124; org.apache.solr.commo= n.cloud.ConnectionManager; Client is connected to ZooKeeper [junit4:junit4] 1> INFO - 2013-04-24 20:49:48.128; 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-24 20:49:48.141; org.apache.solr.commo= n.cloud.ConnectionManager; Waiting for client to connect to ZooKeeper [junit4:junit4] 1> INFO - 2013-04-24 20:49:48.146; org.apache.solr.commo= n.cloud.ConnectionManager; Watcher org.apache.solr.common.cloud.ConnectionM= anager@1a35de9 name:ZooKeeperConnection Watcher:127.0.0.1:65446/solr got ev= ent WatchedEvent state:SyncConnected type:None path:null path:null type:Non= e [junit4:junit4] 1> INFO - 2013-04-24 20:49:48.147; org.apache.solr.commo= n.cloud.ConnectionManager; Client is connected to ZooKeeper [junit4:junit4] 1> INFO - 2013-04-24 20:49:48.156; org.apache.solr.commo= n.cloud.SolrZkClient; makePath: /overseer/queue [junit4:junit4] 1> INFO - 2013-04-24 20:49:48.177; org.apache.solr.commo= n.cloud.SolrZkClient; makePath: /overseer/collection-queue-work [junit4:junit4] 1> INFO - 2013-04-24 20:49:48.190; org.apache.solr.commo= n.cloud.SolrZkClient; makePath: /live_nodes [junit4:junit4] 1> INFO - 2013-04-24 20:49:48.205; org.apache.solr.cloud= .ZkController; Register node as live in ZooKeeper:/live_nodes/127.0.0.1:654= 53_ [junit4:junit4] 1> INFO - 2013-04-24 20:49:48.211; org.apache.solr.commo= n.cloud.SolrZkClient; makePath: /live_nodes/127.0.0.1:65453_ [junit4:junit4] 1> INFO - 2013-04-24 20:49:48.241; org.apache.solr.commo= n.cloud.SolrZkClient; makePath: /overseer_elect/election [junit4:junit4] 1> INFO - 2013-04-24 20:49:48.271; org.apache.solr.commo= n.cloud.SolrZkClient; makePath: /overseer_elect/leader [junit4:junit4] 1> INFO - 2013-04-24 20:49:48.276; org.apache.solr.cloud= .Overseer; Overseer (id=3D89577946276298755-127.0.0.1:65453_-n_0000000000) = starting [junit4:junit4] 1> INFO - 2013-04-24 20:49:48.283; org.apache.solr.commo= n.cloud.SolrZkClient; makePath: /overseer/queue-work [junit4:junit4] 1> INFO - 2013-04-24 20:49:48.294; org.apache.solr.commo= n.cloud.SolrZkClient; makePath: /clusterstate.json [junit4:junit4] 1> INFO - 2013-04-24 20:49:48.294; org.apache.solr.cloud= .OverseerCollectionProcessor; Process current queue of collection creations [junit4:junit4] 1> INFO - 2013-04-24 20:49:48.299; org.apache.solr.commo= n.cloud.SolrZkClient; makePath: /aliases.json [junit4:junit4] 1> INFO - 2013-04-24 20:49:48.302; org.apache.solr.commo= n.cloud.ZkStateReader; Updating cluster state from ZooKeeper...=20 [junit4:junit4] 1> INFO - 2013-04-24 20:49:48.308; org.apache.solr.cloud= .Overseer$ClusterStateUpdater; Starting to work on the main queue [junit4:junit4] 1> INFO - 2013-04-24 20:49:48.313; 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-24 20:49:48.313; org.apache.solr.servl= et.SolrDispatchFilter; SolrDispatchFilter.init() done [junit4:junit4] 1> INFO - 2013-04-24 20:49:48.314; 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-24 20:49:48.319; org.apache.solr.clien= t.solrj.impl.HttpClientUtil; Creating new http client, config: [junit4:junit4] 1> INFO - 2013-04-24 20:49:48.321; org.apache.solr.commo= n.cloud.ConnectionManager; Waiting for client to connect to ZooKeeper [junit4:junit4] 1> INFO - 2013-04-24 20:49:48.325; org.apache.solr.commo= n.cloud.ConnectionManager; Watcher org.apache.solr.common.cloud.ConnectionM= anager@15c133c name:ZooKeeperConnection Watcher:127.0.0.1:65446/solr got ev= ent WatchedEvent state:SyncConnected type:None path:null path:null type:Non= e [junit4:junit4] 1> INFO - 2013-04-24 20:49:48.326; org.apache.solr.commo= n.cloud.ConnectionManager; Client is connected to ZooKeeper [junit4:junit4] 1> INFO - 2013-04-24 20:49:48.328; org.apache.solr.commo= n.cloud.ZkStateReader; Updating cluster state from ZooKeeper...=20 [junit4:junit4] 1> INFO - 2013-04-24 20:49:48.332; org.apache.solr.cloud= .ChaosMonkey; monkey: init - expire sessions:true cause connection loss:tru= e [junit4:junit4] 1> INFO - 2013-04-24 20:49:48.796; org.eclipse.jetty.ser= ver.Server; jetty-8.1.10.v20130312 [junit4:junit4] 1> INFO - 2013-04-24 20:49:48.803; org.eclipse.jetty.ser= ver.AbstractConnector; Started SelectChannelConnector@127.0.0.1:65465 [junit4:junit4] 1> INFO - 2013-04-24 20:49:48.804; org.apache.solr.servl= et.SolrDispatchFilter; SolrDispatchFilter.init() [junit4:junit4] 1> INFO - 2013-04-24 20:49:48.805; org.apache.solr.core.= SolrResourceLoader; JNDI not configured for solr (NoInitialContextEx) [junit4:junit4] 1> INFO - 2013-04-24 20:49:48.805; 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-1366850988332 [junit4:junit4] 1> INFO - 2013-04-24 20:49:48.805; 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-1366850988332\solr= .xml [junit4:junit4] 1> INFO - 2013-04-24 20:49:48.805; org.apache.solr.core.= CoreContainer; New CoreContainer 1258783 [junit4:junit4] 1> INFO - 2013-04-24 20:49:48.806; 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-1366850988332\' [junit4:junit4] 1> INFO - 2013-04-24 20:49:48.806; 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-1366850988332\' [junit4:junit4] 1> INFO - 2013-04-24 20:49:48.919; org.apache.solr.core.= SolrCoreDiscoverer; Looking for cores in C:\Users\JenkinsSlave\workspace\Lu= cene-Solr-trunk-Windows\solr\build\solr-core\test\J0\org.apache.solr.cloud.= CollectionsAPIDistributedZkTest-jetty1-1366850988332 [junit4:junit4] 1> INFO - 2013-04-24 20:49:48.921; org.apache.solr.core.= SolrCoreDiscoverer; Looking for cores in C:\Users\JenkinsSlave\workspace\Lu= cene-Solr-trunk-Windows\solr\build\solr-core\test\J0\org.apache.solr.cloud.= CollectionsAPIDistributedZkTest-jetty1-1366850988332\collection1 [junit4:junit4] 1> INFO - 2013-04-24 20:49:48.923; org.apache.solr.core.= SolrCoreDiscoverer; Looking for cores in C:\Users\JenkinsSlave\workspace\Lu= cene-Solr-trunk-Windows\solr\build\solr-core\test\J0\org.apache.solr.cloud.= CollectionsAPIDistributedZkTest-jetty1-1366850988332\collection1\conf [junit4:junit4] 1> INFO - 2013-04-24 20:49:49.185; org.apache.solr.core.= SolrCoreDiscoverer; Looking for cores in C:\Users\JenkinsSlave\workspace\Lu= cene-Solr-trunk-Windows\solr\build\solr-core\test\J0\org.apache.solr.cloud.= CollectionsAPIDistributedZkTest-jetty1-1366850988332\collection1\conf\xslt [junit4:junit4] 1> INFO - 2013-04-24 20:49:49.195; org.apache.solr.core.= SolrCoreDiscoverer; Looking for cores in C:\Users\JenkinsSlave\workspace\Lu= cene-Solr-trunk-Windows\solr\build\solr-core\test\J0\org.apache.solr.cloud.= CollectionsAPIDistributedZkTest-jetty1-1366850988332\collection1\lib [junit4:junit4] 1> INFO - 2013-04-24 20:49:49.199; org.apache.solr.core.= SolrCoreDiscoverer; Looking for cores in C:\Users\JenkinsSlave\workspace\Lu= cene-Solr-trunk-Windows\solr\build\solr-core\test\J0\org.apache.solr.cloud.= CollectionsAPIDistributedZkTest-jetty1-1366850988332\collection1\lib\classe= s [junit4:junit4] 1> INFO - 2013-04-24 20:49:49.206; org.apache.solr.core.= SolrCoreDiscoverer; Discovered properties file C:\Users\JenkinsSlave\worksp= ace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.sol= r.cloud.CollectionsAPIDistributedZkTest-jetty1-1366850988332\conf\core.prop= erties, adding to cores [junit4:junit4] 1> INFO - 2013-04-24 20:49:49.224; org.apache.solr.handl= er.component.HttpShardHandlerFactory; Setting socketTimeout to: 0 [junit4:junit4] 1> INFO - 2013-04-24 20:49:49.225; org.apache.solr.handl= er.component.HttpShardHandlerFactory; Setting urlScheme to: http:// [junit4:junit4] 1> INFO - 2013-04-24 20:49:49.225; org.apache.solr.handl= er.component.HttpShardHandlerFactory; Setting connTimeout to: 0 [junit4:junit4] 1> INFO - 2013-04-24 20:49:49.225; org.apache.solr.handl= er.component.HttpShardHandlerFactory; Setting maxConnectionsPerHost to: 20 [junit4:junit4] 1> INFO - 2013-04-24 20:49:49.226; org.apache.solr.handl= er.component.HttpShardHandlerFactory; Setting corePoolSize to: 0 [junit4:junit4] 1> INFO - 2013-04-24 20:49:49.226; org.apache.solr.handl= er.component.HttpShardHandlerFactory; Setting maximumPoolSize to: 214748364= 7 [junit4:junit4] 1> INFO - 2013-04-24 20:49:49.226; org.apache.solr.handl= er.component.HttpShardHandlerFactory; Setting maxThreadIdleTime to: 5 [junit4:junit4] 1> INFO - 2013-04-24 20:49:49.226; org.apache.solr.handl= er.component.HttpShardHandlerFactory; Setting sizeOfQueue to: -1 [junit4:junit4] 1> INFO - 2013-04-24 20:49:49.228; org.apache.solr.handl= er.component.HttpShardHandlerFactory; Setting fairnessPolicy to: false [junit4:junit4] 1> INFO - 2013-04-24 20:49:49.228; org.apache.solr.clien= t.solrj.impl.HttpClientUtil; Creating new http client, config:maxConnection= sPerHost=3D20&maxConnections=3D10000&socketTimeout=3D0&connTimeout=3D0&retr= y=3Dfalse [junit4:junit4] 1> INFO - 2013-04-24 20:49:49.236; org.apache.solr.core.= CoreContainer; Registering Log Listener [junit4:junit4] 1> INFO - 2013-04-24 20:49:49.237; org.apache.solr.core.= ZkContainer; Zookeeper client=3D127.0.0.1:65446/solr [junit4:junit4] 1> INFO - 2013-04-24 20:49:49.237; org.apache.solr.cloud= .ZkController; zkHost includes chroot [junit4:junit4] 1> INFO - 2013-04-24 20:49:49.239; org.apache.solr.commo= n.cloud.ConnectionManager; Waiting for client to connect to ZooKeeper [junit4:junit4] 1> INFO - 2013-04-24 20:49:49.256; org.apache.solr.commo= n.cloud.ConnectionManager; Watcher org.apache.solr.common.cloud.ConnectionM= anager@1ea9741 name:ZooKeeperConnection Watcher:127.0.0.1:65446 got event W= atchedEvent state:SyncConnected type:None path:null path:null type:None [junit4:junit4] 1> INFO - 2013-04-24 20:49:49.257; org.apache.solr.commo= n.cloud.ConnectionManager; Client is connected to ZooKeeper [junit4:junit4] 1> WARN - 2013-04-24 20:49:49.260; org.apache.zookeeper.= server.NIOServerCnxn; caught end of stream exception [junit4:junit4] 1> EndOfStreamException: Unable to read additional data f= rom client sessionid 0x13e3eaae3820005, 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-24 20:49:49.260; 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-24 20:49:49.268; org.apache.solr.commo= n.cloud.ConnectionManager; Waiting for client to connect to ZooKeeper [junit4:junit4] 1> INFO - 2013-04-24 20:49:49.273; org.apache.solr.commo= n.cloud.ConnectionManager; Watcher org.apache.solr.common.cloud.ConnectionM= anager@6764e0 name:ZooKeeperConnection Watcher:127.0.0.1:65446/solr got eve= nt WatchedEvent state:SyncConnected type:None path:null path:null type:None [junit4:junit4] 1> INFO - 2013-04-24 20:49:49.273; org.apache.solr.commo= n.cloud.ConnectionManager; Client is connected to ZooKeeper [junit4:junit4] 1> INFO - 2013-04-24 20:49:49.282; org.apache.solr.commo= n.cloud.ZkStateReader; Updating cluster state from ZooKeeper...=20 [junit4:junit4] 1> INFO - 2013-04-24 20:49:50.262; org.apache.solr.cloud= .ZkController; Register node as live in ZooKeeper:/live_nodes/127.0.0.1:654= 65_ [junit4:junit4] 1> INFO - 2013-04-24 20:49:50.269; org.apache.solr.commo= n.cloud.SolrZkClient; makePath: /live_nodes/127.0.0.1:65465_ [junit4:junit4] 1> INFO - 2013-04-24 20:49:50.276; org.apache.solr.commo= n.cloud.ZkStateReader$3; Updating live nodes... (2) [junit4:junit4] 1> INFO - 2013-04-24 20:49:50.276; org.apache.solr.commo= n.cloud.ZkStateReader$3; Updating live nodes... (2) [junit4:junit4] 1> INFO - 2013-04-24 20:49:50.276; org.apache.solr.commo= n.cloud.ZkStateReader$3; Updating live nodes... (2) [junit4:junit4] 1> INFO - 2013-04-24 20:49:50.289; 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-24 20:49:50.290; org.apache.solr.servl= et.SolrDispatchFilter; SolrDispatchFilter.init() done [junit4:junit4] 1> INFO - 2013-04-24 20:49:50.291; 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-24 20:49:50.927; org.eclipse.jetty.ser= ver.Server; jetty-8.1.10.v20130312 [junit4:junit4] 1> INFO - 2013-04-24 20:49:50.933; org.eclipse.jetty.ser= ver.AbstractConnector; Started SelectChannelConnector@127.0.0.1:65474 [junit4:junit4] 1> INFO - 2013-04-24 20:49:50.934; org.apache.solr.servl= et.SolrDispatchFilter; SolrDispatchFilter.init() [junit4:junit4] 1> INFO - 2013-04-24 20:49:50.935; org.apache.solr.core.= SolrResourceLoader; JNDI not configured for solr (NoInitialContextEx) [junit4:junit4] 1> INFO - 2013-04-24 20:49:50.935; 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-1366850990297 [junit4:junit4] 1> INFO - 2013-04-24 20:49:50.936; 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-1366850990297\solr= .xml [junit4:junit4] 1> INFO - 2013-04-24 20:49:50.936; org.apache.solr.core.= CoreContainer; New CoreContainer 26578241 [junit4:junit4] 1> INFO - 2013-04-24 20:49:50.937; 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-1366850990297\' [junit4:junit4] 1> INFO - 2013-04-24 20:49:50.937; 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-1366850990297\' [junit4:junit4] 1> INFO - 2013-04-24 20:49:51.092; org.apache.solr.core.= SolrCoreDiscoverer; Looking for cores in C:\Users\JenkinsSlave\workspace\Lu= cene-Solr-trunk-Windows\solr\build\solr-core\test\J0\org.apache.solr.cloud.= CollectionsAPIDistributedZkTest-jetty2-1366850990297 [junit4:junit4] 1> INFO - 2013-04-24 20:49:51.094; org.apache.solr.core.= SolrCoreDiscoverer; Looking for cores in C:\Users\JenkinsSlave\workspace\Lu= cene-Solr-trunk-Windows\solr\build\solr-core\test\J0\org.apache.solr.cloud.= CollectionsAPIDistributedZkTest-jetty2-1366850990297\collection1 [junit4:junit4] 1> INFO - 2013-04-24 20:49:51.096; org.apache.solr.core.= SolrCoreDiscoverer; Looking for cores in C:\Users\JenkinsSlave\workspace\Lu= cene-Solr-trunk-Windows\solr\build\solr-core\test\J0\org.apache.solr.cloud.= CollectionsAPIDistributedZkTest-jetty2-1366850990297\collection1\conf [junit4:junit4] 1> INFO - 2013-04-24 20:49:51.335; org.apache.solr.core.= SolrCoreDiscoverer; Looking for cores in C:\Users\JenkinsSlave\workspace\Lu= cene-Solr-trunk-Windows\solr\build\solr-core\test\J0\org.apache.solr.cloud.= CollectionsAPIDistributedZkTest-jetty2-1366850990297\collection1\conf\xslt [junit4:junit4] 1> INFO - 2013-04-24 20:49:51.343; org.apache.solr.core.= SolrCoreDiscoverer; Looking for cores in C:\Users\JenkinsSlave\workspace\Lu= cene-Solr-trunk-Windows\solr\build\solr-core\test\J0\org.apache.solr.cloud.= CollectionsAPIDistributedZkTest-jetty2-1366850990297\collection1\lib [junit4:junit4] 1> INFO - 2013-04-24 20:49:51.347; org.apache.solr.core.= SolrCoreDiscoverer; Looking for cores in C:\Users\JenkinsSlave\workspace\Lu= cene-Solr-trunk-Windows\solr\build\solr-core\test\J0\org.apache.solr.cloud.= CollectionsAPIDistributedZkTest-jetty2-1366850990297\collection1\lib\classe= s [junit4:junit4] 1> INFO - 2013-04-24 20:49:51.353; org.apache.solr.core.= SolrCoreDiscoverer; Discovered properties file C:\Users\JenkinsSlave\worksp= ace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.sol= r.cloud.CollectionsAPIDistributedZkTest-jetty2-1366850990297\conf\core.prop= erties, adding to cores [junit4:junit4] 1> INFO - 2013-04-24 20:49:51.371; org.apache.solr.handl= er.component.HttpShardHandlerFactory; Setting socketTimeout to: 0 [junit4:junit4] 1> INFO - 2013-04-24 20:49:51.371; org.apache.solr.handl= er.component.HttpShardHandlerFactory; Setting urlScheme to: http:// [junit4:junit4] 1> INFO - 2013-04-24 20:49:51.371; org.apache.solr.handl= er.component.HttpShardHandlerFactory; Setting connTimeout to: 0 [junit4:junit4] 1> INFO - 2013-04-24 20:49:51.372; org.apache.solr.handl= er.component.HttpShardHandlerFactory; Setting maxConnectionsPerHost to: 20 [junit4:junit4] 1> INFO - 2013-04-24 20:49:51.372; org.apache.solr.handl= er.component.HttpShardHandlerFactory; Setting corePoolSize to: 0 [junit4:junit4] 1> INFO - 2013-04-24 20:49:51.372; org.apache.solr.handl= er.component.HttpShardHandlerFactory; Setting maximumPoolSize to: 214748364= 7 [junit4:junit4] 1> INFO - 2013-04-24 20:49:51.372; org.apache.solr.handl= er.component.HttpShardHandlerFactory; Setting maxThreadIdleTime to: 5 [junit4:junit4] 1> INFO - 2013-04-24 20:49:51.373; org.apache.solr.handl= er.component.HttpShardHandlerFactory; Setting sizeOfQueue to: -1 [junit4:junit4] 1> INFO - 2013-04-24 20:49:51.374; org.apache.solr.handl= er.component.HttpShardHandlerFactory; Setting fairnessPolicy to: false [junit4:junit4] 1> INFO - 2013-04-24 20:49:51.374; org.apache.solr.clien= t.solrj.impl.HttpClientUtil; Creating new http client, config:maxConnection= sPerHost=3D20&maxConnections=3D10000&socketTimeout=3D0&connTimeout=3D0&retr= y=3Dfalse [junit4:junit4] 1> INFO - 2013-04-24 20:49:51.382; org.apache.solr.core.= CoreContainer; Registering Log Listener [junit4:junit4] 1> INFO - 2013-04-24 20:49:51.383; org.apache.solr.core.= ZkContainer; Zookeeper client=3D127.0.0.1:65446/solr [junit4:junit4] 1> INFO - 2013-04-24 20:49:51.383; org.apache.solr.cloud= .ZkController; zkHost includes chroot [junit4:junit4] 1> INFO - 2013-04-24 20:49:51.386; org.apache.solr.commo= n.cloud.ConnectionManager; Waiting for client to connect to ZooKeeper [junit4:junit4] 1> INFO - 2013-04-24 20:49:51.408; org.apache.solr.commo= n.cloud.ConnectionManager; Watcher org.apache.solr.common.cloud.ConnectionM= anager@1eca61a name:ZooKeeperConnection Watcher:127.0.0.1:65446 got event W= atchedEvent state:SyncConnected type:None path:null path:null type:None [junit4:junit4] 1> INFO - 2013-04-24 20:49:51.409; org.apache.solr.commo= n.cloud.ConnectionManager; Client is connected to ZooKeeper [junit4:junit4] 1> WARN - 2013-04-24 20:49:51.430; org.apache.zookeeper.= server.NIOServerCnxn; caught end of stream exception [junit4:junit4] 1> EndOfStreamException: Unable to read additional data f= rom client sessionid 0x13e3eaae3820007, 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-24 20:49:51.430; 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-24 20:49:51.443; org.apache.solr.commo= n.cloud.ConnectionManager; Waiting for client to connect to ZooKeeper [junit4:junit4] 1> INFO - 2013-04-24 20:49:51.448; org.apache.solr.commo= n.cloud.ConnectionManager; Watcher org.apache.solr.common.cloud.ConnectionM= anager@75136f name:ZooKeeperConnection Watcher:127.0.0.1:65446/solr got eve= nt WatchedEvent state:SyncConnected type:None path:null path:null type:None [junit4:junit4] 1> INFO - 2013-04-24 20:49:51.448; org.apache.solr.commo= n.cloud.ConnectionManager; Client is connected to ZooKeeper [junit4:junit4] 1> INFO - 2013-04-24 20:49:51.458; org.apache.solr.commo= n.cloud.ZkStateReader; Updating cluster state from ZooKeeper...=20 [junit4:junit4] 1> INFO - 2013-04-24 20:49:52.439; org.apache.solr.cloud= .ZkController; Register node as live in ZooKeeper:/live_nodes/127.0.0.1:654= 74_ [junit4:junit4] 1> INFO - 2013-04-24 20:49:52.442; org.apache.solr.commo= n.cloud.SolrZkClient; makePath: /live_nodes/127.0.0.1:65474_ [junit4:junit4] 1> INFO - 2013-04-24 20:49:52.448; org.apache.solr.commo= n.cloud.ZkStateReader$3; Updating live nodes... (3) [junit4:junit4] 1> INFO - 2013-04-24 20:49:52.449; org.apache.solr.commo= n.cloud.ZkStateReader$3; Updating live nodes... (3) [junit4:junit4] 1> INFO - 2013-04-24 20:49:52.449; org.apache.solr.commo= n.cloud.ZkStateReader$3; Updating live nodes... (3) [junit4:junit4] 1> INFO - 2013-04-24 20:49:52.449; org.apache.solr.commo= n.cloud.ZkStateReader$3; Updating live nodes... (3) [junit4:junit4] 1> INFO - 2013-04-24 20:49:52.462; 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-24 20:49:52.463; org.apache.solr.servl= et.SolrDispatchFilter; SolrDispatchFilter.init() done [junit4:junit4] 1> INFO - 2013-04-24 20:49:52.464; 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-24 20:49:53.037; org.eclipse.jetty.ser= ver.Server; jetty-8.1.10.v20130312 [junit4:junit4] 1> INFO - 2013-04-24 20:49:53.042; org.eclipse.jetty.ser= ver.AbstractConnector; Started SelectChannelConnector@127.0.0.1:65483 [junit4:junit4] 1> INFO - 2013-04-24 20:49:53.043; org.apache.solr.servl= et.SolrDispatchFilter; SolrDispatchFilter.init() [junit4:junit4] 1> INFO - 2013-04-24 20:49:53.044; org.apache.solr.core.= SolrResourceLoader; JNDI not configured for solr (NoInitialContextEx) [junit4:junit4] 1> INFO - 2013-04-24 20:49:53.045; 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-1366850992471 [junit4:junit4] 1> INFO - 2013-04-24 20:49:53.045; 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-1366850992471\solr= .xml [junit4:junit4] 1> INFO - 2013-04-24 20:49:53.047; org.apache.solr.core.= CoreContainer; New CoreContainer 22405463 [junit4:junit4] 1> INFO - 2013-04-24 20:49:53.047; 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-1366850992471\' [junit4:junit4] 1> INFO - 2013-04-24 20:49:53.048; 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-1366850992471\' [junit4:junit4] 1> INFO - 2013-04-24 20:49:53.202; org.apache.solr.core.= SolrCoreDiscoverer; Looking for cores in C:\Users\JenkinsSlave\workspace\Lu= cene-Solr-trunk-Windows\solr\build\solr-core\test\J0\org.apache.solr.cloud.= CollectionsAPIDistributedZkTest-jetty3-1366850992471 [junit4:junit4] 1> INFO - 2013-04-24 20:49:53.205; org.apache.solr.core.= SolrCoreDiscoverer; Looking for cores in C:\Users\JenkinsSlave\workspace\Lu= cene-Solr-trunk-Windows\solr\build\solr-core\test\J0\org.apache.solr.cloud.= CollectionsAPIDistributedZkTest-jetty3-1366850992471\collection1 [junit4:junit4] 1> INFO - 2013-04-24 20:49:53.208; org.apache.solr.core.= SolrCoreDiscoverer; Looking for cores in C:\Users\JenkinsSlave\workspace\Lu= cene-Solr-trunk-Windows\solr\build\solr-core\test\J0\org.apache.solr.cloud.= CollectionsAPIDistributedZkTest-jetty3-1366850992471\collection1\conf [junit4:junit4] 1> INFO - 2013-04-24 20:49:53.417; org.apache.solr.core.= SolrCoreDiscoverer; Looking for cores in C:\Users\JenkinsSlave\workspace\Lu= cene-Solr-trunk-Windows\solr\build\solr-core\test\J0\org.apache.solr.cloud.= CollectionsAPIDistributedZkTest-jetty3-1366850992471\collection1\conf\xslt [junit4:junit4] 1> INFO - 2013-04-24 20:49:53.424; org.apache.solr.core.= SolrCoreDiscoverer; Looking for cores in C:\Users\JenkinsSlave\workspace\Lu= cene-Solr-trunk-Windows\solr\build\solr-core\test\J0\org.apache.solr.cloud.= CollectionsAPIDistributedZkTest-jetty3-1366850992471\collection1\lib [junit4:junit4] 1> INFO - 2013-04-24 20:49:53.428; org.apache.solr.core.= SolrCoreDiscoverer; Looking for cores in C:\Users\JenkinsSlave\workspace\Lu= cene-Solr-trunk-Windows\solr\build\solr-core\test\J0\org.apache.solr.cloud.= CollectionsAPIDistributedZkTest-jetty3-1366850992471\collection1\lib\classe= s [junit4:junit4] 1> INFO - 2013-04-24 20:49:53.435; org.apache.solr.core.= SolrCoreDiscoverer; Discovered properties file C:\Users\JenkinsSlave\worksp= ace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.sol= r.cloud.CollectionsAPIDistributedZkTest-jetty3-1366850992471\conf\core.prop= erties, adding to cores [junit4:junit4] 1> INFO - 2013-04-24 20:49:53.450; org.apache.solr.handl= er.component.HttpShardHandlerFactory; Setting socketTimeout to: 0 [junit4:junit4] 1> INFO - 2013-04-24 20:49:53.451; org.apache.solr.handl= er.component.HttpShardHandlerFactory; Setting urlScheme to: http:// [junit4:junit4] 1> INFO - 2013-04-24 20:49:53.452; org.apache.solr.handl= er.component.HttpShardHandlerFactory; Setting connTimeout to: 0 [junit4:junit4] 1> INFO - 2013-04-24 20:49:53.452; org.apache.solr.handl= er.component.HttpShardHandlerFactory; Setting maxConnectionsPerHost to: 20 [junit4:junit4] 1> INFO - 2013-04-24 20:49:53.452; org.apache.solr.handl= er.component.HttpShardHandlerFactory; Setting corePoolSize to: 0 [junit4:junit4] 1> INFO - 2013-04-24 20:49:53.453; org.apache.solr.handl= er.component.HttpShardHandlerFactory; Setting maximumPoolSize to: 214748364= 7 [junit4:junit4] 1> INFO - 2013-04-24 20:49:53.453; org.apache.solr.handl= er.component.HttpShardHandlerFactory; Setting maxThreadIdleTime to: 5 [junit4:junit4] 1> INFO - 2013-04-24 20:49:53.454; org.apache.solr.handl= er.component.HttpShardHandlerFactory; Setting sizeOfQueue to: -1 [junit4:junit4] 1> INFO - 2013-04-24 20:49:53.454; org.apache.solr.handl= er.component.HttpShardHandlerFactory; Setting fairnessPolicy to: false [junit4:junit4] 1> INFO - 2013-04-24 20:49:53.454; org.apache.solr.clien= t.solrj.impl.HttpClientUtil; Creating new http client, config:maxConnection= sPerHost=3D20&maxConnections=3D10000&socketTimeout=3D0&connTimeout=3D0&retr= y=3Dfalse [junit4:junit4] 1> INFO - 2013-04-24 20:49:53.462; org.apache.solr.core.= CoreContainer; Registering Log Listener [junit4:junit4] 1> INFO - 2013-04-24 20:49:53.463; org.apache.solr.core.= ZkContainer; Zookeeper client=3D127.0.0.1:65446/solr [junit4:junit4] 1> INFO - 2013-04-24 20:49:53.464; org.apache.solr.cloud= .ZkController; zkHost includes chroot [junit4:junit4] 1> INFO - 2013-04-24 20:49:53.466; org.apache.solr.commo= n.cloud.ConnectionManager; Waiting for client to connect to ZooKeeper [junit4:junit4] 1> INFO - 2013-04-24 20:49:53.482; org.apache.solr.commo= n.cloud.ConnectionManager; Watcher org.apache.solr.common.cloud.ConnectionM= anager@577d54 name:ZooKeeperConnection Watcher:127.0.0.1:65446 got event Wa= tchedEvent state:SyncConnected type:None path:null path:null type:None [junit4:junit4] 1> INFO - 2013-04-24 20:49:53.483; org.apache.solr.commo= n.cloud.ConnectionManager; Client is connected to ZooKeeper [junit4:junit4] 1> INFO - 2013-04-24 20:49:53.487; 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-24 20:49:53.495; org.apache.solr.commo= n.cloud.ConnectionManager; Waiting for client to connect to ZooKeeper [junit4:junit4] 1> INFO - 2013-04-24 20:49:53.499; org.apache.solr.commo= n.cloud.ConnectionManager; Watcher org.apache.solr.common.cloud.ConnectionM= anager@120e80c name:ZooKeeperConnection Watcher:127.0.0.1:65446/solr got ev= ent WatchedEvent state:SyncConnected type:None path:null path:null type:Non= e [junit4:junit4] 1> INFO - 2013-04-24 20:49:53.500; org.apache.solr.commo= n.cloud.ConnectionManager; Client is connected to ZooKeeper [junit4:junit4] 1> INFO - 2013-04-24 20:49:53.507; org.apache.solr.commo= n.cloud.ZkStateReader; Updating cluster state from ZooKeeper...=20 [junit4:junit4] 1> INFO - 2013-04-24 20:49:54.488; org.apache.solr.cloud= .ZkController; Register node as live in ZooKeeper:/live_nodes/127.0.0.1:654= 83_ [junit4:junit4] 1> INFO - 2013-04-24 20:49:54.492; org.apache.solr.commo= n.cloud.SolrZkClient; makePath: /live_nodes/127.0.0.1:65483_ [junit4:junit4] 1> INFO - 2013-04-24 20:49:54.498; org.apache.solr.commo= n.cloud.ZkStateReader$3; Updating live nodes... (4) [junit4:junit4] 1> INFO - 2013-04-24 20:49:54.499; org.apache.solr.commo= n.cloud.ZkStateReader$3; Updating live nodes... (4) [junit4:junit4] 1> INFO - 2013-04-24 20:49:54.500; org.apache.solr.commo= n.cloud.ZkStateReader$3; Updating live nodes... (4) [junit4:junit4] 1> INFO - 2013-04-24 20:49:54.500; org.apache.solr.commo= n.cloud.ZkStateReader$3; Updating live nodes... (4) [junit4:junit4] 1> INFO - 2013-04-24 20:49:54.500; org.apache.solr.commo= n.cloud.ZkStateReader$3; Updating live nodes... (4) [junit4:junit4] 1> INFO - 2013-04-24 20:49:54.513; 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-24 20:49:54.513; org.apache.solr.servl= et.SolrDispatchFilter; SolrDispatchFilter.init() done [junit4:junit4] 1> INFO - 2013-04-24 20:49:54.514; 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-24 20:49:55.054; org.eclipse.jetty.ser= ver.Server; jetty-8.1.10.v20130312 [junit4:junit4] 1> INFO - 2013-04-24 20:49:55.059; org.eclipse.jetty.ser= ver.AbstractConnector; Started SelectChannelConnector@127.0.0.1:65492 [junit4:junit4] 1> INFO - 2013-04-24 20:49:55.060; org.apache.solr.servl= et.SolrDispatchFilter; SolrDispatchFilter.init() [junit4:junit4] 1> INFO - 2013-04-24 20:49:55.061; org.apache.solr.core.= SolrResourceLoader; JNDI not configured for solr (NoInitialContextEx) [junit4:junit4] 1> INFO - 2013-04-24 20:49:55.061; 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-1366850994522 [junit4:junit4] 1> INFO - 2013-04-24 20:49:55.062; 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-1366850994522\solr= .xml [junit4:junit4] 1> INFO - 2013-04-24 20:49:55.062; org.apache.solr.core.= CoreContainer; New CoreContainer 12106993 [junit4:junit4] 1> INFO - 2013-04-24 20:49:55.063; 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-1366850994522\' [junit4:junit4] 1> INFO - 2013-04-24 20:49:55.063; 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-1366850994522\' [junit4:junit4] 1> INFO - 2013-04-24 20:49:55.198; org.apache.solr.core.= SolrCoreDiscoverer; Looking for cores in C:\Users\JenkinsSlave\workspace\Lu= cene-Solr-trunk-Windows\solr\build\solr-core\test\J0\org.apache.solr.cloud.= CollectionsAPIDistributedZkTest-jetty4-1366850994522 [junit4:junit4] 1> INFO - 2013-04-24 20:49:55.200; org.apache.solr.core.= SolrCoreDiscoverer; Looking for cores in C:\Users\JenkinsSlave\workspace\Lu= cene-Solr-trunk-Windows\solr\build\solr-core\test\J0\org.apache.solr.cloud.= CollectionsAPIDistributedZkTest-jetty4-1366850994522\collection1 [junit4:junit4] 1> INFO - 2013-04-24 20:49:55.203; org.apache.solr.core.= SolrCoreDiscoverer; Looking for cores in C:\Users\JenkinsSlave\workspace\Lu= cene-Solr-trunk-Windows\solr\build\solr-core\test\J0\org.apache.solr.cloud.= CollectionsAPIDistributedZkTest-jetty4-1366850994522\collection1\conf [junit4:junit4] 1> INFO - 2013-04-24 20:49:55.433; org.apache.solr.core.= SolrCoreDiscoverer; Looking for cores in C:\Users\JenkinsSlave\workspace\Lu= cene-Solr-trunk-Windows\solr\build\solr-core\test\J0\org.apache.solr.cloud.= CollectionsAPIDistributedZkTest-jetty4-1366850994522\collection1\conf\xslt [junit4:junit4] 1> INFO - 2013-04-24 20:49:55.441; org.apache.solr.core.= SolrCoreDiscoverer; Looking for cores in C:\Users\JenkinsSlave\workspace\Lu= cene-Solr-trunk-Windows\solr\build\solr-core\test\J0\org.apache.solr.cloud.= CollectionsAPIDistributedZkTest-jetty4-1366850994522\collection1\lib [junit4:junit4] 1> INFO - 2013-04-24 20:49:55.444; org.apache.solr.core.= SolrCoreDiscoverer; Looking for cores in C:\Users\JenkinsSlave\workspace\Lu= cene-Solr-trunk-Windows\solr\build\solr-core\test\J0\org.apache.solr.cloud.= CollectionsAPIDistributedZkTest-jetty4-1366850994522\collection1\lib\classe= s [junit4:junit4] 1> INFO - 2013-04-24 20:49:55.449; org.apache.solr.core.= SolrCoreDiscoverer; Discovered properties file C:\Users\JenkinsSlave\worksp= ace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.sol= r.cloud.CollectionsAPIDistributedZkTest-jetty4-1366850994522\conf\core.prop= erties, adding to cores [junit4:junit4] 1> INFO - 2013-04-24 20:49:55.465; org.apache.solr.handl= er.component.HttpShardHandlerFactory; Setting socketTimeout to: 0 [junit4:junit4] 1> INFO - 2013-04-24 20:49:55.465; org.apache.solr.handl= er.component.HttpShardHandlerFactory; Setting urlScheme to: http:// [junit4:junit4] 1> INFO - 2013-04-24 20:49:55.466; org.apache.solr.handl= er.component.HttpShardHandlerFactory; Setting connTimeout to: 0 [junit4:junit4] 1> INFO - 2013-04-24 20:49:55.466; org.apache.solr.handl= er.component.HttpShardHandlerFactory; Setting maxConnectionsPerHost to: 20 [junit4:junit4] 1> INFO - 2013-04-24 20:49:55.467; org.apache.solr.handl= er.component.HttpShardHandlerFactory; Setting corePoolSize to: 0 [junit4:junit4] 1> INFO - 2013-04-24 20:49:55.467; org.apache.solr.handl= er.component.HttpShardHandlerFactory; Setting maximumPoolSize to: 214748364= 7 [junit4:junit4] 1> INFO - 2013-04-24 20:49:55.468; org.apache.solr.handl= er.component.HttpShardHandlerFactory; Setting maxThreadIdleTime to: 5 [junit4:junit4] 1> INFO - 2013-04-24 20:49:55.468; org.apache.solr.handl= er.component.HttpShardHandlerFactory; Setting sizeOfQueue to: -1 [junit4:junit4] 1> INFO - 2013-04-24 20:49:55.468; org.apache.solr.handl= er.component.HttpShardHandlerFactory; Setting fairnessPolicy to: false [junit4:junit4] 1> INFO - 2013-04-24 20:49:55.469; org.apache.solr.clien= t.solrj.impl.HttpClientUtil; Creating new http client, config:maxConnection= sPerHost=3D20&maxConnections=3D10000&socketTimeout=3D0&connTimeout=3D0&retr= y=3Dfalse [junit4:junit4] 1> INFO - 2013-04-24 20:49:55.476; org.apache.solr.core.= CoreContainer; Registering Log Listener [junit4:junit4] 1> INFO - 2013-04-24 20:49:55.477; org.apache.solr.core.= ZkContainer; Zookeeper client=3D127.0.0.1:65446/solr [junit4:junit4] 1> INFO - 2013-04-24 20:49:55.477; org.apache.solr.cloud= .ZkController; zkHost includes chroot [junit4:junit4] 1> INFO - 2013-04-24 20:49:55.479; org.apache.solr.commo= n.cloud.ConnectionManager; Waiting for client to connect to ZooKeeper [junit4:junit4] 1> INFO - 2013-04-24 20:49:55.497; org.apache.solr.commo= n.cloud.ConnectionManager; Watcher org.apache.solr.common.cloud.ConnectionM= anager@18b05f7 name:ZooKeeperConnection Watcher:127.0.0.1:65446 got event W= atchedEvent state:SyncConnected type:None path:null path:null type:None [junit4:junit4] 1> INFO - 2013-04-24 20:49:55.498; org.apache.solr.commo= n.cloud.ConnectionManager; Client is connected to ZooKeeper [junit4:junit4] 1> INFO - 2013-04-24 20:49:55.502; 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-24 20:49:55.510; org.apache.solr.commo= n.cloud.ConnectionManager; Waiting for client to connect to ZooKeeper [junit4:junit4] 1> INFO - 2013-04-24 20:49:55.513; org.apache.solr.commo= n.cloud.ConnectionManager; Watcher org.apache.solr.common.cloud.ConnectionM= anager@bd7498 name:ZooKeeperConnection Watcher:127.0.0.1:65446/solr got eve= nt WatchedEvent state:SyncConnected type:None path:null path:null type:None [junit4:junit4] 1> INFO - 2013-04-24 20:49:55.514; org.apache.solr.commo= n.cloud.ConnectionManager; Client is connected to ZooKeeper [junit4:junit4] 1> INFO - 2013-04-24 20:49:55.522; org.apache.solr.commo= n.cloud.ZkStateReader; Updating cluster state from ZooKeeper...=20 [junit4:junit4] 1> INFO - 2013-04-24 20:49:56.502; org.apache.solr.cloud= .ZkController; Register node as live in ZooKeeper:/live_nodes/127.0.0.1:654= 92_ [junit4:junit4] 1> INFO - 2013-04-24 20:49:56.505; org.apache.solr.commo= n.cloud.SolrZkClient; makePath: /live_nodes/127.0.0.1:65492_ [junit4:junit4] 1> INFO - 2013-04-24 20:49:56.512; org.apache.solr.commo= n.cloud.ZkStateReader$3; Updating live nodes... (5) [junit4:junit4] 1> INFO - 2013-04-24 20:49:56.513; org.apache.solr.commo= n.cloud.ZkStateReader$3; Updating live nodes... (5) [junit4:junit4] 1> INFO - 2013-04-24 20:49:56.513; org.apache.solr.commo= n.cloud.ZkStateReader$3; Updating live nodes... (5) [junit4:junit4] 1> INFO - 2013-04-24 20:49:56.513; org.apache.solr.commo= n.cloud.ZkStateReader$3; Updating live nodes... (5) [junit4:junit4] 1> INFO - 2013-04-24 20:49:56.514; org.apache.solr.commo= n.cloud.ZkStateReader$3; Updating live nodes... (5) [junit4:junit4] 1> INFO - 2013-04-24 20:49:56.514; org.apache.solr.commo= n.cloud.ZkStateReader$3; Updating live nodes... (5) [junit4:junit4] 1> INFO - 2013-04-24 20:49:56.528; 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-24 20:49:56.528; org.apache.solr.servl= et.SolrDispatchFilter; SolrDispatchFilter.init() done [junit4:junit4] 1> INFO - 2013-04-24 20:49:56.529; 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-24 20:49:56.538; 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-24 20:49:56.548; 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-24 20:49:56.552; 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-24 20:49:56.556; 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-24 20:49:56.556; 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:65483_ [junit4:junit4] 1> INFO - 2013-04-24 20:49:56.558; 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:65474_ [junit4:junit4] 1> INFO - 2013-04-24 20:49:56.559; 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:65492_ [junit4:junit4] 1> INFO - 2013-04-24 20:49:56.561; 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:65453_ [junit4:junit4] 1> INFO - 2013-04-24 20:49:56.566; 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-jetty4-1366850994522\nodes_used_collection_shard2_replica1 [junit4:junit4] 1> INFO - 2013-04-24 20:49:56.568; 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-jetty3-1366850992471\nodes_used_collection_shard1_replica1 [junit4:junit4] 1> INFO - 2013-04-24 20:49:56.568; org.apache.solr.cloud= .ZkController; Check for collection zkNode:nodes_used_collection [junit4:junit4] 1> INFO - 2013-04-24 20:49:56.568; 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-1366850987076\nodes_used_collection_shard2_replica2 [junit4:junit4] 1> INFO - 2013-04-24 20:49:56.569; org.apache.solr.cloud= .ZkController; Check for collection zkNode:nodes_used_collection [junit4:junit4] 1> INFO - 2013-04-24 20:49:56.568; org.apache.solr.cloud= .ZkController; Check for collection zkNode:nodes_used_collection [junit4:junit4] 1> INFO - 2013-04-24 20:49:56.567; 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-1366850990297\nodes_used_collection_shard1_replica2 [junit4:junit4] 1> INFO - 2013-04-24 20:49:56.571; org.apache.solr.cloud= .ZkController; Creating collection in ZooKeeper:nodes_used_collection [junit4:junit4] 1> INFO - 2013-04-24 20:49:56.572; org.apache.solr.cloud= .ZkController; Looking for collection configName [junit4:junit4] 1> INFO - 2013-04-24 20:49:56.571; org.apache.solr.cloud= .ZkController; Check for collection zkNode:nodes_used_collection [junit4:junit4] 1> INFO - 2013-04-24 20:49:56.570; org.apache.solr.cloud= .ZkController; Creating collection in ZooKeeper:nodes_used_collection [junit4:junit4] 1> INFO - 2013-04-24 20:49:56.574; org.apache.solr.cloud= .ZkController; Looking for collection configName [junit4:junit4] 1> INFO - 2013-04-24 20:49:56.574; org.apache.solr.cloud= .ZkController; Creating collection in ZooKeeper:nodes_used_collection [junit4:junit4] 1> INFO - 2013-04-24 20:49:56.576; org.apache.solr.cloud= .ZkController; Looking for collection configName [junit4:junit4] 1> INFO - 2013-04-24 20:49:56.572; org.apache.solr.cloud= .ZkController; Creating collection in ZooKeeper:nodes_used_collection [junit4:junit4] 1> INFO - 2013-04-24 20:49:56.578; org.apache.solr.cloud= .ZkController; Looking for collection configName [junit4:junit4] 1> INFO - 2013-04-24 20:49:56.576; org.apache.solr.cloud= .ZkController; Only one config set found in zk - using it:conf1 [junit4:junit4] 1> INFO - 2013-04-24 20:49:56.579; org.apache.solr.commo= n.cloud.SolrZkClient; makePath: /collections/nodes_used_collection [junit4:junit4] 1> INFO - 2013-04-24 20:49:56.579; org.apache.solr.cloud= .ZkController; Only one config set found in zk - using it:conf1 [junit4:junit4] 1> INFO - 2013-04-24 20:49:56.581; org.apache.solr.commo= n.cloud.SolrZkClient; makePath: /collections/nodes_used_collection [junit4:junit4] 1> INFO - 2013-04-24 20:49:56.582; org.apache.solr.cloud= .ZkController; Only one config set found in zk - using it:conf1 [junit4:junit4] 1> INFO - 2013-04-24 20:49:56.583; org.apache.solr.commo= n.cloud.SolrZkClient; makePath: /collections/nodes_used_collection [junit4:junit4] 1> INFO - 2013-04-24 20:49:56.583; org.apache.solr.cloud= .ZkController; Only one config set found in zk - using it:conf1 [junit4:junit4] 1> INFO - 2013-04-24 20:49:56.585; org.apache.solr.commo= n.cloud.SolrZkClient; makePath: /collections/nodes_used_collection [junit4:junit4] 1> INFO - 2013-04-24 20:49:56.595; org.apache.solr.cloud= .ZkController; Load collection config from:/collections/nodes_used_collecti= on [junit4:junit4] 1> INFO - 2013-04-24 20:49:56.596; org.apache.solr.cloud= .ZkController; Load collection config from:/collections/nodes_used_collecti= on [junit4:junit4] 1> INFO - 2013-04-24 20:49:56.600; org.apache.solr.cloud= .ZkController; Load collection config from:/collections/nodes_used_collecti= on [junit4:junit4] 1> INFO - 2013-04-24 20:49:56.601; org.apache.solr.cloud= .ZkController; Load collection config from:/collections/nodes_used_collecti= on [junit4:junit4] 1> INFO - 2013-04-24 20:49:56.604; 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-1366850992471\no= des_used_collection_shard1_replica1\' [junit4:junit4] 1> INFO - 2013-04-24 20:49:56.606; 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-1366850987= 076\nodes_used_collection_shard2_replica2\' [junit4:junit4] 1> INFO - 2013-04-24 20:49:56.608; 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-1366850990297\no= des_used_collection_shard1_replica2\' [junit4:junit4] 1> INFO - 2013-04-24 20:49:56.611; 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-1366850994522\no= des_used_collection_shard2_replica1\' [junit4:junit4] 1> INFO - 2013-04-24 20:49:56.729; org.apache.solr.core.= SolrConfig; Using Lucene MatchVersion: LUCENE_50 [junit4:junit4] 1> INFO - 2013-04-24 20:49:56.761; org.apache.solr.core.= SolrConfig; Using Lucene MatchVersion: LUCENE_50 [junit4:junit4] 1> INFO - 2013-04-24 20:49:56.847; org.apache.solr.core.= SolrConfig; Using Lucene MatchVersion: LUCENE_50 [junit4:junit4] 1> INFO - 2013-04-24 20:49:56.899; org.apache.solr.core.= SolrConfig; Using Lucene MatchVersion: LUCENE_50 [junit4:junit4] 1> INFO - 2013-04-24 20:49:56.949; org.apache.solr.core.= SolrConfig; Loaded SolrConfig: solrconfig.xml [junit4:junit4] 1> INFO - 2013-04-24 20:49:57.079; org.apache.solr.core.= SolrConfig; Loaded SolrConfig: solrconfig.xml [junit4:junit4] 1> INFO - 2013-04-24 20:49:57.082; org.apache.solr.core.= SolrConfig; Loaded SolrConfig: solrconfig.xml [junit4:junit4] 1> INFO - 2013-04-24 20:49:57.083; org.apache.solr.schem= a.IndexSchema; Reading Solr Schema from schema.xml [junit4:junit4] 1> INFO - 2013-04-24 20:49:57.086; org.apache.solr.core.= SolrConfig; Loaded SolrConfig: solrconfig.xml [junit4:junit4] 1> INFO - 2013-04-24 20:49:57.092; org.apache.solr.schem= a.IndexSchema; Reading Solr Schema from schema.xml [junit4:junit4] 1> INFO - 2013-04-24 20:49:57.095; org.apache.solr.schem= a.IndexSchema; Schema name=3Dtest [junit4:junit4] 1> INFO - 2013-04-24 20:49:57.106; org.apache.solr.schem= a.IndexSchema; Schema name=3Dtest [junit4:junit4] 1> INFO - 2013-04-24 20:49:57.143; org.apache.solr.schem= a.IndexSchema; Reading Solr Schema from schema.xml [junit4:junit4] 1> INFO - 2013-04-24 20:49:57.152; org.apache.solr.schem= a.IndexSchema; Schema name=3Dtest [junit4:junit4] 1> INFO - 2013-04-24 20:49:57.143; org.apache.solr.schem= a.IndexSchema; Reading Solr Schema from schema.xml [junit4:junit4] 1> INFO - 2013-04-24 20:49:57.244; org.apache.solr.schem= a.IndexSchema; Schema name=3Dtest [junit4:junit4] 1> INFO - 2013-04-24 20:49:59.357; org.apache.solr.schem= a.OpenExchangeRatesOrgProvider; Initialized with rates=3Dopen-exchange-rate= s.json, refreshInterval=3D1440. [junit4:junit4] 1> INFO - 2013-04-24 20:49:59.361; org.apache.solr.schem= a.OpenExchangeRatesOrgProvider; Initialized with rates=3Dopen-exchange-rate= s.json, refreshInterval=3D1440. [junit4:junit4] 1> INFO - 2013-04-24 20:49:59.417; org.apache.solr.schem= a.OpenExchangeRatesOrgProvider; Initialized with rates=3Dopen-exchange-rate= s.json, refreshInterval=3D1440. [junit4:junit4] 1> INFO - 2013-04-24 20:49:59.433; org.apache.solr.schem= a.IndexSchema; default search field in schema is text [junit4:junit4] 1> INFO - 2013-04-24 20:49:59.438; org.apache.solr.schem= a.IndexSchema; unique key field: id [junit4:junit4] 1> INFO - 2013-04-24 20:49:59.442; org.apache.solr.schem= a.IndexSchema; default search field in schema is text [junit4:junit4] 1> INFO - 2013-04-24 20:49:59.447; org.apache.solr.schem= a.IndexSchema; unique key field: id [junit4:junit4] 1> INFO - 2013-04-24 20:49:59.456; org.apache.solr.schem= a.IndexSchema; default search field in schema is text [junit4:junit4] 1> INFO - 2013-04-24 20:49:59.460; org.apache.solr.schem= a.IndexSchema; unique key field: id [junit4:junit4] 1> INFO - 2013-04-24 20:49:59.502; org.apache.solr.schem= a.OpenExchangeRatesOrgProvider; Initialized with rates=3Dopen-exchange-rate= s.json, refreshInterval=3D1440. [junit4:junit4] 1> INFO - 2013-04-24 20:49:59.508; org.apache.solr.schem= a.FileExchangeRateProvider; Reloading exchange rates from file currency.xml [junit4:junit4] 1> INFO - 2013-04-24 20:49:59.510; org.apache.solr.schem= a.FileExchangeRateProvider; Reloading exchange rates from file currency.xml [junit4:junit4] 1> INFO - 2013-04-24 20:49:59.512; org.apache.solr.schem= a.FileExchangeRateProvider; Reloading exchange rates from file currency.xml [junit4:junit4] 1> INFO - 2013-04-24 20:49:59.518; org.apache.solr.schem= a.FileExchangeRateProvider; Reloading exchange rates from file currency.xml [junit4:junit4] 1> INFO - 2013-04-24 20:49:59.523; org.apache.solr.schem= a.IndexSchema; default search field in schema is text [junit4:junit4] 1> INFO - 2013-04-24 20:49:59.526; org.apache.solr.schem= a.FileExchangeRateProvider; Reloading exchange rates from file currency.xml [junit4:junit4] 1> INFO - 2013-04-24 20:49:59.529; org.apache.solr.schem= a.FileExchangeRateProvider; Reloading exchange rates from file currency.xml [junit4:junit4] 1> INFO - 2013-04-24 20:49:59.532; org.apache.solr.schem= a.IndexSchema; unique key field: id [junit4:junit4] 1> INFO - 2013-04-24 20:49:59.536; org.apache.solr.schem= a.OpenExchangeRatesOrgProvider; Reloading exchange rates from open-exchange= -rates.json [junit4:junit4] 1> INFO - 2013-04-24 20:49:59.539; org.apache.solr.schem= a.OpenExchangeRatesOrgProvider; Reloading exchange rates from open-exchange= -rates.json [junit4:junit4] 1> WARN - 2013-04-24 20:49:59.546; org.apache.solr.schem= a.OpenExchangeRatesOrgProvider$OpenExchangeRates; Unknown key IMPORTANT NOT= E [junit4:junit4] 1> WARN - 2013-04-24 20:49:59.548; org.apache.solr.schem= a.OpenExchangeRatesOrgProvider$OpenExchangeRates; Expected key, got STRING [junit4:junit4] 1> INFO - 2013-04-24 20:49:59.549; org.apache.solr.schem= a.OpenExchangeRatesOrgProvider; Reloading exchange rates from open-exchange= -rates.json [junit4:junit4] 1> INFO - 2013-04-24 20:49:59.548; org.apache.solr.schem= a.OpenExchangeRatesOrgProvider; Reloading exchange rates from open-exchange= -rates.json [junit4:junit4] 1> WARN - 2013-04-24 20:49:59.547; org.apache.solr.schem= a.OpenExchangeRatesOrgProvider$OpenExchangeRates; Unknown key IMPORTANT NOT= E [junit4:junit4] 1> WARN - 2013-04-24 20:49:59.551; org.apache.solr.schem= a.OpenExchangeRatesOrgProvider$OpenExchangeRates; Expected key, got STRING [junit4:junit4] 1> INFO - 2013-04-24 20:49:59.552; org.apache.solr.schem= a.OpenExchangeRatesOrgProvider; Reloading exchange rates from open-exchange= -rates.json [junit4:junit4] 1> WARN - 2013-04-24 20:49:59.553; org.apache.solr.schem= a.OpenExchangeRatesOrgProvider$OpenExchangeRates; Unknown key IMPORTANT NOT= E [junit4:junit4] 1> WARN - 2013-04-24 20:49:59.554; org.apache.solr.schem= a.OpenExchangeRatesOrgProvider$OpenExchangeRates; Expected key, got STRING [junit4:junit4] 1> INFO - 2013-04-24 20:49:59.554; org.apache.solr.core.= SolrCore; org.apache.solr.core.MockDirectoryFactory [junit4:junit4] 1> INFO - 2013-04-24 20:49:59.555; 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-jetty3-1= 366850992471\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-jetty3-136685099247= 1\nodes_used_collection_shard1_replica1\data\ [junit4:junit4] 1> INFO - 2013-04-24 20:49:59.555; org.apache.solr.core.= JmxMonitoredMap; JMX monitoring is enabled. Adding Solr mbeans to JMX Serve= r: com.sun.jmx.mbeanserver.JmxMBeanServer@1b3bfc5 [junit4:junit4] 1> INFO - 2013-04-24 20:49:59.556; org.apache.solr.core.= SolrCore; org.apache.solr.core.MockDirectoryFactory [junit4:junit4] 1> WARN - 2013-04-24 20:49:59.556; org.apache.solr.schem= a.OpenExchangeRatesOrgProvider$OpenExchangeRates; Unknown key IMPORTANT NOT= E [junit4:junit4] 1> WARN - 2013-04-24 20:49:59.557; org.apache.solr.schem= a.OpenExchangeRatesOrgProvider$OpenExchangeRates; Expected key, got STRING [junit4:junit4] 1> INFO - 2013-04-24 20:49:59.557; org.apache.solr.schem= a.OpenExchangeRatesOrgProvider; Reloading exchange rates from open-exchange= -rates.json [junit4:junit4] 1> WARN - 2013-04-24 20:49:59.557; org.apache.solr.schem= a.OpenExchangeRatesOrgProvider$OpenExchangeRates; Unknown key IMPORTANT NOT= E [junit4:junit4] 1> WARN - 2013-04-24 20:49:59.558; org.apache.solr.schem= a.OpenExchangeRatesOrgProvider$OpenExchangeRates; Expected key, got STRING [junit4:junit4] 1> INFO - 2013-04-24 20:49:59.559; org.apache.solr.core.= SolrCore; org.apache.solr.core.MockDirectoryFactory [junit4:junit4] 1> INFO - 2013-04-24 20:49:59.558; 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-jetty3-1366850992471\nodes_used_= collection_shard1_replica1\data\ [junit4:junit4] 1> INFO - 2013-04-24 20:49:59.559; 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-1366850987076\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-= 1366850987076\nodes_used_collection_shard2_replica2\data\ [junit4:junit4] 1> INFO - 2013-04-24 20:49:59.560; org.apache.solr.core.= JmxMonitoredMap; JMX monitoring is enabled. Adding Solr mbeans to JMX Serve= r: com.sun.jmx.mbeanserver.JmxMBeanServer@1b3bfc5 [junit4:junit4] 1> INFO - 2013-04-24 20:49:59.561; 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-jetty3-1366850992471\node= s_used_collection_shard1_replica1\data\index/ [junit4:junit4] 1> INFO - 2013-04-24 20:49:59.561; org.apache.solr.core.= SolrCore; org.apache.solr.core.MockDirectoryFactory [junit4:junit4] 1> WARN - 2013-04-24 20:49:59.562; 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-jetty3-136= 6850992471\nodes_used_collection_shard1_replica1\data\index' doesn't exist.= Creating new index... [junit4:junit4] 1> WARN - 2013-04-24 20:49:59.562; org.apache.solr.schem= a.OpenExchangeRatesOrgProvider$OpenExchangeRates; Unknown key IMPORTANT NOT= E [junit4:junit4] 1> WARN - 2013-04-24 20:49:59.563; org.apache.solr.schem= a.OpenExchangeRatesOrgProvider$OpenExchangeRates; Expected key, got STRING [junit4:junit4] 1> INFO - 2013-04-24 20:49:59.565; org.apache.solr.core.= SolrCore; org.apache.solr.core.MockDirectoryFactory [junit4:junit4] 1> INFO - 2013-04-24 20:49:59.565; 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= 366850990297\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-136685099029= 7\nodes_used_collection_shard1_replica2\data\ [junit4:junit4] 1> INFO - 2013-04-24 20:49:59.566; org.apache.solr.core.= JmxMonitoredMap; JMX monitoring is enabled. Adding Solr mbeans to JMX Serve= r: com.sun.jmx.mbeanserver.JmxMBeanServer@1b3bfc5 [junit4:junit4] 1> INFO - 2013-04-24 20:49:59.566; org.apache.solr.core.= SolrCore; org.apache.solr.core.MockDirectoryFactory [junit4:junit4] 1> INFO - 2013-04-24 20:49:59.563; 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-jetty3-1366850992471\nodes_used_= collection_shard1_replica1\data\index [junit4:junit4] 1> INFO - 2013-04-24 20:49:59.569; 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-1366850987076\nodes= _used_collection_shard2_replica2\data\ [junit4:junit4] 1> INFO - 2013-04-24 20:49:59.569; 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-136685098707= 6\nodes_used_collection_shard2_replica2\data\index/ [junit4:junit4] 1> WARN - 2013-04-24 20:49:59.569; 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-1366850987076\nodes_used_collection_shard2_replica2\data\index' doesn't = exist. Creating new index... [junit4:junit4] 1> INFO - 2013-04-24 20:49:59.570; 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-1366850990297\nodes_used_= collection_shard1_replica2\data\ [junit4:junit4] 1> INFO - 2013-04-24 20:49:59.570; 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-1366850990297\node= s_used_collection_shard1_replica2\data\index/ [junit4:junit4] 1> WARN - 2013-04-24 20:49:59.571; 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= 6850990297\nodes_used_collection_shard1_replica2\data\index' doesn't exist.= Creating new index... [junit4:junit4] 1> INFO - 2013-04-24 20:49:59.571; 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-1366850987076\nodes= _used_collection_shard2_replica2\data\index [junit4:junit4] 1> INFO - 2013-04-24 20:49:59.574; org.apache.solr.core.= SolrDeletionPolicy; SolrDeletionPolicy.onCommit: commits: num=3D1 [junit4:junit4] 1> =09commit{dir=3DMockDirWrapper(org.apache.lucene.store= .RAMDirectory@7a07af lockFactory=3Dorg.apache.lucene.store.NativeFSLockFact= ory@2bff38),segFN=3Dsegments_1,generation=3D1} [junit4:junit4] 1> INFO - 2013-04-24 20:49:59.577; org.apache.solr.core.= SolrDeletionPolicy; newest commit generation =3D 1 [junit4:junit4] 1> INFO - 2013-04-24 20:49:59.581; 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-1366850990297\nodes_used_= collection_shard1_replica2\data\index [junit4:junit4] 1> INFO - 2013-04-24 20:49:59.584; org.apache.solr.core.= SolrDeletionPolicy; SolrDeletionPolicy.onCommit: commits: num=3D1 [junit4:junit4] 1> =09commit{dir=3DMockDirWrapper(org.apache.lucene.store= .RAMDirectory@e8cc3b lockFactory=3Dorg.apache.lucene.store.NativeFSLockFact= ory@125bd40),segFN=3Dsegments_1,generation=3D1} [junit4:junit4] 1> INFO - 2013-04-24 20:49:59.585; org.apache.solr.schem= a.FileExchangeRateProvider; Reloading exchange rates from file currency.xml [junit4:junit4] 1> INFO - 2013-04-24 20:49:59.585; org.apache.solr.core.= SolrDeletionPolicy; newest commit generation =3D 1 [junit4:junit4] 1> INFO - 2013-04-24 20:49:59.603; org.apache.solr.updat= e.processor.UpdateRequestProcessorChain; inserting DistributedUpdateProcess= orFactory into updateRequestProcessorChain "dedupe" [junit4:junit4] 1> INFO - 2013-04-24 20:49:59.603; org.apache.solr.updat= e.processor.UpdateRequestProcessorChain; inserting DistributedUpdateProcess= orFactory into updateRequestProcessorChain "stored_sig" [junit4:junit4] 1> INFO - 2013-04-24 20:49:59.605; org.apache.solr.updat= e.processor.UpdateRequestProcessorChain; inserting DistributedUpdateProcess= orFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit= " [junit4:junit4] 1> INFO - 2013-04-24 20:49:59.606; org.apache.solr.core.= RequestHandlers; created standard: solr.StandardRequestHandler [junit4:junit4] 1> INFO - 2013-04-24 20:49:59.606; org.apache.solr.schem= a.FileExchangeRateProvider; Reloading exchange rates from file currency.xml [junit4:junit4] 1> INFO - 2013-04-24 20:49:59.607; org.apache.solr.core.= RequestHandlers; created /get: solr.RealTimeGetHandler [junit4:junit4] 1> INFO - 2013-04-24 20:49:59.611; org.apache.solr.core.= RequestHandlers; adding lazy requestHandler: solr.ReplicationHandler [junit4:junit4] 1> INFO - 2013-04-24 20:49:59.611; org.apache.solr.core.= RequestHandlers; created /replication: solr.ReplicationHandler [junit4:junit4] 1> INFO - 2013-04-24 20:49:59.612; org.apache.solr.core.= RequestHandlers; created /update: solr.UpdateRequestHandler [junit4:junit4] 1> INFO - 2013-04-24 20:49:59.613; org.apache.solr.core.= RequestHandlers; created /admin/: org.apache.solr.handler.admin.AdminHandle= rs [junit4:junit4] 1> INFO - 2013-04-24 20:49:59.615; org.apache.solr.schem= a.OpenExchangeRatesOrgProvider; Reloading exchange rates from open-exchange= -rates.json [junit4:junit4] 1> WARN - 2013-04-24 20:49:59.618; org.apache.solr.schem= a.OpenExchangeRatesOrgProvider$OpenExchangeRates; Unknown key IMPORTANT NOT= E [junit4:junit4] 1> WARN - 2013-04-24 20:49:59.618; org.apache.solr.schem= a.OpenExchangeRatesOrgProvider$OpenExchangeRates; Expected key, got STRING [junit4:junit4] 1> INFO - 2013-04-24 20:49:59.618; org.apache.solr.schem= a.OpenExchangeRatesOrgProvider; Reloading exchange rates from open-exchange= -rates.json [junit4:junit4] 1> WARN - 2013-04-24 20:49:59.620; org.apache.solr.schem= a.OpenExchangeRatesOrgProvider$OpenExchangeRates; Unknown key IMPORTANT NOT= E [junit4:junit4] 1> WARN - 2013-04-24 20:49:59.620; org.apache.solr.schem= a.OpenExchangeRatesOrgProvider$OpenExchangeRates; Expected key, got STRING [junit4:junit4] 1> INFO - 2013-04-24 20:49:59.620; org.apache.solr.core.= SolrCore; org.apache.solr.core.MockDirectoryFactory [junit4:junit4] 1> INFO - 2013-04-24 20:49:59.621; 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-jetty4-1= 366850994522\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-jetty4-136685099452= 2\nodes_used_collection_shard2_replica1\data\ [junit4:junit4] 1> INFO - 2013-04-24 20:49:59.621; org.apache.solr.core.= JmxMonitoredMap; JMX monitoring is enabled. Adding Solr mbeans to JMX Serve= r: com.sun.jmx.mbeanserver.JmxMBeanServer@1b3bfc5 [junit4:junit4] 1> INFO - 2013-04-24 20:49:59.622; org.apache.solr.core.= SolrCore; org.apache.solr.core.MockDirectoryFactory [junit4:junit4] 1> INFO - 2013-04-24 20:49:59.623; org.apache.solr.updat= e.processor.UpdateRequestProcessorChain; inserting DistributedUpdateProcess= orFactory into updateRequestProcessorChain "dedupe" [junit4:junit4] 1> INFO - 2013-04-24 20:49:59.624; org.apache.solr.updat= e.processor.UpdateRequestProcessorChain; inserting DistributedUpdateProcess= orFactory into updateRequestProcessorChain "stored_sig" [junit4:junit4] 1> INFO - 2013-04-24 20:49:59.624; org.apache.solr.updat= e.processor.UpdateRequestProcessorChain; inserting DistributedUpdateProcess= orFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit= " [junit4:junit4] 1> INFO - 2013-04-24 20:49:59.625; org.apache.solr.core.= RequestHandlers; created standard: solr.StandardRequestHandler [junit4:junit4] 1> INFO - 2013-04-24 20:49:59.625; org.apache.solr.core.= RequestHandlers; created /get: solr.RealTimeGetHandler [junit4:junit4] 1> INFO - 2013-04-24 20:49:59.626; org.apache.solr.core.= RequestHandlers; adding lazy requestHandler: solr.ReplicationHandler [junit4:junit4] 1> INFO - 2013-04-24 20:49:59.626; org.apache.solr.core.= RequestHandlers; created /replication: solr.ReplicationHandler [junit4:junit4] 1> INFO - 2013-04-24 20:49:59.628; org.apache.solr.core.= RequestHandlers; created /update: solr.UpdateRequestHandler [junit4:junit4] 1> INFO - 2013-04-24 20:49:59.628; org.apache.solr.core.= RequestHandlers; created /admin/: org.apache.solr.handler.admin.AdminHandle= rs [junit4:junit4] 1> INFO - 2013-04-24 20:49:59.633; org.apache.solr.handl= er.loader.XMLLoader; xsltCacheLifetimeSeconds=3D60 [junit4:junit4] 1> INFO - 2013-04-24 20:49:59.633; org.apache.solr.handl= er.loader.XMLLoader; xsltCacheLifetimeSeconds=3D60 [junit4:junit4] 1> INFO - 2013-04-24 20:49:59.638; 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-1366850994522\nodes_used_= collection_shard2_replica1\data\ [junit4:junit4] 1> INFO - 2013-04-24 20:49:59.639; 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-1366850994522\node= s_used_collection_shard2_replica1\data\index/ [junit4:junit4] 1> WARN - 2013-04-24 20:49:59.639; 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-jetty4-136= 6850994522\nodes_used_collection_shard2_replica1\data\index' doesn't exist.= Creating new index... [junit4:junit4] 1> INFO - 2013-04-24 20:49:59.640; 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-1366850994522\nodes_used_= collection_shard2_replica1\data\index [junit4:junit4] 1> INFO - 2013-04-24 20:49:59.642; org.apache.solr.searc= h.SolrIndexSearcher; Opening Searcher@7a0eb0 main [junit4:junit4] 1> INFO - 2013-04-24 20:49:59.643; 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-1366850987076\nodes_u= sed_collection_shard2_replica2\data\tlog [junit4:junit4] 1> INFO - 2013-04-24 20:49:59.646; org.apache.solr.updat= e.CommitTracker; Hard AutoCommit: disabled [junit4:junit4] 1> INFO - 2013-04-24 20:49:59.647; org.apache.solr.updat= e.CommitTracker; Soft AutoCommit: disabled [junit4:junit4] 1> INFO - 2013-04-24 20:49:59.647; org.apache.solr.searc= h.SolrIndexSearcher; Opening Searcher@be736 main [junit4:junit4] 1> INFO - 2013-04-24 20:49:59.648; 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-jetty3-1366850992471\nodes_used_co= llection_shard1_replica1\data\tlog [junit4:junit4] 1> INFO - 2013-04-24 20:49:59.647; org.apache.solr.core.= SolrDeletionPolicy; SolrDeletionPolicy.onCommit: commits: num=3D1 [junit4:junit4] 1> =09commit{dir=3DMockDirWrapper(org.apache.lucene.store= .RAMDirectory@7a6ed6 lockFactory=3Dorg.apache.lucene.store.NativeFSLockFact= ory@1b052ab),segFN=3Dsegments_1,generation=3D1} [junit4:junit4] 1> INFO - 2013-04-24 20:49:59.649; org.apache.solr.core.= SolrDeletionPolicy; newest commit generation =3D 1 [junit4:junit4] 1> INFO - 2013-04-24 20:49:59.647; org.apache.solr.core.= SolrDeletionPolicy; SolrDeletionPolicy.onCommit: commits: num=3D1 [junit4:junit4] 1> =09commit{dir=3DMockDirWrapper(org.apache.lucene.store= .RAMDirectory@1abbdf0 lockFactory=3Dorg.apache.lucene.store.NativeFSLockFac= tory@12127b1),segFN=3Dsegments_1,generation=3D1} [junit4:junit4] 1> INFO - 2013-04-24 20:49:59.650; org.apache.solr.core.= SolrDeletionPolicy; newest commit generation =3D 1 [junit4:junit4] 1> INFO - 2013-04-24 20:49:59.653; org.apache.solr.updat= e.CommitTracker; Hard AutoCommit: disabled [junit4:junit4] 1> INFO - 2013-04-24 20:49:59.653; org.apache.solr.updat= e.CommitTracker; Soft AutoCommit: disabled [junit4:junit4] 1> INFO - 2013-04-24 20:49:59.657; org.apache.solr.updat= e.processor.UpdateRequestProcessorChain; inserting DistributedUpdateProcess= orFactory into updateRequestProcessorChain "dedupe" [junit4:junit4] 1> INFO - 2013-04-24 20:49:59.658; org.apache.solr.updat= e.processor.UpdateRequestProcessorChain; inserting DistributedUpdateProcess= orFactory into updateRequestProcessorChain "stored_sig" [junit4:junit4] 1> INFO - 2013-04-24 20:49:59.658; org.apache.solr.updat= e.processor.UpdateRequestProcessorChain; inserting DistributedUpdateProcess= orFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit= " [junit4:junit4] 1> INFO - 2013-04-24 20:49:59.659; org.apache.solr.updat= e.processor.UpdateRequestProcessorChain; inserting DistributedUpdateProcess= orFactory into updateRequestProcessorChain "dedupe" [junit4:junit4] 1> INFO - 2013-04-24 20:49:59.663; org.apache.solr.updat= e.processor.UpdateRequestProcessorChain; inserting DistributedUpdateProcess= orFactory into updateRequestProcessorChain "stored_sig" [junit4:junit4] 1> INFO - 2013-04-24 20:49:59.664; org.apache.solr.updat= e.processor.UpdateRequestProcessorChain; inserting DistributedUpdateProcess= orFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit= " [junit4:junit4] 1> INFO - 2013-04-24 20:49:59.664; org.apache.solr.core.= SolrCore; [nodes_used_collection_shard2_replica2] Registered new searcher S= earcher@7a0eb0 main{StandardDirectoryReader(segments_1:1)} [junit4:junit4] 1> INFO - 2013-04-24 20:49:59.665; org.apache.solr.core.= SolrCore; [nodes_used_collection_shard1_replica1] Registered new searcher S= earcher@be736 main{StandardDirectoryReader(segments_1:1)} [junit4:junit4] 1> INFO - 2013-04-24 20:49:59.660; org.apache.solr.core.= RequestHandlers; created standard: solr.StandardRequestHandler [junit4:junit4] 1> INFO - 2013-04-24 20:49:59.666; org.apache.solr.core.= RequestHandlers; created /get: solr.RealTimeGetHandler [junit4:junit4] 1> INFO - 2013-04-24 20:49:59.666; org.apache.solr.core.= RequestHandlers; adding lazy requestHandler: solr.ReplicationHandler [junit4:junit4] 1> INFO - 2013-04-24 20:49:59.667; org.apache.solr.core.= RequestHandlers; created /replication: solr.ReplicationHandler [junit4:junit4] 1> INFO - 2013-04-24 20:49:59.667; org.apache.solr.core.= RequestHandlers; created /update: solr.UpdateRequestHandler [junit4:junit4] 1> INFO - 2013-04-24 20:49:59.669; org.apache.solr.core.= RequestHandlers; created /admin/: org.apache.solr.handler.admin.AdminHandle= rs [junit4:junit4] 1> INFO - 2013-04-24 20:49:59.670; org.apache.solr.cloud= .ZkController; publishing core=3Dnodes_used_collection_shard1_replica1 stat= e=3Ddown [junit4:junit4] 1> INFO - 2013-04-24 20:49:59.664; org.apache.solr.core.= RequestHandlers; created standard: solr.StandardRequestHandler [junit4:junit4] 1> INFO - 2013-04-24 20:49:59.672; org.apache.solr.core.= RequestHandlers; created /get: solr.RealTimeGetHandler [junit4:junit4] 1> INFO - 2013-04-24 20:49:59.673; org.apache.solr.core.= RequestHandlers; adding lazy requestHandler: solr.ReplicationHandler [junit4:junit4] 1> INFO - 2013-04-24 20:49:59.675; org.apache.solr.core.= RequestHandlers; created /replication: solr.ReplicationHandler [junit4:junit4] 1> INFO - 2013-04-24 20:49:59.676; org.apache.solr.core.= RequestHandlers; created /update: solr.UpdateRequestHandler [junit4:junit4] 1> INFO - 2013-04-24 20:49:59.677; org.apache.solr.core.= RequestHandlers; created /admin/: org.apache.solr.handler.admin.AdminHandle= rs [junit4:junit4] 1> INFO - 2013-04-24 20:49:59.667; org.apache.solr.cloud= .ZkController; publishing core=3Dnodes_used_collection_shard2_replica2 stat= e=3Ddown [junit4:junit4] 1> INFO - 2013-04-24 20:49:59.683; org.apache.solr.handl= er.loader.XMLLoader; xsltCacheLifetimeSeconds=3D60 [junit4:junit4] 1> INFO - 2013-04-24 20:49:59.684; org.apache.solr.handl= er.loader.XMLLoader; xsltCacheLifetimeSeconds=3D60 [junit4:junit4] 1> INFO - 2013-04-24 20:49:59.694; org.apache.solr.searc= h.SolrIndexSearcher; Opening Searcher@f6cc37 main [junit4:junit4] 1> INFO - 2013-04-24 20:49:59.695; org.apache.solr.searc= h.SolrIndexSearcher; Opening Searcher@18323e6 main [junit4:junit4] 1> INFO - 2013-04-24 20:49:59.695; 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-1366850994522\nodes_used_co= llection_shard2_replica1\data\tlog [junit4:junit4] 1> INFO - 2013-04-24 20:49:59.697; 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-1366850990297\nodes_used_co= llection_shard1_replica2\data\tlog [junit4:junit4] 1> INFO - 2013-04-24 20:49:59.698; org.apache.solr.updat= e.CommitTracker; Hard AutoCommit: disabled [junit4:junit4] 1> INFO - 2013-04-24 20:49:59.699; org.apache.solr.updat= e.CommitTracker; Soft AutoCommit: disabled [junit4:junit4] 1> INFO - 2013-04-24 20:49:59.700; org.apache.solr.updat= e.CommitTracker; Hard AutoCommit: disabled [junit4:junit4] 1> INFO - 2013-04-24 20:49:59.700; org.apache.solr.updat= e.CommitTracker; Soft AutoCommit: disabled [junit4:junit4] 1> INFO - 2013-04-24 20:49:59.705; org.apache.solr.core.= SolrCore; [nodes_used_collection_shard2_replica1] Registered new searcher S= earcher@f6cc37 main{StandardDirectoryReader(segments_1:1)} [junit4:junit4] 1> INFO - 2013-04-24 20:49:59.706; org.apache.solr.cloud= .ZkController; publishing core=3Dnodes_used_collection_shard2_replica1 stat= e=3Ddown [junit4:junit4] 1> INFO - 2013-04-24 20:49:59.707; org.apache.solr.core.= SolrCore; [nodes_used_collection_shard1_replica2] Registered new searcher S= earcher@18323e6 main{StandardDirectoryReader(segments_1:1)} [junit4:junit4] 1> INFO - 2013-04-24 20:49:59.706; org.apache.solr.cloud= .ZkController; publishing core=3Dnodes_used_collection_shard1_replica2 stat= e=3Ddown [junit4:junit4] 1> INFO - 2013-04-24 20:50:00.561; org.apache.solr.commo= n.cloud.ZkStateReader; Updating cloud state from ZooKeeper...=20 [junit4:junit4] 1> INFO - 2013-04-24 20:50:00.562; 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:65483_", [junit4:junit4] 1> "base_url":"http://127.0.0.1:65483"} [junit4:junit4] 1> INFO - 2013-04-24 20:50:00.563; org.apache.solr.cloud= .Overseer$ClusterStateUpdater; Create collection nodes_used_collection with= numShards 2 [junit4:junit4] 1> INFO - 2013-04-24 20:50:00.570; 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:65453_", [junit4:junit4] 1> "base_url":"http://127.0.0.1:65453"} [junit4:junit4] 1> INFO - 2013-04-24 20:50:00.578; 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:65492_", [junit4:junit4] 1> "base_url":"http://127.0.0.1:65492"} [junit4:junit4] 1> INFO - 2013-04-24 20:50:00.588; 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:65474_", [junit4:junit4] 1> "base_url":"http://127.0.0.1:65474"} [junit4:junit4] 1> INFO - 2013-04-24 20:50:00.598; 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-24 20:50:00.599; 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-24 20:50:00.599; 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-24 20:50:00.599; 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-24 20:50:00.600; 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-24 20:50:00.600; 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-24 20:50:00.766; org.apache.solr.core.= CoreContainer; registering core: nodes_used_collection_shard1_replica1 [junit4:junit4] 1> INFO - 2013-04-24 20:50:00.766; org.apache.solr.cloud= .ZkController; Register replica - core:nodes_used_collection_shard1_replica= 1 address:http://127.0.0.1:65483 collection:nodes_used_collection shard:sha= rd1 [junit4:junit4] 1> INFO - 2013-04-24 20:50:00.768; org.apache.solr.core.= CoreContainer; registering core: nodes_used_collection_shard2_replica2 [junit4:junit4] 1> INFO - 2013-04-24 20:50:00.768; org.apache.solr.cloud= .ZkController; Register replica - core:nodes_used_collection_shard2_replica= 2 address:http://127.0.0.1:65453 collection:nodes_used_collection shard:sha= rd2 [junit4:junit4] 1> INFO - 2013-04-24 20:50:00.769; org.apache.solr.commo= n.cloud.SolrZkClient; makePath: /collections/nodes_used_collection/leader_e= lect/shard1/election [junit4:junit4] 1> INFO - 2013-04-24 20:50:00.771; org.apache.solr.commo= n.cloud.SolrZkClient; makePath: /collections/nodes_used_collection/leader_e= lect/shard2/election [junit4:junit4] 1> INFO - 2013-04-24 20:50:00.782; org.apache.solr.core.= CoreContainer; registering core: nodes_used_collection_shard2_replica1 [junit4:junit4] 1> INFO - 2013-04-24 20:50:00.782; org.apache.solr.cloud= .ZkController; Register replica - core:nodes_used_collection_shard2_replica= 1 address:http://127.0.0.1:65492 collection:nodes_used_collection shard:sha= rd2 [junit4:junit4] 1> INFO - 2013-04-24 20:50:00.784; org.apache.solr.core.= CoreContainer; registering core: nodes_used_collection_shard1_replica2 [junit4:junit4] 1> INFO - 2013-04-24 20:50:00.785; org.apache.solr.cloud= .ZkController; Register replica - core:nodes_used_collection_shard1_replica= 2 address:http://127.0.0.1:65474 collection:nodes_used_collection shard:sha= rd1 [junit4:junit4] 1> INFO - 2013-04-24 20:50:00.786; org.apache.solr.commo= n.cloud.SolrZkClient; makePath: /collections/nodes_used_collection/leader_e= lect/shard2/election [junit4:junit4] 1> INFO - 2013-04-24 20:50:00.803; org.apache.solr.cloud= .ShardLeaderElectionContext; Running the leader process. [junit4:junit4] 1> INFO - 2013-04-24 20:50:00.806; org.apache.solr.cloud= .ShardLeaderElectionContext; Running the leader process. [junit4:junit4] 1> INFO - 2013-04-24 20:50:00.817; org.apache.solr.cloud= .ShardLeaderElectionContext; Enough replicas found to continue. [junit4:junit4] 1> INFO - 2013-04-24 20:50:00.818; org.apache.solr.cloud= .ShardLeaderElectionContext; I may be the new leader - try and sync [junit4:junit4] 1> INFO - 2013-04-24 20:50:00.818; org.apache.solr.cloud= .SyncStrategy; Sync replicas to http://127.0.0.1:65453/nodes_used_collectio= n_shard2_replica2/ [junit4:junit4] 1> INFO - 2013-04-24 20:50:00.818; org.apache.solr.cloud= .ShardLeaderElectionContext; Enough replicas found to continue. [junit4:junit4] 1> INFO - 2013-04-24 20:50:00.820; org.apache.solr.cloud= .ShardLeaderElectionContext; I may be the new leader - try and sync [junit4:junit4] 1> INFO - 2013-04-24 20:50:00.820; org.apache.solr.cloud= .SyncStrategy; Sync replicas to http://127.0.0.1:65474/nodes_used_collectio= n_shard1_replica2/ [junit4:junit4] 1> INFO - 2013-04-24 20:50:00.819; org.apache.solr.updat= e.PeerSync; PeerSync: core=3Dnodes_used_collection_shard2_replica2 url=3Dht= tp://127.0.0.1:65453 START replicas=3D[http://127.0.0.1:65492/nodes_used_co= llection_shard2_replica1/] nUpdates=3D100 [junit4:junit4] 1> INFO - 2013-04-24 20:50:00.821; org.apache.solr.updat= e.PeerSync; PeerSync: core=3Dnodes_used_collection_shard1_replica2 url=3Dht= tp://127.0.0.1:65474 START replicas=3D[http://127.0.0.1:65483/nodes_used_co= llection_shard1_replica1/] nUpdates=3D100 [junit4:junit4] 1> INFO - 2013-04-24 20:50:00.822; org.apache.solr.updat= e.PeerSync; PeerSync: core=3Dnodes_used_collection_shard2_replica2 url=3Dht= tp://127.0.0.1:65453 DONE. We have no versions. sync failed. [junit4:junit4] 1> INFO - 2013-04-24 20:50:00.822; 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-24 20:50:00.824; 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-24 20:50:00.826; org.apache.solr.cloud= .ShardLeaderElectionContext; I am the new leader: http://127.0.0.1:65453/no= des_used_collection_shard2_replica2/ [junit4:junit4] 1> INFO - 2013-04-24 20:50:00.826; org.apache.solr.commo= n.cloud.SolrZkClient; makePath: /collections/nodes_used_collection/leaders/= shard2 [junit4:junit4] 1> INFO - 2013-04-24 20:50:00.827; org.apache.solr.updat= e.PeerSync; PeerSync: core=3Dnodes_used_collection_shard1_replica2 url=3Dht= tp://127.0.0.1:65474 DONE. We have no versions. sync failed. [junit4:junit4] 1> INFO - 2013-04-24 20:50:00.827; 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-24 20:50:00.827; 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-24 20:50:00.829; org.apache.solr.cloud= .ShardLeaderElectionContext; I am the new leader: http://127.0.0.1:65474/no= des_used_collection_shard1_replica2/ [junit4:junit4] 1> INFO - 2013-04-24 20:50:00.829; org.apache.solr.commo= n.cloud.SolrZkClient; makePath: /collections/nodes_used_collection/leaders/= shard1 [junit4:junit4] 1> INFO - 2013-04-24 20:50:00.841; 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=3D2=20 [junit4:junit4] 1> INFO - 2013-04-24 20:50:00.851; org.apache.solr.core.= SolrCore; [nodes_used_collection_shard1_replica1] webapp=3D path=3D/get par= ams=3D{getVersions=3D100&distrib=3Dfalse&wt=3Djavabin&qt=3D/get&version=3D2= } status=3D0 QTime=3D0=20 [junit4:junit4] 1> INFO - 2013-04-24 20:50:02.238; org.apache.solr.commo= n.cloud.ZkStateReader; Updating cloud state from ZooKeeper...=20 [junit4:junit4] 1> INFO - 2013-04-24 20:50:02.283; 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-24 20:50:02.284; 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-24 20:50:02.284; 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-24 20:50:02.284; 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-24 20:50:02.284; 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-24 20:50:02.284; 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-24 20:50:02.294; org.apache.solr.cloud= .ZkController; We are http://127.0.0.1:65474/nodes_used_collection_shard1_r= eplica2/ and leader is http://127.0.0.1:65474/nodes_used_collection_shard1_= replica2/ [junit4:junit4] 1> INFO - 2013-04-24 20:50:02.295; org.apache.solr.cloud= .ZkController; No LogReplay needed for core=3Dnodes_used_collection_shard1_= replica2 baseURL=3Dhttp://127.0.0.1:65474 [junit4:junit4] 1> INFO - 2013-04-24 20:50:02.296; org.apache.solr.cloud= .ZkController; I am the leader, no recovery necessary [junit4:junit4] 1> INFO - 2013-04-24 20:50:02.296; org.apache.solr.cloud= .ZkController; publishing core=3Dnodes_used_collection_shard1_replica2 stat= e=3Dactive [junit4:junit4] 1> INFO - 2013-04-24 20:50:02.299; org.apache.solr.commo= n.cloud.ZkStateReader; Updating cloud state from ZooKeeper...=20 [junit4:junit4] 1> INFO - 2013-04-24 20:50:02.301; 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=3D5734=20 [junit4:junit4] 1> INFO - 2013-04-24 20:50:02.316; org.apache.solr.cloud= .ZkController; We are http://127.0.0.1:65483/nodes_used_collection_shard1_r= eplica1/ and leader is http://127.0.0.1:65474/nodes_used_collection_shard1_= replica2/ [junit4:junit4] 1> INFO - 2013-04-24 20:50:02.316; org.apache.solr.cloud= .ZkController; No LogReplay needed for core=3Dnodes_used_collection_shard1_= replica1 baseURL=3Dhttp://127.0.0.1:65483 [junit4:junit4] 1> INFO - 2013-04-24 20:50:02.316; org.apache.solr.cloud= .ZkController; Core needs to recover:nodes_used_collection_shard1_replica1 [junit4:junit4] 1> INFO - 2013-04-24 20:50:02.317; org.apache.solr.updat= e.DefaultSolrCoreState; Running recovery - first canceling any ongoing reco= very [junit4:junit4] 1> INFO - 2013-04-24 20:50:02.318; org.apache.solr.cloud= .RecoveryStrategy; Starting recovery process. core=3Dnodes_used_collection= _shard1_replica1 recoveringAfterStartup=3Dtrue [junit4:junit4] 1> INFO - 2013-04-24 20:50:02.318; org.apache.solr.cloud= .RecoveryStrategy; ###### startupVersions=3D[] [junit4:junit4] 1> INFO - 2013-04-24 20:50:02.319; org.apache.solr.cloud= .ZkController; publishing core=3Dnodes_used_collection_shard1_replica1 stat= e=3Drecovering [junit4:junit4] 1> INFO - 2013-04-24 20:50:02.320; org.apache.solr.commo= n.cloud.ZkStateReader; Updating cloud state from ZooKeeper...=20 [junit4:junit4] 1> INFO - 2013-04-24 20:50:02.322; 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-24 20:50:02.324; 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=3D5756=20 [junit4:junit4] 1> INFO - 2013-04-24 20:50:02.327; org.apache.solr.cloud= .ZkController; We are http://127.0.0.1:65492/nodes_used_collection_shard2_r= eplica1/ and leader is http://127.0.0.1:65453/nodes_used_collection_shard2_= replica2/ [junit4:junit4] 1> INFO - 2013-04-24 20:50:02.327; org.apache.solr.cloud= .ZkController; No LogReplay needed for core=3Dnodes_used_collection_shard2_= replica1 baseURL=3Dhttp://127.0.0.1:65492 [junit4:junit4] 1> INFO - 2013-04-24 20:50:02.328; org.apache.solr.cloud= .ZkController; Core needs to recover:nodes_used_collection_shard2_replica1 [junit4:junit4] 1> INFO - 2013-04-24 20:50:02.328; org.apache.solr.updat= e.DefaultSolrCoreState; Running recovery - first canceling any ongoing reco= very [junit4:junit4] 1> INFO - 2013-04-24 20:50:02.330; org.apache.solr.commo= n.cloud.ZkStateReader; Updating cloud state from ZooKeeper...=20 [junit4:junit4] 1> INFO - 2013-04-24 20:50:02.331; org.apache.solr.cloud= .RecoveryStrategy; Starting recovery process. core=3Dnodes_used_collection= _shard2_replica1 recoveringAfterStartup=3Dtrue [junit4:junit4] 1> INFO - 2013-04-24 20:50:02.331; org.apache.solr.cloud= .RecoveryStrategy; ###### startupVersions=3D[] [junit4:junit4] 1> INFO - 2013-04-24 20:50:02.333; org.apache.solr.cloud= .ZkController; publishing core=3Dnodes_used_collection_shard2_replica1 stat= e=3Drecovering [junit4:junit4] 1> INFO - 2013-04-24 20:50:02.333; 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=3D5767=20 [junit4:junit4] 1> INFO - 2013-04-24 20:50:02.338; 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-24 20:50:02.340; org.apache.solr.handl= er.admin.CoreAdminHandler; Going to wait for coreNodeName: 127.0.0.1:65483_= _nodes_used_collection_shard1_replica1, state: recovering, checkLive: true,= onlyIfLeader: true [junit4:junit4] 1> INFO - 2013-04-24 20:50:02.349; org.apache.solr.cloud= .ZkController; We are http://127.0.0.1:65453/nodes_used_collection_shard2_r= eplica2/ and leader is http://127.0.0.1:65453/nodes_used_collection_shard2_= replica2/ [junit4:junit4] 1> INFO - 2013-04-24 20:50:02.350; org.apache.solr.cloud= .ZkController; No LogReplay needed for core=3Dnodes_used_collection_shard2_= replica2 baseURL=3Dhttp://127.0.0.1:65453 [junit4:junit4] 1> INFO - 2013-04-24 20:50:02.350; org.apache.solr.cloud= .ZkController; I am the leader, no recovery necessary [junit4:junit4] 1> INFO - 2013-04-24 20:50:02.351; org.apache.solr.cloud= .ZkController; publishing core=3Dnodes_used_collection_shard2_replica2 stat= e=3Dactive [junit4:junit4] 1> INFO - 2013-04-24 20:50:02.351; org.apache.solr.handl= er.admin.CoreAdminHandler; Going to wait for coreNodeName: 127.0.0.1:65492_= _nodes_used_collection_shard2_replica1, state: recovering, checkLive: true,= onlyIfLeader: true [junit4:junit4] 1> INFO - 2013-04-24 20:50:02.356; org.apache.solr.commo= n.cloud.ZkStateReader; Updating cloud state from ZooKeeper...=20 [junit4:junit4] 1> INFO - 2013-04-24 20:50:02.357; 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=3D5789=20 [junit4:junit4] 1> INFO - 2013-04-24 20:50:02.358; org.apache.solr.cloud= .OverseerCollectionProcessor; Finished create command on all shards for col= lection: nodes_used_collection [junit4:junit4] 1> INFO - 2013-04-24 20:50:02.362; 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-24 20:50:02.365; 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-24 20:50:02.366; 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=3D5734},core=3Dnodes_used_collect= ion_shard1_replica2},null=3D{responseHeader=3D{status=3D0,QTime=3D5756},cor= e=3Dnodes_used_collection_shard1_replica1},null=3D{responseHeader=3D{status= =3D0,QTime=3D5767},core=3Dnodes_used_collection_shard2_replica1},null=3D{re= sponseHeader=3D{status=3D0,QTime=3D5789},core=3Dnodes_used_collection_shard= 2_replica2}}} [junit4:junit4] 1> INFO - 2013-04-24 20:50:02.368; 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=3D5820=20 [junit4:junit4] 1> INFO - 2013-04-24 20:50:02.369; org.apache.solr.clien= t.solrj.impl.HttpClientUtil; Creating new http client, config: [junit4:junit4] 1> INFO - 2013-04-24 20:50:02.372; org.apache.solr.commo= n.cloud.ConnectionManager; Waiting for client to connect to ZooKeeper [junit4:junit4] 1> INFO - 2013-04-24 20:50:02.377; org.apache.solr.commo= n.cloud.ConnectionManager; Watcher org.apache.solr.common.cloud.ConnectionM= anager@d01b83 name:ZooKeeperConnection Watcher:127.0.0.1:65446/solr got eve= nt WatchedEvent state:SyncConnected type:None path:null path:null type:None [junit4:junit4] 1> INFO - 2013-04-24 20:50:02.378; org.apache.solr.commo= n.cloud.ConnectionManager; Client is connected to ZooKeeper [junit4:junit4] 1> INFO - 2013-04-24 20:50:02.379; org.apache.solr.commo= n.cloud.ZkStateReader; Updating cluster state from ZooKeeper...=20 [junit4:junit4] 1> INFO - 2013-04-24 20:50:02.384; org.apache.solr.clien= t.solrj.impl.HttpClientUtil; Creating new http client, config: [junit4:junit4] 1> INFO - 2013-04-24 20:50:02.387; org.apache.solr.commo= n.cloud.ConnectionManager; Waiting for client to connect to ZooKeeper [junit4:junit4] 1> INFO - 2013-04-24 20:50:02.391; org.apache.solr.commo= n.cloud.ConnectionManager; Watcher org.apache.solr.common.cloud.ConnectionM= anager@b97122 name:ZooKeeperConnection Watcher:127.0.0.1:65446/solr got eve= nt WatchedEvent state:SyncConnected type:None path:null path:null type:None [junit4:junit4] 1> INFO - 2013-04-24 20:50:02.393; org.apache.solr.commo= n.cloud.ConnectionManager; Client is connected to ZooKeeper [junit4:junit4] 1> INFO - 2013-04-24 20:50:02.394; org.apache.solr.commo= n.cloud.ZkStateReader; Updating cluster state from ZooKeeper...=20 [junit4:junit4] 1> INFO - 2013-04-24 20:50:02.404; org.apache.solr.handl= er.admin.CollectionsHandler; Creating Collection : numShards=3D2&maxShardsP= erNode=3D3&name=3Dawholynewcollection_0&replicationFactor=3D5&action=3DCREA= TE&wt=3Djavabin&version=3D2 [junit4:junit4] 1> INFO - 2013-04-24 20:50:02.407; 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-24 20:50:02.410; 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":"2", [junit4:junit4] 1> "maxShardsPerNode":"3", [junit4:junit4] 1> "createNodeSet":null, [junit4:junit4] 1> "name":"awholynewcollection_0", [junit4:junit4] 1> "replicationFactor":"5"} [junit4:junit4] 1> INFO - 2013-04-24 20:50:02.410; 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:65465_ [junit4:junit4] 1> INFO - 2013-04-24 20:50:02.411; 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:65453_ [junit4:junit4] 1> INFO - 2013-04-24 20:50:02.411; 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:65483_ [junit4:junit4] 1> INFO - 2013-04-24 20:50:02.411; 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:65474_ [junit4:junit4] 1> INFO - 2013-04-24 20:50:02.412; 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:65492_ [junit4:junit4] 1> INFO - 2013-04-24 20:50:02.413; 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:65465_ [junit4:junit4] 1> INFO - 2013-04-24 20:50:02.413; 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-jetty1-1366850988332\awholynewcollection_0_shard1_replica1 [junit4:junit4] 1> INFO - 2013-04-24 20:50:02.415; org.apache.solr.cloud= .ZkController; Check for collection zkNode:awholynewcollection_0 [junit4:junit4] 1> INFO - 2013-04-24 20:50:02.416; 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-jetty2-1366850990297\awholynewcollection_0_shard1_replica4 [junit4:junit4] 1> INFO - 2013-04-24 20:50:02.416; org.apache.solr.cloud= .ZkController; Check for collection zkNode:awholynewcollection_0 [junit4:junit4] 1> INFO - 2013-04-24 20:50:02.417; org.apache.solr.cloud= .ZkController; Creating collection in ZooKeeper:awholynewcollection_0 [junit4:junit4] 1> INFO - 2013-04-24 20:50:02.417; org.apache.solr.cloud= .ZkController; Looking for collection configName [junit4:junit4] 1> INFO - 2013-04-24 20:50:02.415; 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:65453_ [junit4:junit4] 1> INFO - 2013-04-24 20:50:02.415; 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-controljetty-1366850987076\awholynewcollection_0_shard1_replica2 [junit4:junit4] 1> INFO - 2013-04-24 20:50:02.432; org.apache.solr.cloud= .ZkController; Check for collection zkNode:awholynewcollection_0 [junit4:junit4] 1> INFO - 2013-04-24 20:50:02.432; 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-jetty1-1366850988332\awholynewcollection_0_shard2_replica1 [junit4:junit4] 1> INFO - 2013-04-24 20:50:02.434; org.apache.solr.cloud= .ZkController; Check for collection zkNode:awholynewcollection_0 [junit4:junit4] 1> INFO - 2013-04-24 20:50:02.434; 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-controljetty-1366850987076\awholynewcollection_0_shard2_replica2 [junit4:junit4] 1> INFO - 2013-04-24 20:50:02.431; 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:65483_ [junit4:junit4] 1> INFO - 2013-04-24 20:50:02.430; org.apache.solr.cloud= .ZkController; Creating collection in ZooKeeper:awholynewcollection_0 [junit4:junit4] 1> INFO - 2013-04-24 20:50:02.430; 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-jetty4-1366850994522\awholynewcollection_0_shard1_replica5 [junit4:junit4] 1> INFO - 2013-04-24 20:50:02.437; org.apache.solr.cloud= .ZkController; Check for collection zkNode:awholynewcollection_0 [junit4:junit4] 1> INFO - 2013-04-24 20:50:02.415; 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-jetty3-1366850992471\awholynewcollection_0_shard1_replica3 [junit4:junit4] 1> INFO - 2013-04-24 20:50:02.438; org.apache.solr.cloud= .ZkController; Check for collection zkNode:awholynewcollection_0 [junit4:junit4] 1> INFO - 2013-04-24 20:50:02.439; 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-jetty3-1366850992471\awholynewcollection_0_shard2_replica3 [junit4:junit4] 1> INFO - 2013-04-24 20:50:02.437; 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:65474_ [junit4:junit4] 1> INFO - 2013-04-24 20:50:02.437; org.apache.solr.cloud= .ZkController; Looking for collection configName [junit4:junit4] 1> INFO - 2013-04-24 20:50:02.435; org.apache.solr.cloud= .ZkController; Creating collection in ZooKeeper:awholynewcollection_0 [junit4:junit4] 1> INFO - 2013-04-24 20:50:02.440; org.apache.solr.cloud= .ZkController; Looking for collection configName [junit4:junit4] 1> INFO - 2013-04-24 20:50:02.435; org.apache.solr.cloud= .ZkController; Check for collection zkNode:awholynewcollection_0 [junit4:junit4] 1> INFO - 2013-04-24 20:50:02.434; org.apache.solr.cloud= .ZkController; Creating collection in ZooKeeper:awholynewcollection_0 [junit4:junit4] 1> INFO - 2013-04-24 20:50:02.442; org.apache.solr.cloud= .ZkController; Looking for collection configName [junit4:junit4] 1> INFO - 2013-04-24 20:50:02.443; 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-jetty2-1366850990297\awholynewcollection_0_shard2_replica4 [junit4:junit4] 1> INFO - 2013-04-24 20:50:02.444; org.apache.solr.cloud= .ZkController; Check for collection zkNode:awholynewcollection_0 [junit4:junit4] 1> INFO - 2013-04-24 20:50:02.445; org.apache.solr.cloud= .ZkController; Only one config set found in zk - using it:conf1 [junit4:junit4] 1> INFO - 2013-04-24 20:50:02.445; org.apache.solr.commo= n.cloud.SolrZkClient; makePath: /collections/awholynewcollection_0 [junit4:junit4] 1> INFO - 2013-04-24 20:50:02.434; org.apache.solr.cloud= .ZkController; Only one config set found in zk - using it:conf1 [junit4:junit4] 1> INFO - 2013-04-24 20:50:02.446; org.apache.solr.commo= n.cloud.SolrZkClient; makePath: /collections/awholynewcollection_0 [junit4:junit4] 1> INFO - 2013-04-24 20:50:02.447; org.apache.solr.cloud= .ZkController; Only one config set found in zk - using it:conf1 [junit4:junit4] 1> INFO - 2013-04-24 20:50:02.447; org.apache.solr.commo= n.cloud.SolrZkClient; makePath: /collections/awholynewcollection_0 [junit4:junit4] 1> INFO - 2013-04-24 20:50:02.446; org.apache.solr.cloud= .ZkController; Only one config set found in zk - using it:conf1 [junit4:junit4] 1> INFO - 2013-04-24 20:50:02.448; org.apache.solr.commo= n.cloud.SolrZkClient; makePath: /collections/awholynewcollection_0 [junit4:junit4] 1> INFO - 2013-04-24 20:50:02.444; org.apache.solr.cloud= .ZkController; Creating collection in ZooKeeper:awholynewcollection_0 [junit4:junit4] 1> INFO - 2013-04-24 20:50:02.450; org.apache.solr.cloud= .ZkController; Looking for collection configName [junit4:junit4] 1> INFO - 2013-04-24 20:50:02.440; 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:65492_ [junit4:junit4] 1> INFO - 2013-04-24 20:50:02.440; org.apache.solr.cloud= .ZkController; Creating collection in ZooKeeper:awholynewcollection_0 [junit4:junit4] 1> INFO - 2013-04-24 20:50:02.453; org.apache.solr.cloud= .ZkController; Looking for collection configName [junit4:junit4] 1> INFO - 2013-04-24 20:50:02.439; org.apache.solr.cloud= .ZkController; Creating collection in ZooKeeper:awholynewcollection_0 [junit4:junit4] 1> INFO - 2013-04-24 20:50:02.454; org.apache.solr.cloud= .ZkController; Looking for collection configName [junit4:junit4] 1> INFO - 2013-04-24 20:50:02.439; org.apache.solr.cloud= .ZkController; Check for collection zkNode:awholynewcollection_0 [junit4:junit4] 1> INFO - 2013-04-24 20:50:02.446; org.apache.solr.cloud= .ZkController; Creating collection in ZooKeeper:awholynewcollection_0 [junit4:junit4] 1> INFO - 2013-04-24 20:50:02.460; org.apache.solr.cloud= .ZkController; Looking for collection configName [junit4:junit4] 1> INFO - 2013-04-24 20:50:02.459; org.apache.solr.cloud= .ZkController; Load collection config from:/collections/awholynewcollection= _0 [junit4:junit4] 1> INFO - 2013-04-24 20:50:02.462; org.apache.solr.cloud= .ZkController; Load collection config from:/collections/awholynewcollection= _0 [junit4:junit4] 1> INFO - 2013-04-24 20:50:02.463; org.apache.solr.commo= n.cloud.SolrZkClient; makePath: /collections/awholynewcollection_0 [junit4:junit4] 1> INFO - 2013-04-24 20:50:02.461; org.apache.solr.cloud= .ZkController; Load collection config from:/collections/awholynewcollection= _0 [junit4:junit4] 1> INFO - 2013-04-24 20:50:02.466; org.apache.solr.commo= n.cloud.SolrZkClient; makePath: /collections/awholynewcollection_0 [junit4:junit4] 1> INFO - 2013-04-24 20:50:02.461; 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-jetty4-1366850994522\awholynewcollection_0_shard2_replica5 [junit4:junit4] 1> INFO - 2013-04-24 20:50:02.468; org.apache.solr.cloud= .ZkController; Check for collection zkNode:awholynewcollection_0 [junit4:junit4] 1> INFO - 2013-04-24 20:50:02.469; 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-1366850988332\aw= holynewcollection_0_shard2_replica1\' [junit4:junit4] 1> INFO - 2013-04-24 20:50:02.470; org.apache.solr.commo= n.cloud.SolrZkClient; makePath: /collections/awholynewcollection_0 [junit4:junit4] 1> INFO - 2013-04-24 20:50:02.466; org.apache.solr.commo= n.cloud.SolrZkClient; makePath: /collections/awholynewcollection_0 [junit4:junit4] 1> INFO - 2013-04-24 20:50:02.475; org.apache.solr.cloud= .ZkController; Collection zkNode exists [junit4:junit4] 1> INFO - 2013-04-24 20:50:02.475; org.apache.solr.cloud= .ZkController; Load collection config from:/collections/awholynewcollection= _0 [junit4:junit4] 1> INFO - 2013-04-24 20:50:02.478; 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-1366850988332\aw= holynewcollection_0_shard1_replica1\' [junit4:junit4] 1> INFO - 2013-04-24 20:50:02.466; 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-1366850987= 076\awholynewcollection_0_shard1_replica2\' [junit4:junit4] 1> INFO - 2013-04-24 20:50:02.463; org.apache.solr.cloud= .ZkController; Load collection config from:/collections/awholynewcollection= _0 [junit4:junit4] 1> INFO - 2013-04-24 20:50:02.490; org.apache.solr.cloud= .ZkController; Load collection config from:/collections/awholynewcollection= _0 [junit4:junit4] 1> INFO - 2013-04-24 20:50:02.463; org.apache.solr.cloud= .ZkController; Collection zkNode exists [junit4:junit4] 1> INFO - 2013-04-24 20:50:02.493; org.apache.solr.cloud= .ZkController; Load collection config from:/collections/awholynewcollection= _0 [junit4:junit4] 1> INFO - 2013-04-24 20:50:02.496; org.apache.solr.cloud= .ZkController; Load collection config from:/collections/awholynewcollection= _0 [junit4:junit4] 1> INFO - 2013-04-24 20:50:02.498; 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-1366850994522\aw= holynewcollection_0_shard2_replica5\' [junit4:junit4] 1> INFO - 2013-04-24 20:50:02.515; org.apache.solr.cloud= .ZkController; Load collection config from:/collections/awholynewcollection= _0 [junit4:junit4] 1> INFO - 2013-04-24 20:50:02.516; org.apache.solr.cloud= .ZkController; Load collection config from:/collections/awholynewcollection= _0 [junit4:junit4] 1> INFO - 2013-04-24 20:50:02.520; 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-1366850990297\aw= holynewcollection_0_shard1_replica4\' [junit4:junit4] 1> INFO - 2013-04-24 20:50:02.539; 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-1366850992471\aw= holynewcollection_0_shard2_replica3\' [junit4:junit4] 1> INFO - 2013-04-24 20:50:02.542; 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-1366850987= 076\awholynewcollection_0_shard2_replica2\' [junit4:junit4] 1> INFO - 2013-04-24 20:50:02.543; 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-1366850992471\aw= holynewcollection_0_shard1_replica3\' [junit4:junit4] 1> INFO - 2013-04-24 20:50:02.608; 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-1366850994522\aw= holynewcollection_0_shard1_replica5\' [junit4:junit4] 1> INFO - 2013-04-24 20:50:02.629; 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-1366850990297\aw= holynewcollection_0_shard2_replica4\' [junit4:junit4] 1> INFO - 2013-04-24 20:50:02.638; org.apache.solr.core.= SolrConfig; Using Lucene MatchVersion: LUCENE_50 [junit4:junit4] 1> INFO - 2013-04-24 20:50:02.720; org.apache.solr.core.= SolrConfig; Using Lucene MatchVersion: LUCENE_50 [junit4:junit4] 1> INFO - 2013-04-24 20:50:02.731; org.apache.solr.core.= SolrConfig; Using Lucene MatchVersion: LUCENE_50 [junit4:junit4] 1> INFO - 2013-04-24 20:50:02.831; org.apache.solr.core.= SolrConfig; Loaded SolrConfig: solrconfig.xml [junit4:junit4] 1> INFO - 2013-04-24 20:50:02.838; org.apache.solr.core.= SolrConfig; Loaded SolrConfig: solrconfig.xml [junit4:junit4] 1> INFO - 2013-04-24 20:50:02.873; org.apache.solr.core.= SolrConfig; Using Lucene MatchVersion: LUCENE_50 [junit4:junit4] 1> INFO - 2013-04-24 20:50:02.975; org.apache.solr.core.= SolrConfig; Using Lucene MatchVersion: LUCENE_50 [junit4:junit4] 1> INFO - 2013-04-24 20:50:02.979; org.apache.solr.core.= SolrConfig; Using Lucene MatchVersion: LUCENE_50 [junit4:junit4] 1> INFO - 2013-04-24 20:50:03.012; org.apache.solr.schem= a.IndexSchema; Reading Solr Schema from schema.xml [junit4:junit4] 1> INFO - 2013-04-24 20:50:03.014; org.apache.solr.schem= a.IndexSchema; Reading Solr Schema from schema.xml [junit4:junit4] 1> INFO - 2013-04-24 20:50:03.020; org.apache.solr.schem= a.IndexSchema; Schema name=3Dtest [junit4:junit4] 1> INFO - 2013-04-24 20:50:03.029; org.apache.solr.core.= SolrConfig; Using Lucene MatchVersion: LUCENE_50 [junit4:junit4] 1> INFO - 2013-04-24 20:50:03.031; org.apache.solr.core.= SolrConfig; Using Lucene MatchVersion: LUCENE_50 [junit4:junit4] 1> INFO - 2013-04-24 20:50:03.089; org.apache.solr.core.= SolrConfig; Loaded SolrConfig: solrconfig.xml [junit4:junit4] 1> INFO - 2013-04-24 20:50:03.130; org.apache.solr.core.= SolrConfig; Loaded SolrConfig: solrconfig.xml [junit4:junit4] 1> INFO - 2013-04-24 20:50:03.233; org.apache.solr.core.= SolrConfig; Using Lucene MatchVersion: LUCENE_50 [junit4:junit4] 1> INFO - 2013-04-24 20:50:03.238; org.apache.solr.core.= SolrConfig; Using Lucene MatchVersion: LUCENE_50 [junit4:junit4] 1> INFO - 2013-04-24 20:50:03.297; org.apache.solr.schem= a.IndexSchema; Schema name=3Dtest [junit4:junit4] 1> INFO - 2013-04-24 20:50:03.375; org.apache.solr.schem= a.IndexSchema; Reading Solr Schema from schema.xml [junit4:junit4] 1> INFO - 2013-04-24 20:50:03.385; org.apache.solr.schem= a.IndexSchema; Schema name=3Dtest [junit4:junit4] 1> INFO - 2013-04-24 20:50:03.433; org.apache.solr.core.= SolrConfig; Loaded SolrConfig: solrconfig.xml [junit4:junit4] 1> INFO - 2013-04-24 20:50:03.465; org.apache.solr.schem= a.IndexSchema; Reading Solr Schema from schema.xml [junit4:junit4] 1> INFO - 2013-04-24 20:50:03.492; org.apache.solr.schem= a.IndexSchema; Reading Solr Schema from schema.xml [junit4:junit4] 1> INFO - 2013-04-24 20:50:03.504; org.apache.solr.schem= a.IndexSchema; Schema name=3Dtest [junit4:junit4] 1> INFO - 2013-04-24 20:50:03.521; org.apache.solr.core.= SolrConfig; Loaded SolrConfig: solrconfig.xml [junit4:junit4] 1> INFO - 2013-04-24 20:50:03.573; org.apache.solr.core.= SolrConfig; Loaded SolrConfig: solrconfig.xml [junit4:junit4] 1> INFO - 2013-04-24 20:50:03.642; org.apache.solr.schem= a.IndexSchema; Schema name=3Dtest [junit4:junit4] 1> INFO - 2013-04-24 20:50:03.650; org.apache.solr.schem= a.IndexSchema; Reading Solr Schema from schema.xml [junit4:junit4] 1> INFO - 2013-04-24 20:50:03.659; org.apache.solr.schem= a.IndexSchema; Reading Solr Schema from schema.xml [junit4:junit4] 1> INFO - 2013-04-24 20:50:03.682; org.apache.solr.core.= SolrConfig; Loaded SolrConfig: solrconfig.xml [junit4:junit4] 1> INFO - 2013-04-24 20:50:03.728; org.apache.solr.schem= a.IndexSchema; Reading Solr Schema from schema.xml [junit4:junit4] 1> INFO - 2013-04-24 20:50:03.736; org.apache.solr.core.= SolrConfig; Loaded SolrConfig: solrconfig.xml [junit4:junit4] 1> INFO - 2013-04-24 20:50:03.748; org.apache.solr.schem= a.IndexSchema; Schema name=3Dtest [junit4:junit4] 1> INFO - 2013-04-24 20:50:03.800; org.apache.solr.schem= a.IndexSchema; Reading Solr Schema from schema.xml [junit4:junit4] 1> INFO - 2013-04-24 20:50:03.802; org.apache.solr.schem= a.IndexSchema; Schema name=3Dtest [junit4:junit4] 1> INFO - 2013-04-24 20:50:03.822; org.apache.solr.schem= a.IndexSchema; Schema name=3Dtest [junit4:junit4] 1> INFO - 2013-04-24 20:50:03.827; org.apache.solr.schem= a.IndexSchema; Schema name=3Dtest [junit4:junit4] 1> INFO - 2013-04-24 20:50:03.949; org.apache.solr.core.= SolrConfig; Loaded SolrConfig: solrconfig.xml [junit4:junit4] 1> INFO - 2013-04-24 20:50:03.960; org.apache.solr.schem= a.IndexSchema; Reading Solr Schema from schema.xml [junit4:junit4] 1> INFO - 2013-04-24 20:50:04.009; org.apache.solr.schem= a.IndexSchema; Schema name=3Dtest [junit4:junit4] 1> INFO - 2013-04-24 20:50:04.024; org.apache.solr.commo= n.cloud.ZkStateReader; Updating cloud state from ZooKeeper...=20 [junit4:junit4] 1> INFO - 2013-04-24 20:50:04.030; 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:65474__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:65474_", [junit4:junit4] 1> "base_url":"http://127.0.0.1:65474"} [junit4:junit4] 1> INFO - 2013-04-24 20:50:04.072; 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:65483__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:65483_", [junit4:junit4] 1> "base_url":"http://127.0.0.1:65483"} [junit4:junit4] 1> INFO - 2013-04-24 20:50:04.111; 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:65492__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":"recovering", [junit4:junit4] 1> "shard_state":"active", [junit4:junit4] 1> "core":"nodes_used_collection_shard2_replica1", [junit4:junit4] 1> "collection":"nodes_used_collection", [junit4:junit4] 1> "shard_range":null, [junit4:junit4] 1> "node_name":"127.0.0.1:65492_", [junit4:junit4] 1> "base_url":"http://127.0.0.1:65492"} [junit4:junit4] 1> INFO - 2013-04-24 20:50:04.145; 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:65453__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:65453_", [junit4:junit4] 1> "base_url":"http://127.0.0.1:65453"} [junit4:junit4] 1> INFO - 2013-04-24 20:50:04.215; 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-24 20:50:04.215; 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-24 20:50:04.216; 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-24 20:50:04.216; 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-24 20:50:04.216; 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-24 20:50:04.217; 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-24 20:50:04.216; 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-24 20:50:04.217; 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-24 20:50:04.596; org.apache.solr.handl= er.admin.CoreAdminHandler; Waited coreNodeName: 127.0.0.1:65483__nodes_used= _collection_shard1_replica1, state: recovering, checkLive: true, onlyIfLead= er: true for: 2 seconds. [junit4:junit4] 1> INFO - 2013-04-24 20:50:04.714; org.apache.solr.servl= et.SolrDispatchFilter; [admin] webapp=3Dnull path=3D/admin/cores params=3D{= coreNodeName=3D127.0.0.1:65483__nodes_used_collection_shard1_replica1&state= =3Drecovering&nodeName=3D127.0.0.1:65483_&action=3DPREPRECOVERY&checkLive= =3Dtrue&core=3Dnodes_used_collection_shard1_replica2&wt=3Djavabin&onlyIfLea= der=3Dtrue&version=3D2} status=3D0 QTime=3D2374=20 [junit4:junit4] 1> INFO - 2013-04-24 20:50:04.596; org.apache.solr.handl= er.admin.CoreAdminHandler; Waited coreNodeName: 127.0.0.1:65492__nodes_used= _collection_shard2_replica1, state: recovering, checkLive: true, onlyIfLead= er: true for: 2 seconds. [junit4:junit4] 1> INFO - 2013-04-24 20:50:04.716; org.apache.solr.servl= et.SolrDispatchFilter; [admin] webapp=3Dnull path=3D/admin/cores params=3D{= coreNodeName=3D127.0.0.1:65492__nodes_used_collection_shard2_replica1&state= =3Drecovering&nodeName=3D127.0.0.1:65492_&action=3DPREPRECOVERY&checkLive= =3Dtrue&core=3Dnodes_used_collection_shard2_replica2&wt=3Djavabin&onlyIfLea= der=3Dtrue&version=3D2} status=3D0 QTime=3D2366=20 [junit4:junit4] 1> INFO - 2013-04-24 20:50:06.861; org.apache.solr.cloud= .RecoveryStrategy; Attempting to PeerSync from http://127.0.0.1:65474/nodes= _used_collection_shard1_replica2/ core=3Dnodes_used_collection_shard1_repli= ca1 - recoveringAfterStartup=3Dtrue [junit4:junit4] 1> INFO - 2013-04-24 20:50:06.862; org.apache.solr.updat= e.PeerSync; PeerSync: core=3Dnodes_used_collection_shard1_replica1 url=3Dht= tp://127.0.0.1:65483 START replicas=3D[http://127.0.0.1:65474/nodes_used_co= llection_shard1_replica2/] nUpdates=3D100 [junit4:junit4] 1> WARN - 2013-04-24 20:50:06.863; org.apache.solr.updat= e.PeerSync; no frame of reference to tell of we've missed updates [junit4:junit4] 1> INFO - 2013-04-24 20:50:06.863; 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-24 20:50:06.864; org.apache.solr.cloud= .RecoveryStrategy; Starting Replication Recovery. core=3Dnodes_used_collect= ion_shard1_replica1 [junit4:junit4] 1> INFO - 2013-04-24 20:50:06.864; org.apache.solr.cloud= .RecoveryStrategy; Begin buffering updates. core=3Dnodes_used_collection_sh= ard1_replica1 [junit4:junit4] 1> INFO - 2013-04-24 20:50:06.872; org.apache.solr.updat= e.UpdateLog; Starting to buffer updates. FSUpdateLog{state=3DACTIVE, tlog= =3Dnull} [junit4:junit4] 1> INFO - 2013-04-24 20:50:06.873; org.apache.solr.cloud= .RecoveryStrategy; Attempting to replicate from http://127.0.0.1:65474/node= s_used_collection_shard1_replica2/. core=3Dnodes_used_collection_shard1_rep= lica1 [junit4:junit4] 1> INFO - 2013-04-24 20:50:06.873; 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-24 20:50:06.884; org.apache.solr.cloud= .RecoveryStrategy; Attempting to PeerSync from http://127.0.0.1:65453/nodes= _used_collection_shard2_replica2/ core=3Dnodes_used_collection_shard2_repli= ca1 - recoveringAfterStartup=3Dtrue [junit4:junit4] 1> INFO - 2013-04-24 20:50:06.885; org.apache.solr.updat= e.PeerSync; PeerSync: core=3Dnodes_used_collection_shard2_replica1 url=3Dht= tp://127.0.0.1:65492 START replicas=3D[http://127.0.0.1:65453/nodes_used_co= llection_shard2_replica2/] nUpdates=3D100 [junit4:junit4] 1> WARN - 2013-04-24 20:50:06.887; org.apache.solr.updat= e.PeerSync; no frame of reference to tell of we've missed updates [junit4:junit4] 1> INFO - 2013-04-24 20:50:06.887; org.apache.solr.cloud= .RecoveryStrategy; PeerSync Recovery was not successful - trying replicatio= n. core=3Dnodes_used_collection_shard2_replica1 [junit4:junit4] 1> INFO - 2013-04-24 20:50:06.887; org.apache.solr.cloud= .RecoveryStrategy; Starting Replication Recovery. core=3Dnodes_used_collect= ion_shard2_replica1 [junit4:junit4] 1> INFO - 2013-04-24 20:50:06.888; org.apache.solr.cloud= .RecoveryStrategy; Begin buffering updates. core=3Dnodes_used_collection_sh= ard2_replica1 [junit4:junit4] 1> INFO - 2013-04-24 20:50:06.888; org.apache.solr.updat= e.UpdateLog; Starting to buffer updates. FSUpdateLog{state=3DACTIVE, tlog= =3Dnull} [junit4:junit4] 1> INFO - 2013-04-24 20:50:06.888; org.apache.solr.cloud= .RecoveryStrategy; Attempting to replicate from http://127.0.0.1:65453/node= s_used_collection_shard2_replica2/. core=3Dnodes_used_collection_shard2_rep= lica1 [junit4:junit4] 1> INFO - 2013-04-24 20:50:06.889; 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-24 20:50:06.951; 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=3D1=20 [junit4:junit4] 1> INFO - 2013-04-24 20:50:06.986; 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=3D19=20 [junit4:junit4] 1> INFO - 2013-04-24 20:50:07.095; 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-24 20:50:07.100; 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-24 20:50:07.107; org.apache.solr.core.= SolrDeletionPolicy; SolrDeletionPolicy.onInit: commits: num=3D1 [junit4:junit4] 1> =09commit{dir=3DMockDirWrapper(org.apache.lucene.store= .RAMDirectory@7a6ed6 lockFactory=3Dorg.apache.lucene.store.NativeFSLockFact= ory@1b052ab),segFN=3Dsegments_1,generation=3D1} [junit4:junit4] 1> INFO - 2013-04-24 20:50:07.144; org.apache.solr.core.= SolrDeletionPolicy; newest commit generation =3D 1 [junit4:junit4] 1> INFO - 2013-04-24 20:50:07.149; org.apache.solr.core.= SolrDeletionPolicy; SolrDeletionPolicy.onCommit: commits: num=3D2 [junit4:junit4] 1> =09commit{dir=3DMockDirWrapper(org.apache.lucene.store= .RAMDirectory@7a6ed6 lockFactory=3Dorg.apache.lucene.store.NativeFSLockFact= ory@1b052ab),segFN=3Dsegments_1,generation=3D1} [junit4:junit4] 1> =09commit{dir=3DMockDirWrapper(org.apache.lucene.store= .RAMDirectory@7a6ed6 lockFactory=3Dorg.apache.lucene.store.NativeFSLockFact= ory@1b052ab),segFN=3Dsegments_2,generation=3D2} [junit4:junit4] 1> INFO - 2013-04-24 20:50:07.153; org.apache.solr.core.= SolrDeletionPolicy; newest commit generation =3D 2 [junit4:junit4] 1> INFO - 2013-04-24 20:50:07.154; org.apache.solr.searc= h.SolrIndexSearcher; Opening Searcher@1a19e83 realtime [junit4:junit4] 1> INFO - 2013-04-24 20:50:07.154; org.apache.solr.updat= e.DirectUpdateHandler2; end_commit_flush [junit4:junit4] 1> INFO - 2013-04-24 20:50:07.156; 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 62 [junit4:junit4] 1> INFO - 2013-04-24 20:50:07.160; org.apache.solr.handl= er.ReplicationHandler; Commits will be reserved for 10000 [junit4:junit4] 1> INFO - 2013-04-24 20:50:07.160; org.apache.solr.handl= er.SnapPuller; No value set for 'pollInterval'. Timer Task not started. [junit4:junit4] 1> INFO - 2013-04-24 20:50:07.178; org.apache.solr.handl= er.ReplicationHandler; Commits will be reserved for 10000 [junit4:junit4] 1> INFO - 2013-04-24 20:50:07.179; 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=3D4=20 [junit4:junit4] 1> INFO - 2013-04-24 20:50:07.180; org.apache.solr.handl= er.SnapPuller; Master's generation: 2 [junit4:junit4] 1> INFO - 2013-04-24 20:50:07.180; org.apache.solr.handl= er.SnapPuller; Slave's generation: 1 [junit4:junit4] 1> INFO - 2013-04-24 20:50:07.180; org.apache.solr.handl= er.SnapPuller; Starting replication process [junit4:junit4] 1> INFO - 2013-04-24 20:50:07.186; 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=3D0=20 [junit4:junit4] 1> INFO - 2013-04-24 20:50:07.188; org.apache.solr.handl= er.SnapPuller; Number of files in latest index in master: 1 [junit4:junit4] 1> INFO - 2013-04-24 20:50:07.190; org.apache.solr.core.= SolrDeletionPolicy; SolrDeletionPolicy.onInit: commits: num=3D1 [junit4:junit4] 1> =09commit{dir=3DMockDirWrapper(org.apache.lucene.store= .RAMDirectory@e8cc3b lockFactory=3Dorg.apache.lucene.store.NativeFSLockFact= ory@125bd40),segFN=3Dsegments_1,generation=3D1} [junit4:junit4] 1> INFO - 2013-04-24 20:50:07.213; org.apache.solr.core.= SolrDeletionPolicy; newest commit generation =3D 1 [junit4:junit4] 1> INFO - 2013-04-24 20:50:07.222; 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-jetty3-1366850992471\nodes_used_= collection_shard1_replica1\data\index.20130425105007188 [junit4:junit4] 1> INFO - 2013-04-24 20:50:07.227; org.apache.solr.handl= er.SnapPuller; Starting download to MockDirWrapper(org.apache.lucene.store.= RAMDirectory@15c822 lockFactory=3Dorg.apache.lucene.store.NativeFSLockFacto= ry@df44b) fullCopy=3Dfalse [junit4:junit4] 1> INFO - 2013-04-24 20:50:07.232; org.apache.solr.core.= SolrDeletionPolicy; SolrDeletionPolicy.onCommit: commits: num=3D2 [junit4:junit4] 1> =09commit{dir=3DMockDirWrapper(org.apache.lucene.store= .RAMDirectory@e8cc3b lockFactory=3Dorg.apache.lucene.store.NativeFSLockFact= ory@125bd40),segFN=3Dsegments_1,generation=3D1} [junit4:junit4] 1> =09commit{dir=3DMockDirWrapper(org.apache.lucene.store= .RAMDirectory@e8cc3b lockFactory=3Dorg.apache.lucene.store.NativeFSLockFact= ory@125bd40),segFN=3Dsegments_2,generation=3D2} [junit4:junit4] 1> INFO - 2013-04-24 20:50:07.233; org.apache.solr.core.= SolrDeletionPolicy; newest commit generation =3D 2 [junit4:junit4] 1> INFO - 2013-04-24 20:50:07.234; org.apache.solr.searc= h.SolrIndexSearcher; Opening Searcher@158dcc4 realtime [junit4:junit4] 1> INFO - 2013-04-24 20:50:07.234; org.apache.solr.updat= e.DirectUpdateHandler2; end_commit_flush [junit4:junit4] 1> INFO - 2013-04-24 20:50:07.247; org.apache.solr.updat= e.processor.LogUpdateProcessor; [nodes_used_collection_shard2_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 149 [junit4:junit4] 1> INFO - 2013-04-24 20:50:07.240; 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=3D3=20 [junit4:junit4] 1> INFO - 2013-04-24 20:50:07.251; org.apache.solr.handl= er.ReplicationHandler; Commits will be reserved for 10000 [junit4:junit4] 1> INFO - 2013-04-24 20:50:07.251; org.apache.solr.handl= er.SnapPuller; No value set for 'pollInterval'. Timer Task not started. [junit4:junit4] 1> INFO - 2013-04-24 20:50:07.252; org.apache.solr.handl= er.SnapPuller; Total time taken for download : 0 secs [junit4:junit4] 1> INFO - 2013-04-24 20:50:07.263; org.apache.solr.handl= er.ReplicationHandler; Commits will be reserved for 10000 [junit4:junit4] 1> INFO - 2013-04-24 20:50:07.264; org.apache.solr.core.= SolrCore; [nodes_used_collection_shard2_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-24 20:50:07.265; org.apache.solr.updat= e.DefaultSolrCoreState; Creating new IndexWriter... [junit4:junit4] 1> INFO - 2013-04-24 20:50:07.266; org.apache.solr.updat= e.DefaultSolrCoreState; Waiting until IndexWriter is unused... core=3Dnodes= _used_collection_shard1_replica1 [junit4:junit4] 1> INFO - 2013-04-24 20:50:07.267; org.apache.solr.handl= er.SnapPuller; Master's generation: 2 [junit4:junit4] 1> INFO - 2013-04-24 20:50:07.267; org.apache.solr.handl= er.SnapPuller; Slave's generation: 1 [junit4:junit4] 1> INFO - 2013-04-24 20:50:07.268; org.apache.solr.handl= er.SnapPuller; Starting replication process [junit4:junit4] 1> INFO - 2013-04-24 20:50:07.273; org.apache.solr.core.= SolrCore; [nodes_used_collection_shard2_replica2] webapp=3D path=3D/replica= tion params=3D{command=3Dfilelist&qt=3D/replication&wt=3Djavabin&generation= =3D2&version=3D2} status=3D0 QTime=3D0=20 [junit4:junit4] 1> INFO - 2013-04-24 20:50:07.275; org.apache.solr.handl= er.SnapPuller; Number of files in latest index in master: 1 [junit4:junit4] 1> INFO - 2013-04-24 20:50:07.277; org.apache.solr.core.= SolrDeletionPolicy; SolrDeletionPolicy.onInit: commits: num=3D2 [junit4:junit4] 1> =09commit{dir=3DMockDirWrapper(org.apache.lucene.store= .RAMDirectory@7a07af lockFactory=3Dorg.apache.lucene.store.NativeFSLockFact= ory@2bff38),segFN=3Dsegments_1,generation=3D1} [junit4:junit4] 1> =09commit{dir=3DMockDirWrapper(org.apache.lucene.store= .RAMDirectory@7a07af lockFactory=3Dorg.apache.lucene.store.NativeFSLockFact= ory@2bff38),segFN=3Dsegments_2,generation=3D2} [junit4:junit4] 1> INFO - 2013-04-24 20:50:07.278; 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-1366850994522\nodes_used_= collection_shard2_replica1\data\index.20130425105007275 [junit4:junit4] 1> INFO - 2013-04-24 20:50:07.292; org.apache.solr.core.= SolrDeletionPolicy; newest commit generation =3D 2 [junit4:junit4] 1> INFO - 2013-04-24 20:50:07.302; org.apache.solr.updat= e.DefaultSolrCoreState; New IndexWriter is ready to be used. [junit4:junit4] 1> INFO - 2013-04-24 20:50:07.302; org.apache.solr.searc= h.SolrIndexSearcher; Opening Searcher@c1e830 main [junit4:junit4] 1> INFO - 2013-04-24 20:50:07.305; org.apache.solr.core.= SolrCore; [nodes_used_collection_shard1_replica1] Registered new searcher S= earcher@c1e830 main{StandardDirectoryReader(segments_2:1:nrt)} [junit4:junit4] 1> INFO - 2013-04-24 20:50:07.308; 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-jetty3-1366850992471\nodes_used_collecti= on_shard1_replica1\data\index.20130425105007188 [CachedDir<>] [junit4:junit4] 1> INFO - 2013-04-24 20:50:07.308; 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-jetty3-1366850992471\nodes_used_collec= tion_shard1_replica1\data\index.20130425105007188 [junit4:junit4] 1> INFO - 2013-04-24 20:50:07.310; 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-jetty3-136685099247= 1\nodes_used_collection_shard1_replica1\data\index.20130425105007188 [junit4:junit4] 1> INFO - 2013-04-24 20:50:07.312; org.apache.solr.cloud= .RecoveryStrategy; No replay needed. core=3Dnodes_used_collection_shard1_re= plica1 [junit4:junit4] 1> INFO - 2013-04-24 20:50:07.312; 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-24 20:50:07.313; org.apache.solr.cloud= .ZkController; publishing core=3Dnodes_used_collection_shard1_replica1 stat= e=3Dactive [junit4:junit4] 1> INFO - 2013-04-24 20:50:07.335; org.apache.solr.cloud= .RecoveryStrategy; Finished recovery process. core=3Dnodes_used_collection_= shard1_replica1 [junit4:junit4] 1> INFO - 2013-04-24 20:50:07.362; org.apache.solr.handl= er.SnapPuller; Starting download to MockDirWrapper(org.apache.lucene.store.= RAMDirectory@123feaf lockFactory=3Dorg.apache.lucene.store.NativeFSLockFact= ory@1424a66) fullCopy=3Dfalse [junit4:junit4] 1> INFO - 2013-04-24 20:50:07.369; org.apache.solr.core.= SolrCore; [nodes_used_collection_shard2_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-24 20:50:07.370; org.apache.solr.handl= er.SnapPuller; Total time taken for download : 0 secs [junit4:junit4] 1> INFO - 2013-04-24 20:50:07.377; org.apache.solr.updat= e.DefaultSolrCoreState; Creating new IndexWriter... [junit4:junit4] 1> INFO - 2013-04-24 20:50:07.378; org.apache.solr.updat= e.DefaultSolrCoreState; Waiting until IndexWriter is unused... core=3Dnodes= _used_collection_shard2_replica1 [junit4:junit4] 1> INFO - 2013-04-24 20:50:07.458; org.apache.solr.core.= SolrDeletionPolicy; SolrDeletionPolicy.onInit: commits: num=3D2 [junit4:junit4] 1> =09commit{dir=3DMockDirWrapper(org.apache.lucene.store= .RAMDirectory@1abbdf0 lockFactory=3Dorg.apache.lucene.store.NativeFSLockFac= tory@12127b1),segFN=3Dsegments_1,generation=3D1} [junit4:junit4] 1> =09commit{dir=3DMockDirWrapper(org.apache.lucene.store= .RAMDirectory@1abbdf0 lockFactory=3Dorg.apache.lucene.store.NativeFSLockFac= tory@12127b1),segFN=3Dsegments_2,generation=3D2} [junit4:junit4] 1> INFO - 2013-04-24 20:50:07.479; org.apache.solr.core.= SolrDeletionPolicy; newest commit generation =3D 2 [junit4:junit4] 1> INFO - 2013-04-24 20:50:07.479; org.apache.solr.updat= e.DefaultSolrCoreState; New IndexWriter is ready to be used. [junit4:junit4] 1> INFO - 2013-04-24 20:50:07.480; org.apache.solr.searc= h.SolrIndexSearcher; Opening Searcher@1f57fba main [junit4:junit4] 1> INFO - 2013-04-24 20:50:07.481; org.apache.solr.core.= SolrCore; [nodes_used_collection_shard2_replica1] Registered new searcher S= earcher@1f57fba main{StandardDirectoryReader(segments_2:1:nrt)} [junit4:junit4] 1> INFO - 2013-04-24 20:50:07.490; 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-1366850994522\nodes_used_collecti= on_shard2_replica1\data\index.20130425105007275 [CachedDir<>] [junit4:junit4] 1> INFO - 2013-04-24 20:50:07.491; 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-1366850994522\nodes_used_collec= tion_shard2_replica1\data\index.20130425105007275 [junit4:junit4] 1> INFO - 2013-04-24 20:50:07.491; 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-136685099452= 2\nodes_used_collection_shard2_replica1\data\index.20130425105007275 [junit4:junit4] 1> INFO - 2013-04-24 20:50:07.491; org.apache.solr.cloud= .RecoveryStrategy; No replay needed. core=3Dnodes_used_collection_shard2_re= plica1 [junit4:junit4] 1> INFO - 2013-04-24 20:50:07.491; org.apache.solr.cloud= .RecoveryStrategy; Replication Recovery was successful - registering as Act= ive. core=3Dnodes_used_collection_shard2_replica1 [junit4:junit4] 1> INFO - 2013-04-24 20:50:07.494; org.apache.solr.cloud= .ZkController; publishing core=3Dnodes_used_collection_shard2_replica1 stat= e=3Dactive [junit4:junit4] 1> INFO - 2013-04-24 20:50:07.503; org.apache.solr.cloud= .RecoveryStrategy; Finished recovery process. core=3Dnodes_used_collection_= shard2_replica1 [junit4:junit4] 1> INFO - 2013-04-24 20:50:08.321; org.apache.solr.schem= a.OpenExchangeRatesOrgProvider; Initialized with rates=3Dopen-exchange-rate= s.json, refreshInterval=3D1440. [junit4:junit4] 1> INFO - 2013-04-24 20:50:08.342; org.apache.solr.schem= a.OpenExchangeRatesOrgProvider; Initialized with rates=3Dopen-exchange-rate= s.json, refreshInterval=3D1440. [junit4:junit4] 1> INFO - 2013-04-24 20:50:08.353; org.apache.solr.schem= a.IndexSchema; default search field in schema is text [junit4:junit4] 1> INFO - 2013-04-24 20:50:08.359; org.apache.solr.schem= a.IndexSchema; unique key field: id [junit4:junit4] 1> INFO - 2013-04-24 20:50:08.373; org.apache.solr.schem= a.OpenExchangeRatesOrgProvider; Initialized with rates=3Dopen-exchange-rate= s.json, refreshInterval=3D1440. [junit4:junit4] 1> INFO - 2013-04-24 20:50:08.383; org.apache.solr.schem= a.IndexSchema; default search field in schema is text [junit4:junit4] 1> INFO - 2013-04-24 20:50:08.388; org.apache.solr.schem= a.IndexSchema; unique key field: id [junit4:junit4] 1> INFO - 2013-04-24 20:50:08.467; org.apache.solr.schem= a.IndexSchema; default search field in schema is text [junit4:junit4] 1> INFO - 2013-04-24 20:50:08.473; org.apache.solr.schem= a.IndexSchema; unique key field: id [junit4:junit4] 1> INFO - 2013-04-24 20:50:08.562; org.apache.solr.commo= n.cloud.ZkStateReader; Updating cloud state from ZooKeeper...=20 [junit4:junit4] 1> INFO - 2013-04-24 20:50:08.583; 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:65483__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:65483_", [junit4:junit4] 1> "base_url":"http://127.0.0.1:65483"} [junit4:junit4] 1> INFO - 2013-04-24 20:50:08.744; org.apache.solr.schem= a.OpenExchangeRatesOrgProvider; Initialized with rates=3Dopen-exchange-rate= s.json, refreshInterval=3D1440. [junit4:junit4] 1> INFO - 2013-04-24 20:50:08.754; org.apache.solr.schem= a.IndexSchema; default search field in schema is text [junit4:junit4] 1> INFO - 2013-04-24 20:50:08.760; org.apache.solr.schem= a.IndexSchema; unique key field: id [junit4:junit4] 1> INFO - 2013-04-24 20:50:08.876; 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:65492__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:65492_", [junit4:junit4] 1> "base_url":"http://127.0.0.1:65492"} [junit4:junit4] 1> INFO - 2013-04-24 20:50:08.907; org.apache.solr.schem= a.FileExchangeRateProvider; Reloading exchange rates from file currency.xml [junit4:junit4] 1> INFO - 2013-04-24 20:50:08.914; org.apache.solr.schem= a.FileExchangeRateProvider; Reloading exchange rates from file currency.xml [junit4:junit4] 1> INFO - 2013-04-24 20:50:08.933; 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-24 20:50:08.934; 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-24 20:50:08.934; 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-24 20:50:08.935; 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-24 20:50:08.935; 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-24 20:50:08.937; 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-24 20:50:08.937; 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-24 20:50:08.939; 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-24 20:50:08.947; org.apache.solr.schem= a.FileExchangeRateProvider; Reloading exchange rates from file currency.xml [junit4:junit4] 1> INFO - 2013-04-24 20:50:08.948; org.apache.solr.schem= a.FileExchangeRateProvider; Reloading exchange rates from file currency.xml [junit4:junit4] 1> INFO - 2013-04-24 20:50:08.979; org.apache.solr.schem= a.FileExchangeRateProvider; Reloading exchange rates from file currency.xml [junit4:junit4] 1> INFO - 2013-04-24 20:50:08.985; org.apache.solr.schem= a.FileExchangeRateProvider; Reloading exchange rates from file currency.xml [junit4:junit4] 1> INFO - 2013-04-24 20:50:08.987; org.apache.solr.schem= a.OpenExchangeRatesOrgProvider; Reloading exchange rates from open-exchange= -rates.json [junit4:junit4] 1> WARN - 2013-04-24 20:50:08.994; org.apache.solr.schem= a.OpenExchangeRatesOrgProvider$OpenExchangeRates; Unknown key IMPORTANT NOT= E [junit4:junit4] 1> WARN - 2013-04-24 20:50:08.994; org.apache.solr.schem= a.OpenExchangeRatesOrgProvider$OpenExchangeRates; Expected key, got STRING [junit4:junit4] 1> INFO - 2013-04-24 20:50:08.994; org.apache.solr.schem= a.OpenExchangeRatesOrgProvider; Reloading exchange rates from open-exchange= -rates.json [junit4:junit4] 1> INFO - 2013-04-24 20:50:08.998; org.apache.solr.schem= a.FileExchangeRateProvider; Reloading exchange rates from file currency.xml [junit4:junit4] 1> WARN - 2013-04-24 20:50:09.002; org.apache.solr.schem= a.OpenExchangeRatesOrgProvider$OpenExchangeRates; Unknown key IMPORTANT NOT= E [junit4:junit4] 1> WARN - 2013-04-24 20:50:09.003; org.apache.solr.schem= a.OpenExchangeRatesOrgProvider$OpenExchangeRates; Expected key, got STRING [junit4:junit4] 1> INFO - 2013-04-24 20:50:09.003; org.apache.solr.core.= SolrCore; org.apache.solr.core.MockDirectoryFactory [junit4:junit4] 1> INFO - 2013-04-24 20:50:09.004; org.apache.solr.core.= SolrCore; [awholynewcollection_0_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-controlj= etty-1366850987076\awholynewcollection_0_shard1_replica2\, dataDir=3DC:\Use= rs\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\te= st\J0\.\org.apache.solr.cloud.CollectionsAPIDistributedZkTest-controljetty-= 1366850987076\awholynewcollection_0_shard1_replica2\data\ [junit4:junit4] 1> INFO - 2013-04-24 20:50:09.004; org.apache.solr.core.= JmxMonitoredMap; JMX monitoring is enabled. Adding Solr mbeans to JMX Serve= r: com.sun.jmx.mbeanserver.JmxMBeanServer@1b3bfc5 [junit4:junit4] 1> INFO - 2013-04-24 20:50:09.005; org.apache.solr.core.= SolrCore; org.apache.solr.core.MockDirectoryFactory [junit4:junit4] 1> INFO - 2013-04-24 20:50:09.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-controljetty-1366850987076\awhol= ynewcollection_0_shard1_replica2\data\ [junit4:junit4] 1> INFO - 2013-04-24 20:50:09.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-controljetty-136685098707= 6\awholynewcollection_0_shard1_replica2\data\index/ [junit4:junit4] 1> WARN - 2013-04-24 20:50:09.010; org.apache.solr.core.= SolrCore; [awholynewcollection_0_shard1_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-1366850987076\awholynewcollection_0_shard1_replica2\data\index' doesn't = exist. Creating new index... [junit4:junit4] 1> INFO - 2013-04-24 20:50:09.010; 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-1366850987076\awhol= ynewcollection_0_shard1_replica2\data\index [junit4:junit4] 1> INFO - 2013-04-24 20:50:09.018; org.apache.solr.core.= SolrDeletionPolicy; SolrDeletionPolicy.onCommit: commits: num=3D1 [junit4:junit4] 1> =09commit{dir=3DMockDirWrapper(org.apache.lucene.store= .RAMDirectory@7cd3fc lockFactory=3Dorg.apache.lucene.store.NativeFSLockFact= ory@1592707),segFN=3Dsegments_1,generation=3D1} [junit4:junit4] 1> INFO - 2013-04-24 20:50:09.019; org.apache.solr.core.= SolrDeletionPolicy; newest commit generation =3D 1 [junit4:junit4] 1> INFO - 2013-04-24 20:50:09.033; org.apache.solr.schem= a.FileExchangeRateProvider; Reloading exchange rates from file currency.xml [junit4:junit4] 1> INFO - 2013-04-24 20:50:09.033; org.apache.solr.schem= a.OpenExchangeRatesOrgProvider; Reloading exchange rates from open-exchange= -rates.json [junit4:junit4] 1> INFO - 2013-04-24 20:50:09.036; org.apache.solr.schem= a.OpenExchangeRatesOrgProvider; Reloading exchange rates from open-exchange= -rates.json [junit4:junit4] 1> INFO - 2013-04-24 20:50:09.041; org.apache.solr.updat= e.processor.UpdateRequestProcessorChain; inserting DistributedUpdateProcess= orFactory into updateRequestProcessorChain "dedupe" [junit4:junit4] 1> INFO - 2013-04-24 20:50:09.041; org.apache.solr.updat= e.processor.UpdateRequestProcessorChain; inserting DistributedUpdateProcess= orFactory into updateRequestProcessorChain "stored_sig" [junit4:junit4] 1> INFO - 2013-04-24 20:50:09.042; org.apache.solr.updat= e.processor.UpdateRequestProcessorChain; inserting DistributedUpdateProcess= orFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit= " [junit4:junit4] 1> INFO - 2013-04-24 20:50:09.043; org.apache.solr.core.= RequestHandlers; created standard: solr.StandardRequestHandler [junit4:junit4] 1> INFO - 2013-04-24 20:50:09.046; org.apache.solr.core.= RequestHandlers; created /get: solr.RealTimeGetHandler [junit4:junit4] 1> INFO - 2013-04-24 20:50:09.046; org.apache.solr.core.= RequestHandlers; adding lazy requestHandler: solr.ReplicationHandler [junit4:junit4] 1> INFO - 2013-04-24 20:50:09.046; org.apache.solr.core.= RequestHandlers; created /replication: solr.ReplicationHandler [junit4:junit4] 1> INFO - 2013-04-24 20:50:09.047; org.apache.solr.core.= RequestHandlers; created /update: solr.UpdateRequestHandler [junit4:junit4] 1> INFO - 2013-04-24 20:50:09.048; org.apache.solr.core.= RequestHandlers; created /admin/: org.apache.solr.handler.admin.AdminHandle= rs [junit4:junit4] 1> INFO - 2013-04-24 20:50:09.068; org.apache.solr.schem= a.OpenExchangeRatesOrgProvider; Initialized with rates=3Dopen-exchange-rate= s.json, refreshInterval=3D1440. [junit4:junit4] 1> INFO - 2013-04-24 20:50:09.068; org.apache.solr.handl= er.loader.XMLLoader; xsltCacheLifetimeSeconds=3D60 [junit4:junit4] 1> INFO - 2013-04-24 20:50:09.072; org.apache.solr.searc= h.SolrIndexSearcher; Opening Searcher@6cc502 main [junit4:junit4] 1> INFO - 2013-04-24 20:50:09.078; 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-1366850987076\awholyn= ewcollection_0_shard1_replica2\data\tlog [junit4:junit4] 1> INFO - 2013-04-24 20:50:09.081; org.apache.solr.updat= e.CommitTracker; Hard AutoCommit: disabled [junit4:junit4] 1> INFO - 2013-04-24 20:50:09.083; org.apache.solr.updat= e.CommitTracker; Soft AutoCommit: disabled [junit4:junit4] 1> INFO - 2013-04-24 20:50:09.107; org.apache.solr.core.= SolrCore; [awholynewcollection_0_shard1_replica2] Registered new searcher S= earcher@6cc502 main{StandardDirectoryReader(segments_1:1)} [junit4:junit4] 1> INFO - 2013-04-24 20:50:09.108; org.apache.solr.cloud= .ZkController; publishing core=3Dawholynewcollection_0_shard1_replica2 stat= e=3Ddown [junit4:junit4] 1> WARN - 2013-04-24 20:50:09.113; org.apache.solr.schem= a.OpenExchangeRatesOrgProvider$OpenExchangeRates; Unknown key IMPORTANT NOT= E [junit4:junit4] 1> WARN - 2013-04-24 20:50:09.115; org.apache.solr.schem= a.OpenExchangeRatesOrgProvider$OpenExchangeRates; Expected key, got STRING [junit4:junit4] 1> INFO - 2013-04-24 20:50:09.118; org.apache.solr.schem= a.OpenExchangeRatesOrgProvider; Reloading exchange rates from open-exchange= -rates.json [junit4:junit4] 1> WARN - 2013-04-24 20:50:09.121; org.apache.solr.schem= a.OpenExchangeRatesOrgProvider$OpenExchangeRates; Unknown key IMPORTANT NOT= E [junit4:junit4] 1> WARN - 2013-04-24 20:50:09.121; org.apache.solr.schem= a.OpenExchangeRatesOrgProvider$OpenExchangeRates; Expected key, got STRING [junit4:junit4] 1> INFO - 2013-04-24 20:50:09.122; org.apache.solr.schem= a.OpenExchangeRatesOrgProvider; Reloading exchange rates from open-exchange= -rates.json [junit4:junit4] 1> INFO - 2013-04-24 20:50:09.129; org.apache.solr.schem= a.IndexSchema; default search field in schema is text [junit4:junit4] 1> INFO - 2013-04-24 20:50:09.136; org.apache.solr.schem= a.IndexSchema; unique key field: id [junit4:junit4] 1> WARN - 2013-04-24 20:50:09.406; org.apache.solr.schem= a.OpenExchangeRatesOrgProvider$OpenExchangeRates; Unknown key IMPORTANT NOT= E [junit4:junit4] 1> WARN - 2013-04-24 20:50:09.406; org.apache.solr.schem= a.OpenExchangeRatesOrgProvider$OpenExchangeRates; Expected key, got STRING [junit4:junit4] 1> INFO - 2013-04-24 20:50:09.407; org.apache.solr.core.= SolrCore; org.apache.solr.core.MockDirectoryFactory [junit4:junit4] 1> INFO - 2013-04-24 20:50:09.409; org.apache.solr.core.= SolrCore; [awholynewcollection_0_shard2_replica3] Opening new SolrCore at C= :\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-co= re\test\J0\.\org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty3-1= 366850992471\awholynewcollection_0_shard2_replica3\, dataDir=3DC:\Users\Jen= kinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\= .\org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty3-136685099247= 1\awholynewcollection_0_shard2_replica3\data\ [junit4:junit4] 1> INFO - 2013-04-24 20:50:09.409; org.apache.solr.core.= JmxMonitoredMap; JMX monitoring is enabled. Adding Solr mbeans to JMX Serve= r: com.sun.jmx.mbeanserver.JmxMBeanServer@1b3bfc5 [junit4:junit4] 1> INFO - 2013-04-24 20:50:09.410; org.apache.solr.core.= SolrCore; org.apache.solr.core.MockDirectoryFactory [junit4:junit4] 1> WARN - 2013-04-24 20:50:09.411; org.apache.solr.schem= a.OpenExchangeRatesOrgProvider$OpenExchangeRates; Unknown key IMPORTANT NOT= E [junit4:junit4] 1> WARN - 2013-04-24 20:50:09.411; org.apache.solr.schem= a.OpenExchangeRatesOrgProvider$OpenExchangeRates; Expected key, got STRING [junit4:junit4] 1> INFO - 2013-04-24 20:50:09.412; org.apache.solr.core.= SolrCore; org.apache.solr.core.MockDirectoryFactory [junit4:junit4] 1> INFO - 2013-04-24 20:50:09.413; org.apache.solr.core.= SolrCore; [awholynewcollection_0_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= 366850988332\awholynewcollection_0_shard2_replica1\, dataDir=3DC:\Users\Jen= kinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\= .\org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty1-136685098833= 2\awholynewcollection_0_shard2_replica1\data\ [junit4:junit4] 1> INFO - 2013-04-24 20:50:09.413; org.apache.solr.core.= JmxMonitoredMap; JMX monitoring is enabled. Adding Solr mbeans to JMX Serve= r: com.sun.jmx.mbeanserver.JmxMBeanServer@1b3bfc5 [junit4:junit4] 1> INFO - 2013-04-24 20:50:09.414; org.apache.solr.core.= SolrCore; org.apache.solr.core.MockDirectoryFactory [junit4:junit4] 1> INFO - 2013-04-24 20:50:09.416; 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-jetty3-1366850992471\awholynewco= llection_0_shard2_replica3\data\ [junit4:junit4] 1> INFO - 2013-04-24 20:50:09.417; 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-jetty3-1366850992471\awho= lynewcollection_0_shard2_replica3\data\index/ [junit4:junit4] 1> WARN - 2013-04-24 20:50:09.417; org.apache.solr.core.= SolrCore; [awholynewcollection_0_shard2_replica3] Solr index directory 'C:\= Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core= \test\J0\.\org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty3-136= 6850992471\awholynewcollection_0_shard2_replica3\data\index' doesn't exist.= Creating new index... [junit4:junit4] 1> INFO - 2013-04-24 20:50:09.418; 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-1366850988332\awholynewco= llection_0_shard2_replica1\data\ [junit4:junit4] 1> INFO - 2013-04-24 20:50:09.418; 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-1366850988332\awho= lynewcollection_0_shard2_replica1\data\index/ [junit4:junit4] 1> WARN - 2013-04-24 20:50:09.419; org.apache.solr.core.= SolrCore; [awholynewcollection_0_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= 6850988332\awholynewcollection_0_shard2_replica1\data\index' doesn't exist.= Creating new index... [junit4:junit4] 1> INFO - 2013-04-24 20:50:09.420; 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-jetty3-1366850992471\awholynewco= llection_0_shard2_replica3\data\index [junit4:junit4] 1> INFO - 2013-04-24 20:50:09.424; 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-1366850988332\awholynewco= llection_0_shard2_replica1\data\index [junit4:junit4] 1> INFO - 2013-04-24 20:50:09.441; org.apache.solr.core.= SolrDeletionPolicy; SolrDeletionPolicy.onCommit: commits: num=3D1 [junit4:junit4] 1> =09commit{dir=3DMockDirWrapper(org.apache.lucene.store= .RAMDirectory@1250e36 lockFactory=3Dorg.apache.lucene.store.NativeFSLockFac= tory@158f182),segFN=3Dsegments_1,generation=3D1} [junit4:junit4] 1> INFO - 2013-04-24 20:50:09.442; org.apache.solr.core.= SolrDeletionPolicy; newest commit generation =3D 1 [junit4:junit4] 1> INFO - 2013-04-24 20:50:09.442; org.apache.solr.core.= SolrDeletionPolicy; SolrDeletionPolicy.onCommit: commits: num=3D1 [junit4:junit4] 1> =09commit{dir=3DMockDirWrapper(org.apache.lucene.store= .RAMDirectory@ebf2cc lockFactory=3Dorg.apache.lucene.store.NativeFSLockFact= ory@808f8),segFN=3Dsegments_1,generation=3D1} [junit4:junit4] 1> INFO - 2013-04-24 20:50:09.443; org.apache.solr.core.= SolrDeletionPolicy; newest commit generation =3D 1 [junit4:junit4] 1> INFO - 2013-04-24 20:50:09.454; org.apache.solr.updat= e.processor.UpdateRequestProcessorChain; inserting DistributedUpdateProcess= orFactory into updateRequestProcessorChain "dedupe" [junit4:junit4] 1> INFO - 2013-04-24 20:50:09.455; org.apache.solr.updat= e.processor.UpdateRequestProcessorChain; inserting DistributedUpdateProcess= orFactory into updateRequestProcessorChain "stored_sig" [junit4:junit4] 1> INFO - 2013-04-24 20:50:09.456; org.apache.solr.updat= e.processor.UpdateRequestProcessorChain; inserting DistributedUpdateProcess= orFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit= " [junit4:junit4] 1> INFO - 2013-04-24 20:50:09.456; org.apache.solr.core.= RequestHandlers; created standard: solr.StandardRequestHandl [...truncated too long message...] 04.839; org.apache.solr.core.CachingDirectoryFactory; looking to close C:\U= sers\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\= test\J0\.\org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1366= 850994522\awholynewcollection_5_shard3_replica1\data\ [CachedDir<>] [junit4:junit4] 1> INFO - 2013-04-24 20:54:04.839; 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-1366850994522\awholynewcollecti= on_5_shard3_replica1\data\ [junit4:junit4] 1> INFO - 2013-04-24 20:54:04.842; org.apache.solr.cloud= .Overseer$ClusterStateUpdater; According to ZK I (id=3D89577946276298764-12= 7.0.0.1:65492_-n_0000000004) am no longer a leader. [junit4:junit4] 1> WARN - 2013-04-24 20:54:04.849; org.apache.solr.commo= n.cloud.ZkStateReader$3; ZooKeeper watch triggered, but Solr cannot talk to= ZK [junit4:junit4] 1> INFO - 2013-04-24 20:54:04.850; org.apache.solr.commo= n.cloud.ZkStateReader$2; A cluster state change: WatchedEvent state:SyncCon= nected type:NodeChildrenChanged path:/live_nodes, has occurred - updating..= . (live nodes size: 1) [junit4:junit4] 1> WARN - 2013-04-24 20:54:04.850; org.apache.solr.commo= n.cloud.ZkStateReader$2; ZooKeeper watch triggered, but Solr cannot talk to= ZK [junit4:junit4] 1> INFO - 2013-04-24 20:54:04.862; org.eclipse.jetty.ser= ver.handler.ContextHandler; stopped o.e.j.s.ServletContextHandler{/,null} [junit4:junit4] 1> INFO - 2013-04-24 20:54:04.926; org.apache.solr.SolrT= estCaseJ4; ###Ending testDistribSearch [junit4:junit4] 1> INFO - 2013-04-24 20:54:04.929; org.apache.solr.cloud= .ZkTestServer; connecting to 127.0.0.1:65446 65446 [junit4:junit4] 2> Creating dataDir: C:\Users\JenkinsSlave\workspace\Luce= ne-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\solrtest-CollectionsAP= IDistributedZkTest-1366850986872 [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-1366850986870\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-1366850986870\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-1366850986870\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-1366850986870\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-1366850986870\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-1366850986870 FAILED !!!!= ! [junit4:junit4] 2> NOTE: reproduce with: ant test -Dtestcase=3DCollectio= nsAPIDistributedZkTest -Dtests.method=3DtestDistribSearch -Dtests.seed=3D45= FBF77FED4A7288 -Dtests.slow=3Dtrue -Dtests.locale=3Dar_LY -Dtests.timezone= =3DAustralia/Currie -Dtests.file.encoding=3DCp1252 [junit4:junit4] ERROR 260s | CollectionsAPIDistributedZkTest.testDistrib= Search <<< [junit4:junit4] > Throwable #1: org.apache.solr.client.solrj.impl.HttpSo= lrServer$RemoteSolrException: Server at http://127.0.0.1:65483 returned non= ok status:500, message:Server Error [junit4:junit4] > =09at __randomizedtesting.SeedInfo.seed([45FBF77FED4A7= 288:C41D79679A1512B4]:0) [junit4:junit4] > =09at org.apache.solr.client.solrj.impl.HttpSolrServer= .request(HttpSolrServer.java:385) [junit4:junit4] > =09at org.apache.solr.client.solrj.impl.HttpSolrServer= .request(HttpSolrServer.java:180) [junit4:junit4] > =09at org.apache.solr.cloud.CollectionsAPIDistributedZ= kTest.deleteCollectionWithDownNodes(CollectionsAPIDistributedZkTest.java:20= 6) [junit4:junit4] > =09at org.apache.solr.cloud.CollectionsAPIDistributedZ= kTest.doTest(CollectionsAPIDistributedZkTest.java:148) [junit4:junit4] > =09at org.apache.solr.BaseDistributedSearchTestCase.te= stDistribSearch(BaseDistributedSearchTestCase.java:815) [junit4:junit4] > =09at java.lang.Thread.run(Thread.java:722) [junit4:junit4] 1> INFO - 2013-04-24 20:54:07.335; org.apache.solr.SolrT= estCaseJ4; ###deleteCore [junit4:junit4] 2> NOTE: test params are: codec=3DCheapBastard, sim=3DRan= domSimilarityProvider(queryNorm=3Dfalse,coord=3Dyes): {}, locale=3Dar_LY, t= imezone=3DAustralia/Currie [junit4:junit4] 2> NOTE: Windows 7 6.1 x86/Oracle Corporation 1.7.0_21 (3= 2-bit)/cpus=3D2,threads=3D2,free=3D90226928,total=3D210350080 [junit4:junit4] 2> NOTE: All tests run in this JVM: [ResourceLoaderTest, = SolrTestCaseJ4Test, TestShardHandlerFactory, TestRecovery, TestManagedSchem= a, UniqFieldsUpdateProcessorFactoryTest, TestSolrCoreProperties, TestAnalyz= edSuggestions, TestNumberUtils, ChaosMonkeySafeLeaderTest, ShardRoutingTest= , AliasIntegrationTest, TermVectorComponentTest, SolrCoreTest, TestCSVLoade= r, SliceStateUpdateTest, SearchHandlerTest, OpenCloseCoreStressTest, TestPs= eudoReturnFields, ZkControllerTest, TestSolr4Spatial, RecoveryZkTest, Distr= ibutedTermsComponentTest, TestSchemaVersionResource, TestUpdate, TestRandom= DVFaceting, SoftAutoCommitTest, SimplePostToolTest, TestReversedWildcardFil= terFactory, ShardRoutingCustomTest, TestSolrXml, CopyFieldTest, TestMergePo= licyConfig, TestAtomicUpdateErrorCases, ShardSplitTest, TestSolrIndexConfig= , TestPerFieldSimilarity, BasicDistributedZk2Test, SolrPluginUtilsTest, Tes= tReload, CurrencyFieldOpenExchangeTest, TestPartialUpdateDeduplication, Sta= tsComponentTest, TestPluginEnable, ZkSolrClientTest, TestSolrDeletionPolicy= 2, TestDefaultSimilarityFactory, BasicZkTest, TestSolrXMLSerializer, MultiT= ermTest, TestBM25SimilarityFactory, FileBasedSpellCheckerTest, PrimitiveFie= ldTypeTest, TestFuzzyAnalyzedSuggestions, TestSolrQueryParser, IndexBasedSp= ellCheckerTest, MoreLikeThisHandlerTest, SOLR749Test, TestIndexingPerforman= ce, ChaosMonkeyNothingIsSafeTest, BasicDistributedZkTest, ConvertedLegacyTe= st, TestWordDelimiterFilterFactory, TestSweetSpotSimilarityFactory, CSVRequ= estHandlerTest, TestCharFilters, HighlighterTest, TestQueryUtils, QueryResu= ltKeyTest, TestWriterPerf, DistributedQueryElevationComponentTest, DirectUp= dateHandlerOptimizeTest, TestSolrJ, TestUniqueKeyFieldResource, ZkCLITest, = TestFiltering, JsonLoaderTest, TestRangeQuery, LeaderElectionTest, Overseer= Test, NoCacheHeaderTest, BasicFunctionalityTest, TestCollationField, TestDi= stributedGrouping, TestBinaryField, TestBadConfig, TestQuerySenderNoQuery, = TestSchemaResource, PolyFieldTest, TestStressLucene, NotRequiredUniqueKeyTe= st, ScriptEngineTest, TestFastOutputStream, TestDynamicFieldCollectionResou= rce, RegexBoostProcessorTest, TestSerializedLuceneMatchVersion, TestExtende= dDismaxParser, TestClassNameShortening, SliceStateTest, SpellCheckCollatorT= est, TestSchemaNameResource, TestCoreDiscovery, TestRandomFaceting, TimeZon= eUtilsTest, IndexReaderFactoryTest, TestLuceneMatchVersion, JSONWriterTest,= HardAutoCommitTest, UpdateParamsTest, SolrRequestParserTest, SolrCmdDistri= butorTest, FieldMutatingUpdateProcessorTest, TestSurroundQueryParser, Overs= eerCollectionProcessorTest, ZkNodePropsTest, UpdateRequestProcessorFactoryT= est, TestStressVersions, TestComponentsName, TestJmxIntegration, BadIndexSc= hemaTest, CircularListTest, BinaryUpdateRequestHandlerTest, CurrencyFieldXm= lFileTest, FileUtilsTest, TestDynamicFieldResource, TestRTGBase, RequestHan= dlersTest, PreAnalyzedUpdateProcessorTest, FastVectorHighlighterTest, Syste= mInfoHandlerTest, SolrCoreCheckLockOnStartupTest, TestDocSet, TestUtils, Te= rmVectorComponentDistributedTest, DateMathParserTest, TestTrie, TestCodecSu= pport, UnloadDistributedZkTest, DistributedSpellCheckComponentTest, Suggest= erFSTTest, TestSearchPerf, QueryEqualityTest, CollectionsAPIDistributedZkTe= st] [junit4:junit4] Completed in 260.53s, 1 test, 1 error <<< FAILURES! [...truncated 450 lines...] BUILD FAILED C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\build.xml:378: Th= e following error occurred while executing this line: C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\build.xml:358: 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= 1: The following error occurred while executing this line: C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\common-build= .xml:437: The following error occurred while executing this line: C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\lucene\common-bui= ld.xml:1240: The following error occurred while executing this line: C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\lucene\common-bui= ld.xml:884: There were test failures: 293 suites, 1218 tests, 1 error, 18 i= gnored (12 assumptions) Total time: 70 minutes 30 seconds Build step 'Invoke Ant' marked build as failure Description set: Java: 32bit/jdk1.7.0_21 -client -XX:+UseSerialGC Archiving artifacts Recording test results Email was triggered for: Failure Sending email for trigger: Failure ------=_Part_140_1770855211.1366852193134 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_140_1770855211.1366852193134--