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 CC5DFF923 for ; Tue, 9 Apr 2013 06:36:49 +0000 (UTC) Received: (qmail 18849 invoked by uid 500); 9 Apr 2013 06:36:46 -0000 Delivered-To: apmail-lucene-dev-archive@lucene.apache.org Received: (qmail 18537 invoked by uid 500); 9 Apr 2013 06:36:46 -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 18496 invoked by uid 99); 9 Apr 2013 06:36:44 -0000 Received: from nike.apache.org (HELO nike.apache.org) (192.87.106.230) by apache.org (qpsmtpd/0.29) with ESMTP; Tue, 09 Apr 2013 06:36:44 +0000 X-ASF-Spam-Status: No, hits=-2000.0 required=5.0 tests=ALL_TRUSTED,NORMAL_HTTP_TO_IP,WEIRD_PORT X-Spam-Check-By: apache.org Received: from [140.211.11.8] (HELO aegis.apache.org) (140.211.11.8) by apache.org (qpsmtpd/0.29) with ESMTP; Tue, 09 Apr 2013 06:36:22 +0000 Received: from aegis.apache.org (localhost [127.0.0.1]) by aegis.apache.org (Postfix) with ESMTP id 2115EC0071 for ; Tue, 9 Apr 2013 06:36:00 +0000 (UTC) Date: Tue, 9 Apr 2013 06:35:37 +0000 (UTC) From: Apache Jenkins Server To: dev@lucene.apache.org Message-ID: <1024356923.940.1365489360055.JavaMail.hudson@aegis> Subject: [JENKINS] Lucene-Solr-NightlyTests-trunk - Build # 229 - Failure MIME-Version: 1.0 Content-Type: multipart/mixed; boundary="----=_Part_939_1622103993.1365489337790" X-Jenkins-Job: Lucene-Solr-NightlyTests-trunk X-Jenkins-Result: FAILURE X-Virus-Checked: Checked by ClamAV on apache.org ------=_Part_939_1622103993.1365489337790 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: quoted-printable Build: https://builds.apache.org/job/Lucene-Solr-NightlyTests-trunk/229/ 3 tests failed. REGRESSION: org.apache.solr.cloud.CollectionsAPIDistributedZkTest.testDist= ribSearch Error Message: There are still nodes recoverying - waited for 230 seconds Stack Trace: java.lang.AssertionError: There are still nodes recoverying - waited for 23= 0 seconds =09at __randomizedtesting.SeedInfo.seed([58B3562C02208C06:D955D834757FEC3A]= :0) =09at org.junit.Assert.fail(Assert.java:93) =09at org.apache.solr.cloud.AbstractDistribZkTestBase.waitForRecoveriesToFi= nish(AbstractDistribZkTestBase.java:173) =09at org.apache.solr.cloud.AbstractDistribZkTestBase.waitForRecoveriesToFi= nish(AbstractDistribZkTestBase.java:131) =09at org.apache.solr.cloud.AbstractDistribZkTestBase.waitForRecoveriesToFi= nish(AbstractDistribZkTestBase.java:126) =09at org.apache.solr.cloud.CollectionsAPIDistributedZkTest.testCollections= API(CollectionsAPIDistributedZkTest.java:483) =09at org.apache.solr.cloud.CollectionsAPIDistributedZkTest.doTest(Collecti= onsAPIDistributedZkTest.java:146) =09at org.apache.solr.BaseDistributedSearchTestCase.testDistribSearch(BaseD= istributedSearchTestCase.java:806) =09at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method) =09at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.= java:57) =09at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAcces= sorImpl.java:43) =09at java.lang.reflect.Method.invoke(Method.java:601) =09at com.carrotsearch.randomizedtesting.RandomizedRunner.invoke(Randomized= Runner.java:1559) =09at com.carrotsearch.randomizedtesting.RandomizedRunner.access$600(Random= izedRunner.java:79) =09at com.carrotsearch.randomizedtesting.RandomizedRunner$6.evaluate(Random= izedRunner.java:737) =09at com.carrotsearch.randomizedtesting.RandomizedRunner$7.evaluate(Random= izedRunner.java:773) =09at com.carrotsearch.randomizedtesting.RandomizedRunner$8.evaluate(Random= izedRunner.java:787) =09at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$= 1.evaluate(SystemPropertiesRestoreRule.java:53) =09at org.apache.lucene.util.TestRuleSetupTeardownChained$1.evaluate(TestRu= leSetupTeardownChained.java:50) =09at org.apache.lucene.util.TestRuleFieldCacheSanity$1.evaluate(TestRuleFi= eldCacheSanity.java:51) =09at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBef= oreAfterRule.java:46) =09at com.carrotsearch.randomizedtesting.rules.SystemPropertiesInvariantRul= e$1.evaluate(SystemPropertiesInvariantRule.java:55) =09at org.apache.lucene.util.TestRuleThreadAndTestName$1.evaluate(TestRuleT= hreadAndTestName.java:49) =09at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(Test= RuleIgnoreAfterMaxFailures.java:70) =09at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFai= lure.java:48) =09at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(St= atementAdapter.java:36) =09at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.= run(ThreadLeakControl.java:358) =09at com.carrotsearch.randomizedtesting.ThreadLeakControl.forkTimeoutingTa= sk(ThreadLeakControl.java:782) =09at com.carrotsearch.randomizedtesting.ThreadLeakControl$3.evaluate(Threa= dLeakControl.java:442) =09at com.carrotsearch.randomizedtesting.RandomizedRunner.runSingleTest(Ran= domizedRunner.java:746) =09at com.carrotsearch.randomizedtesting.RandomizedRunner$3.evaluate(Random= izedRunner.java:648) =09at com.carrotsearch.randomizedtesting.RandomizedRunner$4.evaluate(Random= izedRunner.java:682) =09at com.carrotsearch.randomizedtesting.RandomizedRunner$5.evaluate(Random= izedRunner.java:693) =09at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(St= atementAdapter.java:36) =09at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$= 1.evaluate(SystemPropertiesRestoreRule.java:53) =09at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBef= oreAfterRule.java:46) =09at org.apache.lucene.util.TestRuleStoreClassName$1.evaluate(TestRuleStor= eClassName.java:42) =09at com.carrotsearch.randomizedtesting.rules.SystemPropertiesInvariantRul= e$1.evaluate(SystemPropertiesInvariantRule.java:55) =09at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMeth= odsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:39) =09at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMeth= odsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:39) =09at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(St= atementAdapter.java:36) =09at org.apache.lucene.util.TestRuleAssertionsRequired$1.evaluate(TestRule= AssertionsRequired.java:43) =09at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFai= lure.java:48) =09at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(Test= RuleIgnoreAfterMaxFailures.java:70) =09at org.apache.lucene.util.TestRuleIgnoreTestSuites$1.evaluate(TestRuleIg= noreTestSuites.java:55) =09at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(St= atementAdapter.java:36) =09at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.= run(ThreadLeakControl.java:358) =09at java.lang.Thread.run(Thread.java:722) FAILED: junit.framework.TestSuite.org.apache.solr.cloud.CollectionsAPIDist= ributedZkTest Error Message: 2 threads leaked from SUITE scope at org.apache.solr.cloud.CollectionsAPIDi= stributedZkTest: 1) Thread[id=3D3461, name=3DrecoveryCmdExecutor-1229-t= hread-2, state=3DRUNNABLE, group=3DTGRP-CollectionsAPIDistributedZkTest] = at java.net.PlainSocketImpl.socketConnect(Native Method) at j= ava.net.AbstractPlainSocketImpl.doConnect(AbstractPlainSocketImpl.java:339)= at java.net.AbstractPlainSocketImpl.connectToAddress(AbstractPlain= SocketImpl.java:200) at java.net.AbstractPlainSocketImpl.connect(Ab= stractPlainSocketImpl.java:182) at java.net.SocksSocketImpl.connect= (SocksSocketImpl.java:391) at java.net.Socket.connect(Socket.java:5= 79) at org.apache.http.conn.scheme.PlainSocketFactory.connectSocket= (PlainSocketFactory.java:127) at org.apache.http.impl.conn.DefaultC= lientConnectionOperator.openConnection(DefaultClientConnectionOperator.java= :180) at org.apache.http.impl.conn.ManagedClientConnectionImpl.open= (ManagedClientConnectionImpl.java:294) at org.apache.http.impl.clie= nt.DefaultRequestDirector.tryConnect(DefaultRequestDirector.java:645) = at org.apache.http.impl.client.DefaultRequestDirector.execute(DefaultReq= uestDirector.java:480) at org.apache.http.impl.client.AbstractHttpC= lient.execute(AbstractHttpClient.java:906) at org.apache.http.impl.= client.AbstractHttpClient.execute(AbstractHttpClient.java:805) at o= rg.apache.http.impl.client.AbstractHttpClient.execute(AbstractHttpClient.ja= va:784) at org.apache.solr.client.solrj.impl.HttpSolrServer.request= (HttpSolrServer.java:353) at org.apache.solr.client.solrj.impl.Http= SolrServer.request(HttpSolrServer.java:181) at org.apache.solr.clou= d.SyncStrategy$1.run(SyncStrategy.java:298) at java.util.concurrent= .ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145) at java= .util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615)= at java.lang.Thread.run(Thread.java:722) 2) Thread[id=3D3459, n= ame=3DrecoveryCmdExecutor-1229-thread-1, state=3DRUNNABLE, group=3DTGRP-Col= lectionsAPIDistributedZkTest] at java.net.PlainSocketImpl.socketCon= nect(Native Method) at java.net.AbstractPlainSocketImpl.doConnect(A= bstractPlainSocketImpl.java:339) at java.net.AbstractPlainSocketImp= l.connectToAddress(AbstractPlainSocketImpl.java:200) at java.net.Ab= stractPlainSocketImpl.connect(AbstractPlainSocketImpl.java:182) at = java.net.SocksSocketImpl.connect(SocksSocketImpl.java:391) at java.= net.Socket.connect(Socket.java:579) at org.apache.http.conn.scheme.= PlainSocketFactory.connectSocket(PlainSocketFactory.java:127) at or= g.apache.http.impl.conn.DefaultClientConnectionOperator.openConnection(Defa= ultClientConnectionOperator.java:180) at org.apache.http.impl.conn.= ManagedClientConnectionImpl.open(ManagedClientConnectionImpl.java:294) = at org.apache.http.impl.client.DefaultRequestDirector.tryConnect(Defaul= tRequestDirector.java:645) at org.apache.http.impl.client.DefaultRe= questDirector.execute(DefaultRequestDirector.java:480) at org.apach= e.http.impl.client.AbstractHttpClient.execute(AbstractHttpClient.java:906) = at org.apache.http.impl.client.AbstractHttpClient.execute(AbstractH= ttpClient.java:805) at org.apache.http.impl.client.AbstractHttpClie= nt.execute(AbstractHttpClient.java:784) at org.apache.solr.client.s= olrj.impl.HttpSolrServer.request(HttpSolrServer.java:353) at org.ap= ache.solr.client.solrj.impl.HttpSolrServer.request(HttpSolrServer.java:181)= at org.apache.solr.cloud.SyncStrategy$1.run(SyncStrategy.java:298)= at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExe= cutor.java:1145) at java.util.concurrent.ThreadPoolExecutor$Worker.= run(ThreadPoolExecutor.java:615) at java.lang.Thread.run(Thread.jav= a:722) Stack Trace: com.carrotsearch.randomizedtesting.ThreadLeakError: 2 threads leaked from S= UITE scope at org.apache.solr.cloud.CollectionsAPIDistributedZkTest:=20 1) Thread[id=3D3461, name=3DrecoveryCmdExecutor-1229-thread-2, state=3DR= UNNABLE, group=3DTGRP-CollectionsAPIDistributedZkTest] at java.net.PlainSocketImpl.socketConnect(Native Method) at java.net.AbstractPlainSocketImpl.doConnect(AbstractPlainSocketIm= pl.java:339) at java.net.AbstractPlainSocketImpl.connectToAddress(AbstractPlainS= ocketImpl.java:200) at java.net.AbstractPlainSocketImpl.connect(AbstractPlainSocketImpl= .java:182) at java.net.SocksSocketImpl.connect(SocksSocketImpl.java:391) at java.net.Socket.connect(Socket.java:579) at org.apache.http.conn.scheme.PlainSocketFactory.connectSocket(Pla= inSocketFactory.java:127) at org.apache.http.impl.conn.DefaultClientConnectionOperator.openCo= nnection(DefaultClientConnectionOperator.java:180) at org.apache.http.impl.conn.ManagedClientConnectionImpl.open(Manag= edClientConnectionImpl.java:294) at org.apache.http.impl.client.DefaultRequestDirector.tryConnect(De= faultRequestDirector.java:645) at org.apache.http.impl.client.DefaultRequestDirector.execute(Defau= ltRequestDirector.java:480) at org.apache.http.impl.client.AbstractHttpClient.execute(AbstractH= ttpClient.java:906) at org.apache.http.impl.client.AbstractHttpClient.execute(AbstractH= ttpClient.java:805) at org.apache.http.impl.client.AbstractHttpClient.execute(AbstractH= ttpClient.java:784) at org.apache.solr.client.solrj.impl.HttpSolrServer.request(HttpSol= rServer.java:353) at org.apache.solr.client.solrj.impl.HttpSolrServer.request(HttpSol= rServer.java:181) at org.apache.solr.cloud.SyncStrategy$1.run(SyncStrategy.java:298) at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExec= utor.java:1145) at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExe= cutor.java:615) at java.lang.Thread.run(Thread.java:722) 2) Thread[id=3D3459, name=3DrecoveryCmdExecutor-1229-thread-1, state=3DR= UNNABLE, group=3DTGRP-CollectionsAPIDistributedZkTest] at java.net.PlainSocketImpl.socketConnect(Native Method) at java.net.AbstractPlainSocketImpl.doConnect(AbstractPlainSocketIm= pl.java:339) at java.net.AbstractPlainSocketImpl.connectToAddress(AbstractPlainS= ocketImpl.java:200) at java.net.AbstractPlainSocketImpl.connect(AbstractPlainSocketImpl= .java:182) at java.net.SocksSocketImpl.connect(SocksSocketImpl.java:391) at java.net.Socket.connect(Socket.java:579) at org.apache.http.conn.scheme.PlainSocketFactory.connectSocket(Pla= inSocketFactory.java:127) at org.apache.http.impl.conn.DefaultClientConnectionOperator.openCo= nnection(DefaultClientConnectionOperator.java:180) at org.apache.http.impl.conn.ManagedClientConnectionImpl.open(Manag= edClientConnectionImpl.java:294) at org.apache.http.impl.client.DefaultRequestDirector.tryConnect(De= faultRequestDirector.java:645) at org.apache.http.impl.client.DefaultRequestDirector.execute(Defau= ltRequestDirector.java:480) at org.apache.http.impl.client.AbstractHttpClient.execute(AbstractH= ttpClient.java:906) at org.apache.http.impl.client.AbstractHttpClient.execute(AbstractH= ttpClient.java:805) at org.apache.http.impl.client.AbstractHttpClient.execute(AbstractH= ttpClient.java:784) at org.apache.solr.client.solrj.impl.HttpSolrServer.request(HttpSol= rServer.java:353) at org.apache.solr.client.solrj.impl.HttpSolrServer.request(HttpSol= rServer.java:181) at org.apache.solr.cloud.SyncStrategy$1.run(SyncStrategy.java:298) at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExec= utor.java:1145) at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExe= cutor.java:615) at java.lang.Thread.run(Thread.java:722) =09at __randomizedtesting.SeedInfo.seed([58B3562C02208C06]:0) FAILED: junit.framework.TestSuite.org.apache.solr.cloud.CollectionsAPIDist= ributedZkTest Error Message: There are still zombie threads that couldn't be terminated: 1) Thread[id= =3D3461, name=3DrecoveryCmdExecutor-1229-thread-2, state=3DRUNNABLE, group= =3DTGRP-CollectionsAPIDistributedZkTest] at java.net.PlainSocketImp= l.socketConnect(Native Method) at java.net.AbstractPlainSocketImpl.= doConnect(AbstractPlainSocketImpl.java:339) at java.net.AbstractPla= inSocketImpl.connectToAddress(AbstractPlainSocketImpl.java:200) at = java.net.AbstractPlainSocketImpl.connect(AbstractPlainSocketImpl.java:182) = at java.net.SocksSocketImpl.connect(SocksSocketImpl.java:391) = at java.net.Socket.connect(Socket.java:579) at org.apache.http.c= onn.scheme.PlainSocketFactory.connectSocket(PlainSocketFactory.java:127) = at org.apache.http.impl.conn.DefaultClientConnectionOperator.openConn= ection(DefaultClientConnectionOperator.java:180) at org.apache.http= .impl.conn.ManagedClientConnectionImpl.open(ManagedClientConnectionImpl.jav= a:294) at org.apache.http.impl.client.DefaultRequestDirector.tryCon= nect(DefaultRequestDirector.java:645) at org.apache.http.impl.clien= t.DefaultRequestDirector.execute(DefaultRequestDirector.java:480) a= t org.apache.http.impl.client.AbstractHttpClient.execute(AbstractHttpClient= .java:906) at org.apache.http.impl.client.AbstractHttpClient.execut= e(AbstractHttpClient.java:805) at org.apache.http.impl.client.Abstr= actHttpClient.execute(AbstractHttpClient.java:784) at org.apache.so= lr.client.solrj.impl.HttpSolrServer.request(HttpSolrServer.java:353) = at org.apache.solr.client.solrj.impl.HttpSolrServer.request(HttpSolrServe= r.java:181) at org.apache.solr.cloud.SyncStrategy$1.run(SyncStrateg= y.java:298) at java.util.concurrent.ThreadPoolExecutor.runWorker(Th= readPoolExecutor.java:1145) at java.util.concurrent.ThreadPoolExecu= tor$Worker.run(ThreadPoolExecutor.java:615) at java.lang.Thread.run= (Thread.java:722) 2) Thread[id=3D3459, name=3DrecoveryCmdExecutor-1229-t= hread-1, state=3DRUNNABLE, group=3DTGRP-CollectionsAPIDistributedZkTest] = at java.net.PlainSocketImpl.socketConnect(Native Method) at j= ava.net.AbstractPlainSocketImpl.doConnect(AbstractPlainSocketImpl.java:339)= at java.net.AbstractPlainSocketImpl.connectToAddress(AbstractPlain= SocketImpl.java:200) at java.net.AbstractPlainSocketImpl.connect(Ab= stractPlainSocketImpl.java:182) at java.net.SocksSocketImpl.connect= (SocksSocketImpl.java:391) at java.net.Socket.connect(Socket.java:5= 79) at org.apache.http.conn.scheme.PlainSocketFactory.connectSocket= (PlainSocketFactory.java:127) at org.apache.http.impl.conn.DefaultC= lientConnectionOperator.openConnection(DefaultClientConnectionOperator.java= :180) at org.apache.http.impl.conn.ManagedClientConnectionImpl.open= (ManagedClientConnectionImpl.java:294) at org.apache.http.impl.clie= nt.DefaultRequestDirector.tryConnect(DefaultRequestDirector.java:645) = at org.apache.http.impl.client.DefaultRequestDirector.execute(DefaultReq= uestDirector.java:480) at org.apache.http.impl.client.AbstractHttpC= lient.execute(AbstractHttpClient.java:906) at org.apache.http.impl.= client.AbstractHttpClient.execute(AbstractHttpClient.java:805) at o= rg.apache.http.impl.client.AbstractHttpClient.execute(AbstractHttpClient.ja= va:784) at org.apache.solr.client.solrj.impl.HttpSolrServer.request= (HttpSolrServer.java:353) at org.apache.solr.client.solrj.impl.Http= SolrServer.request(HttpSolrServer.java:181) at org.apache.solr.clou= d.SyncStrategy$1.run(SyncStrategy.java:298) at java.util.concurrent= .ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145) at java= .util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615)= at java.lang.Thread.run(Thread.java:722) Stack Trace: com.carrotsearch.randomizedtesting.ThreadLeakError: There are still zombie = threads that couldn't be terminated: 1) Thread[id=3D3461, name=3DrecoveryCmdExecutor-1229-thread-2, state=3DR= UNNABLE, group=3DTGRP-CollectionsAPIDistributedZkTest] at java.net.PlainSocketImpl.socketConnect(Native Method) at java.net.AbstractPlainSocketImpl.doConnect(AbstractPlainSocketIm= pl.java:339) at java.net.AbstractPlainSocketImpl.connectToAddress(AbstractPlainS= ocketImpl.java:200) at java.net.AbstractPlainSocketImpl.connect(AbstractPlainSocketImpl= .java:182) at java.net.SocksSocketImpl.connect(SocksSocketImpl.java:391) at java.net.Socket.connect(Socket.java:579) at org.apache.http.conn.scheme.PlainSocketFactory.connectSocket(Pla= inSocketFactory.java:127) at org.apache.http.impl.conn.DefaultClientConnectionOperator.openCo= nnection(DefaultClientConnectionOperator.java:180) at org.apache.http.impl.conn.ManagedClientConnectionImpl.open(Manag= edClientConnectionImpl.java:294) at org.apache.http.impl.client.DefaultRequestDirector.tryConnect(De= faultRequestDirector.java:645) at org.apache.http.impl.client.DefaultRequestDirector.execute(Defau= ltRequestDirector.java:480) at org.apache.http.impl.client.AbstractHttpClient.execute(AbstractH= ttpClient.java:906) at org.apache.http.impl.client.AbstractHttpClient.execute(AbstractH= ttpClient.java:805) at org.apache.http.impl.client.AbstractHttpClient.execute(AbstractH= ttpClient.java:784) at org.apache.solr.client.solrj.impl.HttpSolrServer.request(HttpSol= rServer.java:353) at org.apache.solr.client.solrj.impl.HttpSolrServer.request(HttpSol= rServer.java:181) at org.apache.solr.cloud.SyncStrategy$1.run(SyncStrategy.java:298) at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExec= utor.java:1145) at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExe= cutor.java:615) at java.lang.Thread.run(Thread.java:722) 2) Thread[id=3D3459, name=3DrecoveryCmdExecutor-1229-thread-1, state=3DR= UNNABLE, group=3DTGRP-CollectionsAPIDistributedZkTest] at java.net.PlainSocketImpl.socketConnect(Native Method) at java.net.AbstractPlainSocketImpl.doConnect(AbstractPlainSocketIm= pl.java:339) at java.net.AbstractPlainSocketImpl.connectToAddress(AbstractPlainS= ocketImpl.java:200) at java.net.AbstractPlainSocketImpl.connect(AbstractPlainSocketImpl= .java:182) at java.net.SocksSocketImpl.connect(SocksSocketImpl.java:391) at java.net.Socket.connect(Socket.java:579) at org.apache.http.conn.scheme.PlainSocketFactory.connectSocket(Pla= inSocketFactory.java:127) at org.apache.http.impl.conn.DefaultClientConnectionOperator.openCo= nnection(DefaultClientConnectionOperator.java:180) at org.apache.http.impl.conn.ManagedClientConnectionImpl.open(Manag= edClientConnectionImpl.java:294) at org.apache.http.impl.client.DefaultRequestDirector.tryConnect(De= faultRequestDirector.java:645) at org.apache.http.impl.client.DefaultRequestDirector.execute(Defau= ltRequestDirector.java:480) at org.apache.http.impl.client.AbstractHttpClient.execute(AbstractH= ttpClient.java:906) at org.apache.http.impl.client.AbstractHttpClient.execute(AbstractH= ttpClient.java:805) at org.apache.http.impl.client.AbstractHttpClient.execute(AbstractH= ttpClient.java:784) at org.apache.solr.client.solrj.impl.HttpSolrServer.request(HttpSol= rServer.java:353) at org.apache.solr.client.solrj.impl.HttpSolrServer.request(HttpSol= rServer.java:181) at org.apache.solr.cloud.SyncStrategy$1.run(SyncStrategy.java:298) at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExec= utor.java:1145) at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExe= cutor.java:615) at java.lang.Thread.run(Thread.java:722) =09at __randomizedtesting.SeedInfo.seed([58B3562C02208C06]:0) Build Log: [...truncated 9430 lines...] [junit4:junit4] Suite: org.apache.solr.cloud.CollectionsAPIDistributedZkTes= t [junit4:junit4] 1> INFO - 2013-04-09 06:27:54.660; org.apache.solr.BaseD= istributedSearchTestCase; Setting hostContext system property: / [junit4:junit4] 1> INFO - 2013-04-09 06:27:54.664; org.apache.solr.SolrT= estCaseJ4; ###Starting testDistribSearch [junit4:junit4] 1> INFO - 2013-04-09 06:27:54.665; 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-09 06:27:54.666; org.apache.solr.cloud= .ZkTestServer$ZKServerMain; Starting server [junit4:junit4] 1> INFO - 2013-04-09 06:27:54.766; org.apache.solr.cloud= .ZkTestServer; start zk server on port:11081 [junit4:junit4] 1> INFO - 2013-04-09 06:27:54.767; org.apache.solr.commo= n.cloud.ConnectionManager; Waiting for client to connect to ZooKeeper [junit4:junit4] 1> INFO - 2013-04-09 06:27:54.802; org.apache.solr.commo= n.cloud.ConnectionManager; Watcher org.apache.solr.common.cloud.ConnectionM= anager@75f7d549 name:ZooKeeperConnection Watcher:127.0.0.1:11081 got event = WatchedEvent state:SyncConnected type:None path:null path:null type:None [junit4:junit4] 1> INFO - 2013-04-09 06:27:54.802; org.apache.solr.commo= n.cloud.ConnectionManager; Client is connected to ZooKeeper [junit4:junit4] 1> INFO - 2013-04-09 06:27:54.803; org.apache.solr.commo= n.cloud.SolrZkClient; makePath: /solr [junit4:junit4] 1> INFO - 2013-04-09 06:27:54.816; org.apache.solr.commo= n.cloud.ConnectionManager; Waiting for client to connect to ZooKeeper [junit4:junit4] 1> INFO - 2013-04-09 06:27:54.819; org.apache.solr.commo= n.cloud.ConnectionManager; Watcher org.apache.solr.common.cloud.ConnectionM= anager@4b1fcfde name:ZooKeeperConnection Watcher:127.0.0.1:11081/solr got e= vent WatchedEvent state:SyncConnected type:None path:null path:null type:No= ne [junit4:junit4] 1> INFO - 2013-04-09 06:27:54.819; org.apache.solr.commo= n.cloud.ConnectionManager; Client is connected to ZooKeeper [junit4:junit4] 1> INFO - 2013-04-09 06:27:54.819; org.apache.solr.commo= n.cloud.SolrZkClient; makePath: /collections/collection1 [junit4:junit4] 1> INFO - 2013-04-09 06:27:54.837; org.apache.solr.commo= n.cloud.SolrZkClient; makePath: /collections/collection1/shards [junit4:junit4] 1> INFO - 2013-04-09 06:27:54.840; org.apache.solr.commo= n.cloud.SolrZkClient; makePath: /collections/control_collection [junit4:junit4] 1> INFO - 2013-04-09 06:27:54.842; org.apache.solr.commo= n.cloud.SolrZkClient; makePath: /collections/control_collection/shards [junit4:junit4] 1> INFO - 2013-04-09 06:27:54.852; org.apache.solr.cloud= .AbstractZkTestCase; put /usr/home/hudson/hudson-slave/workspace/Lucene-Sol= r-NightlyTests-trunk/solr/build/solr-core/test-files/solr/collection1/conf/= solrconfig-tlog.xml to /configs/conf1/solrconfig.xml [junit4:junit4] 1> INFO - 2013-04-09 06:27:54.853; org.apache.solr.commo= n.cloud.SolrZkClient; makePath: /configs/conf1/solrconfig.xml [junit4:junit4] 1> INFO - 2013-04-09 06:27:54.865; org.apache.solr.cloud= .AbstractZkTestCase; put /usr/home/hudson/hudson-slave/workspace/Lucene-Sol= r-NightlyTests-trunk/solr/build/solr-core/test-files/solr/collection1/conf/= schema.xml to /configs/conf1/schema.xml [junit4:junit4] 1> INFO - 2013-04-09 06:27:54.866; org.apache.solr.commo= n.cloud.SolrZkClient; makePath: /configs/conf1/schema.xml [junit4:junit4] 1> INFO - 2013-04-09 06:27:54.972; org.apache.solr.cloud= .AbstractZkTestCase; put /usr/home/hudson/hudson-slave/workspace/Lucene-Sol= r-NightlyTests-trunk/solr/build/solr-core/test-files/solr/collection1/conf/= stopwords.txt to /configs/conf1/stopwords.txt [junit4:junit4] 1> INFO - 2013-04-09 06:27:54.972; org.apache.solr.commo= n.cloud.SolrZkClient; makePath: /configs/conf1/stopwords.txt [junit4:junit4] 1> INFO - 2013-04-09 06:27:54.975; org.apache.solr.cloud= .AbstractZkTestCase; put /usr/home/hudson/hudson-slave/workspace/Lucene-Sol= r-NightlyTests-trunk/solr/build/solr-core/test-files/solr/collection1/conf/= protwords.txt to /configs/conf1/protwords.txt [junit4:junit4] 1> INFO - 2013-04-09 06:27:54.976; org.apache.solr.commo= n.cloud.SolrZkClient; makePath: /configs/conf1/protwords.txt [junit4:junit4] 1> INFO - 2013-04-09 06:27:54.985; org.apache.solr.cloud= .AbstractZkTestCase; put /usr/home/hudson/hudson-slave/workspace/Lucene-Sol= r-NightlyTests-trunk/solr/build/solr-core/test-files/solr/collection1/conf/= currency.xml to /configs/conf1/currency.xml [junit4:junit4] 1> INFO - 2013-04-09 06:27:54.986; org.apache.solr.commo= n.cloud.SolrZkClient; makePath: /configs/conf1/currency.xml [junit4:junit4] 1> INFO - 2013-04-09 06:27:54.989; org.apache.solr.cloud= .AbstractZkTestCase; put /usr/home/hudson/hudson-slave/workspace/Lucene-Sol= r-NightlyTests-trunk/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-09 06:27:54.990; org.apache.solr.commo= n.cloud.SolrZkClient; makePath: /configs/conf1/open-exchange-rates.json [junit4:junit4] 1> INFO - 2013-04-09 06:27:54.993; org.apache.solr.cloud= .AbstractZkTestCase; put /usr/home/hudson/hudson-slave/workspace/Lucene-Sol= r-NightlyTests-trunk/solr/build/solr-core/test-files/solr/collection1/conf/= mapping-ISOLatin1Accent.txt to /configs/conf1/mapping-ISOLatin1Accent.txt [junit4:junit4] 1> INFO - 2013-04-09 06:27:54.995; org.apache.solr.commo= n.cloud.SolrZkClient; makePath: /configs/conf1/mapping-ISOLatin1Accent.txt [junit4:junit4] 1> INFO - 2013-04-09 06:27:54.998; org.apache.solr.cloud= .AbstractZkTestCase; put /usr/home/hudson/hudson-slave/workspace/Lucene-Sol= r-NightlyTests-trunk/solr/build/solr-core/test-files/solr/collection1/conf/= old_synonyms.txt to /configs/conf1/old_synonyms.txt [junit4:junit4] 1> INFO - 2013-04-09 06:27:54.998; org.apache.solr.commo= n.cloud.SolrZkClient; makePath: /configs/conf1/old_synonyms.txt [junit4:junit4] 1> INFO - 2013-04-09 06:27:55.001; org.apache.solr.cloud= .AbstractZkTestCase; put /usr/home/hudson/hudson-slave/workspace/Lucene-Sol= r-NightlyTests-trunk/solr/build/solr-core/test-files/solr/collection1/conf/= synonyms.txt to /configs/conf1/synonyms.txt [junit4:junit4] 1> INFO - 2013-04-09 06:27:55.002; org.apache.solr.commo= n.cloud.SolrZkClient; makePath: /configs/conf1/synonyms.txt [junit4:junit4] 1> INFO - 2013-04-09 06:27:55.216; org.eclipse.jetty.ser= ver.Server; jetty-8.1.8.v20121106 [junit4:junit4] 1> INFO - 2013-04-09 06:27:55.221; org.eclipse.jetty.ser= ver.AbstractConnector; Started SocketConnector@127.0.0.1:46998 [junit4:junit4] 1> INFO - 2013-04-09 06:27:55.221; org.apache.solr.servl= et.SolrDispatchFilter; SolrDispatchFilter.init() [junit4:junit4] 1> INFO - 2013-04-09 06:27:55.222; org.apache.solr.core.= SolrResourceLoader; JNDI not configured for solr (NoInitialContextEx) [junit4:junit4] 1> INFO - 2013-04-09 06:27:55.222; org.apache.solr.core.= SolrResourceLoader; using system property solr.solr.home: /usr/home/hudson/= hudson-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/= test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-controljett= y-1365488875013 [junit4:junit4] 1> INFO - 2013-04-09 06:27:55.223; org.apache.solr.core.= CoreContainer$Initializer; looking for solr config file: /usr/home/hudson/h= udson-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/t= est/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-controljetty= -1365488875013/solr.xml [junit4:junit4] 1> INFO - 2013-04-09 06:27:55.223; org.apache.solr.core.= CoreContainer; New CoreContainer 2078163428 [junit4:junit4] 1> INFO - 2013-04-09 06:27:55.224; org.apache.solr.core.= CoreContainer; Loading CoreContainer using Solr Home: '/usr/home/hudson/hud= son-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/tes= t/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-controljetty-1= 365488875013/' [junit4:junit4] 1> INFO - 2013-04-09 06:27:55.224; org.apache.solr.core.= SolrResourceLoader; new SolrResourceLoader for directory: '/usr/home/hudson= /hudson-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core= /test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-controljet= ty-1365488875013/' [junit4:junit4] 1> INFO - 2013-04-09 06:27:55.281; org.apache.solr.handl= er.component.HttpShardHandlerFactory; Setting socketTimeout to: 120000 [junit4:junit4] 1> INFO - 2013-04-09 06:27:55.282; org.apache.solr.handl= er.component.HttpShardHandlerFactory; Setting urlScheme to: http:// [junit4:junit4] 1> INFO - 2013-04-09 06:27:55.282; org.apache.solr.handl= er.component.HttpShardHandlerFactory; Setting connTimeout to: 15000 [junit4:junit4] 1> INFO - 2013-04-09 06:27:55.283; org.apache.solr.handl= er.component.HttpShardHandlerFactory; Setting maxConnectionsPerHost to: 20 [junit4:junit4] 1> INFO - 2013-04-09 06:27:55.283; org.apache.solr.handl= er.component.HttpShardHandlerFactory; Setting corePoolSize to: 0 [junit4:junit4] 1> INFO - 2013-04-09 06:27:55.284; org.apache.solr.handl= er.component.HttpShardHandlerFactory; Setting maximumPoolSize to: 214748364= 7 [junit4:junit4] 1> INFO - 2013-04-09 06:27:55.285; org.apache.solr.handl= er.component.HttpShardHandlerFactory; Setting maxThreadIdleTime to: 5 [junit4:junit4] 1> INFO - 2013-04-09 06:27:55.285; org.apache.solr.handl= er.component.HttpShardHandlerFactory; Setting sizeOfQueue to: -1 [junit4:junit4] 1> INFO - 2013-04-09 06:27:55.285; org.apache.solr.handl= er.component.HttpShardHandlerFactory; Setting fairnessPolicy to: false [junit4:junit4] 1> INFO - 2013-04-09 06:27:55.286; org.apache.solr.clien= t.solrj.impl.HttpClientUtil; Creating new http client, config:maxConnection= sPerHost=3D20&maxConnections=3D10000&socketTimeout=3D120000&connTimeout=3D1= 5000&retry=3Dfalse [junit4:junit4] 1> INFO - 2013-04-09 06:27:55.309; org.apache.solr.core.= CoreContainer; Registering Log Listener [junit4:junit4] 1> INFO - 2013-04-09 06:27:55.325; org.apache.solr.core.= CoreContainer; Zookeeper client=3D127.0.0.1:11081/solr [junit4:junit4] 1> INFO - 2013-04-09 06:27:55.326; org.apache.solr.cloud= .ZkController; zkHost includes chroot [junit4:junit4] 1> INFO - 2013-04-09 06:27:55.327; org.apache.solr.commo= n.cloud.ConnectionManager; Waiting for client to connect to ZooKeeper [junit4:junit4] 1> INFO - 2013-04-09 06:27:55.330; org.apache.solr.commo= n.cloud.ConnectionManager; Watcher org.apache.solr.common.cloud.ConnectionM= anager@35be76eb name:ZooKeeperConnection Watcher:127.0.0.1:11081 got event = WatchedEvent state:SyncConnected type:None path:null path:null type:None [junit4:junit4] 1> INFO - 2013-04-09 06:27:55.331; org.apache.solr.commo= n.cloud.ConnectionManager; Client is connected to ZooKeeper [junit4:junit4] 1> INFO - 2013-04-09 06:27:55.333; 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-09 06:27:55.342; org.apache.solr.commo= n.cloud.ConnectionManager; Waiting for client to connect to ZooKeeper [junit4:junit4] 1> INFO - 2013-04-09 06:27:55.345; org.apache.solr.commo= n.cloud.ConnectionManager; Watcher org.apache.solr.common.cloud.ConnectionM= anager@3adfad34 name:ZooKeeperConnection Watcher:127.0.0.1:11081/solr got e= vent WatchedEvent state:SyncConnected type:None path:null path:null type:No= ne [junit4:junit4] 1> INFO - 2013-04-09 06:27:55.345; org.apache.solr.commo= n.cloud.ConnectionManager; Client is connected to ZooKeeper [junit4:junit4] 1> INFO - 2013-04-09 06:27:55.347; org.apache.solr.commo= n.cloud.SolrZkClient; makePath: /overseer/queue [junit4:junit4] 1> INFO - 2013-04-09 06:27:55.357; org.apache.solr.commo= n.cloud.SolrZkClient; makePath: /overseer/collection-queue-work [junit4:junit4] 1> INFO - 2013-04-09 06:27:55.360; org.apache.solr.commo= n.cloud.SolrZkClient; makePath: /live_nodes [junit4:junit4] 1> INFO - 2013-04-09 06:27:55.363; org.apache.solr.cloud= .ZkController; Register node as live in ZooKeeper:/live_nodes/127.0.0.1:469= 98_ [junit4:junit4] 1> INFO - 2013-04-09 06:27:55.364; org.apache.solr.commo= n.cloud.SolrZkClient; makePath: /live_nodes/127.0.0.1:46998_ [junit4:junit4] 1> INFO - 2013-04-09 06:27:55.374; org.apache.solr.commo= n.cloud.SolrZkClient; makePath: /overseer_elect/election [junit4:junit4] 1> INFO - 2013-04-09 06:27:55.388; org.apache.solr.commo= n.cloud.SolrZkClient; makePath: /overseer_elect/leader [junit4:junit4] 1> INFO - 2013-04-09 06:27:55.391; org.apache.solr.cloud= .Overseer; Overseer (id=3D89488678890373123-127.0.0.1:46998_-n_0000000000) = starting [junit4:junit4] 1> INFO - 2013-04-09 06:27:55.395; org.apache.solr.commo= n.cloud.SolrZkClient; makePath: /overseer/queue-work [junit4:junit4] 1> INFO - 2013-04-09 06:27:55.408; org.apache.solr.cloud= .OverseerCollectionProcessor; Process current queue of collection creations [junit4:junit4] 1> INFO - 2013-04-09 06:27:55.408; org.apache.solr.commo= n.cloud.SolrZkClient; makePath: /clusterstate.json [junit4:junit4] 1> INFO - 2013-04-09 06:27:55.410; org.apache.solr.commo= n.cloud.SolrZkClient; makePath: /aliases.json [junit4:junit4] 1> INFO - 2013-04-09 06:27:55.412; org.apache.solr.commo= n.cloud.ZkStateReader; Updating cluster state from ZooKeeper...=20 [junit4:junit4] 1> INFO - 2013-04-09 06:27:55.414; org.apache.solr.cloud= .Overseer$ClusterStateUpdater; Starting to work on the main queue [junit4:junit4] 1> INFO - 2013-04-09 06:27:55.416; org.apache.solr.servl= et.SolrDispatchFilter; user.dir=3D/usr/home/hudson/hudson-slave/workspace/L= ucene-Solr-NightlyTests-trunk/solr/build/solr-core/test/J1 [junit4:junit4] 1> INFO - 2013-04-09 06:27:55.417; org.apache.solr.servl= et.SolrDispatchFilter; SolrDispatchFilter.init() done [junit4:junit4] 1> INFO - 2013-04-09 06:27:55.417; 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-09 06:27:55.426; org.apache.solr.clien= t.solrj.impl.HttpClientUtil; Creating new http client, config: [junit4:junit4] 1> INFO - 2013-04-09 06:27:55.428; org.apache.solr.commo= n.cloud.ConnectionManager; Waiting for client to connect to ZooKeeper [junit4:junit4] 1> INFO - 2013-04-09 06:27:55.430; org.apache.solr.commo= n.cloud.ConnectionManager; Watcher org.apache.solr.common.cloud.ConnectionM= anager@3910daec name:ZooKeeperConnection Watcher:127.0.0.1:11081/solr got e= vent WatchedEvent state:SyncConnected type:None path:null path:null type:No= ne [junit4:junit4] 1> INFO - 2013-04-09 06:27:55.430; org.apache.solr.commo= n.cloud.ConnectionManager; Client is connected to ZooKeeper [junit4:junit4] 1> INFO - 2013-04-09 06:27:55.432; org.apache.solr.commo= n.cloud.ZkStateReader; Updating cluster state from ZooKeeper...=20 [junit4:junit4] 1> INFO - 2013-04-09 06:27:55.434; org.apache.solr.cloud= .ChaosMonkey; monkey: init - expire sessions:true cause connection loss:tru= e [junit4:junit4] 1> INFO - 2013-04-09 06:27:55.615; org.eclipse.jetty.ser= ver.Server; jetty-8.1.8.v20121106 [junit4:junit4] 1> INFO - 2013-04-09 06:27:55.617; org.eclipse.jetty.ser= ver.AbstractConnector; Started SocketConnector@127.0.0.1:10515 [junit4:junit4] 1> INFO - 2013-04-09 06:27:55.618; org.apache.solr.servl= et.SolrDispatchFilter; SolrDispatchFilter.init() [junit4:junit4] 1> INFO - 2013-04-09 06:27:55.618; org.apache.solr.core.= SolrResourceLoader; JNDI not configured for solr (NoInitialContextEx) [junit4:junit4] 1> INFO - 2013-04-09 06:27:55.619; org.apache.solr.core.= SolrResourceLoader; using system property solr.solr.home: /usr/home/hudson/= hudson-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/= test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty1-1365= 488875434 [junit4:junit4] 1> INFO - 2013-04-09 06:27:55.619; org.apache.solr.core.= CoreContainer$Initializer; looking for solr config file: /usr/home/hudson/h= udson-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/t= est/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty1-13654= 88875434/solr.xml [junit4:junit4] 1> INFO - 2013-04-09 06:27:55.619; org.apache.solr.core.= CoreContainer; New CoreContainer 1185857325 [junit4:junit4] 1> INFO - 2013-04-09 06:27:55.620; org.apache.solr.core.= CoreContainer; Loading CoreContainer using Solr Home: '/usr/home/hudson/hud= son-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/tes= t/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty1-1365488= 875434/' [junit4:junit4] 1> INFO - 2013-04-09 06:27:55.620; org.apache.solr.core.= SolrResourceLoader; new SolrResourceLoader for directory: '/usr/home/hudson= /hudson-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core= /test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty1-136= 5488875434/' [junit4:junit4] 1> INFO - 2013-04-09 06:27:55.677; org.apache.solr.handl= er.component.HttpShardHandlerFactory; Setting socketTimeout to: 120000 [junit4:junit4] 1> INFO - 2013-04-09 06:27:55.678; org.apache.solr.handl= er.component.HttpShardHandlerFactory; Setting urlScheme to: http:// [junit4:junit4] 1> INFO - 2013-04-09 06:27:55.678; org.apache.solr.handl= er.component.HttpShardHandlerFactory; Setting connTimeout to: 15000 [junit4:junit4] 1> INFO - 2013-04-09 06:27:55.678; org.apache.solr.handl= er.component.HttpShardHandlerFactory; Setting maxConnectionsPerHost to: 20 [junit4:junit4] 1> INFO - 2013-04-09 06:27:55.679; org.apache.solr.handl= er.component.HttpShardHandlerFactory; Setting corePoolSize to: 0 [junit4:junit4] 1> INFO - 2013-04-09 06:27:55.679; org.apache.solr.handl= er.component.HttpShardHandlerFactory; Setting maximumPoolSize to: 214748364= 7 [junit4:junit4] 1> INFO - 2013-04-09 06:27:55.680; org.apache.solr.handl= er.component.HttpShardHandlerFactory; Setting maxThreadIdleTime to: 5 [junit4:junit4] 1> INFO - 2013-04-09 06:27:55.680; org.apache.solr.handl= er.component.HttpShardHandlerFactory; Setting sizeOfQueue to: -1 [junit4:junit4] 1> INFO - 2013-04-09 06:27:55.680; org.apache.solr.handl= er.component.HttpShardHandlerFactory; Setting fairnessPolicy to: false [junit4:junit4] 1> INFO - 2013-04-09 06:27:55.681; org.apache.solr.clien= t.solrj.impl.HttpClientUtil; Creating new http client, config:maxConnection= sPerHost=3D20&maxConnections=3D10000&socketTimeout=3D120000&connTimeout=3D1= 5000&retry=3Dfalse [junit4:junit4] 1> INFO - 2013-04-09 06:27:55.698; org.apache.solr.core.= CoreContainer; Registering Log Listener [junit4:junit4] 1> INFO - 2013-04-09 06:27:55.722; org.apache.solr.core.= CoreContainer; Zookeeper client=3D127.0.0.1:11081/solr [junit4:junit4] 1> INFO - 2013-04-09 06:27:55.722; org.apache.solr.cloud= .ZkController; zkHost includes chroot [junit4:junit4] 1> INFO - 2013-04-09 06:27:55.723; org.apache.solr.commo= n.cloud.ConnectionManager; Waiting for client to connect to ZooKeeper [junit4:junit4] 1> INFO - 2013-04-09 06:27:55.726; org.apache.solr.commo= n.cloud.ConnectionManager; Watcher org.apache.solr.common.cloud.ConnectionM= anager@2f9edf1e name:ZooKeeperConnection Watcher:127.0.0.1:11081 got event = WatchedEvent state:SyncConnected type:None path:null path:null type:None [junit4:junit4] 1> INFO - 2013-04-09 06:27:55.727; org.apache.solr.commo= n.cloud.ConnectionManager; Client is connected to ZooKeeper [junit4:junit4] 1> INFO - 2013-04-09 06:27:55.741; 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-09 06:27:55.750; org.apache.solr.commo= n.cloud.ConnectionManager; Waiting for client to connect to ZooKeeper [junit4:junit4] 1> INFO - 2013-04-09 06:27:55.752; org.apache.solr.commo= n.cloud.ConnectionManager; Watcher org.apache.solr.common.cloud.ConnectionM= anager@d6d194f name:ZooKeeperConnection Watcher:127.0.0.1:11081/solr got ev= ent WatchedEvent state:SyncConnected type:None path:null path:null type:Non= e [junit4:junit4] 1> INFO - 2013-04-09 06:27:55.752; org.apache.solr.commo= n.cloud.ConnectionManager; Client is connected to ZooKeeper [junit4:junit4] 1> INFO - 2013-04-09 06:27:55.763; org.apache.solr.commo= n.cloud.ZkStateReader; Updating cluster state from ZooKeeper...=20 [junit4:junit4] 1> INFO - 2013-04-09 06:27:56.766; org.apache.solr.cloud= .ZkController; Register node as live in ZooKeeper:/live_nodes/127.0.0.1:105= 15_ [junit4:junit4] 1> INFO - 2013-04-09 06:27:56.768; org.apache.solr.commo= n.cloud.SolrZkClient; makePath: /live_nodes/127.0.0.1:10515_ [junit4:junit4] 1> INFO - 2013-04-09 06:27:56.772; org.apache.solr.commo= n.cloud.ZkStateReader$3; Updating live nodes... (2) [junit4:junit4] 1> INFO - 2013-04-09 06:27:56.772; org.apache.solr.commo= n.cloud.ZkStateReader$3; Updating live nodes... (2) [junit4:junit4] 1> INFO - 2013-04-09 06:27:56.772; org.apache.solr.commo= n.cloud.ZkStateReader$3; Updating live nodes... (2) [junit4:junit4] 1> INFO - 2013-04-09 06:27:56.785; org.apache.solr.servl= et.SolrDispatchFilter; user.dir=3D/usr/home/hudson/hudson-slave/workspace/L= ucene-Solr-NightlyTests-trunk/solr/build/solr-core/test/J1 [junit4:junit4] 1> INFO - 2013-04-09 06:27:56.786; org.apache.solr.servl= et.SolrDispatchFilter; SolrDispatchFilter.init() done [junit4:junit4] 1> INFO - 2013-04-09 06:27:56.786; 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-09 06:27:57.004; org.eclipse.jetty.ser= ver.Server; jetty-8.1.8.v20121106 [junit4:junit4] 1> INFO - 2013-04-09 06:27:57.007; org.eclipse.jetty.ser= ver.AbstractConnector; Started SocketConnector@127.0.0.1:15909 [junit4:junit4] 1> INFO - 2013-04-09 06:27:57.008; org.apache.solr.servl= et.SolrDispatchFilter; SolrDispatchFilter.init() [junit4:junit4] 1> INFO - 2013-04-09 06:27:57.008; org.apache.solr.core.= SolrResourceLoader; JNDI not configured for solr (NoInitialContextEx) [junit4:junit4] 1> INFO - 2013-04-09 06:27:57.009; org.apache.solr.core.= SolrResourceLoader; using system property solr.solr.home: /usr/home/hudson/= hudson-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/= test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty2-1365= 488876797 [junit4:junit4] 1> INFO - 2013-04-09 06:27:57.009; org.apache.solr.core.= CoreContainer$Initializer; looking for solr config file: /usr/home/hudson/h= udson-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/t= est/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty2-13654= 88876797/solr.xml [junit4:junit4] 1> INFO - 2013-04-09 06:27:57.010; org.apache.solr.core.= CoreContainer; New CoreContainer 2147206543 [junit4:junit4] 1> INFO - 2013-04-09 06:27:57.010; org.apache.solr.core.= CoreContainer; Loading CoreContainer using Solr Home: '/usr/home/hudson/hud= son-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/tes= t/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty2-1365488= 876797/' [junit4:junit4] 1> INFO - 2013-04-09 06:27:57.011; org.apache.solr.core.= SolrResourceLoader; new SolrResourceLoader for directory: '/usr/home/hudson= /hudson-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core= /test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty2-136= 5488876797/' [junit4:junit4] 1> INFO - 2013-04-09 06:27:57.077; org.apache.solr.handl= er.component.HttpShardHandlerFactory; Setting socketTimeout to: 120000 [junit4:junit4] 1> INFO - 2013-04-09 06:27:57.078; org.apache.solr.handl= er.component.HttpShardHandlerFactory; Setting urlScheme to: http:// [junit4:junit4] 1> INFO - 2013-04-09 06:27:57.078; org.apache.solr.handl= er.component.HttpShardHandlerFactory; Setting connTimeout to: 15000 [junit4:junit4] 1> INFO - 2013-04-09 06:27:57.079; org.apache.solr.handl= er.component.HttpShardHandlerFactory; Setting maxConnectionsPerHost to: 20 [junit4:junit4] 1> INFO - 2013-04-09 06:27:57.079; org.apache.solr.handl= er.component.HttpShardHandlerFactory; Setting corePoolSize to: 0 [junit4:junit4] 1> INFO - 2013-04-09 06:27:57.079; org.apache.solr.handl= er.component.HttpShardHandlerFactory; Setting maximumPoolSize to: 214748364= 7 [junit4:junit4] 1> INFO - 2013-04-09 06:27:57.080; org.apache.solr.handl= er.component.HttpShardHandlerFactory; Setting maxThreadIdleTime to: 5 [junit4:junit4] 1> INFO - 2013-04-09 06:27:57.080; org.apache.solr.handl= er.component.HttpShardHandlerFactory; Setting sizeOfQueue to: -1 [junit4:junit4] 1> INFO - 2013-04-09 06:27:57.081; org.apache.solr.handl= er.component.HttpShardHandlerFactory; Setting fairnessPolicy to: false [junit4:junit4] 1> INFO - 2013-04-09 06:27:57.081; org.apache.solr.clien= t.solrj.impl.HttpClientUtil; Creating new http client, config:maxConnection= sPerHost=3D20&maxConnections=3D10000&socketTimeout=3D120000&connTimeout=3D1= 5000&retry=3Dfalse [junit4:junit4] 1> INFO - 2013-04-09 06:27:57.103; org.apache.solr.core.= CoreContainer; Registering Log Listener [junit4:junit4] 1> INFO - 2013-04-09 06:27:57.122; org.apache.solr.core.= CoreContainer; Zookeeper client=3D127.0.0.1:11081/solr [junit4:junit4] 1> INFO - 2013-04-09 06:27:57.123; org.apache.solr.cloud= .ZkController; zkHost includes chroot [junit4:junit4] 1> INFO - 2013-04-09 06:27:57.124; org.apache.solr.commo= n.cloud.ConnectionManager; Waiting for client to connect to ZooKeeper [junit4:junit4] 1> INFO - 2013-04-09 06:27:57.126; org.apache.solr.commo= n.cloud.ConnectionManager; Watcher org.apache.solr.common.cloud.ConnectionM= anager@29ac1cac name:ZooKeeperConnection Watcher:127.0.0.1:11081 got event = WatchedEvent state:SyncConnected type:None path:null path:null type:None [junit4:junit4] 1> INFO - 2013-04-09 06:27:57.127; org.apache.solr.commo= n.cloud.ConnectionManager; Client is connected to ZooKeeper [junit4:junit4] 1> INFO - 2013-04-09 06:27:57.129; 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-09 06:27:57.142; org.apache.solr.commo= n.cloud.ConnectionManager; Waiting for client to connect to ZooKeeper [junit4:junit4] 1> INFO - 2013-04-09 06:27:57.144; org.apache.solr.commo= n.cloud.ConnectionManager; Watcher org.apache.solr.common.cloud.ConnectionM= anager@5079458b name:ZooKeeperConnection Watcher:127.0.0.1:11081/solr got e= vent WatchedEvent state:SyncConnected type:None path:null path:null type:No= ne [junit4:junit4] 1> INFO - 2013-04-09 06:27:57.144; org.apache.solr.commo= n.cloud.ConnectionManager; Client is connected to ZooKeeper [junit4:junit4] 1> INFO - 2013-04-09 06:27:57.156; org.apache.solr.commo= n.cloud.ZkStateReader; Updating cluster state from ZooKeeper...=20 [junit4:junit4] 1> INFO - 2013-04-09 06:27:58.159; org.apache.solr.cloud= .ZkController; Register node as live in ZooKeeper:/live_nodes/127.0.0.1:159= 09_ [junit4:junit4] 1> INFO - 2013-04-09 06:27:58.161; org.apache.solr.commo= n.cloud.SolrZkClient; makePath: /live_nodes/127.0.0.1:15909_ [junit4:junit4] 1> INFO - 2013-04-09 06:27:58.165; org.apache.solr.commo= n.cloud.ZkStateReader$3; Updating live nodes... (3) [junit4:junit4] 1> INFO - 2013-04-09 06:27:58.165; org.apache.solr.commo= n.cloud.ZkStateReader$3; Updating live nodes... (3) [junit4:junit4] 1> INFO - 2013-04-09 06:27:58.165; org.apache.solr.commo= n.cloud.ZkStateReader$3; Updating live nodes... (3) [junit4:junit4] 1> INFO - 2013-04-09 06:27:58.165; org.apache.solr.commo= n.cloud.ZkStateReader$3; Updating live nodes... (3) [junit4:junit4] 1> INFO - 2013-04-09 06:27:58.175; org.apache.solr.servl= et.SolrDispatchFilter; user.dir=3D/usr/home/hudson/hudson-slave/workspace/L= ucene-Solr-NightlyTests-trunk/solr/build/solr-core/test/J1 [junit4:junit4] 1> INFO - 2013-04-09 06:27:58.176; org.apache.solr.servl= et.SolrDispatchFilter; SolrDispatchFilter.init() done [junit4:junit4] 1> INFO - 2013-04-09 06:27:58.176; 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-09 06:27:58.318; org.eclipse.jetty.ser= ver.Server; jetty-8.1.8.v20121106 [junit4:junit4] 1> INFO - 2013-04-09 06:27:58.320; org.eclipse.jetty.ser= ver.AbstractConnector; Started SocketConnector@127.0.0.1:37902 [junit4:junit4] 1> INFO - 2013-04-09 06:27:58.321; org.apache.solr.servl= et.SolrDispatchFilter; SolrDispatchFilter.init() [junit4:junit4] 1> INFO - 2013-04-09 06:27:58.321; org.apache.solr.core.= SolrResourceLoader; JNDI not configured for solr (NoInitialContextEx) [junit4:junit4] 1> INFO - 2013-04-09 06:27:58.321; org.apache.solr.core.= SolrResourceLoader; using system property solr.solr.home: /usr/home/hudson/= hudson-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/= test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty3-1365= 488878182 [junit4:junit4] 1> INFO - 2013-04-09 06:27:58.322; org.apache.solr.core.= CoreContainer$Initializer; looking for solr config file: /usr/home/hudson/h= udson-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/t= est/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty3-13654= 88878182/solr.xml [junit4:junit4] 1> INFO - 2013-04-09 06:27:58.322; org.apache.solr.core.= CoreContainer; New CoreContainer 1105589664 [junit4:junit4] 1> INFO - 2013-04-09 06:27:58.322; org.apache.solr.core.= CoreContainer; Loading CoreContainer using Solr Home: '/usr/home/hudson/hud= son-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/tes= t/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty3-1365488= 878182/' [junit4:junit4] 1> INFO - 2013-04-09 06:27:58.323; org.apache.solr.core.= SolrResourceLoader; new SolrResourceLoader for directory: '/usr/home/hudson= /hudson-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core= /test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty3-136= 5488878182/' [junit4:junit4] 1> INFO - 2013-04-09 06:27:58.366; org.apache.solr.handl= er.component.HttpShardHandlerFactory; Setting socketTimeout to: 120000 [junit4:junit4] 1> INFO - 2013-04-09 06:27:58.366; org.apache.solr.handl= er.component.HttpShardHandlerFactory; Setting urlScheme to: http:// [junit4:junit4] 1> INFO - 2013-04-09 06:27:58.366; org.apache.solr.handl= er.component.HttpShardHandlerFactory; Setting connTimeout to: 15000 [junit4:junit4] 1> INFO - 2013-04-09 06:27:58.367; org.apache.solr.handl= er.component.HttpShardHandlerFactory; Setting maxConnectionsPerHost to: 20 [junit4:junit4] 1> INFO - 2013-04-09 06:27:58.367; org.apache.solr.handl= er.component.HttpShardHandlerFactory; Setting corePoolSize to: 0 [junit4:junit4] 1> INFO - 2013-04-09 06:27:58.367; org.apache.solr.handl= er.component.HttpShardHandlerFactory; Setting maximumPoolSize to: 214748364= 7 [junit4:junit4] 1> INFO - 2013-04-09 06:27:58.368; org.apache.solr.handl= er.component.HttpShardHandlerFactory; Setting maxThreadIdleTime to: 5 [junit4:junit4] 1> INFO - 2013-04-09 06:27:58.368; org.apache.solr.handl= er.component.HttpShardHandlerFactory; Setting sizeOfQueue to: -1 [junit4:junit4] 1> INFO - 2013-04-09 06:27:58.368; org.apache.solr.handl= er.component.HttpShardHandlerFactory; Setting fairnessPolicy to: false [junit4:junit4] 1> INFO - 2013-04-09 06:27:58.369; org.apache.solr.clien= t.solrj.impl.HttpClientUtil; Creating new http client, config:maxConnection= sPerHost=3D20&maxConnections=3D10000&socketTimeout=3D120000&connTimeout=3D1= 5000&retry=3Dfalse [junit4:junit4] 1> INFO - 2013-04-09 06:27:58.382; org.apache.solr.core.= CoreContainer; Registering Log Listener [junit4:junit4] 1> INFO - 2013-04-09 06:27:58.394; org.apache.solr.core.= CoreContainer; Zookeeper client=3D127.0.0.1:11081/solr [junit4:junit4] 1> INFO - 2013-04-09 06:27:58.395; org.apache.solr.cloud= .ZkController; zkHost includes chroot [junit4:junit4] 1> INFO - 2013-04-09 06:27:58.395; org.apache.solr.commo= n.cloud.ConnectionManager; Waiting for client to connect to ZooKeeper [junit4:junit4] 1> INFO - 2013-04-09 06:27:58.398; org.apache.solr.commo= n.cloud.ConnectionManager; Watcher org.apache.solr.common.cloud.ConnectionM= anager@4a2c192b name:ZooKeeperConnection Watcher:127.0.0.1:11081 got event = WatchedEvent state:SyncConnected type:None path:null path:null type:None [junit4:junit4] 1> INFO - 2013-04-09 06:27:58.398; org.apache.solr.commo= n.cloud.ConnectionManager; Client is connected to ZooKeeper [junit4:junit4] 1> INFO - 2013-04-09 06:27:58.401; 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-09 06:27:58.407; org.apache.solr.commo= n.cloud.ConnectionManager; Waiting for client to connect to ZooKeeper [junit4:junit4] 1> INFO - 2013-04-09 06:27:58.414; org.apache.solr.commo= n.cloud.ConnectionManager; Watcher org.apache.solr.common.cloud.ConnectionM= anager@12a765f name:ZooKeeperConnection Watcher:127.0.0.1:11081/solr got ev= ent WatchedEvent state:SyncConnected type:None path:null path:null type:Non= e [junit4:junit4] 1> INFO - 2013-04-09 06:27:58.414; org.apache.solr.commo= n.cloud.ConnectionManager; Client is connected to ZooKeeper [junit4:junit4] 1> INFO - 2013-04-09 06:27:58.425; org.apache.solr.commo= n.cloud.ZkStateReader; Updating cluster state from ZooKeeper...=20 [junit4:junit4] 1> INFO - 2013-04-09 06:27:59.439; org.apache.solr.cloud= .ZkController; Register node as live in ZooKeeper:/live_nodes/127.0.0.1:379= 02_ [junit4:junit4] 1> INFO - 2013-04-09 06:27:59.441; org.apache.solr.commo= n.cloud.SolrZkClient; makePath: /live_nodes/127.0.0.1:37902_ [junit4:junit4] 1> INFO - 2013-04-09 06:27:59.445; org.apache.solr.commo= n.cloud.ZkStateReader$3; Updating live nodes... (4) [junit4:junit4] 1> INFO - 2013-04-09 06:27:59.446; org.apache.solr.commo= n.cloud.ZkStateReader$3; Updating live nodes... (4) [junit4:junit4] 1> INFO - 2013-04-09 06:27:59.446; org.apache.solr.commo= n.cloud.ZkStateReader$3; Updating live nodes... (4) [junit4:junit4] 1> INFO - 2013-04-09 06:27:59.446; org.apache.solr.commo= n.cloud.ZkStateReader$3; Updating live nodes... (4) [junit4:junit4] 1> INFO - 2013-04-09 06:27:59.445; org.apache.solr.commo= n.cloud.ZkStateReader$3; Updating live nodes... (4) [junit4:junit4] 1> INFO - 2013-04-09 06:27:59.455; org.apache.solr.servl= et.SolrDispatchFilter; user.dir=3D/usr/home/hudson/hudson-slave/workspace/L= ucene-Solr-NightlyTests-trunk/solr/build/solr-core/test/J1 [junit4:junit4] 1> INFO - 2013-04-09 06:27:59.455; org.apache.solr.servl= et.SolrDispatchFilter; SolrDispatchFilter.init() done [junit4:junit4] 1> INFO - 2013-04-09 06:27:59.456; 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-09 06:27:59.597; org.eclipse.jetty.ser= ver.Server; jetty-8.1.8.v20121106 [junit4:junit4] 1> INFO - 2013-04-09 06:27:59.599; org.eclipse.jetty.ser= ver.AbstractConnector; Started SocketConnector@127.0.0.1:46348 [junit4:junit4] 1> INFO - 2013-04-09 06:27:59.599; org.apache.solr.servl= et.SolrDispatchFilter; SolrDispatchFilter.init() [junit4:junit4] 1> INFO - 2013-04-09 06:27:59.600; org.apache.solr.core.= SolrResourceLoader; JNDI not configured for solr (NoInitialContextEx) [junit4:junit4] 1> INFO - 2013-04-09 06:27:59.600; org.apache.solr.core.= SolrResourceLoader; using system property solr.solr.home: /usr/home/hudson/= hudson-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/= test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1365= 488879462 [junit4:junit4] 1> INFO - 2013-04-09 06:27:59.600; org.apache.solr.core.= CoreContainer$Initializer; looking for solr config file: /usr/home/hudson/h= udson-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/t= est/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-13654= 88879462/solr.xml [junit4:junit4] 1> INFO - 2013-04-09 06:27:59.601; org.apache.solr.core.= CoreContainer; New CoreContainer 1189566055 [junit4:junit4] 1> INFO - 2013-04-09 06:27:59.601; org.apache.solr.core.= CoreContainer; Loading CoreContainer using Solr Home: '/usr/home/hudson/hud= son-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/tes= t/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1365488= 879462/' [junit4:junit4] 1> INFO - 2013-04-09 06:27:59.601; org.apache.solr.core.= SolrResourceLoader; new SolrResourceLoader for directory: '/usr/home/hudson= /hudson-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core= /test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-136= 5488879462/' [junit4:junit4] 1> INFO - 2013-04-09 06:27:59.644; org.apache.solr.handl= er.component.HttpShardHandlerFactory; Setting socketTimeout to: 120000 [junit4:junit4] 1> INFO - 2013-04-09 06:27:59.645; org.apache.solr.handl= er.component.HttpShardHandlerFactory; Setting urlScheme to: http:// [junit4:junit4] 1> INFO - 2013-04-09 06:27:59.645; org.apache.solr.handl= er.component.HttpShardHandlerFactory; Setting connTimeout to: 15000 [junit4:junit4] 1> INFO - 2013-04-09 06:27:59.645; org.apache.solr.handl= er.component.HttpShardHandlerFactory; Setting maxConnectionsPerHost to: 20 [junit4:junit4] 1> INFO - 2013-04-09 06:27:59.646; org.apache.solr.handl= er.component.HttpShardHandlerFactory; Setting corePoolSize to: 0 [junit4:junit4] 1> INFO - 2013-04-09 06:27:59.646; org.apache.solr.handl= er.component.HttpShardHandlerFactory; Setting maximumPoolSize to: 214748364= 7 [junit4:junit4] 1> INFO - 2013-04-09 06:27:59.646; org.apache.solr.handl= er.component.HttpShardHandlerFactory; Setting maxThreadIdleTime to: 5 [junit4:junit4] 1> INFO - 2013-04-09 06:27:59.646; org.apache.solr.handl= er.component.HttpShardHandlerFactory; Setting sizeOfQueue to: -1 [junit4:junit4] 1> INFO - 2013-04-09 06:27:59.647; org.apache.solr.handl= er.component.HttpShardHandlerFactory; Setting fairnessPolicy to: false [junit4:junit4] 1> INFO - 2013-04-09 06:27:59.647; org.apache.solr.clien= t.solrj.impl.HttpClientUtil; Creating new http client, config:maxConnection= sPerHost=3D20&maxConnections=3D10000&socketTimeout=3D120000&connTimeout=3D1= 5000&retry=3Dfalse [junit4:junit4] 1> INFO - 2013-04-09 06:27:59.660; org.apache.solr.core.= CoreContainer; Registering Log Listener [junit4:junit4] 1> INFO - 2013-04-09 06:27:59.672; org.apache.solr.core.= CoreContainer; Zookeeper client=3D127.0.0.1:11081/solr [junit4:junit4] 1> INFO - 2013-04-09 06:27:59.673; org.apache.solr.cloud= .ZkController; zkHost includes chroot [junit4:junit4] 1> INFO - 2013-04-09 06:27:59.674; org.apache.solr.commo= n.cloud.ConnectionManager; Waiting for client to connect to ZooKeeper [junit4:junit4] 1> INFO - 2013-04-09 06:27:59.676; org.apache.solr.commo= n.cloud.ConnectionManager; Watcher org.apache.solr.common.cloud.ConnectionM= anager@3b0f47b9 name:ZooKeeperConnection Watcher:127.0.0.1:11081 got event = WatchedEvent state:SyncConnected type:None path:null path:null type:None [junit4:junit4] 1> INFO - 2013-04-09 06:27:59.677; org.apache.solr.commo= n.cloud.ConnectionManager; Client is connected to ZooKeeper [junit4:junit4] 1> INFO - 2013-04-09 06:27:59.679; 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-09 06:27:59.686; org.apache.solr.commo= n.cloud.ConnectionManager; Waiting for client to connect to ZooKeeper [junit4:junit4] 1> INFO - 2013-04-09 06:27:59.688; org.apache.solr.commo= n.cloud.ConnectionManager; Watcher org.apache.solr.common.cloud.ConnectionM= anager@5def48e8 name:ZooKeeperConnection Watcher:127.0.0.1:11081/solr got e= vent WatchedEvent state:SyncConnected type:None path:null path:null type:No= ne [junit4:junit4] 1> INFO - 2013-04-09 06:27:59.689; org.apache.solr.commo= n.cloud.ConnectionManager; Client is connected to ZooKeeper [junit4:junit4] 1> INFO - 2013-04-09 06:27:59.700; org.apache.solr.commo= n.cloud.ZkStateReader; Updating cluster state from ZooKeeper...=20 [junit4:junit4] 1> INFO - 2013-04-09 06:28:00.703; org.apache.solr.cloud= .ZkController; Register node as live in ZooKeeper:/live_nodes/127.0.0.1:463= 48_ [junit4:junit4] 1> INFO - 2013-04-09 06:28:00.734; org.apache.solr.commo= n.cloud.SolrZkClient; makePath: /live_nodes/127.0.0.1:46348_ [junit4:junit4] 1> INFO - 2013-04-09 06:28:00.737; org.apache.solr.commo= n.cloud.ZkStateReader$3; Updating live nodes... (5) [junit4:junit4] 1> INFO - 2013-04-09 06:28:00.737; org.apache.solr.commo= n.cloud.ZkStateReader$3; Updating live nodes... (5) [junit4:junit4] 1> INFO - 2013-04-09 06:28:00.737; org.apache.solr.commo= n.cloud.ZkStateReader$3; Updating live nodes... (5) [junit4:junit4] 1> INFO - 2013-04-09 06:28:00.737; org.apache.solr.commo= n.cloud.ZkStateReader$3; Updating live nodes... (5) [junit4:junit4] 1> INFO - 2013-04-09 06:28:00.737; org.apache.solr.commo= n.cloud.ZkStateReader$3; Updating live nodes... (5) [junit4:junit4] 1> INFO - 2013-04-09 06:28:00.737; org.apache.solr.commo= n.cloud.ZkStateReader$3; Updating live nodes... (5) [junit4:junit4] 1> INFO - 2013-04-09 06:28:00.748; org.apache.solr.servl= et.SolrDispatchFilter; user.dir=3D/usr/home/hudson/hudson-slave/workspace/L= ucene-Solr-NightlyTests-trunk/solr/build/solr-core/test/J1 [junit4:junit4] 1> INFO - 2013-04-09 06:28:00.748; org.apache.solr.servl= et.SolrDispatchFilter; SolrDispatchFilter.init() done [junit4:junit4] 1> INFO - 2013-04-09 06:28:00.748; 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-09 06:28:00.759; 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-09 06:28:00.772; 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-09 06:28:00.774; 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-09 06:28:00.796; 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-09 06:28:00.797; 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:46998_ [junit4:junit4] 1> INFO - 2013-04-09 06:28:00.797; 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:46348_ [junit4:junit4] 1> INFO - 2013-04-09 06:28:00.798; 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:37902_ [junit4:junit4] 1> INFO - 2013-04-09 06:28:00.799; 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:10515_ [junit4:junit4] 1> INFO - 2013-04-09 06:28:00.799; org.apache.solr.core.= CoreContainer; Creating SolrCore 'nodes_used_collection_shard1_replica2' us= ing instanceDir: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Nightl= yTests-trunk/solr/build/solr-core/test/J1/./org.apache.solr.cloud.Collectio= nsAPIDistributedZkTest-jetty4-1365488879462/nodes_used_collection_shard1_re= plica2 [junit4:junit4] 1> INFO - 2013-04-09 06:28:00.800; org.apache.solr.core.= CoreContainer; Creating SolrCore 'nodes_used_collection_shard1_replica1' us= ing instanceDir: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Nightl= yTests-trunk/solr/build/solr-core/test/J1/./org.apache.solr.cloud.Collectio= nsAPIDistributedZkTest-controljetty-1365488875013/nodes_used_collection_sha= rd1_replica1 [junit4:junit4] 1> INFO - 2013-04-09 06:28:00.800; org.apache.solr.core.= CoreContainer; Creating SolrCore 'nodes_used_collection_shard2_replica1' us= ing instanceDir: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Nightl= yTests-trunk/solr/build/solr-core/test/J1/./org.apache.solr.cloud.Collectio= nsAPIDistributedZkTest-jetty3-1365488878182/nodes_used_collection_shard2_re= plica1 [junit4:junit4] 1> INFO - 2013-04-09 06:28:00.801; org.apache.solr.cloud= .ZkController; Check for collection zkNode:nodes_used_collection [junit4:junit4] 1> INFO - 2013-04-09 06:28:00.800; org.apache.solr.cloud= .ZkController; Check for collection zkNode:nodes_used_collection [junit4:junit4] 1> INFO - 2013-04-09 06:28:00.800; org.apache.solr.core.= CoreContainer; Creating SolrCore 'nodes_used_collection_shard2_replica2' us= ing instanceDir: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Nightl= yTests-trunk/solr/build/solr-core/test/J1/./org.apache.solr.cloud.Collectio= nsAPIDistributedZkTest-jetty1-1365488875434/nodes_used_collection_shard2_re= plica2 [junit4:junit4] 1> INFO - 2013-04-09 06:28:00.802; org.apache.solr.cloud= .ZkController; Check for collection zkNode:nodes_used_collection [junit4:junit4] 1> INFO - 2013-04-09 06:28:00.800; org.apache.solr.cloud= .ZkController; Check for collection zkNode:nodes_used_collection [junit4:junit4] 1> INFO - 2013-04-09 06:28:00.802; org.apache.solr.cloud= .ZkController; Creating collection in ZooKeeper:nodes_used_collection [junit4:junit4] 1> INFO - 2013-04-09 06:28:00.802; org.apache.solr.cloud= .ZkController; Creating collection in ZooKeeper:nodes_used_collection [junit4:junit4] 1> INFO - 2013-04-09 06:28:00.802; org.apache.solr.cloud= .ZkController; Creating collection in ZooKeeper:nodes_used_collection [junit4:junit4] 1> INFO - 2013-04-09 06:28:00.803; org.apache.solr.cloud= .ZkController; Looking for collection configName [junit4:junit4] 1> INFO - 2013-04-09 06:28:00.803; org.apache.solr.cloud= .ZkController; Creating collection in ZooKeeper:nodes_used_collection [junit4:junit4] 1> INFO - 2013-04-09 06:28:00.802; org.apache.solr.cloud= .ZkController; Looking for collection configName [junit4:junit4] 1> INFO - 2013-04-09 06:28:00.804; org.apache.solr.cloud= .ZkController; Looking for collection configName [junit4:junit4] 1> INFO - 2013-04-09 06:28:00.803; org.apache.solr.cloud= .ZkController; Looking for collection configName [junit4:junit4] 1> INFO - 2013-04-09 06:28:00.805; org.apache.solr.cloud= .ZkController; Only one config set found in zk - using it:conf1 [junit4:junit4] 1> INFO - 2013-04-09 06:28:00.804; org.apache.solr.cloud= .ZkController; Only one config set found in zk - using it:conf1 [junit4:junit4] 1> INFO - 2013-04-09 06:28:00.805; org.apache.solr.cloud= .ZkController; Only one config set found in zk - using it:conf1 [junit4:junit4] 1> INFO - 2013-04-09 06:28:00.805; org.apache.solr.commo= n.cloud.SolrZkClient; makePath: /collections/nodes_used_collection [junit4:junit4] 1> INFO - 2013-04-09 06:28:00.806; org.apache.solr.commo= n.cloud.SolrZkClient; makePath: /collections/nodes_used_collection [junit4:junit4] 1> INFO - 2013-04-09 06:28:00.806; org.apache.solr.cloud= .ZkController; Only one config set found in zk - using it:conf1 [junit4:junit4] 1> INFO - 2013-04-09 06:28:00.805; org.apache.solr.commo= n.cloud.SolrZkClient; makePath: /collections/nodes_used_collection [junit4:junit4] 1> INFO - 2013-04-09 06:28:00.807; org.apache.solr.commo= n.cloud.SolrZkClient; makePath: /collections/nodes_used_collection [junit4:junit4] 1> INFO - 2013-04-09 06:28:00.808; org.apache.solr.cloud= .ZkController; Load collection config from:/collections/nodes_used_collecti= on [junit4:junit4] 1> INFO - 2013-04-09 06:28:00.813; org.apache.solr.cloud= .ZkController; Load collection config from:/collections/nodes_used_collecti= on [junit4:junit4] 1> INFO - 2013-04-09 06:28:00.814; org.apache.solr.cloud= .ZkController; Load collection config from:/collections/nodes_used_collecti= on [junit4:junit4] 1> INFO - 2013-04-09 06:28:00.815; org.apache.solr.core.= SolrResourceLoader; new SolrResourceLoader for directory: '/usr/home/hudson= /hudson-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core= /test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty1-136= 5488875434/nodes_used_collection_shard2_replica2/' [junit4:junit4] 1> INFO - 2013-04-09 06:28:00.815; org.apache.solr.cloud= .ZkController; Load collection config from:/collections/nodes_used_collecti= on [junit4:junit4] 1> INFO - 2013-04-09 06:28:00.816; org.apache.solr.core.= SolrResourceLoader; new SolrResourceLoader for directory: '/usr/home/hudson= /hudson-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core= /test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-controljet= ty-1365488875013/nodes_used_collection_shard1_replica1/' [junit4:junit4] 1> INFO - 2013-04-09 06:28:00.816; org.apache.solr.core.= SolrResourceLoader; new SolrResourceLoader for directory: '/usr/home/hudson= /hudson-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core= /test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-136= 5488879462/nodes_used_collection_shard1_replica2/' [junit4:junit4] 1> INFO - 2013-04-09 06:28:00.816; org.apache.solr.core.= SolrResourceLoader; new SolrResourceLoader for directory: '/usr/home/hudson= /hudson-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core= /test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty3-136= 5488878182/nodes_used_collection_shard2_replica1/' [junit4:junit4] 1> INFO - 2013-04-09 06:28:00.852; org.apache.solr.core.= SolrConfig; Using Lucene MatchVersion: LUCENE_50 [junit4:junit4] 1> INFO - 2013-04-09 06:28:00.859; org.apache.solr.core.= SolrConfig; Using Lucene MatchVersion: LUCENE_50 [junit4:junit4] 1> INFO - 2013-04-09 06:28:00.861; org.apache.solr.core.= SolrConfig; Using Lucene MatchVersion: LUCENE_50 [junit4:junit4] 1> INFO - 2013-04-09 06:28:00.867; org.apache.solr.core.= SolrConfig; Using Lucene MatchVersion: LUCENE_50 [junit4:junit4] 1> INFO - 2013-04-09 06:28:00.914; org.apache.solr.core.= SolrConfig; Loaded SolrConfig: solrconfig.xml [junit4:junit4] 1> INFO - 2013-04-09 06:28:00.921; org.apache.solr.core.= SolrConfig; Loaded SolrConfig: solrconfig.xml [junit4:junit4] 1> INFO - 2013-04-09 06:28:00.923; org.apache.solr.core.= SolrConfig; Loaded SolrConfig: solrconfig.xml [junit4:junit4] 1> INFO - 2013-04-09 06:28:00.940; org.apache.solr.core.= SolrConfig; Loaded SolrConfig: solrconfig.xml [junit4:junit4] 1> INFO - 2013-04-09 06:28:01.015; org.apache.solr.schem= a.IndexSchema; Reading Solr Schema from schema.xml [junit4:junit4] 1> INFO - 2013-04-09 06:28:01.020; org.apache.solr.schem= a.IndexSchema; Schema name=3Dtest [junit4:junit4] 1> INFO - 2013-04-09 06:28:01.022; org.apache.solr.schem= a.IndexSchema; Reading Solr Schema from schema.xml [junit4:junit4] 1> INFO - 2013-04-09 06:28:01.024; org.apache.solr.schem= a.IndexSchema; Reading Solr Schema from schema.xml [junit4:junit4] 1> INFO - 2013-04-09 06:28:01.026; org.apache.solr.schem= a.IndexSchema; Schema name=3Dtest [junit4:junit4] 1> INFO - 2013-04-09 06:28:01.028; org.apache.solr.schem= a.IndexSchema; Schema name=3Dtest [junit4:junit4] 1> INFO - 2013-04-09 06:28:01.041; org.apache.solr.schem= a.IndexSchema; Reading Solr Schema from schema.xml [junit4:junit4] 1> INFO - 2013-04-09 06:28:01.049; org.apache.solr.schem= a.IndexSchema; Schema name=3Dtest [junit4:junit4] 1> INFO - 2013-04-09 06:28:01.604; org.apache.solr.schem= a.OpenExchangeRatesOrgProvider; Initialized with rates=3Dopen-exchange-rate= s.json, refreshInterval=3D1440. [junit4:junit4] 1> INFO - 2013-04-09 06:28:01.616; org.apache.solr.schem= a.IndexSchema; default search field in schema is text [junit4:junit4] 1> INFO - 2013-04-09 06:28:01.621; org.apache.solr.schem= a.IndexSchema; unique key field: id [junit4:junit4] 1> INFO - 2013-04-09 06:28:01.634; org.apache.solr.schem= a.OpenExchangeRatesOrgProvider; Initialized with rates=3Dopen-exchange-rate= s.json, refreshInterval=3D1440. [junit4:junit4] 1> INFO - 2013-04-09 06:28:01.635; org.apache.solr.schem= a.FileExchangeRateProvider; Reloading exchange rates from file currency.xml [junit4:junit4] 1> INFO - 2013-04-09 06:28:01.640; org.apache.solr.schem= a.FileExchangeRateProvider; Reloading exchange rates from file currency.xml [junit4:junit4] 1> INFO - 2013-04-09 06:28:01.643; org.apache.solr.schem= a.IndexSchema; default search field in schema is text [junit4:junit4] 1> INFO - 2013-04-09 06:28:01.645; org.apache.solr.schem= a.OpenExchangeRatesOrgProvider; Reloading exchange rates from open-exchange= -rates.json [junit4:junit4] 1> WARN - 2013-04-09 06:28:01.647; org.apache.solr.schem= a.OpenExchangeRatesOrgProvider$OpenExchangeRates; Unknown key IMPORTANT NOT= E [junit4:junit4] 1> WARN - 2013-04-09 06:28:01.647; org.apache.solr.schem= a.OpenExchangeRatesOrgProvider$OpenExchangeRates; Expected key, got STRING [junit4:junit4] 1> INFO - 2013-04-09 06:28:01.647; org.apache.solr.schem= a.IndexSchema; unique key field: id [junit4:junit4] 1> INFO - 2013-04-09 06:28:01.647; org.apache.solr.schem= a.OpenExchangeRatesOrgProvider; Reloading exchange rates from open-exchange= -rates.json [junit4:junit4] 1> WARN - 2013-04-09 06:28:01.649; org.apache.solr.schem= a.OpenExchangeRatesOrgProvider$OpenExchangeRates; Unknown key IMPORTANT NOT= E [junit4:junit4] 1> WARN - 2013-04-09 06:28:01.649; org.apache.solr.schem= a.OpenExchangeRatesOrgProvider$OpenExchangeRates; Expected key, got STRING [junit4:junit4] 1> INFO - 2013-04-09 06:28:01.649; org.apache.solr.core.= SolrCore; org.apache.solr.core.MockDirectoryFactory [junit4:junit4] 1> INFO - 2013-04-09 06:28:01.650; org.apache.solr.core.= SolrCore; [nodes_used_collection_shard2_replica1] Opening new SolrCore at /= usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/= build/solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZk= Test-jetty3-1365488878182/nodes_used_collection_shard2_replica1/, dataDir= =3D/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-trunk/s= olr/build/solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistribut= edZkTest-jetty3-1365488878182/nodes_used_collection_shard2_replica1/data/ [junit4:junit4] 1> INFO - 2013-04-09 06:28:01.650; org.apache.solr.core.= JmxMonitoredMap; JMX monitoring is enabled. Adding Solr mbeans to JMX Serve= r: com.sun.jmx.mbeanserver.JmxMBeanServer@2432a50a [junit4:junit4] 1> INFO - 2013-04-09 06:28:01.651; org.apache.solr.core.= SolrCore; org.apache.solr.core.MockDirectoryFactory [junit4:junit4] 1> INFO - 2013-04-09 06:28:01.653; org.apache.solr.core.= CachingDirectoryFactory; return new directory for /usr/home/hudson/hudson-s= lave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test/J1/= ./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty3-136548887818= 2/nodes_used_collection_shard2_replica1/data [junit4:junit4] 1> INFO - 2013-04-09 06:28:01.654; org.apache.solr.core.= SolrCore; New index directory detected: old=3Dnull new=3D/usr/home/hudson/h= udson-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/t= est/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty3-13654= 88878182/nodes_used_collection_shard2_replica1/data/index/ [junit4:junit4] 1> WARN - 2013-04-09 06:28:01.655; org.apache.solr.core.= SolrCore; [nodes_used_collection_shard2_replica1] Solr index directory '/us= r/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/bu= ild/solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTe= st-jetty3-1365488878182/nodes_used_collection_shard2_replica1/data/index' d= oesn't exist. Creating new index... [junit4:junit4] 1> INFO - 2013-04-09 06:28:01.655; org.apache.solr.core.= CachingDirectoryFactory; return new directory for /usr/home/hudson/hudson-s= lave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test/J1/= ./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty3-136548887818= 2/nodes_used_collection_shard2_replica1/data/index [junit4:junit4] 1> INFO - 2013-04-09 06:28:01.660; org.apache.solr.core.= SolrDeletionPolicy; SolrDeletionPolicy.onCommit: commits:num=3D1 [junit4:junit4] 1> =09commit{dir=3DMockDirWrapper(RateLimitedDirectoryWra= pper(org.apache.lucene.store.RAMDirectory@60fe3fe8 lockFactory=3Dorg.apache= .lucene.store.NativeFSLockFactory@295ea10)),segFN=3Dsegments_1,generation= =3D1,filenames=3D[segments_1] [junit4:junit4] 1> INFO - 2013-04-09 06:28:01.660; org.apache.solr.core.= SolrDeletionPolicy; newest commit =3D 1[segments_1] [junit4:junit4] 1> INFO - 2013-04-09 06:28:01.660; org.apache.solr.schem= a.FileExchangeRateProvider; Reloading exchange rates from file currency.xml [junit4:junit4] 1> INFO - 2013-04-09 06:28:01.663; org.apache.solr.updat= e.processor.UpdateRequestProcessorChain; inserting DistributedUpdateProcess= orFactory into updateRequestProcessorChain "dedupe" [junit4:junit4] 1> INFO - 2013-04-09 06:28:01.664; org.apache.solr.updat= e.processor.UpdateRequestProcessorChain; inserting DistributedUpdateProcess= orFactory into updateRequestProcessorChain "stored_sig" [junit4:junit4] 1> INFO - 2013-04-09 06:28:01.664; org.apache.solr.updat= e.processor.UpdateRequestProcessorChain; inserting DistributedUpdateProcess= orFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit= " [junit4:junit4] 1> INFO - 2013-04-09 06:28:01.665; org.apache.solr.core.= RequestHandlers; created standard: solr.StandardRequestHandler [junit4:junit4] 1> INFO - 2013-04-09 06:28:01.666; org.apache.solr.core.= RequestHandlers; created /get: solr.RealTimeGetHandler [junit4:junit4] 1> INFO - 2013-04-09 06:28:01.666; org.apache.solr.core.= RequestHandlers; adding lazy requestHandler: solr.ReplicationHandler [junit4:junit4] 1> INFO - 2013-04-09 06:28:01.667; org.apache.solr.core.= RequestHandlers; created /replication: solr.ReplicationHandler [junit4:junit4] 1> INFO - 2013-04-09 06:28:01.667; org.apache.solr.core.= RequestHandlers; created /update: solr.UpdateRequestHandler [junit4:junit4] 1> INFO - 2013-04-09 06:28:01.668; org.apache.solr.core.= RequestHandlers; created /admin/: org.apache.solr.handler.admin.AdminHandle= rs [junit4:junit4] 1> INFO - 2013-04-09 06:28:01.681; org.apache.solr.schem= a.FileExchangeRateProvider; Reloading exchange rates from file currency.xml [junit4:junit4] 1> INFO - 2013-04-09 06:28:01.684; org.apache.solr.handl= er.loader.XMLLoader; xsltCacheLifetimeSeconds=3D60 [junit4:junit4] 1> INFO - 2013-04-09 06:28:01.686; org.apache.solr.schem= a.OpenExchangeRatesOrgProvider; Reloading exchange rates from open-exchange= -rates.json [junit4:junit4] 1> WARN - 2013-04-09 06:28:01.687; org.apache.solr.schem= a.OpenExchangeRatesOrgProvider$OpenExchangeRates; Unknown key IMPORTANT NOT= E [junit4:junit4] 1> WARN - 2013-04-09 06:28:01.689; org.apache.solr.schem= a.OpenExchangeRatesOrgProvider$OpenExchangeRates; Expected key, got STRING [junit4:junit4] 1> INFO - 2013-04-09 06:28:01.689; org.apache.solr.schem= a.OpenExchangeRatesOrgProvider; Reloading exchange rates from open-exchange= -rates.json [junit4:junit4] 1> INFO - 2013-04-09 06:28:01.690; org.apache.solr.searc= h.SolrIndexSearcher; Opening Searcher@6a8bd0bd main [junit4:junit4] 1> INFO - 2013-04-09 06:28:01.690; org.apache.solr.updat= e.UpdateHandler; Clearing tlog files, tlogDir=3D/usr/home/hudson/hudson-sla= ve/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test/J1/./= org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty3-1365488878182/= nodes_used_collection_shard2_replica1/data/tlog [junit4:junit4] 1> WARN - 2013-04-09 06:28:01.690; org.apache.solr.schem= a.OpenExchangeRatesOrgProvider$OpenExchangeRates; Unknown key IMPORTANT NOT= E [junit4:junit4] 1> WARN - 2013-04-09 06:28:01.691; org.apache.solr.schem= a.OpenExchangeRatesOrgProvider$OpenExchangeRates; Expected key, got STRING [junit4:junit4] 1> INFO - 2013-04-09 06:28:01.691; org.apache.solr.core.= SolrCore; org.apache.solr.core.MockDirectoryFactory [junit4:junit4] 1> INFO - 2013-04-09 06:28:01.692; org.apache.solr.updat= e.CommitTracker; Hard AutoCommit: disabled [junit4:junit4] 1> INFO - 2013-04-09 06:28:01.692; org.apache.solr.core.= SolrCore; [nodes_used_collection_shard2_replica2] Opening new SolrCore at /= usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/= build/solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZk= Test-jetty1-1365488875434/nodes_used_collection_shard2_replica2/, dataDir= =3D/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-trunk/s= olr/build/solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistribut= edZkTest-jetty1-1365488875434/nodes_used_collection_shard2_replica2/data/ [junit4:junit4] 1> INFO - 2013-04-09 06:28:01.692; org.apache.solr.updat= e.CommitTracker; Soft AutoCommit: disabled [junit4:junit4] 1> INFO - 2013-04-09 06:28:01.693; org.apache.solr.core.= JmxMonitoredMap; JMX monitoring is enabled. Adding Solr mbeans to JMX Serve= r: com.sun.jmx.mbeanserver.JmxMBeanServer@2432a50a [junit4:junit4] 1> INFO - 2013-04-09 06:28:01.694; org.apache.solr.core.= SolrCore; org.apache.solr.core.MockDirectoryFactory [junit4:junit4] 1> INFO - 2013-04-09 06:28:01.696; org.apache.solr.schem= a.OpenExchangeRatesOrgProvider; Initialized with rates=3Dopen-exchange-rate= s.json, refreshInterval=3D1440. [junit4:junit4] 1> INFO - 2013-04-09 06:28:01.696; org.apache.solr.core.= CachingDirectoryFactory; return new directory for /usr/home/hudson/hudson-s= lave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test/J1/= ./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty1-136548887543= 4/nodes_used_collection_shard2_replica2/data [junit4:junit4] 1> INFO - 2013-04-09 06:28:01.696; org.apache.solr.core.= SolrCore; [nodes_used_collection_shard2_replica1] Registered new searcher S= earcher@6a8bd0bd main{StandardDirectoryReader(segments_1:1)} [junit4:junit4] 1> INFO - 2013-04-09 06:28:01.697; org.apache.solr.core.= SolrCore; New index directory detected: old=3Dnull new=3D/usr/home/hudson/h= udson-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/t= est/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty1-13654= 88875434/nodes_used_collection_shard2_replica2/data/index/ [junit4:junit4] 1> WARN - 2013-04-09 06:28:01.697; org.apache.solr.core.= SolrCore; [nodes_used_collection_shard2_replica2] Solr index directory '/us= r/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/bu= ild/solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTe= st-jetty1-1365488875434/nodes_used_collection_shard2_replica2/data/index' d= oesn't exist. Creating new index... [junit4:junit4] 1> INFO - 2013-04-09 06:28:01.698; org.apache.solr.core.= CachingDirectoryFactory; return new directory for /usr/home/hudson/hudson-s= lave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test/J1/= ./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty1-136548887543= 4/nodes_used_collection_shard2_replica2/data/index [junit4:junit4] 1> INFO - 2013-04-09 06:28:01.698; org.apache.solr.cloud= .ZkController; publishing core=3Dnodes_used_collection_shard2_replica1 stat= e=3Ddown [junit4:junit4] 1> INFO - 2013-04-09 06:28:01.702; org.apache.solr.core.= SolrDeletionPolicy; SolrDeletionPolicy.onCommit: commits:num=3D1 [junit4:junit4] 1> =09commit{dir=3DMockDirWrapper(RateLimitedDirectoryWra= pper(org.apache.lucene.store.RAMDirectory@855b33f lockFactory=3Dorg.apache.= lucene.store.NativeFSLockFactory@6d68809d)),segFN=3Dsegments_1,generation= =3D1,filenames=3D[segments_1] [junit4:junit4] 1> INFO - 2013-04-09 06:28:01.708; org.apache.solr.core.= SolrDeletionPolicy; newest commit =3D 1[segments_1] [junit4:junit4] 1> INFO - 2013-04-09 06:28:01.711; org.apache.solr.updat= e.processor.UpdateRequestProcessorChain; inserting DistributedUpdateProcess= orFactory into updateRequestProcessorChain "dedupe" [junit4:junit4] 1> INFO - 2013-04-09 06:28:01.712; org.apache.solr.updat= e.processor.UpdateRequestProcessorChain; inserting DistributedUpdateProcess= orFactory into updateRequestProcessorChain "stored_sig" [junit4:junit4] 1> INFO - 2013-04-09 06:28:01.713; org.apache.solr.updat= e.processor.UpdateRequestProcessorChain; inserting DistributedUpdateProcess= orFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit= " [junit4:junit4] 1> INFO - 2013-04-09 06:28:01.713; org.apache.solr.core.= RequestHandlers; created standard: solr.StandardRequestHandler [junit4:junit4] 1> INFO - 2013-04-09 06:28:01.714; org.apache.solr.schem= a.IndexSchema; default search field in schema is text [junit4:junit4] 1> INFO - 2013-04-09 06:28:01.714; org.apache.solr.core.= RequestHandlers; created /get: solr.RealTimeGetHandler [junit4:junit4] 1> INFO - 2013-04-09 06:28:01.715; org.apache.solr.core.= RequestHandlers; adding lazy requestHandler: solr.ReplicationHandler [junit4:junit4] 1> INFO - 2013-04-09 06:28:01.715; org.apache.solr.core.= RequestHandlers; created /replication: solr.ReplicationHandler [junit4:junit4] 1> INFO - 2013-04-09 06:28:01.716; org.apache.solr.core.= RequestHandlers; created /update: solr.UpdateRequestHandler [junit4:junit4] 1> INFO - 2013-04-09 06:28:01.716; org.apache.solr.core.= RequestHandlers; created /admin/: org.apache.solr.handler.admin.AdminHandle= rs [junit4:junit4] 1> INFO - 2013-04-09 06:28:01.717; org.apache.solr.schem= a.IndexSchema; unique key field: id [junit4:junit4] 1> INFO - 2013-04-09 06:28:01.728; org.apache.solr.schem= a.FileExchangeRateProvider; Reloading exchange rates from file currency.xml [junit4:junit4] 1> INFO - 2013-04-09 06:28:01.730; org.apache.solr.handl= er.loader.XMLLoader; xsltCacheLifetimeSeconds=3D60 [junit4:junit4] 1> INFO - 2013-04-09 06:28:01.735; org.apache.solr.searc= h.SolrIndexSearcher; Opening Searcher@1b5bb539 main [junit4:junit4] 1> INFO - 2013-04-09 06:28:01.735; org.apache.solr.updat= e.UpdateHandler; Clearing tlog files, tlogDir=3D/usr/home/hudson/hudson-sla= ve/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test/J1/./= org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty1-1365488875434/= nodes_used_collection_shard2_replica2/data/tlog [junit4:junit4] 1> INFO - 2013-04-09 06:28:01.737; org.apache.solr.updat= e.CommitTracker; Hard AutoCommit: disabled [junit4:junit4] 1> INFO - 2013-04-09 06:28:01.737; org.apache.solr.updat= e.CommitTracker; Soft AutoCommit: disabled [junit4:junit4] 1> INFO - 2013-04-09 06:28:01.740; org.apache.solr.core.= SolrCore; [nodes_used_collection_shard2_replica2] Registered new searcher S= earcher@1b5bb539 main{StandardDirectoryReader(segments_1:1)} [junit4:junit4] 1> INFO - 2013-04-09 06:28:01.742; org.apache.solr.cloud= .ZkController; publishing core=3Dnodes_used_collection_shard2_replica2 stat= e=3Ddown [junit4:junit4] 1> INFO - 2013-04-09 06:28:01.743; org.apache.solr.schem= a.FileExchangeRateProvider; Reloading exchange rates from file currency.xml [junit4:junit4] 1> INFO - 2013-04-09 06:28:01.747; org.apache.solr.schem= a.OpenExchangeRatesOrgProvider; Reloading exchange rates from open-exchange= -rates.json [junit4:junit4] 1> WARN - 2013-04-09 06:28:01.748; org.apache.solr.schem= a.OpenExchangeRatesOrgProvider$OpenExchangeRates; Unknown key IMPORTANT NOT= E [junit4:junit4] 1> WARN - 2013-04-09 06:28:01.748; org.apache.solr.schem= a.OpenExchangeRatesOrgProvider$OpenExchangeRates; Expected key, got STRING [junit4:junit4] 1> INFO - 2013-04-09 06:28:01.749; org.apache.solr.schem= a.OpenExchangeRatesOrgProvider; Reloading exchange rates from open-exchange= -rates.json [junit4:junit4] 1> WARN - 2013-04-09 06:28:01.749; org.apache.solr.schem= a.OpenExchangeRatesOrgProvider$OpenExchangeRates; Unknown key IMPORTANT NOT= E [junit4:junit4] 1> WARN - 2013-04-09 06:28:01.750; org.apache.solr.schem= a.OpenExchangeRatesOrgProvider$OpenExchangeRates; Expected key, got STRING [junit4:junit4] 1> INFO - 2013-04-09 06:28:01.750; org.apache.solr.core.= SolrCore; org.apache.solr.core.MockDirectoryFactory [junit4:junit4] 1> INFO - 2013-04-09 06:28:01.750; org.apache.solr.core.= SolrCore; [nodes_used_collection_shard1_replica1] Opening new SolrCore at /= usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/= build/solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZk= Test-controljetty-1365488875013/nodes_used_collection_shard1_replica1/, dat= aDir=3D/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-tru= nk/solr/build/solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistr= ibutedZkTest-controljetty-1365488875013/nodes_used_collection_shard1_replic= a1/data/ [junit4:junit4] 1> INFO - 2013-04-09 06:28:01.751; org.apache.solr.core.= JmxMonitoredMap; JMX monitoring is enabled. Adding Solr mbeans to JMX Serve= r: com.sun.jmx.mbeanserver.JmxMBeanServer@2432a50a [junit4:junit4] 1> INFO - 2013-04-09 06:28:01.751; org.apache.solr.core.= SolrCore; org.apache.solr.core.MockDirectoryFactory [junit4:junit4] 1> INFO - 2013-04-09 06:28:01.753; org.apache.solr.core.= CachingDirectoryFactory; return new directory for /usr/home/hudson/hudson-s= lave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test/J1/= ./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-controljetty-136548= 8875013/nodes_used_collection_shard1_replica1/data [junit4:junit4] 1> INFO - 2013-04-09 06:28:01.753; org.apache.solr.core.= SolrCore; New index directory detected: old=3Dnull new=3D/usr/home/hudson/h= udson-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/t= est/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-controljetty= -1365488875013/nodes_used_collection_shard1_replica1/data/index/ [junit4:junit4] 1> WARN - 2013-04-09 06:28:01.754; org.apache.solr.core.= SolrCore; [nodes_used_collection_shard1_replica1] Solr index directory '/us= r/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/bu= ild/solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTe= st-controljetty-1365488875013/nodes_used_collection_shard1_replica1/data/in= dex' doesn't exist. Creating new index... [junit4:junit4] 1> INFO - 2013-04-09 06:28:01.754; org.apache.solr.core.= CachingDirectoryFactory; return new directory for /usr/home/hudson/hudson-s= lave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test/J1/= ./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-controljetty-136548= 8875013/nodes_used_collection_shard1_replica1/data/index [junit4:junit4] 1> INFO - 2013-04-09 06:28:01.757; org.apache.solr.core.= SolrDeletionPolicy; SolrDeletionPolicy.onCommit: commits:num=3D1 [junit4:junit4] 1> =09commit{dir=3DMockDirWrapper(RateLimitedDirectoryWra= pper(org.apache.lucene.store.RAMDirectory@6f55f3d7 lockFactory=3Dorg.apache= .lucene.store.NativeFSLockFactory@62815f5b)),segFN=3Dsegments_1,generation= =3D1,filenames=3D[segments_1] [junit4:junit4] 1> INFO - 2013-04-09 06:28:01.757; org.apache.solr.core.= SolrDeletionPolicy; newest commit =3D 1[segments_1] [junit4:junit4] 1> INFO - 2013-04-09 06:28:01.760; org.apache.solr.updat= e.processor.UpdateRequestProcessorChain; inserting DistributedUpdateProcess= orFactory into updateRequestProcessorChain "dedupe" [junit4:junit4] 1> INFO - 2013-04-09 06:28:01.760; org.apache.solr.updat= e.processor.UpdateRequestProcessorChain; inserting DistributedUpdateProcess= orFactory into updateRequestProcessorChain "stored_sig" [junit4:junit4] 1> INFO - 2013-04-09 06:28:01.760; org.apache.solr.updat= e.processor.UpdateRequestProcessorChain; inserting DistributedUpdateProcess= orFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit= " [junit4:junit4] 1> INFO - 2013-04-09 06:28:01.761; org.apache.solr.core.= RequestHandlers; created standard: solr.StandardRequestHandler [junit4:junit4] 1> INFO - 2013-04-09 06:28:01.761; org.apache.solr.core.= RequestHandlers; created /get: solr.RealTimeGetHandler [junit4:junit4] 1> INFO - 2013-04-09 06:28:01.762; org.apache.solr.core.= RequestHandlers; adding lazy requestHandler: solr.ReplicationHandler [junit4:junit4] 1> INFO - 2013-04-09 06:28:01.762; org.apache.solr.core.= RequestHandlers; created /replication: solr.ReplicationHandler [junit4:junit4] 1> INFO - 2013-04-09 06:28:01.762; org.apache.solr.core.= RequestHandlers; created /update: solr.UpdateRequestHandler [junit4:junit4] 1> INFO - 2013-04-09 06:28:01.763; org.apache.solr.core.= RequestHandlers; created /admin/: org.apache.solr.handler.admin.AdminHandle= rs [junit4:junit4] 1> INFO - 2013-04-09 06:28:01.773; org.apache.solr.handl= er.loader.XMLLoader; xsltCacheLifetimeSeconds=3D60 [junit4:junit4] 1> INFO - 2013-04-09 06:28:01.776; org.apache.solr.searc= h.SolrIndexSearcher; Opening Searcher@b6f73ec main [junit4:junit4] 1> INFO - 2013-04-09 06:28:01.777; org.apache.solr.updat= e.UpdateHandler; Clearing tlog files, tlogDir=3D/usr/home/hudson/hudson-sla= ve/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test/J1/./= org.apache.solr.cloud.CollectionsAPIDistributedZkTest-controljetty-13654888= 75013/nodes_used_collection_shard1_replica1/data/tlog [junit4:junit4] 1> INFO - 2013-04-09 06:28:01.778; org.apache.solr.updat= e.CommitTracker; Hard AutoCommit: disabled [junit4:junit4] 1> INFO - 2013-04-09 06:28:01.778; org.apache.solr.updat= e.CommitTracker; Soft AutoCommit: disabled [junit4:junit4] 1> INFO - 2013-04-09 06:28:01.780; org.apache.solr.core.= SolrCore; [nodes_used_collection_shard1_replica1] Registered new searcher S= earcher@b6f73ec main{StandardDirectoryReader(segments_1:1)} [junit4:junit4] 1> INFO - 2013-04-09 06:28:01.782; org.apache.solr.cloud= .ZkController; publishing core=3Dnodes_used_collection_shard1_replica1 stat= e=3Ddown [junit4:junit4] 1> INFO - 2013-04-09 06:28:01.791; org.apache.solr.schem= a.OpenExchangeRatesOrgProvider; Initialized with rates=3Dopen-exchange-rate= s.json, refreshInterval=3D1440. [junit4:junit4] 1> INFO - 2013-04-09 06:28:01.801; org.apache.solr.schem= a.IndexSchema; default search field in schema is text [junit4:junit4] 1> INFO - 2013-04-09 06:28:01.805; org.apache.solr.schem= a.IndexSchema; unique key field: id [junit4:junit4] 1> INFO - 2013-04-09 06:28:01.818; org.apache.solr.schem= a.FileExchangeRateProvider; Reloading exchange rates from file currency.xml [junit4:junit4] 1> INFO - 2013-04-09 06:28:01.833; org.apache.solr.schem= a.FileExchangeRateProvider; Reloading exchange rates from file currency.xml [junit4:junit4] 1> INFO - 2013-04-09 06:28:01.838; org.apache.solr.schem= a.OpenExchangeRatesOrgProvider; Reloading exchange rates from open-exchange= -rates.json [junit4:junit4] 1> WARN - 2013-04-09 06:28:01.839; org.apache.solr.schem= a.OpenExchangeRatesOrgProvider$OpenExchangeRates; Unknown key IMPORTANT NOT= E [junit4:junit4] 1> WARN - 2013-04-09 06:28:01.839; org.apache.solr.schem= a.OpenExchangeRatesOrgProvider$OpenExchangeRates; Expected key, got STRING [junit4:junit4] 1> INFO - 2013-04-09 06:28:01.839; org.apache.solr.schem= a.OpenExchangeRatesOrgProvider; Reloading exchange rates from open-exchange= -rates.json [junit4:junit4] 1> WARN - 2013-04-09 06:28:01.840; org.apache.solr.schem= a.OpenExchangeRatesOrgProvider$OpenExchangeRates; Unknown key IMPORTANT NOT= E [junit4:junit4] 1> WARN - 2013-04-09 06:28:01.841; org.apache.solr.schem= a.OpenExchangeRatesOrgProvider$OpenExchangeRates; Expected key, got STRING [junit4:junit4] 1> INFO - 2013-04-09 06:28:01.841; org.apache.solr.core.= SolrCore; org.apache.solr.core.MockDirectoryFactory [junit4:junit4] 1> INFO - 2013-04-09 06:28:01.842; org.apache.solr.core.= SolrCore; [nodes_used_collection_shard1_replica2] Opening new SolrCore at /= usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/= build/solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZk= Test-jetty4-1365488879462/nodes_used_collection_shard1_replica2/, dataDir= =3D/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-trunk/s= olr/build/solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistribut= edZkTest-jetty4-1365488879462/nodes_used_collection_shard1_replica2/data/ [junit4:junit4] 1> INFO - 2013-04-09 06:28:01.842; org.apache.solr.core.= JmxMonitoredMap; JMX monitoring is enabled. Adding Solr mbeans to JMX Serve= r: com.sun.jmx.mbeanserver.JmxMBeanServer@2432a50a [junit4:junit4] 1> INFO - 2013-04-09 06:28:01.843; org.apache.solr.core.= SolrCore; org.apache.solr.core.MockDirectoryFactory [junit4:junit4] 1> INFO - 2013-04-09 06:28:01.845; org.apache.solr.core.= CachingDirectoryFactory; return new directory for /usr/home/hudson/hudson-s= lave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test/J1/= ./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-136548887946= 2/nodes_used_collection_shard1_replica2/data [junit4:junit4] 1> INFO - 2013-04-09 06:28:01.845; org.apache.solr.core.= SolrCore; New index directory detected: old=3Dnull new=3D/usr/home/hudson/h= udson-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/t= est/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-13654= 88879462/nodes_used_collection_shard1_replica2/data/index/ [junit4:junit4] 1> WARN - 2013-04-09 06:28:01.846; org.apache.solr.core.= SolrCore; [nodes_used_collection_shard1_replica2] Solr index directory '/us= r/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/bu= ild/solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTe= st-jetty4-1365488879462/nodes_used_collection_shard1_replica2/data/index' d= oesn't exist. Creating new index... [junit4:junit4] 1> INFO - 2013-04-09 06:28:01.846; org.apache.solr.core.= CachingDirectoryFactory; return new directory for /usr/home/hudson/hudson-s= lave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test/J1/= ./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-136548887946= 2/nodes_used_collection_shard1_replica2/data/index [junit4:junit4] 1> INFO - 2013-04-09 06:28:01.850; org.apache.solr.core.= SolrDeletionPolicy; SolrDeletionPolicy.onCommit: commits:num=3D1 [junit4:junit4] 1> =09commit{dir=3DMockDirWrapper(RateLimitedDirectoryWra= pper(org.apache.lucene.store.RAMDirectory@8846fa6 lockFactory=3Dorg.apache.= lucene.store.NativeFSLockFactory@495fb84a)),segFN=3Dsegments_1,generation= =3D1,filenames=3D[segments_1] [junit4:junit4] 1> INFO - 2013-04-09 06:28:01.851; org.apache.solr.core.= SolrDeletionPolicy; newest commit =3D 1[segments_1] [junit4:junit4] 1> INFO - 2013-04-09 06:28:01.854; org.apache.solr.updat= e.processor.UpdateRequestProcessorChain; inserting DistributedUpdateProcess= orFactory into updateRequestProcessorChain "dedupe" [junit4:junit4] 1> INFO - 2013-04-09 06:28:01.854; org.apache.solr.updat= e.processor.UpdateRequestProcessorChain; inserting DistributedUpdateProcess= orFactory into updateRequestProcessorChain "stored_sig" [junit4:junit4] 1> INFO - 2013-04-09 06:28:01.855; org.apache.solr.updat= e.processor.UpdateRequestProcessorChain; inserting DistributedUpdateProcess= orFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit= " [junit4:junit4] 1> INFO - 2013-04-09 06:28:01.855; org.apache.solr.core.= RequestHandlers; created standard: solr.StandardRequestHandler [junit4:junit4] 1> INFO - 2013-04-09 06:28:01.856; org.apache.solr.core.= RequestHandlers; created /get: solr.RealTimeGetHandler [junit4:junit4] 1> INFO - 2013-04-09 06:28:01.856; org.apache.solr.core.= RequestHandlers; adding lazy requestHandler: solr.ReplicationHandler [junit4:junit4] 1> INFO - 2013-04-09 06:28:01.857; org.apache.solr.core.= RequestHandlers; created /replication: solr.ReplicationHandler [junit4:junit4] 1> INFO - 2013-04-09 06:28:01.857; org.apache.solr.core.= RequestHandlers; created /update: solr.UpdateRequestHandler [junit4:junit4] 1> INFO - 2013-04-09 06:28:01.858; org.apache.solr.core.= RequestHandlers; created /admin/: org.apache.solr.handler.admin.AdminHandle= rs [junit4:junit4] 1> INFO - 2013-04-09 06:28:01.871; org.apache.solr.handl= er.loader.XMLLoader; xsltCacheLifetimeSeconds=3D60 [junit4:junit4] 1> INFO - 2013-04-09 06:28:01.877; org.apache.solr.searc= h.SolrIndexSearcher; Opening Searcher@2df0b73f main [junit4:junit4] 1> INFO - 2013-04-09 06:28:01.877; org.apache.solr.updat= e.UpdateHandler; Clearing tlog files, tlogDir=3D/usr/home/hudson/hudson-sla= ve/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test/J1/./= org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1365488879462/= nodes_used_collection_shard1_replica2/data/tlog [junit4:junit4] 1> INFO - 2013-04-09 06:28:01.879; org.apache.solr.updat= e.CommitTracker; Hard AutoCommit: disabled [junit4:junit4] 1> INFO - 2013-04-09 06:28:01.879; org.apache.solr.updat= e.CommitTracker; Soft AutoCommit: disabled [junit4:junit4] 1> INFO - 2013-04-09 06:28:01.882; org.apache.solr.core.= SolrCore; [nodes_used_collection_shard1_replica2] Registered new searcher S= earcher@2df0b73f main{StandardDirectoryReader(segments_1:1)} [junit4:junit4] 1> INFO - 2013-04-09 06:28:01.884; org.apache.solr.cloud= .ZkController; publishing core=3Dnodes_used_collection_shard1_replica2 stat= e=3Ddown [junit4:junit4] 1> INFO - 2013-04-09 06:28:02.929; org.apache.solr.commo= n.cloud.ZkStateReader; Updating cloud state from ZooKeeper...=20 [junit4:junit4] 1> INFO - 2013-04-09 06:28:02.930; 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:37902_", [junit4:junit4] 1> "base_url":"http://127.0.0.1:37902"} [junit4:junit4] 1> INFO - 2013-04-09 06:28:02.931; org.apache.solr.cloud= .Overseer$ClusterStateUpdater; Create collection nodes_used_collection with= numShards 2 [junit4:junit4] 1> INFO - 2013-04-09 06:28:02.967; 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:10515_", [junit4:junit4] 1> "base_url":"http://127.0.0.1:10515"} [junit4:junit4] 1> INFO - 2013-04-09 06:28:02.985; 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:46998_", [junit4:junit4] 1> "base_url":"http://127.0.0.1:46998"} [junit4:junit4] 1> INFO - 2013-04-09 06:28:02.995; 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:46348_", [junit4:junit4] 1> "base_url":"http://127.0.0.1:46348"} [junit4:junit4] 1> INFO - 2013-04-09 06:28:03.008; 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-09 06:28:03.008; 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-09 06:28:03.008; 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-09 06:28:03.008; 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-09 06:28:03.008; 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-09 06:28:03.008; 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-09 06:28:03.702; org.apache.solr.core.= CoreContainer; registering core: nodes_used_collection_shard2_replica1 [junit4:junit4] 1> INFO - 2013-04-09 06:28:03.702; org.apache.solr.cloud= .ZkController; Register replica - core:nodes_used_collection_shard2_replica= 1 address:http://127.0.0.1:37902 collection:nodes_used_collection shard:sha= rd2 [junit4:junit4] 1> INFO - 2013-04-09 06:28:03.703; org.apache.solr.commo= n.cloud.SolrZkClient; makePath: /collections/nodes_used_collection/leader_e= lect/shard2/election [junit4:junit4] 1> INFO - 2013-04-09 06:28:03.746; org.apache.solr.core.= CoreContainer; registering core: nodes_used_collection_shard2_replica2 [junit4:junit4] 1> INFO - 2013-04-09 06:28:03.746; org.apache.solr.cloud= .ZkController; Register replica - core:nodes_used_collection_shard2_replica= 2 address:http://127.0.0.1:10515 collection:nodes_used_collection shard:sha= rd2 [junit4:junit4] 1> INFO - 2013-04-09 06:28:03.786; org.apache.solr.core.= CoreContainer; registering core: nodes_used_collection_shard1_replica1 [junit4:junit4] 1> INFO - 2013-04-09 06:28:03.786; org.apache.solr.cloud= .ZkController; Register replica - core:nodes_used_collection_shard1_replica= 1 address:http://127.0.0.1:46998 collection:nodes_used_collection shard:sha= rd1 [junit4:junit4] 1> INFO - 2013-04-09 06:28:03.831; org.apache.solr.commo= n.cloud.SolrZkClient; makePath: /collections/nodes_used_collection/leader_e= lect/shard1/election [junit4:junit4] 1> INFO - 2013-04-09 06:28:03.831; org.apache.solr.cloud= .ShardLeaderElectionContext; Running the leader process. [junit4:junit4] 1> INFO - 2013-04-09 06:28:03.884; org.apache.solr.cloud= .ShardLeaderElectionContext; Enough replicas found to continue. [junit4:junit4] 1> INFO - 2013-04-09 06:28:03.885; org.apache.solr.cloud= .ShardLeaderElectionContext; I may be the new leader - try and sync [junit4:junit4] 1> INFO - 2013-04-09 06:28:03.886; org.apache.solr.cloud= .SyncStrategy; Sync replicas to http://127.0.0.1:37902/nodes_used_collectio= n_shard2_replica1/ [junit4:junit4] 1> INFO - 2013-04-09 06:28:03.887; org.apache.solr.updat= e.PeerSync; PeerSync: core=3Dnodes_used_collection_shard2_replica1 url=3Dht= tp://127.0.0.1:37902 START replicas=3D[http://127.0.0.1:10515/nodes_used_co= llection_shard2_replica2/] nUpdates=3D100 [junit4:junit4] 1> INFO - 2013-04-09 06:28:03.887; org.apache.solr.updat= e.PeerSync; PeerSync: core=3Dnodes_used_collection_shard2_replica1 url=3Dht= tp://127.0.0.1:37902 DONE. We have no versions. sync failed. [junit4:junit4] 1> INFO - 2013-04-09 06:28:03.888; org.apache.solr.core.= CoreContainer; registering core: nodes_used_collection_shard1_replica2 [junit4:junit4] 1> INFO - 2013-04-09 06:28:03.888; 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-09 06:28:03.889; org.apache.solr.cloud= .ZkController; Register replica - core:nodes_used_collection_shard1_replica= 2 address:http://127.0.0.1:46348 collection:nodes_used_collection shard:sha= rd1 [junit4:junit4] 1> INFO - 2013-04-09 06:28:03.889; 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-09 06:28:03.890; org.apache.solr.cloud= .ShardLeaderElectionContext; I am the new leader: http://127.0.0.1:37902/no= des_used_collection_shard2_replica1/ [junit4:junit4] 1> INFO - 2013-04-09 06:28:03.891; org.apache.solr.commo= n.cloud.SolrZkClient; makePath: /collections/nodes_used_collection/leaders/= shard2 [junit4:junit4] 1> INFO - 2013-04-09 06:28:03.893; 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=3D1=20 [junit4:junit4] 1> INFO - 2013-04-09 06:28:03.967; org.apache.solr.cloud= .ShardLeaderElectionContext; Running the leader process. [junit4:junit4] 1> INFO - 2013-04-09 06:28:04.044; org.apache.solr.cloud= .ShardLeaderElectionContext; Enough replicas found to continue. [junit4:junit4] 1> INFO - 2013-04-09 06:28:04.044; org.apache.solr.cloud= .ShardLeaderElectionContext; I may be the new leader - try and sync [junit4:junit4] 1> INFO - 2013-04-09 06:28:04.045; org.apache.solr.cloud= .SyncStrategy; Sync replicas to http://127.0.0.1:46998/nodes_used_collectio= n_shard1_replica1/ [junit4:junit4] 1> INFO - 2013-04-09 06:28:04.046; org.apache.solr.updat= e.PeerSync; PeerSync: core=3Dnodes_used_collection_shard1_replica1 url=3Dht= tp://127.0.0.1:46998 START replicas=3D[http://127.0.0.1:46348/nodes_used_co= llection_shard1_replica2/] nUpdates=3D100 [junit4:junit4] 1> INFO - 2013-04-09 06:28:04.047; org.apache.solr.updat= e.PeerSync; PeerSync: core=3Dnodes_used_collection_shard1_replica1 url=3Dht= tp://127.0.0.1:46998 DONE. We have no versions. sync failed. [junit4:junit4] 1> INFO - 2013-04-09 06:28:04.047; 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-09 06:28:04.048; 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-09 06:28:04.049; org.apache.solr.cloud= .ShardLeaderElectionContext; I am the new leader: http://127.0.0.1:46998/no= des_used_collection_shard1_replica1/ [junit4:junit4] 1> INFO - 2013-04-09 06:28:04.049; org.apache.solr.commo= n.cloud.SolrZkClient; makePath: /collections/nodes_used_collection/leaders/= shard1 [junit4:junit4] 1> INFO - 2013-04-09 06:28:04.052; 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=3D0=20 [junit4:junit4] 1> INFO - 2013-04-09 06:28:04.525; org.apache.solr.commo= n.cloud.ZkStateReader; Updating cloud state from ZooKeeper...=20 [junit4:junit4] 1> INFO - 2013-04-09 06:28:04.550; 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-09 06:28:04.550; 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-09 06:28:04.550; 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-09 06:28:04.550; 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-09 06:28:04.550; 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-09 06:28:04.550; 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-09 06:28:04.593; org.apache.solr.cloud= .ZkController; We are http://127.0.0.1:37902/nodes_used_collection_shard2_r= eplica1/ and leader is http://127.0.0.1:37902/nodes_used_collection_shard2_= replica1/ [junit4:junit4] 1> INFO - 2013-04-09 06:28:04.593; org.apache.solr.cloud= .ZkController; No LogReplay needed for core=3Dnodes_used_collection_shard2_= replica1 baseURL=3Dhttp://127.0.0.1:37902 [junit4:junit4] 1> INFO - 2013-04-09 06:28:04.593; org.apache.solr.cloud= .ZkController; I am the leader, no recovery necessary [junit4:junit4] 1> INFO - 2013-04-09 06:28:04.594; org.apache.solr.cloud= .ZkController; publishing core=3Dnodes_used_collection_shard2_replica1 stat= e=3Dactive [junit4:junit4] 1> INFO - 2013-04-09 06:28:04.595; org.apache.solr.commo= n.cloud.ZkStateReader; Updating cloud state from ZooKeeper...=20 [junit4:junit4] 1> INFO - 2013-04-09 06:28:04.596; org.apache.solr.core.= CoreContainer; Persisting cores config to /usr/home/hudson/hudson-slave/wor= kspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test/J1/./org.ap= ache.solr.cloud.CollectionsAPIDistributedZkTest-jetty3-1365488878182/solr.x= ml [junit4:junit4] 1> INFO - 2013-04-09 06:28:04.598; org.apache.solr.cloud= .ZkController; We are http://127.0.0.1:46998/nodes_used_collection_shard1_r= eplica1/ and leader is http://127.0.0.1:46998/nodes_used_collection_shard1_= replica1/ [junit4:junit4] 1> INFO - 2013-04-09 06:28:04.598; org.apache.solr.cloud= .ZkController; No LogReplay needed for core=3Dnodes_used_collection_shard1_= replica1 baseURL=3Dhttp://127.0.0.1:46998 [junit4:junit4] 1> INFO - 2013-04-09 06:28:04.598; org.apache.solr.cloud= .ZkController; I am the leader, no recovery necessary [junit4:junit4] 1> INFO - 2013-04-09 06:28:04.598; org.apache.solr.cloud= .ZkController; publishing core=3Dnodes_used_collection_shard1_replica1 stat= e=3Dactive [junit4:junit4] 1> INFO - 2013-04-09 06:28:04.600; org.apache.solr.commo= n.cloud.ZkStateReader; Updating cloud state from ZooKeeper...=20 [junit4:junit4] 1> INFO - 2013-04-09 06:28:04.600; org.apache.solr.core.= CoreContainer; Persisting cores config to /usr/home/hudson/hudson-slave/wor= kspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test/J1/./org.ap= ache.solr.cloud.CollectionsAPIDistributedZkTest-controljetty-1365488875013/= solr.xml [junit4:junit4] 1> INFO - 2013-04-09 06:28:04.603; org.apache.solr.core.= SolrXMLSerializer; Persisting cores config to /usr/home/hudson/hudson-slave= /workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test/J1/./or= g.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty3-1365488878182/so= lr.xml [junit4:junit4] 1> INFO - 2013-04-09 06:28:04.604; org.apache.solr.servl= et.SolrDispatchFilter; [admin] webapp=3Dnull path=3D/admin/cores params=3D{= numShards=3D2&shard=3Dshard2&name=3Dnodes_used_collection_shard2_replica1&a= ction=3DCREATE&collection=3Dnodes_used_collection&wt=3Djavabin&qt=3D/admin/= cores&version=3D2} status=3D0 QTime=3D3804=20 [junit4:junit4] 1> INFO - 2013-04-09 06:28:04.609; org.apache.solr.core.= SolrXMLSerializer; Persisting cores config to /usr/home/hudson/hudson-slave= /workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test/J1/./or= g.apache.solr.cloud.CollectionsAPIDistributedZkTest-controljetty-1365488875= 013/solr.xml [junit4:junit4] 1> INFO - 2013-04-09 06:28:04.610; 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=3D3810=20 [junit4:junit4] 1> INFO - 2013-04-09 06:28:04.832; org.apache.solr.cloud= .ZkController; We are http://127.0.0.1:10515/nodes_used_collection_shard2_r= eplica2/ and leader is http://127.0.0.1:37902/nodes_used_collection_shard2_= replica1/ [junit4:junit4] 1> INFO - 2013-04-09 06:28:04.833; org.apache.solr.cloud= .ZkController; No LogReplay needed for core=3Dnodes_used_collection_shard2_= replica2 baseURL=3Dhttp://127.0.0.1:10515 [junit4:junit4] 1> INFO - 2013-04-09 06:28:04.833; org.apache.solr.cloud= .ZkController; Core needs to recover:nodes_used_collection_shard2_replica2 [junit4:junit4] 1> INFO - 2013-04-09 06:28:04.833; org.apache.solr.updat= e.DefaultSolrCoreState; Running recovery - first canceling any ongoing reco= very [junit4:junit4] 1> INFO - 2013-04-09 06:28:04.834; org.apache.solr.cloud= .RecoveryStrategy; Starting recovery process. core=3Dnodes_used_collection= _shard2_replica2 recoveringAfterStartup=3Dtrue [junit4:junit4] 1> INFO - 2013-04-09 06:28:04.834; org.apache.solr.cloud= .RecoveryStrategy; ###### startupVersions=3D[] [junit4:junit4] 1> INFO - 2013-04-09 06:28:04.834; org.apache.solr.commo= n.cloud.ZkStateReader; Updating cloud state from ZooKeeper...=20 [junit4:junit4] 1> INFO - 2013-04-09 06:28:04.835; org.apache.solr.cloud= .ZkController; publishing core=3Dnodes_used_collection_shard2_replica2 stat= e=3Drecovering [junit4:junit4] 1> INFO - 2013-04-09 06:28:04.835; org.apache.solr.core.= CoreContainer; Persisting cores config to /usr/home/hudson/hudson-slave/wor= kspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test/J1/./org.ap= ache.solr.cloud.CollectionsAPIDistributedZkTest-jetty1-1365488875434/solr.x= ml [junit4:junit4] 1> INFO - 2013-04-09 06:28:04.841; 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-09 06:28:04.850; org.apache.solr.core.= SolrXMLSerializer; Persisting cores config to /usr/home/hudson/hudson-slave= /workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test/J1/./or= g.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty1-1365488875434/so= lr.xml [junit4:junit4] 1> INFO - 2013-04-09 06:28:04.851; org.apache.solr.handl= er.admin.CoreAdminHandler; Going to wait for coreNodeName: 127.0.0.1:10515_= _nodes_used_collection_shard2_replica2, state: recovering, checkLive: true,= onlyIfLeader: true [junit4:junit4] 1> INFO - 2013-04-09 06:28:04.852; 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=3D4052=20 [junit4:junit4] 1> INFO - 2013-04-09 06:28:04.969; org.apache.solr.cloud= .ZkController; We are http://127.0.0.1:46348/nodes_used_collection_shard1_r= eplica2/ and leader is http://127.0.0.1:46998/nodes_used_collection_shard1_= replica1/ [junit4:junit4] 1> INFO - 2013-04-09 06:28:04.970; org.apache.solr.cloud= .ZkController; No LogReplay needed for core=3Dnodes_used_collection_shard1_= replica2 baseURL=3Dhttp://127.0.0.1:46348 [junit4:junit4] 1> INFO - 2013-04-09 06:28:04.970; org.apache.solr.cloud= .ZkController; Core needs to recover:nodes_used_collection_shard1_replica2 [junit4:junit4] 1> INFO - 2013-04-09 06:28:04.970; org.apache.solr.updat= e.DefaultSolrCoreState; Running recovery - first canceling any ongoing reco= very [junit4:junit4] 1> INFO - 2013-04-09 06:28:04.971; org.apache.solr.cloud= .RecoveryStrategy; Starting recovery process. core=3Dnodes_used_collection= _shard1_replica2 recoveringAfterStartup=3Dtrue [junit4:junit4] 1> INFO - 2013-04-09 06:28:04.971; org.apache.solr.cloud= .RecoveryStrategy; ###### startupVersions=3D[] [junit4:junit4] 1> INFO - 2013-04-09 06:28:04.971; org.apache.solr.commo= n.cloud.ZkStateReader; Updating cloud state from ZooKeeper...=20 [junit4:junit4] 1> INFO - 2013-04-09 06:28:04.972; org.apache.solr.cloud= .ZkController; publishing core=3Dnodes_used_collection_shard1_replica2 stat= e=3Drecovering [junit4:junit4] 1> INFO - 2013-04-09 06:28:04.972; org.apache.solr.core.= CoreContainer; Persisting cores config to /usr/home/hudson/hudson-slave/wor= kspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test/J1/./org.ap= ache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1365488879462/solr.x= ml [junit4:junit4] 1> INFO - 2013-04-09 06:28:04.973; org.apache.solr.clien= t.solrj.impl.HttpClientUtil; Creating new http client, config:maxConnection= s=3D128&maxConnectionsPerHost=3D32&followRedirects=3Dfalse [junit4:junit4] 1> INFO - 2013-04-09 06:28:04.982; org.apache.solr.core.= SolrXMLSerializer; Persisting cores config to /usr/home/hudson/hudson-slave= /workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test/J1/./or= g.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1365488879462/so= lr.xml [junit4:junit4] 1> INFO - 2013-04-09 06:28:04.983; 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=3D4184=20 [junit4:junit4] 1> INFO - 2013-04-09 06:28:04.984; org.apache.solr.cloud= .OverseerCollectionProcessor; Finished create command on all shards for col= lection: nodes_used_collection [junit4:junit4] 1> INFO - 2013-04-09 06:28:04.984; org.apache.solr.handl= er.admin.CoreAdminHandler; Going to wait for coreNodeName: 127.0.0.1:46348_= _nodes_used_collection_shard1_replica2, state: recovering, checkLive: true,= onlyIfLeader: true [junit4:junit4] 1> INFO - 2013-04-09 06:28:04.990; 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-09 06:28:04.992; 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-09 06:28:04.992; 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=3D3804},core=3Dnodes_used_collect= ion_shard2_replica1,saved=3D/usr/home/hudson/hudson-slave/workspace/Lucene-= Solr-NightlyTests-trunk/solr/build/solr-core/test/J1/./org.apache.solr.clou= d.CollectionsAPIDistributedZkTest-jetty3-1365488878182/solr.xml},null=3D{re= sponseHeader=3D{status=3D0,QTime=3D3810},core=3Dnodes_used_collection_shard= 1_replica1,saved=3D/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Nigh= tlyTests-trunk/solr/build/solr-core/test/J1/./org.apache.solr.cloud.Collect= ionsAPIDistributedZkTest-controljetty-1365488875013/solr.xml},null=3D{respo= nseHeader=3D{status=3D0,QTime=3D4052},core=3Dnodes_used_collection_shard2_r= eplica2,saved=3D/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Nightly= Tests-trunk/solr/build/solr-core/test/J1/./org.apache.solr.cloud.Collection= sAPIDistributedZkTest-jetty1-1365488875434/solr.xml},null=3D{responseHeader= =3D{status=3D0,QTime=3D4184},core=3Dnodes_used_collection_shard1_replica2,s= aved=3D/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-tru= nk/solr/build/solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistr= ibutedZkTest-jetty4-1365488879462/solr.xml}}} [junit4:junit4] 1> INFO - 2013-04-09 06:28:05.005; 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=3D4236=20 [junit4:junit4] 1> INFO - 2013-04-09 06:28:05.006; org.apache.solr.clien= t.solrj.impl.HttpClientUtil; Creating new http client, config: [junit4:junit4] 1> INFO - 2013-04-09 06:28:05.007; org.apache.solr.commo= n.cloud.ConnectionManager; Waiting for client to connect to ZooKeeper [junit4:junit4] 1> INFO - 2013-04-09 06:28:05.009; org.apache.solr.commo= n.cloud.ConnectionManager; Watcher org.apache.solr.common.cloud.ConnectionM= anager@23efe853 name:ZooKeeperConnection Watcher:127.0.0.1:11081/solr got e= vent WatchedEvent state:SyncConnected type:None path:null path:null type:No= ne [junit4:junit4] 1> INFO - 2013-04-09 06:28:05.009; org.apache.solr.commo= n.cloud.ConnectionManager; Client is connected to ZooKeeper [junit4:junit4] 1> INFO - 2013-04-09 06:28:05.015; org.apache.solr.commo= n.cloud.ZkStateReader; Updating cluster state from ZooKeeper...=20 [junit4:junit4] 1> INFO - 2013-04-09 06:28:05.018; org.apache.solr.clien= t.solrj.impl.HttpClientUtil; Creating new http client, config: [junit4:junit4] 1> INFO - 2013-04-09 06:28:05.024; org.apache.solr.commo= n.cloud.ConnectionManager; Waiting for client to connect to ZooKeeper [junit4:junit4] 1> INFO - 2013-04-09 06:28:05.027; org.apache.solr.commo= n.cloud.ConnectionManager; Watcher org.apache.solr.common.cloud.ConnectionM= anager@5ec5059c name:ZooKeeperConnection Watcher:127.0.0.1:11081/solr got e= vent WatchedEvent state:SyncConnected type:None path:null path:null type:No= ne [junit4:junit4] 1> INFO - 2013-04-09 06:28:05.027; org.apache.solr.commo= n.cloud.ConnectionManager; Client is connected to ZooKeeper [junit4:junit4] 1> INFO - 2013-04-09 06:28:05.028; org.apache.solr.commo= n.cloud.ZkStateReader; Updating cluster state from ZooKeeper...=20 [junit4:junit4] 1> INFO - 2013-04-09 06:28:05.041; org.apache.solr.handl= er.admin.CollectionsHandler; Creating Collection : numShards=3D5&maxShardsP= erNode=3D4&name=3Dawholynewcollection_0&replicationFactor=3D3&action=3DCREA= TE&wt=3Djavabin&version=3D2 [junit4:junit4] 1> INFO - 2013-04-09 06:28:05.043; 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-09 06:28:05.045; 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":"5", [junit4:junit4] 1> "maxShardsPerNode":"4", [junit4:junit4] 1> "createNodeSet":null, [junit4:junit4] 1> "name":"awholynewcollection_0", [junit4:junit4] 1> "replicationFactor":"3"} [junit4:junit4] 1> INFO - 2013-04-09 06:28:05.045; 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:10515_ [junit4:junit4] 1> INFO - 2013-04-09 06:28:05.045; 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:46998_ [junit4:junit4] 1> INFO - 2013-04-09 06:28:05.046; 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:15909_ [junit4:junit4] 1> INFO - 2013-04-09 06:28:05.046; 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:46348_ [junit4:junit4] 1> INFO - 2013-04-09 06:28:05.046; 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:37902_ [junit4:junit4] 1> INFO - 2013-04-09 06:28:05.046; 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:10515_ [junit4:junit4] 1> INFO - 2013-04-09 06:28:05.047; org.apache.solr.cloud= .OverseerCollectionProcessor; Creating shard awholynewcollection_0_shard3_r= eplica1 as part of slice shard3 of collection awholynewcollection_0 on 127.= 0.0.1:46998_ [junit4:junit4] 1> INFO - 2013-04-09 06:28:05.047; org.apache.solr.cloud= .OverseerCollectionProcessor; Creating shard awholynewcollection_0_shard3_r= eplica2 as part of slice shard3 of collection awholynewcollection_0 on 127.= 0.0.1:15909_ [junit4:junit4] 1> INFO - 2013-04-09 06:28:05.047; org.apache.solr.core.= CoreContainer; Creating SolrCore 'awholynewcollection_0_shard1_replica3' us= ing instanceDir: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Nightl= yTests-trunk/solr/build/solr-core/test/J1/./org.apache.solr.cloud.Collectio= nsAPIDistributedZkTest-jetty2-1365488876797/awholynewcollection_0_shard1_re= plica3 [junit4:junit4] 1> INFO - 2013-04-09 06:28:05.048; org.apache.solr.core.= CoreContainer; Creating SolrCore 'awholynewcollection_0_shard1_replica1' us= ing instanceDir: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Nightl= yTests-trunk/solr/build/solr-core/test/J1/./org.apache.solr.cloud.Collectio= nsAPIDistributedZkTest-jetty1-1365488875434/awholynewcollection_0_shard1_re= plica1 [junit4:junit4] 1> INFO - 2013-04-09 06:28:05.049; org.apache.solr.cloud= .ZkController; Check for collection zkNode:awholynewcollection_0 [junit4:junit4] 1> INFO - 2013-04-09 06:28:05.048; org.apache.solr.core.= CoreContainer; Creating SolrCore 'awholynewcollection_0_shard3_replica1' us= ing instanceDir: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Nightl= yTests-trunk/solr/build/solr-core/test/J1/./org.apache.solr.cloud.Collectio= nsAPIDistributedZkTest-controljetty-1365488875013/awholynewcollection_0_sha= rd3_replica1 [junit4:junit4] 1> INFO - 2013-04-09 06:28:05.049; org.apache.solr.cloud= .ZkController; Check for collection zkNode:awholynewcollection_0 [junit4:junit4] 1> INFO - 2013-04-09 06:28:05.048; org.apache.solr.cloud= .ZkController; Check for collection zkNode:awholynewcollection_0 [junit4:junit4] 1> INFO - 2013-04-09 06:28:05.050; org.apache.solr.cloud= .ZkController; Creating collection in ZooKeeper:awholynewcollection_0 [junit4:junit4] 1> INFO - 2013-04-09 06:28:05.048; org.apache.solr.core.= CoreContainer; Creating SolrCore 'awholynewcollection_0_shard2_replica3' us= ing instanceDir: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Nightl= yTests-trunk/solr/build/solr-core/test/J1/./org.apache.solr.cloud.Collectio= nsAPIDistributedZkTest-jetty1-1365488875434/awholynewcollection_0_shard2_re= plica3 [junit4:junit4] 1> INFO - 2013-04-09 06:28:05.048; org.apache.solr.core.= CoreContainer; Creating SolrCore 'awholynewcollection_0_shard2_replica1' us= ing instanceDir: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Nightl= yTests-trunk/solr/build/solr-core/test/J1/./org.apache.solr.cloud.Collectio= nsAPIDistributedZkTest-jetty4-1365488879462/awholynewcollection_0_shard2_re= plica1 [junit4:junit4] 1> INFO - 2013-04-09 06:28:05.051; org.apache.solr.cloud= .ZkController; Check for collection zkNode:awholynewcollection_0 [junit4:junit4] 1> INFO - 2013-04-09 06:28:05.048; org.apache.solr.core.= CoreContainer; Creating SolrCore 'awholynewcollection_0_shard1_replica2' us= ing instanceDir: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Nightl= yTests-trunk/solr/build/solr-core/test/J1/./org.apache.solr.cloud.Collectio= nsAPIDistributedZkTest-controljetty-1365488875013/awholynewcollection_0_sha= rd1_replica2 [junit4:junit4] 1> INFO - 2013-04-09 06:28:05.047; org.apache.solr.cloud= .OverseerCollectionProcessor; Creating shard awholynewcollection_0_shard3_r= eplica3 as part of slice shard3 of collection awholynewcollection_0 on 127.= 0.0.1:46348_ [junit4:junit4] 1> INFO - 2013-04-09 06:28:05.052; org.apache.solr.cloud= .ZkController; Check for collection zkNode:awholynewcollection_0 [junit4:junit4] 1> INFO - 2013-04-09 06:28:05.052; org.apache.solr.cloud= .ZkController; Creating collection in ZooKeeper:awholynewcollection_0 [junit4:junit4] 1> INFO - 2013-04-09 06:28:05.051; org.apache.solr.cloud= .ZkController; Check for collection zkNode:awholynewcollection_0 [junit4:junit4] 1> INFO - 2013-04-09 06:28:05.050; org.apache.solr.cloud= .ZkController; Creating collection in ZooKeeper:awholynewcollection_0 [junit4:junit4] 1> INFO - 2013-04-09 06:28:05.050; org.apache.solr.cloud= .ZkController; Looking for collection configName [junit4:junit4] 1> INFO - 2013-04-09 06:28:05.053; org.apache.solr.cloud= .ZkController; Creating collection in ZooKeeper:awholynewcollection_0 [junit4:junit4] 1> INFO - 2013-04-09 06:28:05.050; org.apache.solr.cloud= .ZkController; Creating collection in ZooKeeper:awholynewcollection_0 [junit4:junit4] 1> INFO - 2013-04-09 06:28:05.049; org.apache.solr.core.= CoreContainer; Creating SolrCore 'awholynewcollection_0_shard3_replica2' us= ing instanceDir: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Nightl= yTests-trunk/solr/build/solr-core/test/J1/./org.apache.solr.cloud.Collectio= nsAPIDistributedZkTest-jetty2-1365488876797/awholynewcollection_0_shard3_re= plica2 [junit4:junit4] 1> INFO - 2013-04-09 06:28:05.049; org.apache.solr.core.= CoreContainer; Creating SolrCore 'awholynewcollection_0_shard2_replica2' us= ing instanceDir: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Nightl= yTests-trunk/solr/build/solr-core/test/J1/./org.apache.solr.cloud.Collectio= nsAPIDistributedZkTest-jetty3-1365488878182/awholynewcollection_0_shard2_re= plica2 [junit4:junit4] 1> INFO - 2013-04-09 06:28:05.055; org.apache.solr.cloud= .ZkController; Check for collection zkNode:awholynewcollection_0 [junit4:junit4] 1> INFO - 2013-04-09 06:28:05.054; org.apache.solr.cloud= .ZkController; Check for collection zkNode:awholynewcollection_0 [junit4:junit4] 1> INFO - 2013-04-09 06:28:05.054; org.apache.solr.cloud= .ZkController; Looking for collection configName [junit4:junit4] 1> INFO - 2013-04-09 06:28:05.054; org.apache.solr.cloud= .ZkController; Looking for collection configName [junit4:junit4] 1> INFO - 2013-04-09 06:28:05.053; org.apache.solr.cloud= .ZkController; Creating collection in ZooKeeper:awholynewcollection_0 [junit4:junit4] 1> INFO - 2013-04-09 06:28:05.053; org.apache.solr.cloud= .ZkController; Looking for collection configName [junit4:junit4] 1> INFO - 2013-04-09 06:28:05.057; org.apache.solr.cloud= .ZkController; Only one config set found in zk - using it:conf1 [junit4:junit4] 1> INFO - 2013-04-09 06:28:05.053; org.apache.solr.core.= CoreContainer; Creating SolrCore 'awholynewcollection_0_shard3_replica3' us= ing instanceDir: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Nightl= yTests-trunk/solr/build/solr-core/test/J1/./org.apache.solr.cloud.Collectio= nsAPIDistributedZkTest-jetty4-1365488879462/awholynewcollection_0_shard3_re= plica3 [junit4:junit4] 1> INFO - 2013-04-09 06:28:05.057; org.apache.solr.cloud= .ZkController; Only one config set found in zk - using it:conf1 [junit4:junit4] 1> INFO - 2013-04-09 06:28:05.052; org.apache.solr.cloud= .ZkController; Looking for collection configName [junit4:junit4] 1> INFO - 2013-04-09 06:28:05.052; org.apache.solr.cloud= .OverseerCollectionProcessor; Creating shard awholynewcollection_0_shard4_r= eplica1 as part of slice shard4 of collection awholynewcollection_0 on 127.= 0.0.1:37902_ [junit4:junit4] 1> INFO - 2013-04-09 06:28:05.058; org.apache.solr.commo= n.cloud.SolrZkClient; makePath: /collections/awholynewcollection_0 [junit4:junit4] 1> INFO - 2013-04-09 06:28:05.057; org.apache.solr.cloud= .ZkController; Check for collection zkNode:awholynewcollection_0 [junit4:junit4] 1> INFO - 2013-04-09 06:28:05.057; org.apache.solr.commo= n.cloud.SolrZkClient; makePath: /collections/awholynewcollection_0 [junit4:junit4] 1> INFO - 2013-04-09 06:28:05.057; org.apache.solr.cloud= .ZkController; Only one config set found in zk - using it:conf1 [junit4:junit4] 1> INFO - 2013-04-09 06:28:05.059; org.apache.solr.cloud= .ZkController; Creating collection in ZooKeeper:awholynewcollection_0 [junit4:junit4] 1> INFO - 2013-04-09 06:28:05.056; org.apache.solr.cloud= .ZkController; Only one config set found in zk - using it:conf1 [junit4:junit4] 1> INFO - 2013-04-09 06:28:05.056; org.apache.solr.cloud= .ZkController; Looking for collection configName [junit4:junit4] 1> INFO - 2013-04-09 06:28:05.056; org.apache.solr.cloud= .ZkController; Creating collection in ZooKeeper:awholynewcollection_0 [junit4:junit4] 1> INFO - 2013-04-09 06:28:05.055; org.apache.solr.cloud= .ZkController; Creating collection in ZooKeeper:awholynewcollection_0 [junit4:junit4] 1> INFO - 2013-04-09 06:28:05.061; org.apache.solr.cloud= .ZkController; Looking for collection configName [junit4:junit4] 1> INFO - 2013-04-09 06:28:05.060; org.apache.solr.cloud= .ZkController; Load collection config from:/collections/awholynewcollection= _0 [junit4:junit4] 1> INFO - 2013-04-09 06:28:05.060; org.apache.solr.commo= n.cloud.SolrZkClient; makePath: /collections/awholynewcollection_0 [junit4:junit4] 1> INFO - 2013-04-09 06:28:05.062; org.apache.solr.commo= n.cloud.SolrZkClient; makePath: /collections/awholynewcollection_0 [junit4:junit4] 1> INFO - 2013-04-09 06:28:05.060; org.apache.solr.cloud= .ZkController; Looking for collection configName [junit4:junit4] 1> INFO - 2013-04-09 06:28:05.059; org.apache.solr.commo= n.cloud.SolrZkClient; makePath: /collections/awholynewcollection_0 [junit4:junit4] 1> INFO - 2013-04-09 06:28:05.059; org.apache.solr.core.= CoreContainer; Creating SolrCore 'awholynewcollection_0_shard4_replica1' us= ing instanceDir: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Nightl= yTests-trunk/solr/build/solr-core/test/J1/./org.apache.solr.cloud.Collectio= nsAPIDistributedZkTest-jetty3-1365488878182/awholynewcollection_0_shard4_re= plica1 [junit4:junit4] 1> INFO - 2013-04-09 06:28:05.058; org.apache.solr.cloud= .ZkController; Only one config set found in zk - using it:conf1 [junit4:junit4] 1> INFO - 2013-04-09 06:28:05.058; org.apache.solr.cloud= .OverseerCollectionProcessor; Creating shard awholynewcollection_0_shard4_r= eplica2 as part of slice shard4 of collection awholynewcollection_0 on 127.= 0.0.1:10515_ [junit4:junit4] 1> INFO - 2013-04-09 06:28:05.064; org.apache.solr.cloud= .ZkController; Load collection config from:/collections/awholynewcollection= _0 [junit4:junit4] 1> INFO - 2013-04-09 06:28:05.064; org.apache.solr.cloud= .OverseerCollectionProcessor; Creating shard awholynewcollection_0_shard4_r= eplica3 as part of slice shard4 of collection awholynewcollection_0 on 127.= 0.0.1:46998_ [junit4:junit4] 1> INFO - 2013-04-09 06:28:05.063; org.apache.solr.commo= n.cloud.SolrZkClient; makePath: /collections/awholynewcollection_0 [junit4:junit4] 1> INFO - 2013-04-09 06:28:05.063; org.apache.solr.cloud= .ZkController; Check for collection zkNode:awholynewcollection_0 [junit4:junit4] 1> INFO - 2013-04-09 06:28:05.063; org.apache.solr.core.= SolrResourceLoader; new SolrResourceLoader for directory: '/usr/home/hudson= /hudson-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core= /test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty2-136= 5488876797/awholynewcollection_0_shard1_replica3/' [junit4:junit4] 1> INFO - 2013-04-09 06:28:05.061; org.apache.solr.commo= n.cloud.SolrZkClient; makePath: /collections/awholynewcollection_0 [junit4:junit4] 1> INFO - 2013-04-09 06:28:05.061; org.apache.solr.cloud= .ZkController; Load collection config from:/collections/awholynewcollection= _0 [junit4:junit4] 1> INFO - 2013-04-09 06:28:05.061; org.apache.solr.cloud= .ZkController; Looking for collection configName [junit4:junit4] 1> INFO - 2013-04-09 06:28:05.065; org.apache.solr.core.= CoreContainer; Creating SolrCore 'awholynewcollection_0_shard4_replica3' us= ing instanceDir: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Nightl= yTests-trunk/solr/build/solr-core/test/J1/./org.apache.solr.cloud.Collectio= nsAPIDistributedZkTest-controljetty-1365488875013/awholynewcollection_0_sha= rd4_replica3 [junit4:junit4] 1> INFO - 2013-04-09 06:28:05.065; org.apache.solr.core.= CoreContainer; Creating SolrCore 'awholynewcollection_0_shard4_replica2' us= ing instanceDir: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Nightl= yTests-trunk/solr/build/solr-core/test/J1/./org.apache.solr.cloud.Collectio= nsAPIDistributedZkTest-jetty1-1365488875434/awholynewcollection_0_shard4_re= plica2 [junit4:junit4] 1> INFO - 2013-04-09 06:28:05.064; org.apache.solr.cloud= .OverseerCollectionProcessor; Creating shard awholynewcollection_0_shard5_r= eplica1 as part of slice shard5 of collection awholynewcollection_0 on 127.= 0.0.1:15909_ [junit4:junit4] 1> INFO - 2013-04-09 06:28:05.064; org.apache.solr.cloud= .ZkController; Load collection config from:/collections/awholynewcollection= _0 [junit4:junit4] 1> INFO - 2013-04-09 06:28:05.064; org.apache.solr.commo= n.cloud.SolrZkClient; makePath: /collections/awholynewcollection_0 [junit4:junit4] 1> INFO - 2013-04-09 06:28:05.068; org.apache.solr.commo= n.cloud.SolrZkClient; makePath: /collections/awholynewcollection_0 [junit4:junit4] 1> INFO - 2013-04-09 06:28:05.068; org.apache.solr.core.= CoreContainer; Creating SolrCore 'awholynewcollection_0_shard5_replica1' us= ing instanceDir: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Nightl= yTests-trunk/solr/build/solr-core/test/J1/./org.apache.solr.cloud.Collectio= nsAPIDistributedZkTest-jetty2-1365488876797/awholynewcollection_0_shard5_re= plica1 [junit4:junit4] 1> INFO - 2013-04-09 06:28:05.067; org.apache.solr.core.= SolrResourceLoader; new SolrResourceLoader for directory: '/usr/home/hudson= /hudson-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core= /test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-controljet= ty-1365488875013/awholynewcollection_0_shard3_replica1/' [junit4:junit4] 1> INFO - 2013-04-09 06:28:05.069; org.apache.solr.core.= SolrResourceLoader; new SolrResourceLoader for directory: '/usr/home/hudson= /hudson-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core= /test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty1-136= 5488875434/awholynewcollection_0_shard1_replica1/' [junit4:junit4] 1> INFO - 2013-04-09 06:28:05.067; org.apache.solr.cloud= .ZkController; Load collection config from:/collections/awholynewcollection= _0 [junit4:junit4] 1> INFO - 2013-04-09 06:28:05.067; org.apache.solr.cloud= .OverseerCollectionProcessor; Creating shard awholynewcollection_0_shard5_r= eplica2 as part of slice shard5 of collection awholynewcollection_0 on 127.= 0.0.1:46348_ [junit4:junit4] 1> INFO - 2013-04-09 06:28:05.067; org.apache.solr.cloud= .ZkController; Check for collection zkNode:awholynewcollection_0 [junit4:junit4] 1> INFO - 2013-04-09 06:28:05.067; org.apache.solr.cloud= .ZkController; Collection zkNode exists [junit4:junit4] 1> INFO - 2013-04-09 06:28:05.066; org.apache.solr.cloud= .ZkController; Load collection config from:/collections/awholynewcollection= _0 [junit4:junit4] 1> INFO - 2013-04-09 06:28:05.071; org.apache.solr.cloud= .ZkController; Collection zkNode exists [junit4:junit4] 1> INFO - 2013-04-09 06:28:05.066; org.apache.solr.cloud= .ZkController; Check for collection zkNode:awholynewcollection_0 [junit4:junit4] 1> INFO - 2013-04-09 06:28:05.071; org.apache.solr.cloud= .ZkController; Load collection config from:/collections/awholynewcollection= _0 [junit4:junit4] 1> INFO - 2013-04-09 06:28:05.071; org.apache.solr.core.= CoreContainer; Creating SolrCore 'awholynewcollection_0_shard5_replica2' us= ing instanceDir: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Nightl= yTests-trunk/solr/build/solr-core/test/J1/./org.apache.solr.cloud.Collectio= nsAPIDistributedZkTest-jetty4-1365488879462/awholynewcollection_0_shard5_re= plica2 [junit4:junit4] 1> INFO - 2013-04-09 06:28:05.071; org.apache.solr.cloud= .ZkController; Load collection config from:/collections/awholynewcollection= _0 [junit4:junit4] 1> INFO - 2013-04-09 06:28:05.071; org.apache.solr.cloud= .ZkController; Load collection config from:/collections/awholynewcollection= _0 [junit4:junit4] 1> INFO - 2013-04-09 06:28:05.070; org.apache.solr.cloud= .ZkController; Load collection config from:/collections/awholynewcollection= _0 [junit4:junit4] 1> INFO - 2013-04-09 06:28:05.070; org.apache.solr.cloud= .OverseerCollectionProcessor; Creating shard awholynewcollection_0_shard5_r= eplica3 as part of slice shard5 of collection awholynewcollection_0 on 127.= 0.0.1:37902_ [junit4:junit4] 1> INFO - 2013-04-09 06:28:05.070; org.apache.solr.core.= SolrResourceLoader; new SolrResourceLoader for directory: '/usr/home/hudson= /hudson-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core= /test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty2-136= 5488876797/awholynewcollection_0_shard3_replica2/' [junit4:junit4] 1> INFO - 2013-04-09 06:28:05.069; org.apache.solr.cloud= .ZkController; Load collection config from:/collections/awholynewcollection= _0 [junit4:junit4] 1> INFO - 2013-04-09 06:28:05.069; org.apache.solr.cloud= .ZkController; Check for collection zkNode:awholynewcollection_0 [junit4:junit4] 1> INFO - 2013-04-09 06:28:05.073; org.apache.solr.core.= SolrResourceLoader; new SolrResourceLoader for directory: '/usr/home/hudson= /hudson-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core= /test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty1-136= 5488875434/awholynewcollection_0_shard4_replica2/' [junit4:junit4] 1> INFO - 2013-04-09 06:28:05.075; org.apache.solr.core.= SolrResourceLoader; new SolrResourceLoader for directory: '/usr/home/hudson= /hudson-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core= /test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty3-136= 5488878182/awholynewcollection_0_shard4_replica1/' [junit4:junit4] 1> INFO - 2013-04-09 06:28:05.072; org.apache.solr.core.= SolrResourceLoader; new SolrResourceLoader for directory: '/usr/home/hudson= /hudson-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core= /test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-controljet= ty-1365488875013/awholynewcollection_0_shard1_replica2/' [junit4:junit4] 1> INFO - 2013-04-09 06:28:05.072; org.apache.solr.cloud= .ZkController; Check for collection zkNode:awholynewcollection_0 [junit4:junit4] 1> INFO - 2013-04-09 06:28:05.072; org.apache.solr.core.= SolrResourceLoader; new SolrResourceLoader for directory: '/usr/home/hudson= /hudson-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core= /test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-136= 5488879462/awholynewcollection_0_shard2_replica1/' [junit4:junit4] 1> INFO - 2013-04-09 06:28:05.072; org.apache.solr.cloud= .ZkController; Collection zkNode exists [junit4:junit4] 1> INFO - 2013-04-09 06:28:05.078; org.apache.solr.cloud= .ZkController; Load collection config from:/collections/awholynewcollection= _0 [junit4:junit4] 1> INFO - 2013-04-09 06:28:05.076; org.apache.solr.core.= SolrResourceLoader; new SolrResourceLoader for directory: '/usr/home/hudson= /hudson-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core= /test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-136= 5488879462/awholynewcollection_0_shard3_replica3/' [junit4:junit4] 1> INFO - 2013-04-09 06:28:05.076; org.apache.solr.core.= SolrResourceLoader; new SolrResourceLoader for directory: '/usr/home/hudson= /hudson-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core= /test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty3-136= 5488878182/awholynewcollection_0_shard2_replica2/' [junit4:junit4] 1> INFO - 2013-04-09 06:28:05.075; org.apache.solr.cloud= .ZkController; Collection zkNode exists [junit4:junit4] 1> INFO - 2013-04-09 06:28:05.079; org.apache.solr.cloud= .ZkController; Load collection config from:/collections/awholynewcollection= _0 [junit4:junit4] 1> INFO - 2013-04-09 06:28:05.075; org.apache.solr.core.= CoreContainer; Creating SolrCore 'awholynewcollection_0_shard5_replica3' us= ing instanceDir: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Nightl= yTests-trunk/solr/build/solr-core/test/J1/./org.apache.solr.cloud.Collectio= nsAPIDistributedZkTest-jetty3-1365488878182/awholynewcollection_0_shard5_re= plica3 [junit4:junit4] 1> INFO - 2013-04-09 06:28:05.079; org.apache.solr.cloud= .ZkController; Collection zkNode exists [junit4:junit4] 1> INFO - 2013-04-09 06:28:05.080; org.apache.solr.cloud= .ZkController; Load collection config from:/collections/awholynewcollection= _0 [junit4:junit4] 1> INFO - 2013-04-09 06:28:05.078; org.apache.solr.core.= SolrResourceLoader; new SolrResourceLoader for directory: '/usr/home/hudson= /hudson-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core= /test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty1-136= 5488875434/awholynewcollection_0_shard2_replica3/' [junit4:junit4] 1> INFO - 2013-04-09 06:28:05.080; org.apache.solr.core.= SolrResourceLoader; new SolrResourceLoader for directory: '/usr/home/hudson= /hudson-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core= /test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-controljet= ty-1365488875013/awholynewcollection_0_shard4_replica3/' [junit4:junit4] 1> INFO - 2013-04-09 06:28:05.080; org.apache.solr.cloud= .ZkController; Check for collection zkNode:awholynewcollection_0 [junit4:junit4] 1> INFO - 2013-04-09 06:28:05.081; org.apache.solr.core.= SolrResourceLoader; new SolrResourceLoader for directory: '/usr/home/hudson= /hudson-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core= /test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty2-136= 5488876797/awholynewcollection_0_shard5_replica1/' [junit4:junit4] 1> INFO - 2013-04-09 06:28:05.083; org.apache.solr.cloud= .ZkController; Collection zkNode exists [junit4:junit4] 1> INFO - 2013-04-09 06:28:05.083; org.apache.solr.cloud= .ZkController; Load collection config from:/collections/awholynewcollection= _0 [junit4:junit4] 1> INFO - 2013-04-09 06:28:05.083; org.apache.solr.core.= SolrResourceLoader; new SolrResourceLoader for directory: '/usr/home/hudson= /hudson-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core= /test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-136= 5488879462/awholynewcollection_0_shard5_replica2/' [junit4:junit4] 1> INFO - 2013-04-09 06:28:05.085; org.apache.solr.core.= SolrResourceLoader; new SolrResourceLoader for directory: '/usr/home/hudson= /hudson-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core= /test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty3-136= 5488878182/awholynewcollection_0_shard5_replica3/' [junit4:junit4] 1> INFO - 2013-04-09 06:28:05.170; org.apache.solr.core.= SolrConfig; Using Lucene MatchVersion: LUCENE_50 [junit4:junit4] 1> INFO - 2013-04-09 06:28:05.177; org.apache.solr.core.= SolrConfig; Using Lucene MatchVersion: LUCENE_50 [junit4:junit4] 1> INFO - 2013-04-09 06:28:05.178; org.apache.solr.core.= SolrConfig; Using Lucene MatchVersion: LUCENE_50 [junit4:junit4] 1> INFO - 2013-04-09 06:28:05.181; org.apache.solr.core.= SolrConfig; Using Lucene MatchVersion: LUCENE_50 [junit4:junit4] 1> INFO - 2013-04-09 06:28:05.183; org.apache.solr.core.= SolrConfig; Using Lucene MatchVersion: LUCENE_50 [junit4:junit4] 1> INFO - 2013-04-09 06:28:05.183; org.apache.solr.core.= SolrConfig; Using Lucene MatchVersion: LUCENE_50 [junit4:junit4] 1> INFO - 2013-04-09 06:28:05.186; org.apache.solr.core.= SolrConfig; Using Lucene MatchVersion: LUCENE_50 [junit4:junit4] 1> INFO - 2013-04-09 06:28:05.194; org.apache.solr.core.= SolrConfig; Using Lucene MatchVersion: LUCENE_50 [junit4:junit4] 1> INFO - 2013-04-09 06:28:05.202; org.apache.solr.core.= SolrConfig; Using Lucene MatchVersion: LUCENE_50 [junit4:junit4] 1> INFO - 2013-04-09 06:28:05.203; org.apache.solr.core.= SolrConfig; Using Lucene MatchVersion: LUCENE_50 [junit4:junit4] 1> INFO - 2013-04-09 06:28:05.213; org.apache.solr.core.= SolrConfig; Using Lucene MatchVersion: LUCENE_50 [junit4:junit4] 1> INFO - 2013-04-09 06:28:05.217; org.apache.solr.core.= SolrConfig; Using Lucene MatchVersion: LUCENE_50 [junit4:junit4] 1> INFO - 2013-04-09 06:28:05.225; org.apache.solr.core.= SolrConfig; Using Lucene MatchVersion: LUCENE_50 [junit4:junit4] 1> INFO - 2013-04-09 06:28:05.239; org.apache.solr.core.= SolrConfig; Using Lucene MatchVersion: LUCENE_50 [junit4:junit4] 1> INFO - 2013-04-09 06:28:05.246; org.apache.solr.core.= SolrConfig; Using Lucene MatchVersion: LUCENE_50 [junit4:junit4] 1> INFO - 2013-04-09 06:28:05.331; org.apache.solr.core.= SolrConfig; Loaded SolrConfig: solrconfig.xml [junit4:junit4] 1> INFO - 2013-04-09 06:28:05.336; org.apache.solr.core.= SolrConfig; Loaded SolrConfig: solrconfig.xml [junit4:junit4] 1> INFO - 2013-04-09 06:28:05.338; org.apache.solr.core.= SolrConfig; Loaded SolrConfig: solrconfig.xml [junit4:junit4] 1> INFO - 2013-04-09 06:28:05.338; org.apache.solr.core.= SolrConfig; Loaded SolrConfig: solrconfig.xml [junit4:junit4] 1> INFO - 2013-04-09 06:28:05.339; org.apache.solr.core.= SolrConfig; Loaded SolrConfig: solrconfig.xml [junit4:junit4] 1> INFO - 2013-04-09 06:28:05.341; org.apache.solr.schem= a.IndexSchema; Reading Solr Schema from schema.xml [junit4:junit4] 1> INFO - 2013-04-09 06:28:05.343; org.apache.solr.core.= SolrConfig; Loaded SolrConfig: solrconfig.xml [junit4:junit4] 1> INFO - 2013-04-09 06:28:05.344; org.apache.solr.schem= a.IndexSchema; Reading Solr Schema from schema.xml [junit4:junit4] 1> INFO - 2013-04-09 06:28:05.345; org.apache.solr.core.= SolrConfig; Loaded SolrConfig: solrconfig.xml [junit4:junit4] 1> INFO - 2013-04-09 06:28:05.345; org.apache.solr.schem= a.IndexSchema; Reading Solr Schema from schema.xml [junit4:junit4] 1> INFO - 2013-04-09 06:28:05.346; org.apache.solr.schem= a.IndexSchema; Reading Solr Schema from schema.xml [junit4:junit4] 1> INFO - 2013-04-09 06:28:05.347; org.apache.solr.schem= a.IndexSchema; Reading Solr Schema from schema.xml [junit4:junit4] 1> INFO - 2013-04-09 06:28:05.349; org.apache.solr.schem= a.IndexSchema; Schema name=3Dtest [junit4:junit4] 1> INFO - 2013-04-09 06:28:05.352; org.apache.solr.schem= a.IndexSchema; Schema name=3Dtest [junit4:junit4] 1> INFO - 2013-04-09 06:28:05.352; org.apache.solr.schem= a.IndexSchema; Schema name=3Dtest [junit4:junit4] 1> INFO - 2013-04-09 06:28:05.352; org.apache.solr.schem= a.IndexSchema; Schema name=3Dtest [junit4:junit4] 1> INFO - 2013-04-09 06:28:05.355; org.apache.solr.schem= a.IndexSchema; Schema name=3Dtest [junit4:junit4] 1> INFO - 2013-04-09 06:28:05.355; org.apache.solr.core.= SolrConfig; Loaded SolrConfig: solrconfig.xml [junit4:junit4] 1> INFO - 2013-04-09 06:28:05.357; org.apache.solr.schem= a.IndexSchema; Reading Solr Schema from schema.xml [junit4:junit4] 1> INFO - 2013-04-09 06:28:05.363; org.apache.solr.core.= SolrConfig; Loaded SolrConfig: solrconfig.xml [junit4:junit4] 1> INFO - 2013-04-09 06:28:05.366; org.apache.solr.schem= a.IndexSchema; Schema name=3Dtest [junit4:junit4] 1> INFO - 2013-04-09 06:28:05.368; org.apache.solr.schem= a.IndexSchema; Reading Solr Schema from schema.xml [junit4:junit4] 1> INFO - 2013-04-09 06:28:05.370; org.apache.solr.core.= SolrConfig; Loaded SolrConfig: solrconfig.xml [junit4:junit4] 1> INFO - 2013-04-09 06:28:05.371; org.apache.solr.core.= SolrConfig; Loaded SolrConfig: solrconfig.xml [junit4:junit4] 1> INFO - 2013-04-09 06:28:05.371; org.apache.solr.schem= a.IndexSchema; Reading Solr Schema from schema.xml [junit4:junit4] 1> INFO - 2013-04-09 06:28:05.372; org.apache.solr.core.= SolrConfig; Loaded SolrConfig: solrconfig.xml [junit4:junit4] 1> INFO - 2013-04-09 06:28:05.373; org.apache.solr.schem= a.IndexSchema; Reading Solr Schema from schema.xml [junit4:junit4] 1> INFO - 2013-04-09 06:28:05.373; org.apache.solr.schem= a.IndexSchema; Reading Solr Schema from schema.xml [junit4:junit4] 1> INFO - 2013-04-09 06:28:05.375; org.apache.solr.schem= a.IndexSchema; Reading Solr Schema from schema.xml [junit4:junit4] 1> INFO - 2013-04-09 06:28:05.375; org.apache.solr.schem= a.IndexSchema; Reading Solr Schema from schema.xml [junit4:junit4] 1> INFO - 2013-04-09 06:28:05.378; org.apache.solr.schem= a.IndexSchema; Schema name=3Dtest [junit4:junit4] 1> INFO - 2013-04-09 06:28:05.379; org.apache.solr.schem= a.IndexSchema; Schema name=3Dtest [junit4:junit4] 1> INFO - 2013-04-09 06:28:05.382; org.apache.solr.schem= a.IndexSchema; Schema name=3Dtest [junit4:junit4] 1> INFO - 2013-04-09 06:28:05.382; org.apache.solr.schem= a.IndexSchema; Schema name=3Dtest [junit4:junit4] 1> INFO - 2013-04-09 06:28:05.383; org.apache.solr.schem= a.IndexSchema; Schema name=3Dtest [junit4:junit4] 1> INFO - 2013-04-09 06:28:05.384; org.apache.solr.core.= SolrConfig; Loaded SolrConfig: solrconfig.xml [junit4:junit4] 1> INFO - 2013-04-09 06:28:05.385; org.apache.solr.core.= SolrConfig; Loaded SolrConfig: solrconfig.xml [junit4:junit4] 1> INFO - 2013-04-09 06:28:05.385; org.apache.solr.schem= a.IndexSchema; Schema name=3Dtest [junit4:junit4] 1> INFO - 2013-04-09 06:28:05.386; org.apache.solr.core.= SolrConfig; Loaded SolrConfig: solrconfig.xml [junit4:junit4] 1> INFO - 2013-04-09 06:28:05.387; org.apache.solr.schem= a.IndexSchema; Reading Solr Schema from schema.xml [junit4:junit4] 1> INFO - 2013-04-09 06:28:05.388; org.apache.solr.schem= a.IndexSchema; Reading Solr Schema from schema.xml [junit4:junit4] 1> INFO - 2013-04-09 06:28:05.390; org.apache.solr.schem= a.IndexSchema; Reading Solr Schema from schema.xml [junit4:junit4] 1> INFO - 2013-04-09 06:28:05.397; org.apache.solr.schem= a.IndexSchema; Schema name=3Dtest [junit4:junit4] 1> INFO - 2013-04-09 06:28:05.397; org.apache.solr.schem= a.IndexSchema; Schema name=3Dtest [junit4:junit4] 1> INFO - 2013-04-09 06:28:05.398; org.apache.solr.schem= a.IndexSchema; Schema name=3Dtest [junit4:junit4] 1> INFO - 2013-04-09 06:28:06.098; org.apache.solr.commo= n.cloud.ZkStateReader; Updating cloud state from ZooKeeper...=20 [junit4:junit4] 1> INFO - 2013-04-09 06:28:06.100; 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:37902__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:37902_", [junit4:junit4] 1> "base_url":"http://127.0.0.1:37902"} [junit4:junit4] 1> INFO - 2013-04-09 06:28:06.127; 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:46998__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:46998_", [junit4:junit4] 1> "base_url":"http://127.0.0.1:46998"} [junit4:junit4] 1> INFO - 2013-04-09 06:28:06.134; 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:10515__nodes_used_collec= tion_shard2_replica2", [junit4:junit4] 1> "numShards":"2", [junit4:junit4] 1> "shard":"shard2", [junit4:junit4] 1> "roles":null, [junit4:junit4] 1> "state":"recovering", [junit4:junit4] 1> "shard_state":"active", [junit4:junit4] 1> "core":"nodes_used_collection_shard2_replica2", [junit4:junit4] 1> "collection":"nodes_used_collection", [junit4:junit4] 1> "shard_range":null, [junit4:junit4] 1> "node_name":"127.0.0.1:10515_", [junit4:junit4] 1> "base_url":"http://127.0.0.1:10515"} [junit4:junit4] 1> INFO - 2013-04-09 06:28:06.151; 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:46348__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":"recovering", [junit4:junit4] 1> "shard_state":"active", [junit4:junit4] 1> "core":"nodes_used_collection_shard1_replica2", [junit4:junit4] 1> "collection":"nodes_used_collection", [junit4:junit4] 1> "shard_range":null, [junit4:junit4] 1> "node_name":"127.0.0.1:46348_", [junit4:junit4] 1> "base_url":"http://127.0.0.1:46348"} [junit4:junit4] 1> INFO - 2013-04-09 06:28:06.164; 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-09 06:28:06.165; 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-09 06:28:06.165; 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-09 06:28:06.165; 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-09 06:28:06.165; 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-09 06:28:06.164; 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-09 06:28:06.166; 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-09 06:28:06.165; 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-09 06:28:06.854; org.apache.solr.handl= er.admin.CoreAdminHandler; Waited coreNodeName: 127.0.0.1:10515__nodes_used= _collection_shard2_replica2, state: recovering, checkLive: true, onlyIfLead= er: true for: 2 seconds. [junit4:junit4] 1> INFO - 2013-04-09 06:28:06.854; org.apache.solr.servl= et.SolrDispatchFilter; [admin] webapp=3Dnull path=3D/admin/cores params=3D{= coreNodeName=3D127.0.0.1:10515__nodes_used_collection_shard2_replica2&state= =3Drecovering&nodeName=3D127.0.0.1:10515_&action=3DPREPRECOVERY&checkLive= =3Dtrue&core=3Dnodes_used_collection_shard2_replica1&wt=3Djavabin&onlyIfLea= der=3Dtrue&version=3D2} status=3D0 QTime=3D2003=20 [junit4:junit4] 1> INFO - 2013-04-09 06:28:06.987; org.apache.solr.handl= er.admin.CoreAdminHandler; Waited coreNodeName: 127.0.0.1:46348__nodes_used= _collection_shard1_replica2, state: recovering, checkLive: true, onlyIfLead= er: true for: 2 seconds. [junit4:junit4] 1> INFO - 2013-04-09 06:28:06.987; org.apache.solr.servl= et.SolrDispatchFilter; [admin] webapp=3Dnull path=3D/admin/cores params=3D{= coreNodeName=3D127.0.0.1:46348__nodes_used_collection_shard1_replica2&state= =3Drecovering&nodeName=3D127.0.0.1:46348_&action=3DPREPRECOVERY&checkLive= =3Dtrue&core=3Dnodes_used_collection_shard1_replica1&wt=3Djavabin&onlyIfLea= der=3Dtrue&version=3D2} status=3D0 QTime=3D2003=20 [junit4:junit4] 1> INFO - 2013-04-09 06:28:07.077; org.apache.solr.schem= a.OpenExchangeRatesOrgProvider; Initialized with rates=3Dopen-exchange-rate= s.json, refreshInterval=3D1440. [junit4:junit4] 1> INFO - 2013-04-09 06:28:07.088; org.apache.solr.schem= a.OpenExchangeRatesOrgProvider; Initialized with rates=3Dopen-exchange-rate= s.json, refreshInterval=3D1440. [junit4:junit4] 1> INFO - 2013-04-09 06:28:07.097; org.apache.solr.schem= a.OpenExchangeRatesOrgProvider; Initialized with rates=3Dopen-exchange-rate= s.json, refreshInterval=3D1440. [junit4:junit4] 1> INFO - 2013-04-09 06:28:07.100; org.apache.solr.schem= a.OpenExchangeRatesOrgProvider; Initialized with rates=3Dopen-exchange-rate= s.json, refreshInterval=3D1440. [junit4:junit4] 1> INFO - 2013-04-09 06:28:07.103; org.apache.solr.schem= a.IndexSchema; default search field in schema is text [junit4:junit4] 1> INFO - 2013-04-09 06:28:07.103; org.apache.solr.schem= a.IndexSchema; default search field in schema is text [junit4:junit4] 1> INFO - 2013-04-09 06:28:07.106; org.apache.solr.schem= a.OpenExchangeRatesOrgProvider; Initialized with rates=3Dopen-exchange-rate= s.json, refreshInterval=3D1440. [junit4:junit4] 1> INFO - 2013-04-09 06:28:07.107; org.apache.solr.schem= a.OpenExchangeRatesOrgProvider; Initialized with rates=3Dopen-exchange-rate= s.json, refreshInterval=3D1440. [junit4:junit4] 1> INFO - 2013-04-09 06:28:07.109; org.apache.solr.schem= a.OpenExchangeRatesOrgProvider; Initialized with rates=3Dopen-exchange-rate= s.json, refreshInterval=3D1440. [junit4:junit4] 1> INFO - 2013-04-09 06:28:07.111; org.apache.solr.schem= a.IndexSchema; default search field in schema is text [junit4:junit4] 1> INFO - 2013-04-09 06:28:07.112; org.apache.solr.schem= a.IndexSchema; unique key field: id [junit4:junit4] 1> INFO - 2013-04-09 06:28:07.113; org.apache.solr.schem= a.IndexSchema; default search field in schema is text [junit4:junit4] 1> INFO - 2013-04-09 06:28:07.115; org.apache.solr.schem= a.IndexSchema; unique key field: id [junit4:junit4] 1> INFO - 2013-04-09 06:28:07.117; org.apache.solr.schem= a.IndexSchema; unique key field: id [junit4:junit4] 1> INFO - 2013-04-09 06:28:07.119; org.apache.solr.schem= a.IndexSchema; default search field in schema is text [junit4:junit4] 1> INFO - 2013-04-09 06:28:07.121; org.apache.solr.schem= a.IndexSchema; unique key field: id [junit4:junit4] 1> INFO - 2013-04-09 06:28:07.121; org.apache.solr.schem= a.IndexSchema; default search field in schema is text [junit4:junit4] 1> INFO - 2013-04-09 06:28:07.121; org.apache.solr.schem= a.IndexSchema; default search field in schema is text [junit4:junit4] 1> INFO - 2013-04-09 06:28:07.122; org.apache.solr.schem= a.OpenExchangeRatesOrgProvider; Initialized with rates=3Dopen-exchange-rate= s.json, refreshInterval=3D1440. [junit4:junit4] 1> INFO - 2013-04-09 06:28:07.123; org.apache.solr.schem= a.OpenExchangeRatesOrgProvider; Initialized with rates=3Dopen-exchange-rate= s.json, refreshInterval=3D1440. [junit4:junit4] 1> INFO - 2013-04-09 06:28:07.125; org.apache.solr.schem= a.IndexSchema; unique key field: id [junit4:junit4] 1> INFO - 2013-04-09 06:28:07.126; org.apache.solr.schem= a.IndexSchema; unique key field: id [junit4:junit4] 1> INFO - 2013-04-09 06:28:07.127; org.apache.solr.schem= a.IndexSchema; unique key field: id [junit4:junit4] 1> INFO - 2013-04-09 06:28:07.130; org.apache.solr.schem= a.OpenExchangeRatesOrgProvider; Initialized with rates=3Dopen-exchange-rate= s.json, refreshInterval=3D1440. [junit4:junit4] 1> INFO - 2013-04-09 06:28:07.130; org.apache.solr.schem= a.OpenExchangeRatesOrgProvider; Initialized with rates=3Dopen-exchange-rate= s.json, refreshInterval=3D1440. [junit4:junit4] 1> INFO - 2013-04-09 06:28:07.134; org.apache.solr.schem= a.IndexSchema; default search field in schema is text [junit4:junit4] 1> INFO - 2013-04-09 06:28:07.134; org.apache.solr.schem= a.IndexSchema; default search field in schema is text [junit4:junit4] 1> INFO - 2013-04-09 06:28:07.145; org.apache.solr.schem= a.OpenExchangeRatesOrgProvider; Initialized with rates=3Dopen-exchange-rate= s.json, refreshInterval=3D1440. [junit4:junit4] 1> INFO - 2013-04-09 06:28:07.147; org.apache.solr.schem= a.IndexSchema; unique key field: id [junit4:junit4] 1> INFO - 2013-04-09 06:28:07.148; org.apache.solr.schem= a.IndexSchema; unique key field: id [junit4:junit4] 1> INFO - 2013-04-09 06:28:07.148; org.apache.solr.schem= a.OpenExchangeRatesOrgProvider; Initialized with rates=3Dopen-exchange-rate= s.json, refreshInterval=3D1440. [junit4:junit4] 1> INFO - 2013-04-09 06:28:07.149; org.apache.solr.schem= a.IndexSchema; default search field in schema is text [junit4:junit4] 1> INFO - 2013-04-09 06:28:07.150; org.apache.solr.schem= a.FileExchangeRateProvider; Reloading exchange rates from file currency.xml [junit4:junit4] 1> INFO - 2013-04-09 06:28:07.151; org.apache.solr.schem= a.OpenExchangeRatesOrgProvider; Initialized with rates=3Dopen-exchange-rate= s.json, refreshInterval=3D1440. [junit4:junit4] 1> INFO - 2013-04-09 06:28:07.152; org.apache.solr.schem= a.IndexSchema; default search field in schema is text [junit4:junit4] 1> INFO - 2013-04-09 06:28:07.153; org.apache.solr.schem= a.IndexSchema; unique key field: id [junit4:junit4] 1> INFO - 2013-04-09 06:28:07.154; org.apache.solr.schem= a.FileExchangeRateProvider; Reloading exchange rates from file currency.xml [junit4:junit4] 1> INFO - 2013-04-09 06:28:07.155; org.apache.solr.schem= a.FileExchangeRateProvider; Reloading exchange rates from file currency.xml [junit4:junit4] 1> INFO - 2013-04-09 06:28:07.157; org.apache.solr.schem= a.IndexSchema; unique key field: id [junit4:junit4] 1> INFO - 2013-04-09 06:28:07.157; org.apache.solr.schem= a.IndexSchema; default search field in schema is text [junit4:junit4] 1> INFO - 2013-04-09 06:28:07.158; org.apache.solr.schem= a.FileExchangeRateProvider; Reloading exchange rates from file currency.xml [junit4:junit4] 1> INFO - 2013-04-09 06:28:07.159; org.apache.solr.schem= a.FileExchangeRateProvider; Reloading exchange rates from file currency.xml [junit4:junit4] 1> INFO - 2013-04-09 06:28:07.160; org.apache.solr.schem= a.FileExchangeRateProvider; Reloading exchange rates from file currency.xml [junit4:junit4] 1> INFO - 2013-04-09 06:28:07.160; org.apache.solr.schem= a.IndexSchema; default search field in schema is text [junit4:junit4] 1> INFO - 2013-04-09 06:28:07.162; org.apache.solr.schem= a.IndexSchema; unique key field: id [junit4:junit4] 1> INFO - 2013-04-09 06:28:07.162; org.apache.solr.schem= a.IndexSchema; default search field in schema is text [junit4:junit4] 1> INFO - 2013-04-09 06:28:07.164; org.apache.solr.schem= a.FileExchangeRateProvider; Reloading exchange rates from file currency.xml [junit4:junit4] 1> INFO - 2013-04-09 06:28:07.164; org.apache.solr.schem= a.FileExchangeRateProvider; Reloading exchange rates from file currency.xml [junit4:junit4] 1> INFO - 2013-04-09 06:28:07.165; org.apache.solr.schem= a.FileExchangeRateProvider; Reloading exchange rates from file currency.xml [junit4:junit4] 1> INFO - 2013-04-09 06:28:07.166; org.apache.solr.schem= a.FileExchangeRateProvider; Reloading exchange rates from file currency.xml [junit4:junit4] 1> INFO - 2013-04-09 06:28:07.166; org.apache.solr.schem= a.FileExchangeRateProvider; Reloading exchange rates from file currency.xml [junit4:junit4] 1> INFO - 2013-04-09 06:28:07.166; org.apache.solr.schem= a.FileExchangeRateProvider; Reloading exchange rates from file currency.xml [junit4:junit4] 1> INFO - 2013-04-09 06:28:07.167; org.apache.solr.schem= a.IndexSchema; unique key field: id [junit4:junit4] 1> INFO - 2013-04-09 06:28:07.168; org.apache.solr.schem= a.IndexSchema; unique key field: id [junit4:junit4] 1> INFO - 2013-04-09 06:28:07.169; org.apache.solr.schem= a.OpenExchangeRatesOrgProvider; Reloading exchange rates from open-exchange= -rates.json [junit4:junit4] 1> WARN - 2013-04-09 06:28:07.171; org.apache.solr.schem= a.OpenExchangeRatesOrgProvider$OpenExchangeRates; Unknown key IMPORTANT NOT= E [junit4:junit4] 1> WARN - 2013-04-09 06:28:07.171; org.apache.solr.schem= a.OpenExchangeRatesOrgProvider$OpenExchangeRates; Expected key, got STRING [junit4:junit4] 1> INFO - 2013-04-09 06:28:07.171; org.apache.solr.schem= a.OpenExchangeRatesOrgProvider; Reloading exchange rates from open-exchange= -rates.json [junit4:junit4] 1> INFO - 2013-04-09 06:28:07.171; org.apache.solr.schem= a.OpenExchangeRatesOrgProvider; Reloading exchange rates from open-exchange= -rates.json [junit4:junit4] 1> INFO - 2013-04-09 06:28:07.173; org.apache.solr.schem= a.OpenExchangeRatesOrgProvider; Reloading exchange rates from open-exchange= -rates.json [junit4:junit4] 1> WARN - 2013-04-09 06:28:07.174; org.apache.solr.schem= a.OpenExchangeRatesOrgProvider$OpenExchangeRates; Unknown key IMPORTANT NOT= E [junit4:junit4] 1> INFO - 2013-04-09 06:28:07.174; org.apache.solr.schem= a.FileExchangeRateProvider; Reloading exchange rates from file currency.xml [junit4:junit4] 1> INFO - 2013-04-09 06:28:07.174; org.apache.solr.schem= a.OpenExchangeRatesOrgProvider; Reloading exchange rates from open-exchange= -rates.json [junit4:junit4] 1> WARN - 2013-04-09 06:28:07.175; org.apache.solr.schem= a.OpenExchangeRatesOrgProvider$OpenExchangeRates; Unknown key IMPORTANT NOT= E [junit4:junit4] 1> WARN - 2013-04-09 06:28:07.173; org.apache.solr.schem= a.OpenExchangeRatesOrgProvider$OpenExchangeRates; Unknown key IMPORTANT NOT= E [junit4:junit4] 1> INFO - 2013-04-09 06:28:07.176; org.apache.solr.schem= a.FileExchangeRateProvider; Reloading exchange rates from file currency.xml [junit4:junit4] 1> INFO - 2013-04-09 06:28:07.173; org.apache.solr.schem= a.FileExchangeRateProvider; Reloading exchange rates from file currency.xml [junit4:junit4] 1> WARN - 2013-04-09 06:28:07.176; org.apache.solr.schem= a.OpenExchangeRatesOrgProvider$OpenExchangeRates; Unknown key IMPORTANT NOT= E [junit4:junit4] 1> WARN - 2013-04-09 06:28:07.176; org.apache.solr.schem= a.OpenExchangeRatesOrgProvider$OpenExchangeRates; Expected key, got STRING [junit4:junit4] 1> INFO - 2013-04-09 06:28:07.175; org.apache.solr.schem= a.OpenExchangeRatesOrgProvider; Reloading exchange rates from open-exchange= -rates.json [junit4:junit4] 1> WARN - 2013-04-09 06:28:07.175; org.apache.solr.schem= a.OpenExchangeRatesOrgProvider$OpenExchangeRates; Expected key, got STRING [junit4:junit4] 1> INFO - 2013-04-09 06:28:07.174; org.apache.solr.schem= a.FileExchangeRateProvider; Reloading exchange rates from file currency.xml [junit4:junit4] 1> WARN - 2013-04-09 06:28:07.174; org.apache.solr.schem= a.OpenExchangeRatesOrgProvider$OpenExchangeRates; Expected key, got STRING [junit4:junit4] 1> INFO - 2013-04-09 06:28:07.178; org.apache.solr.schem= a.OpenExchangeRatesOrgProvider; Reloading exchange rates from open-exchange= -rates.json [junit4:junit4] 1> INFO - 2013-04-09 06:28:07.177; org.apache.solr.schem= a.OpenExchangeRatesOrgProvider; Reloading exchange rates from open-exchange= -rates.json [junit4:junit4] 1> INFO - 2013-04-09 06:28:07.180; org.apache.solr.schem= a.FileExchangeRateProvider; Reloading exchange rates from file currency.xml [junit4:junit4] 1> WARN - 2013-04-09 06:28:07.177; org.apache.solr.schem= a.OpenExchangeRatesOrgProvider$OpenExchangeRates; Expected key, got STRING [junit4:junit4] 1> INFO - 2013-04-09 06:28:07.180; org.apache.solr.schem= a.OpenExchangeRatesOrgProvider; Reloading exchange rates from open-exchange= -rates.json [junit4:junit4] 1> INFO - 2013-04-09 06:28:07.179; org.apache.solr.core.= SolrCore; org.apache.solr.core.MockDirectoryFactory [junit4:junit4] 1> WARN - 2013-04-09 06:28:07.179; org.apache.solr.schem= a.OpenExchangeRatesOrgProvider$OpenExchangeRates; Unknown key IMPORTANT NOT= E [junit4:junit4] 1> INFO - 2013-04-09 06:28:07.182; org.apache.solr.schem= a.OpenExchangeRatesOrgProvider; Reloading exchange rates from open-exchange= -rates.json [junit4:junit4] 1> WARN - 2013-04-09 06:28:07.182; org.apache.solr.schem= a.OpenExchangeRatesOrgProvider$OpenExchangeRates; Unknown key IMPORTANT NOT= E [junit4:junit4] 1> INFO - 2013-04-09 06:28:07.181; org.apache.solr.core.= SolrCore; [awholynewcollection_0_shard4_replica3] Opening new SolrCore at /= usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/= build/solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZk= Test-controljetty-1365488875013/awholynewcollection_0_shard4_replica3/, dat= aDir=3D/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-tru= nk/solr/build/solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistr= ibutedZkTest-controljetty-1365488875013/awholynewcollection_0_shard4_replic= a3/data/ [junit4:junit4] 1> WARN - 2013-04-09 06:28:07.183; org.apache.solr.schem= a.OpenExchangeRatesOrgProvider$OpenExchangeRates; Unknown key IMPORTANT NOT= E [junit4:junit4] 1> INFO - 2013-04-09 06:28:07.181; org.apache.solr.schem= a.FileExchangeRateProvider; Reloading exchange rates from file currency.xml [junit4:junit4] 1> WARN - 2013-04-09 06:28:07.181; org.apache.solr.schem= a.OpenExchangeRatesOrgProvider$OpenExchangeRates; Unknown key IMPORTANT NOT= E [junit4:junit4] 1> WARN - 2013-04-09 06:28:07.181; org.apache.solr.schem= a.OpenExchangeRatesOrgProvider$OpenExchangeRates; Unknown key IMPORTANT NOT= E [junit4:junit4] 1> INFO - 2013-04-09 06:28:07.181; org.apache.solr.schem= a.OpenExchangeRatesOrgProvider; Reloading exchange rates from open-exchange= -rates.json [junit4:junit4] 1> WARN - 2013-04-09 06:28:07.184; org.apache.solr.schem= a.OpenExchangeRatesOrgProvider$OpenExchangeRates; Expected key, got STRING [junit4:junit4] 1> WARN - 2013-04-09 06:28:07.184; org.apache.solr.schem= a.OpenExchangeRatesOrgProvider$OpenExchangeRates; Expected key, got STRING [junit4:junit4] 1> WARN - 2013-04-09 06:28:07.183; org.apache.solr.schem= a.OpenExchangeRatesOrgProvider$OpenExchangeRates; Expected key, got STRING [junit4:junit4] 1> INFO - 2013-04-09 06:28:07.183; org.apache.solr.core.= JmxMonitoredMap; JMX monitoring is enabled. Adding Solr mbeans to JMX Serve= r: com.sun.jmx.mbeanserver.JmxMBeanServer@2432a50a [junit4:junit4] 1> WARN - 2013-04-09 06:28:07.183; org.apache.solr.schem= a.OpenExchangeRatesOrgProvider$OpenExchangeRates; Expected key, got STRING [junit4:junit4] 1> INFO - 2013-04-09 06:28:07.186; org.apache.solr.core.= SolrCore; org.apache.solr.core.MockDirectoryFactory [junit4:junit4] 1> INFO - 2013-04-09 06:28:07.182; org.apache.solr.schem= a.FileExchangeRateProvider; Reloading exchange rates from file currency.xml [junit4:junit4] 1> INFO - 2013-04-09 06:28:07.182; org.apache.solr.schem= a.FileExchangeRateProvider; Reloading exchange rates from file currency.xml [junit4:junit4] 1> WARN - 2013-04-09 06:28:07.182; org.apache.solr.schem= a.OpenExchangeRatesOrgProvider$OpenExchangeRates; Expected key, got STRING [junit4:junit4] 1> INFO - 2013-04-09 06:28:07.186; org.apache.solr.schem= a.FileExchangeRateProvider; Reloading exchange rates from file currency.xml [junit4:junit4] 1> INFO - 2013-04-09 06:28:07.186; org.apache.solr.schem= a.OpenExchangeRatesOrgProvider; Reloading exchange rates from open-exchange= -rates.json [junit4:junit4] 1> INFO - 2013-04-09 06:28:07.186; org.apache.solr.schem= a.FileExchangeRateProvider; Reloading exchange rates from file currency.xml [junit4:junit4] 1> INFO - 2013-04-09 06:28:07.186; org.apache.solr.schem= a.OpenExchangeRatesOrgProvider; Reloading exchange rates from open-exchange= -rates.json [junit4:junit4] 1> INFO - 2013-04-09 06:28:07.185; org.apache.solr.core.= SolrCore; org.apache.solr.core.MockDirectoryFactory [junit4:junit4] 1> WARN - 2013-04-09 06:28:07.189; org.apache.solr.schem= a.OpenExchangeRatesOrgProvider$OpenExchangeRates; Unknown key IMPORTANT NOT= E [junit4:junit4] 1> WARN - 2013-04-09 06:28:07.185; org.apache.solr.schem= a.OpenExchangeRatesOrgProvider$OpenExchangeRates; Unknown key IMPORTANT NOT= E [junit4:junit4] 1> WARN - 2013-04-09 06:28:07.190; org.apache.solr.schem= a.OpenExchangeRatesOrgProvider$OpenExchangeRates; Expected key, got STRING [junit4:junit4] 1> INFO - 2013-04-09 06:28:07.185; org.apache.solr.schem= a.FileExchangeRateProvider; Reloading exchange rates from file currency.xml [junit4:junit4] 1> WARN - 2013-04-09 06:28:07.191; org.apache.solr.schem= a.OpenExchangeRatesOrgProvider$OpenExchangeRates; Unknown key IMPORTANT NOT= E [junit4:junit4] 1> WARN - 2013-04-09 06:28:07.191; org.apache.solr.schem= a.OpenExchangeRatesOrgProvider$OpenExchangeRates; Expected key, got STRING [junit4:junit4] 1> INFO - 2013-04-09 06:28:07.185; org.apache.solr.core.= SolrCore; org.apache.solr.core.MockDirectoryFactory [junit4:junit4] 1> INFO - 2013-04-09 06:28:07.185; org.apache.solr.schem= a.FileExchangeRateProvider; Reloading exchange rates from file currency.xml [junit4:junit4] 1> INFO - 2013-04-09 06:28:07.192; org.apache.solr.core.= SolrCore; [awholynewcollection_0_shard5_replica3] Opening new SolrCore at /= usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/= build/solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZk= Test-jetty3-1365488878182/awholynewcollection_0_shard5_replica3/, dataDir= =3D/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-trunk/s= olr/build/solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistribut= edZkTest-jetty3-1365488878182/awholynewcollection_0_shard5_replica3/data/ [junit4:junit4] 1> INFO - 2013-04-09 06:28:07.191; org.apache.solr.schem= a.FileExchangeRateProvider; Reloading exchange rates from file currency.xml [junit4:junit4] 1> INFO - 2013-04-09 06:28:07.191; org.apache.solr.core.= SolrCore; org.apache.solr.core.MockDirectoryFactory [junit4:junit4] 1> INFO - 2013-04-09 06:28:07.190; org.apache.solr.core.= SolrCore; org.apache.solr.core.MockDirectoryFactory [junit4:junit4] 1> INFO - 2013-04-09 06:28:07.193; org.apache.solr.schem= a.FileExchangeRateProvider; Reloading exchange rates from file currency.xml [junit4:junit4] 1> WARN - 2013-04-09 06:28:07.189; org.apache.solr.schem= a.OpenExchangeRatesOrgProvider$OpenExchangeRates; Expected key, got STRING [junit4:junit4] 1> INFO - 2013-04-09 06:28:07.189; org.apache.solr.core.= SolrCore; [awholynewcollection_0_shard3_replica2] Opening new SolrCore at /= usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/= build/solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZk= Test-jetty2-1365488876797/awholynewcollection_0_shard3_replica2/, dataDir= =3D/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-trunk/s= olr/build/solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistribut= edZkTest-jetty2-1365488876797/awholynewcollection_0_shard3_replica2/data/ [junit4:junit4] 1> INFO - 2013-04-09 06:28:07.189; org.apache.solr.schem= a.OpenExchangeRatesOrgProvider; Reloading exchange rates from open-exchange= -rates.json [junit4:junit4] 1> INFO - 2013-04-09 06:28:07.188; org.apache.solr.core.= CachingDirectoryFactory; return new directory for /usr/home/hudson/hudson-s= lave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test/J1/= ./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-controljetty-136548= 8875013/awholynewcollection_0_shard4_replica3/data [junit4:junit4] 1> INFO - 2013-04-09 06:28:07.188; org.apache.solr.schem= a.OpenExchangeRatesOrgProvider; Reloading exchange rates from open-exchange= -rates.json [junit4:junit4] 1> INFO - 2013-04-09 06:28:07.194; org.apache.solr.core.= JmxMonitoredMap; JMX monitoring is enabled. Adding Solr mbeans to JMX Serve= r: com.sun.jmx.mbeanserver.JmxMBeanServer@2432a50a [junit4:junit4] 1> INFO - 2013-04-09 06:28:07.194; org.apache.solr.core.= SolrCore; org.apache.solr.core.MockDirectoryFactory [junit4:junit4] 1> INFO - 2013-04-09 06:28:07.193; org.apache.solr.core.= SolrCore; [awholynewcollection_0_shard4_replica1] Opening new SolrCore at /= usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/= build/solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZk= Test-jetty3-1365488878182/awholynewcollection_0_shard4_replica1/, dataDir= =3D/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-trunk/s= olr/build/solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistribut= edZkTest-jetty3-1365488878182/awholynewcollection_0_shard4_replica1/data/ [junit4:junit4] 1> INFO - 2013-04-09 06:28:07.193; org.apache.solr.core.= SolrCore; [awholynewcollection_0_shard3_replica1] Opening new SolrCore at /= usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/= build/solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZk= Test-controljetty-1365488875013/awholynewcollection_0_shard3_replica1/, dat= aDir=3D/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-tru= nk/solr/build/solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistr= ibutedZkTest-controljetty-1365488875013/awholynewcollection_0_shard3_replic= a1/data/ [junit4:junit4] 1> INFO - 2013-04-09 06:28:07.196; org.apache.solr.schem= a.OpenExchangeRatesOrgProvider; Reloading exchange rates from open-exchange= -rates.json [junit4:junit4] 1> INFO - 2013-04-09 06:28:07.193; org.apache.solr.schem= a.OpenExchangeRatesOrgProvider; Reloading exchange rates from open-exchange= -rates.json [junit4:junit4] 1> INFO - 2013-04-09 06:28:07.192; org.apache.solr.core.= JmxMonitoredMap; JMX monitoring is enabled. Adding Solr mbeans to JMX Serve= r: com.sun.jmx.mbeanserver.JmxMBeanServer@2432a50a [junit4:junit4] 1> INFO - 2013-04-09 06:28:07.192; org.apache.solr.schem= a.FileExchangeRateProvider; Reloading exchange rates from file currency.xml [junit4:junit4] 1> WARN - 2013-04-09 06:28:07.198; org.apache.solr.schem= a.OpenExchangeRatesOrgProvider$OpenExchangeRates; Unknown key IMPORTANT NOT= E [junit4:junit4] 1> WARN - 2013-04-09 06:28:07.198; org.apache.solr.schem= a.OpenExchangeRatesOrgProvider$OpenExchangeRates; Unknown key IMPORTANT NOT= E [junit4:junit4] 1> INFO - 2013-04-09 06:28:07.198; org.apache.solr.schem= a.OpenExchangeRatesOrgProvider; Reloading exchange rates from open-exchange= -rates.json [junit4:junit4] 1> INFO - 2013-04-09 06:28:07.198; org.apache.solr.core.= SolrCore; org.apache.solr.core.MockDirectoryFactory [junit4:junit4] 1> INFO - 2013-04-09 06:28:07.198; org.apache.solr.schem= a.OpenExchangeRatesOrgProvider; Reloading exchange rates from open-exchange= -rates.json [junit4:junit4] 1> INFO - 2013-04-09 06:28:07.198; org.apache.solr.schem= a.FileExchangeRateProvider; Reloading exchange rates from file currency.xml [junit4:junit4] 1> INFO - 2013-04-09 06:28:07.196; org.apache.solr.core.= JmxMonitoredMap; JMX monitoring is enabled. Adding Solr mbeans to JMX Serve= r: com.sun.jmx.mbeanserver.JmxMBeanServer@2432a50a [junit4:junit4] 1> INFO - 2013-04-09 06:28:07.196; org.apache.solr.core.= JmxMonitoredMap; JMX monitoring is enabled. Adding Solr mbeans to JMX Serve= r: com.sun.jmx.mbeanserver.JmxMBeanServer@2432a50a [junit4:junit4] 1> INFO - 2013-04-09 06:28:07.196; org.apache.solr.core.= SolrCore; org.apache.solr.core.MockDirectoryFactory [junit4:junit4] 1> INFO - 2013-04-09 06:28:07.201; org.apache.solr.core.= SolrCore; org.apache.solr.core.MockDirectoryFactory [junit4:junit4] 1> INFO - 2013-04-09 06:28:07.196; org.apache.solr.core.= SolrCore; [awholynewcollection_0_shard1_replica3] Opening new SolrCore at /= usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/= build/solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZk= Test-jetty2-1365488876797/awholynewcollection_0_shard1_replica3/, dataDir= =3D/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-trunk/s= olr/build/solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistribut= edZkTest-jetty2-1365488876797/awholy [...truncated too long message...] tConnectionImpl.open(ManagedClientConnectionImpl.java:294) [junit4:junit4] > at org.apache.http.impl.client.DefaultRequestD= irector.tryConnect(DefaultRequestDirector.java:645) [junit4:junit4] > at org.apache.http.impl.client.DefaultRequestD= irector.execute(DefaultRequestDirector.java:480) [junit4:junit4] > at org.apache.http.impl.client.AbstractHttpCli= ent.execute(AbstractHttpClient.java:906) [junit4:junit4] > at org.apache.http.impl.client.AbstractHttpCli= ent.execute(AbstractHttpClient.java:805) [junit4:junit4] > at org.apache.http.impl.client.AbstractHttpCli= ent.execute(AbstractHttpClient.java:784) [junit4:junit4] > at org.apache.solr.client.solrj.impl.HttpSolrS= erver.request(HttpSolrServer.java:353) [junit4:junit4] > at org.apache.solr.client.solrj.impl.HttpSolrS= erver.request(HttpSolrServer.java:181) [junit4:junit4] > at org.apache.solr.cloud.SyncStrategy$1.run(Sy= ncStrategy.java:298) [junit4:junit4] > at java.util.concurrent.ThreadPoolExecutor.run= Worker(ThreadPoolExecutor.java:1145) [junit4:junit4] > at java.util.concurrent.ThreadPoolExecutor$Wor= ker.run(ThreadPoolExecutor.java:615) [junit4:junit4] > at java.lang.Thread.run(Thread.java:722) [junit4:junit4] > 2) Thread[id=3D3459, name=3DrecoveryCmdExecutor-122= 9-thread-1, state=3DRUNNABLE, group=3DTGRP-CollectionsAPIDistributedZkTest] [junit4:junit4] > at java.net.PlainSocketImpl.socketConnect(Nati= ve Method) [junit4:junit4] > at java.net.AbstractPlainSocketImpl.doConnect(= AbstractPlainSocketImpl.java:339) [junit4:junit4] > at java.net.AbstractPlainSocketImpl.connectToA= ddress(AbstractPlainSocketImpl.java:200) [junit4:junit4] > at java.net.AbstractPlainSocketImpl.connect(Ab= stractPlainSocketImpl.java:182) [junit4:junit4] > at java.net.SocksSocketImpl.connect(SocksSocke= tImpl.java:391) [junit4:junit4] > at java.net.Socket.connect(Socket.java:579) [junit4:junit4] > at org.apache.http.conn.scheme.PlainSocketFact= ory.connectSocket(PlainSocketFactory.java:127) [junit4:junit4] > at org.apache.http.impl.conn.DefaultClientConn= ectionOperator.openConnection(DefaultClientConnectionOperator.java:180) [junit4:junit4] > at org.apache.http.impl.conn.ManagedClientConn= ectionImpl.open(ManagedClientConnectionImpl.java:294) [junit4:junit4] > at org.apache.http.impl.client.DefaultRequestD= irector.tryConnect(DefaultRequestDirector.java:645) [junit4:junit4] > at org.apache.http.impl.client.DefaultRequestD= irector.execute(DefaultRequestDirector.java:480) [junit4:junit4] > at org.apache.http.impl.client.AbstractHttpCli= ent.execute(AbstractHttpClient.java:906) [junit4:junit4] > at org.apache.http.impl.client.AbstractHttpCli= ent.execute(AbstractHttpClient.java:805) [junit4:junit4] > at org.apache.http.impl.client.AbstractHttpCli= ent.execute(AbstractHttpClient.java:784) [junit4:junit4] > at org.apache.solr.client.solrj.impl.HttpSolrS= erver.request(HttpSolrServer.java:353) [junit4:junit4] > at org.apache.solr.client.solrj.impl.HttpSolrS= erver.request(HttpSolrServer.java:181) [junit4:junit4] > at org.apache.solr.cloud.SyncStrategy$1.run(Sy= ncStrategy.java:298) [junit4:junit4] > at java.util.concurrent.ThreadPoolExecutor.run= Worker(ThreadPoolExecutor.java:1145) [junit4:junit4] > at java.util.concurrent.ThreadPoolExecutor$Wor= ker.run(ThreadPoolExecutor.java:615) [junit4:junit4] > at java.lang.Thread.run(Thread.java:722) [junit4:junit4] > =09at __randomizedtesting.SeedInfo.seed([58B3562C02208= C06]:0)Throwable #2: com.carrotsearch.randomizedtesting.ThreadLeakError: Th= ere are still zombie threads that couldn't be terminated: [junit4:junit4] > 1) Thread[id=3D3461, name=3DrecoveryCmdExecutor-122= 9-thread-2, state=3DRUNNABLE, group=3DTGRP-CollectionsAPIDistributedZkTest] [junit4:junit4] > at java.net.PlainSocketImpl.socketConnect(Nati= ve Method) [junit4:junit4] > at java.net.AbstractPlainSocketImpl.doConnect(= AbstractPlainSocketImpl.java:339) [junit4:junit4] > at java.net.AbstractPlainSocketImpl.connectToA= ddress(AbstractPlainSocketImpl.java:200) [junit4:junit4] > at java.net.AbstractPlainSocketImpl.connect(Ab= stractPlainSocketImpl.java:182) [junit4:junit4] > at java.net.SocksSocketImpl.connect(SocksSocke= tImpl.java:391) [junit4:junit4] > at java.net.Socket.connect(Socket.java:579) [junit4:junit4] > at org.apache.http.conn.scheme.PlainSocketFact= ory.connectSocket(PlainSocketFactory.java:127) [junit4:junit4] > at org.apache.http.impl.conn.DefaultClientConn= ectionOperator.openConnection(DefaultClientConnectionOperator.java:180) [junit4:junit4] > at org.apache.http.impl.conn.ManagedClientConn= ectionImpl.open(ManagedClientConnectionImpl.java:294) [junit4:junit4] > at org.apache.http.impl.client.DefaultRequestD= irector.tryConnect(DefaultRequestDirector.java:645) [junit4:junit4] > at org.apache.http.impl.client.DefaultRequestD= irector.execute(DefaultRequestDirector.java:480) [junit4:junit4] > at org.apache.http.impl.client.AbstractHttpCli= ent.execute(AbstractHttpClient.java:906) [junit4:junit4] > at org.apache.http.impl.client.AbstractHttpCli= ent.execute(AbstractHttpClient.java:805) [junit4:junit4] > at org.apache.http.impl.client.AbstractHttpCli= ent.execute(AbstractHttpClient.java:784) [junit4:junit4] > at org.apache.solr.client.solrj.impl.HttpSolrS= erver.request(HttpSolrServer.java:353) [junit4:junit4] > at org.apache.solr.client.solrj.impl.HttpSolrS= erver.request(HttpSolrServer.java:181) [junit4:junit4] > at org.apache.solr.cloud.SyncStrategy$1.run(Sy= ncStrategy.java:298) [junit4:junit4] > at java.util.concurrent.ThreadPoolExecutor.run= Worker(ThreadPoolExecutor.java:1145) [junit4:junit4] > at java.util.concurrent.ThreadPoolExecutor$Wor= ker.run(ThreadPoolExecutor.java:615) [junit4:junit4] > at java.lang.Thread.run(Thread.java:722) [junit4:junit4] > 2) Thread[id=3D3459, name=3DrecoveryCmdExecutor-122= 9-thread-1, state=3DRUNNABLE, group=3DTGRP-CollectionsAPIDistributedZkTest] [junit4:junit4] > at java.net.PlainSocketImpl.socketConnect(Nati= ve Method) [junit4:junit4] > at java.net.AbstractPlainSocketImpl.doConnect(= AbstractPlainSocketImpl.java:339) [junit4:junit4] > at java.net.AbstractPlainSocketImpl.connectToA= ddress(AbstractPlainSocketImpl.java:200) [junit4:junit4] > at java.net.AbstractPlainSocketImpl.connect(Ab= stractPlainSocketImpl.java:182) [junit4:junit4] > at java.net.SocksSocketImpl.connect(SocksSocke= tImpl.java:391) [junit4:junit4] > at java.net.Socket.connect(Socket.java:579) [junit4:junit4] > at org.apache.http.conn.scheme.PlainSocketFact= ory.connectSocket(PlainSocketFactory.java:127) [junit4:junit4] > at org.apache.http.impl.conn.DefaultClientConn= ectionOperator.openConnection(DefaultClientConnectionOperator.java:180) [junit4:junit4] > at org.apache.http.impl.conn.ManagedClientConn= ectionImpl.open(ManagedClientConnectionImpl.java:294) [junit4:junit4] > at org.apache.http.impl.client.DefaultRequestD= irector.tryConnect(DefaultRequestDirector.java:645) [junit4:junit4] > at org.apache.http.impl.client.DefaultRequestD= irector.execute(DefaultRequestDirector.java:480) [junit4:junit4] > at org.apache.http.impl.client.AbstractHttpCli= ent.execute(AbstractHttpClient.java:906) [junit4:junit4] > at org.apache.http.impl.client.AbstractHttpCli= ent.execute(AbstractHttpClient.java:805) [junit4:junit4] > at org.apache.http.impl.client.AbstractHttpCli= ent.execute(AbstractHttpClient.java:784) [junit4:junit4] > at org.apache.solr.client.solrj.impl.HttpSolrS= erver.request(HttpSolrServer.java:353) [junit4:junit4] > at org.apache.solr.client.solrj.impl.HttpSolrS= erver.request(HttpSolrServer.java:181) [junit4:junit4] > at org.apache.solr.cloud.SyncStrategy$1.run(Sy= ncStrategy.java:298) [junit4:junit4] > at java.util.concurrent.ThreadPoolExecutor.run= Worker(ThreadPoolExecutor.java:1145) [junit4:junit4] > at java.util.concurrent.ThreadPoolExecutor$Wor= ker.run(ThreadPoolExecutor.java:615) [junit4:junit4] > at java.lang.Thread.run(Thread.java:722) [junit4:junit4] > =09at __randomizedtesting.SeedInfo.seed([58B3562C02208= C06]:0) [junit4:junit4] Completed on J1 in 341.57s, 1 test, 1 failure, 2 errors <<<= FAILURES! [...truncated 427 lines...] BUILD FAILED /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-trunk/buil= d.xml:382: The following error occurred while executing this line: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-trunk/buil= d.xml:355: The following error occurred while executing this line: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-trunk/buil= d.xml:39: The following error occurred while executing this line: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr= /build.xml:183: The following error occurred while executing this line: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr= /common-build.xml:448: The following error occurred while executing this li= ne: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-trunk/luce= ne/common-build.xml:1231: The following error occurred while executing this= line: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-trunk/luce= ne/common-build.xml:875: There were test failures: 287 suites, 1183 tests, = 2 suite-level errors, 1 failure, 545 ignored (2 assumptions) Total time: 103 minutes 7 seconds Build step 'Invoke Ant' marked build as failure Archiving artifacts Recording test results Email was triggered for: Failure Sending email for trigger: Failure ------=_Part_939_1622103993.1365489337790 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_939_1622103993.1365489337790--