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 41E5EEE0B for ; Mon, 4 Feb 2013 12:42:07 +0000 (UTC) Received: (qmail 94306 invoked by uid 500); 4 Feb 2013 12:42:04 -0000 Delivered-To: apmail-lucene-dev-archive@lucene.apache.org Received: (qmail 94095 invoked by uid 500); 4 Feb 2013 12:42:01 -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 94073 invoked by uid 99); 4 Feb 2013 12:42:00 -0000 Received: from athena.apache.org (HELO athena.apache.org) (140.211.11.136) by apache.org (qpsmtpd/0.29) with ESMTP; Mon, 04 Feb 2013 12:42:00 +0000 X-ASF-Spam-Status: No, hits=0.0 required=5.0 tests=NORMAL_HTTP_TO_IP,SPF_PASS,WEIRD_PORT X-Spam-Check-By: apache.org Received-SPF: pass (athena.apache.org: domain of jenkins@thetaphi.de designates 188.138.97.18 as permitted sender) Received: from [188.138.97.18] (HELO mail.sd-datasolutions.de) (188.138.97.18) by apache.org (qpsmtpd/0.29) with ESMTP; Mon, 04 Feb 2013 12:41:51 +0000 Received: from serv1 (localhost.localdomain [127.0.0.1]) by mail.sd-datasolutions.de (Postfix) with ESMTP id BD55B14AA055 for ; Mon, 4 Feb 2013 12:41:27 +0000 (UTC) Date: Mon, 4 Feb 2013 12:41:07 +0000 (UTC) From: Policeman Jenkins Server To: dev@lucene.apache.org Message-ID: <578322521.39.1359981687756.JavaMail.jenkins@serv1.sd-datasolutions.de> Subject: [JENKINS] Lucene-Solr-trunk-MacOSX (64bit/jdk1.7.0) - Build # 182 - Failure! MIME-Version: 1.0 Content-Type: multipart/mixed; boundary="----=_Part_38_1931705201.1359981667568" X-Jenkins-Job: Lucene-Solr-trunk-MacOSX X-Jenkins-Result: FAILURE X-Virus-Checked: Checked by ClamAV on apache.org ------=_Part_38_1931705201.1359981667568 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: quoted-printable Build: http://jenkins.thetaphi.de/job/Lucene-Solr-trunk-MacOSX/182/ Java: 64bit/jdk1.7.0 -XX:+UseConcMarkSweepGC 1 tests failed. REGRESSION: org.apache.solr.cloud.BasicDistributedZkTest.testDistribSearch 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([930688C156120156:12E006D9214D616A]= :0) =09at org.junit.Assert.fail(Assert.java:93) =09at org.apache.solr.cloud.AbstractDistribZkTestBase.waitForRecoveriesToFi= nish(AbstractDistribZkTestBase.java:168) =09at org.apache.solr.cloud.AbstractDistribZkTestBase.waitForRecoveriesToFi= nish(AbstractDistribZkTestBase.java:126) =09at org.apache.solr.cloud.AbstractDistribZkTestBase.waitForRecoveriesToFi= nish(AbstractDistribZkTestBase.java:121) =09at org.apache.solr.cloud.BasicDistributedZkTest.testCoreUnloadAndLeaders= (BasicDistributedZkTest.java:599) =09at org.apache.solr.cloud.BasicDistributedZkTest.doTest(BasicDistributedZ= kTest.java:337) =09at org.apache.solr.BaseDistributedSearchTestCase.testDistribSearch(BaseD= istributedSearchTestCase.java:794) =09at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method) =09at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.= java:57) =09at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAcces= sorImpl.java:43) =09at java.lang.reflect.Method.invoke(Method.java:601) =09at com.carrotsearch.randomizedtesting.RandomizedRunner.invoke(Randomized= Runner.java:1559) =09at com.carrotsearch.randomizedtesting.RandomizedRunner.access$600(Random= izedRunner.java:79) =09at com.carrotsearch.randomizedtesting.RandomizedRunner$6.evaluate(Random= izedRunner.java:737) =09at com.carrotsearch.randomizedtesting.RandomizedRunner$7.evaluate(Random= izedRunner.java:773) =09at com.carrotsearch.randomizedtesting.RandomizedRunner$8.evaluate(Random= izedRunner.java:787) =09at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$= 1.evaluate(SystemPropertiesRestoreRule.java:53) =09at org.apache.lucene.util.TestRuleSetupTeardownChained$1.evaluate(TestRu= leSetupTeardownChained.java:50) =09at org.apache.lucene.util.TestRuleFieldCacheSanity$1.evaluate(TestRuleFi= eldCacheSanity.java:51) =09at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBef= oreAfterRule.java:46) =09at com.carrotsearch.randomizedtesting.rules.SystemPropertiesInvariantRul= e$1.evaluate(SystemPropertiesInvariantRule.java:55) =09at org.apache.lucene.util.TestRuleThreadAndTestName$1.evaluate(TestRuleT= hreadAndTestName.java:49) =09at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(Test= RuleIgnoreAfterMaxFailures.java:70) =09at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFai= lure.java:48) =09at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(St= atementAdapter.java:36) =09at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.= run(ThreadLeakControl.java:358) =09at com.carrotsearch.randomizedtesting.ThreadLeakControl.forkTimeoutingTa= sk(ThreadLeakControl.java:782) =09at com.carrotsearch.randomizedtesting.ThreadLeakControl$3.evaluate(Threa= dLeakControl.java:442) =09at com.carrotsearch.randomizedtesting.RandomizedRunner.runSingleTest(Ran= domizedRunner.java:746) =09at com.carrotsearch.randomizedtesting.RandomizedRunner$3.evaluate(Random= izedRunner.java:648) =09at com.carrotsearch.randomizedtesting.RandomizedRunner$4.evaluate(Random= izedRunner.java:682) =09at com.carrotsearch.randomizedtesting.RandomizedRunner$5.evaluate(Random= izedRunner.java:693) =09at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(St= atementAdapter.java:36) =09at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$= 1.evaluate(SystemPropertiesRestoreRule.java:53) =09at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBef= oreAfterRule.java:46) =09at org.apache.lucene.util.TestRuleStoreClassName$1.evaluate(TestRuleStor= eClassName.java:42) =09at com.carrotsearch.randomizedtesting.rules.SystemPropertiesInvariantRul= e$1.evaluate(SystemPropertiesInvariantRule.java:55) =09at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMeth= odsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:39) =09at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMeth= odsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:39) =09at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(St= atementAdapter.java:36) =09at org.apache.lucene.util.TestRuleAssertionsRequired$1.evaluate(TestRule= AssertionsRequired.java:43) =09at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFai= lure.java:48) =09at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(Test= RuleIgnoreAfterMaxFailures.java:70) =09at org.apache.lucene.util.TestRuleIgnoreTestSuites$1.evaluate(TestRuleIg= noreTestSuites.java:55) =09at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(St= atementAdapter.java:36) =09at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.= run(ThreadLeakControl.java:358) =09at java.lang.Thread.run(Thread.java:722) Build Log: [...truncated 8753 lines...] [junit4:junit4] Suite: org.apache.solr.cloud.BasicDistributedZkTest [junit4:junit4] 2> 0 T703 oas.BaseDistributedSearchTestCase.initHostConte= xt Setting hostContext system property: / [junit4:junit4] 2> 15 T703 oas.SolrTestCaseJ4.setUp ###Starting testDistr= ibSearch [junit4:junit4] 2> Creating dataDir: /Users/jenkins/jenkins-slave/workspa= ce/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./solrtest-BasicDi= stributedZkTest-1359979901484 [junit4:junit4] 2> 16 T703 oasc.ZkTestServer.run STARTING ZK TEST SERVER [junit4:junit4] 2> 17 T704 oasc.ZkTestServer$ZKServerMain.runFromConfig S= tarting server [junit4:junit4] 2> 25 T704 oazs.ZooKeeperServer.setTickTime tickTime set = to 1000 [junit4:junit4] 2> 25 T704 oazs.ZooKeeperServer.setMinSessionTimeout minS= essionTimeout set to -1 [junit4:junit4] 2> 26 T704 oazs.ZooKeeperServer.setMaxSessionTimeout maxS= essionTimeout set to -1 [junit4:junit4] 2> 26 T704 oazs.NIOServerCnxnFactory.configure binding to= port 0.0.0.0/0.0.0.0:0 [junit4:junit4] 2> 28 T704 oazsp.FileTxnSnapLog.save Snapshotting: 0x0 to= /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build= /solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZkTest-135997990= 1483/zookeeper/server1/data/version-2/snapshot.0 [junit4:junit4] 2> 126 T703 oasc.ZkTestServer.run start zk server on port= :49308 [junit4:junit4] 2> 127 T703 oaz.ZooKeeper. Initiating client connec= tion, connectString=3D127.0.0.1:49308 sessionTimeout=3D10000 watcher=3Dorg.= apache.solr.common.cloud.ConnectionManager@5854278 [junit4:junit4] 2> 129 T709 oaz.ClientCnxn$SendThread.logStartConnect Ope= ning socket connection to server localhost/127.0.0.1:49308. Will not attemp= t to authenticate using SASL (access denied ("javax.security.auth.AuthPermi= ssion" "getLoginConfiguration")) [junit4:junit4] 2> 130 T705 oazs.NIOServerCnxnFactory.run Accepted socket= connection from /127.0.0.1:49309 [junit4:junit4] 2> 131 T703 oascc.ConnectionManager.waitForConnected Wait= ing for client to connect to ZooKeeper [junit4:junit4] 2> 132 T709 oaz.ClientCnxn$SendThread.primeConnection Soc= ket connection established to localhost/127.0.0.1:49308, initiating session [junit4:junit4] 2> 132 T705 oazs.ZooKeeperServer.processConnectRequest Cl= ient attempting to establish new session at /127.0.0.1:49309 [junit4:junit4] 2> 133 T707 oazsp.FileTxnLog.append Creating new log file= : log.1 [junit4:junit4] 2> 137 T707 oazs.ZooKeeperServer.finishSessionInit Establ= ished session 0x13ca51e72390000 with negotiated timeout 10000 for client /1= 27.0.0.1:49309 [junit4:junit4] 2> 137 T709 oaz.ClientCnxn$SendThread.onConnected Session= establishment complete on server localhost/127.0.0.1:49308, sessionid =3D = 0x13ca51e72390000, negotiated timeout =3D 10000 [junit4:junit4] 2> 138 T710 oascc.ConnectionManager.process Watcher org.a= pache.solr.common.cloud.ConnectionManager@5854278 name:ZooKeeperConnection = Watcher:127.0.0.1:49308 got event WatchedEvent state:SyncConnected type:Non= e path:null path:null type:None [junit4:junit4] 2> 138 T703 oascc.ConnectionManager.waitForConnected Clie= nt is connected to ZooKeeper [junit4:junit4] 2> 139 T703 oascc.SolrZkClient.makePath makePath: /solr [junit4:junit4] 2> 144 T708 oazs.PrepRequestProcessor.pRequest2Txn Proces= sed session termination for sessionid: 0x13ca51e72390000 [junit4:junit4] 2> 146 T710 oaz.ClientCnxn$EventThread.run EventThread sh= ut down [junit4:junit4] 2> 146 T703 oaz.ZooKeeper.close Session: 0x13ca51e7239000= 0 closed [junit4:junit4] 2> 147 T703 oaz.ZooKeeper. Initiating client connec= tion, connectString=3D127.0.0.1:49308/solr sessionTimeout=3D10000 watcher= =3Dorg.apache.solr.common.cloud.ConnectionManager@3dbb284a [junit4:junit4] 2> 148 T711 oaz.ClientCnxn$SendThread.logStartConnect Ope= ning socket connection to server localhost/127.0.0.1:49308. Will not attemp= t to authenticate using SASL (access denied ("javax.security.auth.AuthPermi= ssion" "getLoginConfiguration")) [junit4:junit4] 2> 148 T703 oascc.ConnectionManager.waitForConnected Wait= ing for client to connect to ZooKeeper [junit4:junit4] 2> 149 T711 oaz.ClientCnxn$SendThread.primeConnection Soc= ket connection established to localhost/127.0.0.1:49308, initiating session [junit4:junit4] 2> 149 T705 oazs.NIOServerCnxn.closeSock Closed socket co= nnection for client /127.0.0.1:49309 which had sessionid 0x13ca51e72390000 [junit4:junit4] 2> 151 T705 oazs.NIOServerCnxnFactory.run Accepted socket= connection from /127.0.0.1:49310 [junit4:junit4] 2> 153 T705 oazs.ZooKeeperServer.processConnectRequest Cl= ient attempting to establish new session at /127.0.0.1:49310 [junit4:junit4] 2> 158 T707 oazs.ZooKeeperServer.finishSessionInit Establ= ished session 0x13ca51e72390001 with negotiated timeout 10000 for client /1= 27.0.0.1:49310 [junit4:junit4] 2> 158 T711 oaz.ClientCnxn$SendThread.onConnected Session= establishment complete on server localhost/127.0.0.1:49308, sessionid =3D = 0x13ca51e72390001, negotiated timeout =3D 10000 [junit4:junit4] 2> 159 T712 oascc.ConnectionManager.process Watcher org.a= pache.solr.common.cloud.ConnectionManager@3dbb284a name:ZooKeeperConnection= Watcher:127.0.0.1:49308/solr got event WatchedEvent state:SyncConnected ty= pe:None path:null path:null type:None [junit4:junit4] 2> 159 T703 oascc.ConnectionManager.waitForConnected Clie= nt is connected to ZooKeeper [junit4:junit4] 2> 160 T703 oascc.SolrZkClient.makePath makePath: /collec= tions/collection1 [junit4:junit4] 2> 169 T703 oascc.SolrZkClient.makePath makePath: /collec= tions/collection1/shards [junit4:junit4] 2> 176 T703 oascc.SolrZkClient.makePath makePath: /collec= tions/control_collection [junit4:junit4] 2> 181 T703 oascc.SolrZkClient.makePath makePath: /collec= tions/control_collection/shards [junit4:junit4] 2> 189 T703 oasc.AbstractZkTestCase.putConfig put /Users/= jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-co= re/test-files/solr/collection1/conf/solrconfig.xml to /configs/conf1/solrco= nfig.xml [junit4:junit4] 2> 190 T703 oascc.SolrZkClient.makePath makePath: /config= s/conf1/solrconfig.xml [junit4:junit4] 2> 231 T703 oasc.AbstractZkTestCase.putConfig put /Users/= jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-co= re/test-files/solr/collection1/conf/schema.xml to /configs/conf1/schema.xml [junit4:junit4] 2> 233 T703 oascc.SolrZkClient.makePath makePath: /config= s/conf1/schema.xml [junit4:junit4] 2> 238 T703 oasc.AbstractZkTestCase.putConfig put /Users/= jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-co= re/test-files/solr/collection1/conf/stopwords.txt to /configs/conf1/stopwor= ds.txt [junit4:junit4] 2> 239 T703 oascc.SolrZkClient.makePath makePath: /config= s/conf1/stopwords.txt [junit4:junit4] 2> 245 T703 oasc.AbstractZkTestCase.putConfig put /Users/= jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-co= re/test-files/solr/collection1/conf/protwords.txt to /configs/conf1/protwor= ds.txt [junit4:junit4] 2> 246 T703 oascc.SolrZkClient.makePath makePath: /config= s/conf1/protwords.txt [junit4:junit4] 2> 255 T703 oasc.AbstractZkTestCase.putConfig put /Users/= jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-co= re/test-files/solr/collection1/conf/currency.xml to /configs/conf1/currency= .xml [junit4:junit4] 2> 256 T703 oascc.SolrZkClient.makePath makePath: /config= s/conf1/currency.xml [junit4:junit4] 2> 264 T703 oasc.AbstractZkTestCase.putConfig put /Users/= jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-co= re/test-files/solr/collection1/conf/open-exchange-rates.json to /configs/co= nf1/open-exchange-rates.json [junit4:junit4] 2> 264 T703 oascc.SolrZkClient.makePath makePath: /config= s/conf1/open-exchange-rates.json [junit4:junit4] 2> 272 T703 oasc.AbstractZkTestCase.putConfig put /Users/= jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-co= re/test-files/solr/collection1/conf/mapping-ISOLatin1Accent.txt to /configs= /conf1/mapping-ISOLatin1Accent.txt [junit4:junit4] 2> 272 T703 oascc.SolrZkClient.makePath makePath: /config= s/conf1/mapping-ISOLatin1Accent.txt [junit4:junit4] 2> 292 T703 oasc.AbstractZkTestCase.putConfig put /Users/= jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-co= re/test-files/solr/collection1/conf/old_synonyms.txt to /configs/conf1/old_= synonyms.txt [junit4:junit4] 2> 293 T703 oascc.SolrZkClient.makePath makePath: /config= s/conf1/old_synonyms.txt [junit4:junit4] 2> 299 T703 oasc.AbstractZkTestCase.putConfig put /Users/= jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-co= re/test-files/solr/collection1/conf/synonyms.txt to /configs/conf1/synonyms= .txt [junit4:junit4] 2> 300 T703 oascc.SolrZkClient.makePath makePath: /config= s/conf1/synonyms.txt [junit4:junit4] 2> 306 T708 oazs.PrepRequestProcessor.pRequest2Txn Proces= sed session termination for sessionid: 0x13ca51e72390001 [junit4:junit4] 2> 308 T705 oazs.NIOServerCnxn.closeSock Closed socket co= nnection for client /127.0.0.1:49310 which had sessionid 0x13ca51e72390001 [junit4:junit4] 2> 313 T712 oaz.ClientCnxn$EventThread.run EventThread sh= ut down [junit4:junit4] 2> 314 T703 oaz.ZooKeeper.close Session: 0x13ca51e7239000= 1 closed [junit4:junit4] 2> 537 T703 oejs.Server.doStart jetty-8.1.8.v20121106 [junit4:junit4] 2> 830 T703 oejs.AbstractConnector.doStart Started Select= ChannelConnector@127.0.0.1:49311 [junit4:junit4] 2> 831 T703 oass.SolrDispatchFilter.init SolrDispatchFilt= er.init() [junit4:junit4] 2> 832 T703 oasc.SolrResourceLoader.locateSolrHome JNDI n= ot configured for solr (NoInitialContextEx) [junit4:junit4] 2> 833 T703 oasc.SolrResourceLoader.locateSolrHome using = system property solr.solr.home: /Users/jenkins/jenkins-slave/workspace/Luce= ne-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.B= asicDistributedZkTest-controljetty-1359979901783 [junit4:junit4] 2> 833 T703 oasc.CoreContainer$Initializer.initialize loo= king for solr.xml: /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk= -MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistribut= edZkTest-controljetty-1359979901783/solr.xml [junit4:junit4] 2> 834 T703 oasc.CoreContainer. New CoreContainer 3= 07548210 [junit4:junit4] 2> 835 T703 oasc.CoreContainer.load Loading CoreContainer= using Solr Home: '/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk= -MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistribut= edZkTest-controljetty-1359979901783/' [junit4:junit4] 2> 835 T703 oasc.SolrResourceLoader. new SolrResour= ceLoader for directory: '/Users/jenkins/jenkins-slave/workspace/Lucene-Solr= -trunk-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDis= tributedZkTest-controljetty-1359979901783/' [junit4:junit4] 2> 882 T703 oashc.HttpShardHandlerFactory.getParameter Se= tting socketTimeout to: 60000 [junit4:junit4] 2> 887 T703 oashc.HttpShardHandlerFactory.getParameter Se= tting urlScheme to: http:// [junit4:junit4] 2> 887 T703 oashc.HttpShardHandlerFactory.getParameter Se= tting connTimeout to: 15000 [junit4:junit4] 2> 888 T703 oashc.HttpShardHandlerFactory.getParameter Se= tting maxConnectionsPerHost to: 20 [junit4:junit4] 2> 889 T703 oashc.HttpShardHandlerFactory.getParameter Se= tting corePoolSize to: 0 [junit4:junit4] 2> 890 T703 oashc.HttpShardHandlerFactory.getParameter Se= tting maximumPoolSize to: 2147483647 [junit4:junit4] 2> 891 T703 oashc.HttpShardHandlerFactory.getParameter Se= tting maxThreadIdleTime to: 5 [junit4:junit4] 2> 891 T703 oashc.HttpShardHandlerFactory.getParameter Se= tting sizeOfQueue to: -1 [junit4:junit4] 2> 892 T703 oashc.HttpShardHandlerFactory.getParameter Se= tting fairnessPolicy to: false [junit4:junit4] 2> 894 T703 oascsi.HttpClientUtil.createClient Creating n= ew http client, config:maxConnectionsPerHost=3D20&maxConnections=3D10000&so= cketTimeout=3D60000&connTimeout=3D15000&retry=3Dfalse [junit4:junit4] 2> 928 T703 oasc.CoreContainer.load Registering Log Liste= ner [junit4:junit4] 2> 948 T703 oasc.CoreContainer.initZooKeeper Zookeeper cl= ient=3D127.0.0.1:49308/solr [junit4:junit4] 2> 949 T703 oasc.ZkController.checkChrootPath zkHost incl= udes chroot [junit4:junit4] 2> 949 T703 oaz.ZooKeeper. Initiating client connec= tion, connectString=3D127.0.0.1:49308 sessionTimeout=3D60000 watcher=3Dorg.= apache.solr.common.cloud.ConnectionManager@31daa59d [junit4:junit4] 2> 955 T722 oaz.ClientCnxn$SendThread.logStartConnect Ope= ning socket connection to server localhost/127.0.0.1:49308. Will not attemp= t to authenticate using SASL (access denied ("javax.security.auth.AuthPermi= ssion" "getLoginConfiguration")) [junit4:junit4] 2> 955 T703 oascc.ConnectionManager.waitForConnected Wait= ing for client to connect to ZooKeeper [junit4:junit4] 2> 964 T722 oaz.ClientCnxn$SendThread.primeConnection Soc= ket connection established to localhost/127.0.0.1:49308, initiating session [junit4:junit4] 2> 971 T705 oazs.NIOServerCnxnFactory.run Accepted socket= connection from /127.0.0.1:49312 [junit4:junit4] 2> 974 T705 oazs.ZooKeeperServer.processConnectRequest Cl= ient attempting to establish new session at /127.0.0.1:49312 [junit4:junit4] 2> 976 T707 oazs.ZooKeeperServer.finishSessionInit Establ= ished session 0x13ca51e72390002 with negotiated timeout 20000 for client /1= 27.0.0.1:49312 [junit4:junit4] 2> 976 T722 oaz.ClientCnxn$SendThread.onConnected Session= establishment complete on server localhost/127.0.0.1:49308, sessionid =3D = 0x13ca51e72390002, negotiated timeout =3D 20000 [junit4:junit4] 2> 977 T723 oascc.ConnectionManager.process Watcher org.a= pache.solr.common.cloud.ConnectionManager@31daa59d name:ZooKeeperConnection= Watcher:127.0.0.1:49308 got event WatchedEvent state:SyncConnected type:No= ne path:null path:null type:None [junit4:junit4] 2> 977 T703 oascc.ConnectionManager.waitForConnected Clie= nt is connected to ZooKeeper [junit4:junit4] 2> 980 T708 oazs.PrepRequestProcessor.pRequest2Txn Proces= sed session termination for sessionid: 0x13ca51e72390002 [junit4:junit4] 2> 984 T705 oazs.NIOServerCnxn.closeSock Closed socket co= nnection for client /127.0.0.1:49312 which had sessionid 0x13ca51e72390002 [junit4:junit4] 2> 985 T703 oaz.ZooKeeper.close Session: 0x13ca51e7239000= 2 closed [junit4:junit4] 2> 985 T703 oascsi.HttpClientUtil.createClient Creating n= ew http client, config:maxConnections=3D500&maxConnectionsPerHost=3D16&sock= etTimeout=3D60000&connTimeout=3D15000 [junit4:junit4] 2> 996 T703 oaz.ZooKeeper. Initiating client connec= tion, connectString=3D127.0.0.1:49308/solr sessionTimeout=3D30000 watcher= =3Dorg.apache.solr.common.cloud.ConnectionManager@47c40da1 [junit4:junit4] 2> 998 T724 oaz.ClientCnxn$SendThread.logStartConnect Ope= ning socket connection to server localhost/127.0.0.1:49308. Will not attemp= t to authenticate using SASL (access denied ("javax.security.auth.AuthPermi= ssion" "getLoginConfiguration")) [junit4:junit4] 2> 998 T723 oaz.ClientCnxn$EventThread.run EventThread sh= ut down [junit4:junit4] 2> 998 T724 oaz.ClientCnxn$SendThread.primeConnection Soc= ket connection established to localhost/127.0.0.1:49308, initiating session [junit4:junit4] 2> 999 T705 oazs.NIOServerCnxnFactory.run Accepted socket= connection from /127.0.0.1:49313 [junit4:junit4] 2> 999 T705 oazs.ZooKeeperServer.processConnectRequest Cl= ient attempting to establish new session at /127.0.0.1:49313 [junit4:junit4] 2> 1004 T703 oascc.ConnectionManager.waitForConnected Wai= ting for client to connect to ZooKeeper [junit4:junit4] 2> 1005 T707 oazs.ZooKeeperServer.finishSessionInit Estab= lished session 0x13ca51e72390003 with negotiated timeout 20000 for client /= 127.0.0.1:49313 [junit4:junit4] 2> 1005 T724 oaz.ClientCnxn$SendThread.onConnected Sessio= n establishment complete on server localhost/127.0.0.1:49308, sessionid =3D= 0x13ca51e72390003, negotiated timeout =3D 20000 [junit4:junit4] 2> 1005 T725 oascc.ConnectionManager.process Watcher org.= apache.solr.common.cloud.ConnectionManager@47c40da1 name:ZooKeeperConnectio= n Watcher:127.0.0.1:49308/solr got event WatchedEvent state:SyncConnected t= ype:None path:null path:null type:None [junit4:junit4] 2> 1006 T703 oascc.ConnectionManager.waitForConnected Cli= ent is connected to ZooKeeper [junit4:junit4] 2> 1008 T708 oazs.PrepRequestProcessor.pRequest Got user-= level KeeperException when processing sessionid:0x13ca51e72390003 type:crea= te cxid:0x2 zxid:0x1a txntype:-1 reqpath:n/a Error Path:/solr/overseer Erro= r:KeeperErrorCode =3D NodeExists for /solr/overseer [junit4:junit4] 2> 1010 T703 oascc.SolrZkClient.makePath makePath: /live_= nodes [junit4:junit4] 2> 1023 T703 oasc.ZkController.createEphemeralLiveNode Re= gister node as live in ZooKeeper:/live_nodes/127.0.0.1:49311_ [junit4:junit4] 2> 1024 T708 oazs.PrepRequestProcessor.pRequest Got user-= level KeeperException when processing sessionid:0x13ca51e72390003 type:dele= te cxid:0x7 zxid:0x1c txntype:-1 reqpath:n/a Error Path:/solr/live_nodes/12= 7.0.0.1:49311_ Error:KeeperErrorCode =3D NoNode for /solr/live_nodes/127.0.= 0.1:49311_ [junit4:junit4] 2> 1025 T703 oascc.SolrZkClient.makePath makePath: /live_= nodes/127.0.0.1:49311_ [junit4:junit4] 2> 1031 T703 oascc.SolrZkClient.makePath makePath: /overs= eer_elect/election [junit4:junit4] 2> 1042 T708 oazs.PrepRequestProcessor.pRequest Got user-= level KeeperException when processing sessionid:0x13ca51e72390003 type:dele= te cxid:0x15 zxid:0x21 txntype:-1 reqpath:n/a Error Path:/solr/overseer_ele= ct/leader Error:KeeperErrorCode =3D NoNode for /solr/overseer_elect/leader [junit4:junit4] 2> 1043 T703 oascc.SolrZkClient.makePath makePath: /overs= eer_elect/leader [junit4:junit4] 2> 1048 T703 oasc.Overseer.start Overseer (id=3D891276428= 24507395-127.0.0.1:49311_-n_0000000000) starting [junit4:junit4] 2> 1048 T708 oazs.PrepRequestProcessor.pRequest Got user-= level KeeperException when processing sessionid:0x13ca51e72390003 type:crea= te cxid:0x1a zxid:0x23 txntype:-1 reqpath:n/a Error Path:/solr/overseer Err= or:KeeperErrorCode =3D NodeExists for /solr/overseer [junit4:junit4] 2> 1050 T708 oazs.PrepRequestProcessor.pRequest Got user-= level KeeperException when processing sessionid:0x13ca51e72390003 type:crea= te cxid:0x1b zxid:0x24 txntype:-1 reqpath:n/a Error Path:/solr/overseer Err= or:KeeperErrorCode =3D NodeExists for /solr/overseer [junit4:junit4] 2> 1051 T708 oazs.PrepRequestProcessor.pRequest Got user-= level KeeperException when processing sessionid:0x13ca51e72390003 type:crea= te cxid:0x1c zxid:0x25 txntype:-1 reqpath:n/a Error Path:/solr/overseer Err= or:KeeperErrorCode =3D NodeExists for /solr/overseer [junit4:junit4] 2> 1053 T708 oazs.PrepRequestProcessor.pRequest Got user-= level KeeperException when processing sessionid:0x13ca51e72390003 type:crea= te cxid:0x1d zxid:0x26 txntype:-1 reqpath:n/a Error Path:/solr/overseer Err= or:KeeperErrorCode =3D NodeExists for /solr/overseer [junit4:junit4] 2> 1054 T727 oasc.OverseerCollectionProcessor.run Process= current queue of collection creations [junit4:junit4] 2> 1056 T703 oascc.SolrZkClient.makePath makePath: /clust= erstate.json [junit4:junit4] 2> 1060 T703 oascc.ZkStateReader.createClusterStateWatche= rsAndUpdate Updating cluster state from ZooKeeper...=20 [junit4:junit4] 2> 1068 T728 oasc.CoreContainer.create Creating SolrCore = 'collection1' using instanceDir: /Users/jenkins/jenkins-slave/workspace/Luc= ene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.= BasicDistributedZkTest-controljetty-1359979901783/collection1 [junit4:junit4] 2> 1068 T728 oasc.ZkController.createCollectionZkNode Che= ck for collection zkNode:control_collection [junit4:junit4] 2> 1070 T728 oasc.ZkController.createCollectionZkNode Col= lection zkNode exists [junit4:junit4] 2> 1070 T728 oasc.ZkController.readConfigName Load collec= tion config from:/collections/control_collection [junit4:junit4] 2> 1072 T728 oasc.SolrResourceLoader. new SolrResou= rceLoader for directory: '/Users/jenkins/jenkins-slave/workspace/Lucene-Sol= r-trunk-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDi= stributedZkTest-controljetty-1359979901783/collection1/' [junit4:junit4] 2> 1073 T728 oasc.SolrResourceLoader.replaceClassLoader A= dding 'file:/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX= /solr/build/solr-core/test/J0/org.apache.solr.cloud.BasicDistributedZkTest-= controljetty-1359979901783/collection1/lib/classes/' to classloader [junit4:junit4] 2> 1074 T728 oasc.SolrResourceLoader.replaceClassLoader A= dding 'file:/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX= /solr/build/solr-core/test/J0/org.apache.solr.cloud.BasicDistributedZkTest-= controljetty-1359979901783/collection1/lib/README' to classloader [junit4:junit4] 2> 1096 T726 oasc.Overseer$ClusterStateUpdater.run Starti= ng to work on the main queue [junit4:junit4] 2> 1159 T728 oasc.SolrConfig. Using Lucene MatchVer= sion: LUCENE_50 [junit4:junit4] 2> 1257 T728 oasc.SolrConfig. Loaded SolrConfig: so= lrconfig.xml [junit4:junit4] 2> 1259 T728 oass.IndexSchema.readSchema Reading Solr Sch= ema [junit4:junit4] 2> 1268 T728 oass.IndexSchema.readSchema Schema name=3Dte= st [junit4:junit4] 2> 2197 T728 oass.OpenExchangeRatesOrgProvider.init Initi= alized with rates=3Dopen-exchange-rates.json, refreshInterval=3D1440. [junit4:junit4] 2> 2207 T728 oass.IndexSchema.readSchema default search f= ield in schema is text [junit4:junit4] 2> 2211 T728 oass.IndexSchema.readSchema unique key field= : id [junit4:junit4] 2> 2250 T728 oass.FileExchangeRateProvider.reload Reloadi= ng exchange rates from file currency.xml [junit4:junit4] 2> 2258 T728 oass.FileExchangeRateProvider.reload Reloadi= ng exchange rates from file currency.xml [junit4:junit4] 2> 2267 T728 oass.OpenExchangeRatesOrgProvider.reload Rel= oading exchange rates from open-exchange-rates.json [junit4:junit4] 2> 2270 T728 oass.OpenExchangeRatesOrgProvider.reload Rel= oading exchange rates from open-exchange-rates.json [junit4:junit4] 2> 2273 T728 oasc.SolrCore. [collection1] Opening n= ew SolrCore at /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-Mac= OSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZk= Test-controljetty-1359979901783/collection1/, dataDir=3D./org.apache.solr.c= loud.BasicDistributedZkTest-1359979901483/control/data/ [junit4:junit4] 2> 2273 T728 oasc.JmxMonitoredMap. JMX monitoring i= s enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBe= anServer@36298619 [junit4:junit4] 2> 2273 T728 oasc.SolrCore.initDirectoryFactory solr.NRTC= achingDirectoryFactory [junit4:junit4] 2> 2275 T728 oasc.CachingDirectoryFactory.get return new = directory for /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacO= SX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZkT= est-1359979901483/control/data forceNew:false [junit4:junit4] 2> 2276 T728 oasc.CachingDirectoryFactory.close Releasing= directory:/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/= solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZkTest= -1359979901483/control/data [junit4:junit4] 2> 2276 T728 oasc.SolrCore.getNewIndexDir New index direc= tory detected: old=3Dnull new=3D./org.apache.solr.cloud.BasicDistributedZkT= est-1359979901483/control/data/index/ [junit4:junit4] 2> 2277 T728 oasc.SolrCore.initIndex WARNING [collection1= ] Solr index directory './org.apache.solr.cloud.BasicDistributedZkTest-1359= 979901483/control/data/index' doesn't exist. Creating new index... [junit4:junit4] 2> 2278 T728 oasc.CachingDirectoryFactory.get return new = directory for /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacO= SX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZkT= est-1359979901483/control/data/index forceNew:false [junit4:junit4] 2> 2292 T728 oasc.SolrDeletionPolicy.onCommit SolrDeletio= nPolicy.onCommit: commits:num=3D1 [junit4:junit4] 2> =09=09commit{dir=3DRateLimitedDirectoryWrapper(NRTCach= ingDirectory(org.apache.lucene.store.NIOFSDirectory@/Users/jenkins/jenkins-= slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/org.a= pache.solr.cloud.BasicDistributedZkTest-1359979901483/control/data/index lo= ckFactory=3Dorg.apache.lucene.store.NativeFSLockFactory@45f60505; maxCacheM= B=3D48.0 maxMergeSizeMB=3D4.0)),segFN=3Dsegments_1,generation=3D1,filenames= =3D[segments_1] [junit4:junit4] 2> 2292 T728 oasc.SolrDeletionPolicy.updateCommits newest= commit =3D 1[segments_1] [junit4:junit4] 2> 2293 T728 oasc.CachingDirectoryFactory.close Releasing= directory:/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/= solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZkTest= -1359979901483/control/data/index [junit4:junit4] 2> 2294 T728 oasc.SolrCore.initWriters created xml: solr.= XMLResponseWriter [junit4:junit4] 2> 2296 T728 oasup.UpdateRequestProcessorChain.init inser= ting DistributedUpdateProcessorFactory into updateRequestProcessorChain "de= dupe" [junit4:junit4] 2> 2297 T728 oasup.UpdateRequestProcessorChain.init inser= ting DistributedUpdateProcessorFactory into updateRequestProcessorChain "de= dupe-allfields" [junit4:junit4] 2> 2298 T728 oasup.UpdateRequestProcessorChain.init inser= ting DistributedUpdateProcessorFactory into updateRequestProcessorChain "st= ored_sig" [junit4:junit4] 2> 2298 T728 oasup.UpdateRequestProcessorChain.init inser= ting DistributedUpdateProcessorFactory into updateRequestProcessorChain "un= iq-fields" [junit4:junit4] 2> 2299 T728 oasup.UpdateRequestProcessorChain.init inser= ting DistributedUpdateProcessorFactory into updateRequestProcessorChain "di= strib-dup-test-chain-implicit" [junit4:junit4] 2> 2299 T728 oasc.RequestHandlers.initHandlersFromConfig = adding lazy requestHandler: solr.ReplicationHandler [junit4:junit4] 2> 2300 T728 oasc.RequestHandlers.initHandlersFromConfig = created /replication: solr.ReplicationHandler [junit4:junit4] 2> 2300 T728 oasc.RequestHandlers.initHandlersFromConfig = created standard: solr.StandardRequestHandler [junit4:junit4] 2> 2301 T728 oasc.RequestHandlers.initHandlersFromConfig = created /get: solr.RealTimeGetHandler [junit4:junit4] 2> 2302 T728 oasc.RequestHandlers.initHandlersFromConfig = created dismax: solr.SearchHandler [junit4:junit4] 2> 2302 T728 oasc.RequestHandlers.initHandlersFromConfig = created mock: org.apache.solr.core.MockQuerySenderListenerReqHandler [junit4:junit4] 2> 2303 T728 oasc.RequestHandlers.initHandlersFromConfig = created /admin/: org.apache.solr.handler.admin.AdminHandlers [junit4:junit4] 2> 2304 T728 oasc.RequestHandlers.initHandlersFromConfig = created defaults: solr.StandardRequestHandler [junit4:junit4] 2> 2304 T728 oasc.RequestHandlers.initHandlersFromConfig = adding lazy requestHandler: solr.StandardRequestHandler [junit4:junit4] 2> 2305 T728 oasc.RequestHandlers.initHandlersFromConfig = created lazy: solr.StandardRequestHandler [junit4:junit4] 2> 2306 T728 oasc.RequestHandlers.initHandlersFromConfig = created /update: solr.UpdateRequestHandler [junit4:junit4] 2> 2307 T728 oasc.RequestHandlers.initHandlersFromConfig = created /terms: org.apache.solr.handler.component.SearchHandler [junit4:junit4] 2> 2309 T728 oasc.RequestHandlers.initHandlersFromConfig = created spellCheckCompRH: org.apache.solr.handler.component.SearchHandler [junit4:junit4] 2> 2310 T728 oasc.RequestHandlers.initHandlersFromConfig = created spellCheckCompRH_Direct: org.apache.solr.handler.component.SearchHa= ndler [junit4:junit4] 2> 2310 T728 oasc.RequestHandlers.initHandlersFromConfig = created spellCheckWithWordbreak: org.apache.solr.handler.component.SearchHa= ndler [junit4:junit4] 2> 2311 T728 oasc.RequestHandlers.initHandlersFromConfig = created spellCheckWithWordbreak_Direct: org.apache.solr.handler.component.S= earchHandler [junit4:junit4] 2> 2311 T728 oasc.RequestHandlers.initHandlersFromConfig = created spellCheckCompRH1: org.apache.solr.handler.component.SearchHandler [junit4:junit4] 2> 2312 T728 oasc.RequestHandlers.initHandlersFromConfig = created mltrh: org.apache.solr.handler.component.SearchHandler [junit4:junit4] 2> 2312 T728 oasc.RequestHandlers.initHandlersFromConfig = created tvrh: org.apache.solr.handler.component.SearchHandler [junit4:junit4] 2> 2313 T728 oasc.RequestHandlers.initHandlersFromConfig = created /mlt: solr.MoreLikeThisHandler [junit4:junit4] 2> 2314 T728 oasc.RequestHandlers.initHandlersFromConfig = created /debug/dump: solr.DumpRequestHandler [junit4:junit4] 2> 2323 T728 oashl.XMLLoader.init xsltCacheLifetimeSecond= s=3D60 [junit4:junit4] 2> 2329 T728 oasc.SolrCore.initDeprecatedSupport WARNING = solrconfig.xml uses deprecated , Please update your co= nfig to use the ShowFileRequestHandler. [junit4:junit4] 2> 2332 T728 oasc.SolrCore.initDeprecatedSupport WARNING = adding ShowFileRequestHandler with hidden files: [SCHEMA.XML, OLD_SYNONYMS.= TXT, STOPWORDS.TXT, PROTWORDS.TXT, OPEN-EXCHANGE-RATES.JSON, SYNONYMS.TXT, = CURRENCY.XML, MAPPING-ISOLATIN1ACCENT.TXT] [junit4:junit4] 2> 2335 T728 oasc.CachingDirectoryFactory.close Releasing= directory:/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/= solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZkTest= -1359979901483/control/data [junit4:junit4] 2> 2336 T728 oass.SolrIndexSearcher. Opening Search= er@50a3b5e5 main [junit4:junit4] 2> 2337 T728 oasu.CommitTracker. Hard AutoCommit: d= isabled [junit4:junit4] 2> 2337 T728 oasu.CommitTracker. Soft AutoCommit: d= isabled [junit4:junit4] 2> 2338 T728 oashc.SpellCheckComponent.inform Initializin= g spell checkers [junit4:junit4] 2> 2344 T728 oass.DirectSolrSpellChecker.init init: {name= =3Ddirect,classname=3DDirectSolrSpellChecker,field=3Dlowerfilt,minQueryLeng= th=3D3} [junit4:junit4] 2> 2399 T728 oasc.ZkController.publish publishing core=3D= collection1 state=3Ddown [junit4:junit4] 2> 2399 T728 oasc.ZkController.publish numShards not foun= d on descriptor - reading it from system property [junit4:junit4] 2> 2401 T729 oasc.SolrCore.registerSearcher [collection1]= Registered new searcher Searcher@50a3b5e5 main{StandardDirectoryReader(seg= ments_1:1)} [junit4:junit4] 2> 2401 T708 oazs.PrepRequestProcessor.pRequest Got user-= level KeeperException when processing sessionid:0x13ca51e72390003 type:crea= te cxid:0x50 zxid:0x29 txntype:-1 reqpath:n/a Error Path:/solr/overseer/que= ue Error:KeeperErrorCode =3D NoNode for /solr/overseer/queue [junit4:junit4] 2> 2619 T726 oascc.ZkStateReader.updateClusterState Updat= ing cloud state from ZooKeeper...=20 [junit4:junit4] 2> 2621 T726 oasc.Overseer$ClusterStateUpdater.updateStat= e Update state numShards=3D1 message=3D{ [junit4:junit4] 2> =09 "operation":"state", [junit4:junit4] 2> =09 "numShards":"1", [junit4:junit4] 2> =09 "shard":null, [junit4:junit4] 2> =09 "roles":null, [junit4:junit4] 2> =09 "state":"down", [junit4:junit4] 2> =09 "core":"collection1", [junit4:junit4] 2> =09 "collection":"control_collection", [junit4:junit4] 2> =09 "node_name":"127.0.0.1:49311_", [junit4:junit4] 2> =09 "base_url":"http://127.0.0.1:49311"} [junit4:junit4] 2> 2621 T726 oasc.Overseer$ClusterStateUpdater.createColl= ection Create collection control_collection with numShards 1 [junit4:junit4] 2> 2622 T726 oasc.Overseer$ClusterStateUpdater.updateStat= e Assigning new node to shard shard=3Dshard1 [junit4:junit4] 2> 2623 T708 oazs.PrepRequestProcessor.pRequest Got user-= level KeeperException when processing sessionid:0x13ca51e72390003 type:crea= te cxid:0x58 zxid:0x2c txntype:-1 reqpath:n/a Error Path:/solr/overseer/que= ue-work Error:KeeperErrorCode =3D NoNode for /solr/overseer/queue-work [junit4:junit4] 2> 2634 T725 oascc.ZkStateReader$2.process A cluster stat= e change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clust= erstate.json, has occurred - updating... (live nodes size: 1) [junit4:junit4] 2> 3411 T728 oasc.CoreContainer.registerCore registering = core: collection1 [junit4:junit4] 2> 3411 T728 oasc.ZkController.register Register replica = - core:collection1 address:http://127.0.0.1:49311 collection:control_collec= tion shard:shard1 [junit4:junit4] 2> 3413 T728 oascc.SolrZkClient.makePath makePath: /colle= ctions/control_collection/leader_elect/shard1/election [junit4:junit4] 2> 3427 T708 oazs.PrepRequestProcessor.pRequest Got user-= level KeeperException when processing sessionid:0x13ca51e72390003 type:dele= te cxid:0x72 zxid:0x36 txntype:-1 reqpath:n/a Error Path:/solr/collections/= control_collection/leaders Error:KeeperErrorCode =3D NoNode for /solr/colle= ctions/control_collection/leaders [junit4:junit4] 2> 3429 T728 oasc.ShardLeaderElectionContext.runLeaderPro= cess Running the leader process. [junit4:junit4] 2> 3430 T708 oazs.PrepRequestProcessor.pRequest Got user-= level KeeperException when processing sessionid:0x13ca51e72390003 type:crea= te cxid:0x73 zxid:0x37 txntype:-1 reqpath:n/a Error Path:/solr/overseer Err= or:KeeperErrorCode =3D NodeExists for /solr/overseer [junit4:junit4] 2> 3433 T728 oasc.ShardLeaderElectionContext.waitForRepli= casToComeUp Enough replicas found to continue. [junit4:junit4] 2> 3433 T728 oasc.ShardLeaderElectionContext.runLeaderPro= cess I may be the new leader - try and sync [junit4:junit4] 2> 3434 T728 oasc.SyncStrategy.sync Sync replicas to http= ://127.0.0.1:49311/collection1/ [junit4:junit4] 2> 3435 T728 oasc.SyncStrategy.syncReplicas Sync Success = - now sync replicas to me [junit4:junit4] 2> 3439 T728 oasc.SyncStrategy.syncToMe http://127.0.0.1:= 49311/collection1/ has no replicas [junit4:junit4] 2> 3439 T728 oasc.ShardLeaderElectionContext.runLeaderPro= cess I am the new leader: http://127.0.0.1:49311/collection1/ [junit4:junit4] 2> 3439 T728 oascc.SolrZkClient.makePath makePath: /colle= ctions/control_collection/leaders/shard1 [junit4:junit4] 2> 3446 T708 oazs.PrepRequestProcessor.pRequest Got user-= level KeeperException when processing sessionid:0x13ca51e72390003 type:crea= te cxid:0x7d zxid:0x3b txntype:-1 reqpath:n/a Error Path:/solr/overseer Err= or:KeeperErrorCode =3D NodeExists for /solr/overseer [junit4:junit4] 2> 4144 T726 oascc.ZkStateReader.updateClusterState Updat= ing cloud state from ZooKeeper...=20 [junit4:junit4] 2> 4161 T725 oascc.ZkStateReader$2.process A cluster stat= e change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clust= erstate.json, has occurred - updating... (live nodes size: 1) [junit4:junit4] 2> 4192 T728 oasc.ZkController.register We are http://127= .0.0.1:49311/collection1/ and leader is http://127.0.0.1:49311/collection1/ [junit4:junit4] 2> 4192 T728 oasc.ZkController.register No LogReplay need= ed for core=3Dcollection1 baseURL=3Dhttp://127.0.0.1:49311 [junit4:junit4] 2> 4192 T728 oasc.ZkController.checkRecovery I am the lea= der, no recovery necessary [junit4:junit4] 2> 4192 T728 oasc.ZkController.publish publishing core=3D= collection1 state=3Dactive [junit4:junit4] 2> 4193 T728 oasc.ZkController.publish numShards not foun= d on descriptor - reading it from system property [junit4:junit4] 2> 4196 T728 oascc.ZkStateReader.updateClusterState Updat= ing cloud state from ZooKeeper...=20 [junit4:junit4] 2> 4198 T703 oass.SolrDispatchFilter.init user.dir=3D/Use= rs/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr= -core/test/J0 [junit4:junit4] 2> 4198 T703 oass.SolrDispatchFilter.init SolrDispatchFil= ter.init() done [junit4:junit4] 2> 4199 T703 oascsi.HttpClientUtil.createClient Creating = new http client, config:maxConnections=3D128&maxConnectionsPerHost=3D32&fol= lowRedirects=3Dfalse [junit4:junit4] 2> 4230 T703 oascsi.HttpClientUtil.createClient Creating = new http client, config: [junit4:junit4] 2> 4237 T703 oaz.ZooKeeper. Initiating client conne= ction, connectString=3D127.0.0.1:49308/solr sessionTimeout=3D10000 watcher= =3Dorg.apache.solr.common.cloud.ConnectionManager@9e160a [junit4:junit4] 2> 4243 T703 oascc.ConnectionManager.waitForConnected Wai= ting for client to connect to ZooKeeper [junit4:junit4] 2> 4244 T730 oaz.ClientCnxn$SendThread.logStartConnect Op= ening socket connection to server localhost/127.0.0.1:49308. Will not attem= pt to authenticate using SASL (access denied ("javax.security.auth.AuthPerm= ission" "getLoginConfiguration")) [junit4:junit4] 2> 4245 T705 oazs.NIOServerCnxnFactory.run Accepted socke= t connection from /127.0.0.1:49314 [junit4:junit4] 2> 4245 T730 oaz.ClientCnxn$SendThread.primeConnection So= cket connection established to localhost/127.0.0.1:49308, initiating sessio= n [junit4:junit4] 2> 4245 T705 oazs.ZooKeeperServer.processConnectRequest C= lient attempting to establish new session at /127.0.0.1:49314 [junit4:junit4] 2> 4246 T707 oazs.ZooKeeperServer.finishSessionInit Estab= lished session 0x13ca51e72390004 with negotiated timeout 10000 for client /= 127.0.0.1:49314 [junit4:junit4] 2> 4247 T730 oaz.ClientCnxn$SendThread.onConnected Sessio= n establishment complete on server localhost/127.0.0.1:49308, sessionid =3D= 0x13ca51e72390004, negotiated timeout =3D 10000 [junit4:junit4] 2> 4247 T731 oascc.ConnectionManager.process Watcher org.= apache.solr.common.cloud.ConnectionManager@9e160a name:ZooKeeperConnection = Watcher:127.0.0.1:49308/solr got event WatchedEvent state:SyncConnected typ= e:None path:null path:null type:None [junit4:junit4] 2> 4247 T703 oascc.ConnectionManager.waitForConnected Cli= ent is connected to ZooKeeper [junit4:junit4] 2> 4248 T703 oascc.ZkStateReader.createClusterStateWatche= rsAndUpdate Updating cluster state from ZooKeeper...=20 [junit4:junit4] 2> 4256 T703 oasc.ChaosMonkey.monkeyLog monkey: init - ex= pire sessions:true cause connection loss:true [junit4:junit4] 2> 4531 T703 oejs.Server.doStart jetty-8.1.8.v20121106 [junit4:junit4] 2> 4538 T703 oejs.AbstractConnector.doStart Started Selec= tChannelConnector@127.0.0.1:49315 [junit4:junit4] 2> 4539 T703 oass.SolrDispatchFilter.init SolrDispatchFil= ter.init() [junit4:junit4] 2> 4539 T703 oasc.SolrResourceLoader.locateSolrHome JNDI = not configured for solr (NoInitialContextEx) [junit4:junit4] 2> 4540 T703 oasc.SolrResourceLoader.locateSolrHome using= system property solr.solr.home: /Users/jenkins/jenkins-slave/workspace/Luc= ene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.= BasicDistributedZkTest-jetty1-1359979905725 [junit4:junit4] 2> 4540 T703 oasc.CoreContainer$Initializer.initialize lo= oking for solr.xml: /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trun= k-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistribu= tedZkTest-jetty1-1359979905725/solr.xml [junit4:junit4] 2> 4541 T703 oasc.CoreContainer. New CoreContainer = 820959146 [junit4:junit4] 2> 4541 T703 oasc.CoreContainer.load Loading CoreContaine= r using Solr Home: '/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trun= k-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistribu= tedZkTest-jetty1-1359979905725/' [junit4:junit4] 2> 4542 T703 oasc.SolrResourceLoader. new SolrResou= rceLoader for directory: '/Users/jenkins/jenkins-slave/workspace/Lucene-Sol= r-trunk-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDi= stributedZkTest-jetty1-1359979905725/' [junit4:junit4] 2> 4577 T703 oashc.HttpShardHandlerFactory.getParameter S= etting socketTimeout to: 60000 [junit4:junit4] 2> 4577 T703 oashc.HttpShardHandlerFactory.getParameter S= etting urlScheme to: http:// [junit4:junit4] 2> 4578 T703 oashc.HttpShardHandlerFactory.getParameter S= etting connTimeout to: 15000 [junit4:junit4] 2> 4578 T703 oashc.HttpShardHandlerFactory.getParameter S= etting maxConnectionsPerHost to: 20 [junit4:junit4] 2> 4578 T703 oashc.HttpShardHandlerFactory.getParameter S= etting corePoolSize to: 0 [junit4:junit4] 2> 4578 T703 oashc.HttpShardHandlerFactory.getParameter S= etting maximumPoolSize to: 2147483647 [junit4:junit4] 2> 4579 T703 oashc.HttpShardHandlerFactory.getParameter S= etting maxThreadIdleTime to: 5 [junit4:junit4] 2> 4579 T703 oashc.HttpShardHandlerFactory.getParameter S= etting sizeOfQueue to: -1 [junit4:junit4] 2> 4579 T703 oashc.HttpShardHandlerFactory.getParameter S= etting fairnessPolicy to: false [junit4:junit4] 2> 4580 T703 oascsi.HttpClientUtil.createClient Creating = new http client, config:maxConnectionsPerHost=3D20&maxConnections=3D10000&s= ocketTimeout=3D60000&connTimeout=3D15000&retry=3Dfalse [junit4:junit4] 2> 4588 T703 oasc.CoreContainer.load Registering Log List= ener [junit4:junit4] 2> 4600 T703 oasc.CoreContainer.initZooKeeper Zookeeper c= lient=3D127.0.0.1:49308/solr [junit4:junit4] 2> 4600 T703 oasc.ZkController.checkChrootPath zkHost inc= ludes chroot [junit4:junit4] 2> 4600 T703 oaz.ZooKeeper. Initiating client conne= ction, connectString=3D127.0.0.1:49308 sessionTimeout=3D60000 watcher=3Dorg= .apache.solr.common.cloud.ConnectionManager@1a7787b9 [junit4:junit4] 2> 4601 T703 oascc.ConnectionManager.waitForConnected Wai= ting for client to connect to ZooKeeper [junit4:junit4] 2> 4602 T741 oaz.ClientCnxn$SendThread.logStartConnect Op= ening socket connection to server localhost/127.0.0.1:49308. Will not attem= pt to authenticate using SASL (access denied ("javax.security.auth.AuthPerm= ission" "getLoginConfiguration")) [junit4:junit4] 2> 4603 T705 oazs.NIOServerCnxnFactory.run Accepted socke= t connection from /127.0.0.1:49316 [junit4:junit4] 2> 4604 T741 oaz.ClientCnxn$SendThread.primeConnection So= cket connection established to localhost/127.0.0.1:49308, initiating sessio= n [junit4:junit4] 2> 4604 T705 oazs.ZooKeeperServer.processConnectRequest C= lient attempting to establish new session at /127.0.0.1:49316 [junit4:junit4] 2> 4605 T707 oazs.ZooKeeperServer.finishSessionInit Estab= lished session 0x13ca51e72390005 with negotiated timeout 20000 for client /= 127.0.0.1:49316 [junit4:junit4] 2> 4605 T741 oaz.ClientCnxn$SendThread.onConnected Sessio= n establishment complete on server localhost/127.0.0.1:49308, sessionid =3D= 0x13ca51e72390005, negotiated timeout =3D 20000 [junit4:junit4] 2> 4607 T742 oascc.ConnectionManager.process Watcher org.= apache.solr.common.cloud.ConnectionManager@1a7787b9 name:ZooKeeperConnectio= n Watcher:127.0.0.1:49308 got event WatchedEvent state:SyncConnected type:N= one path:null path:null type:None [junit4:junit4] 2> 4607 T703 oascc.ConnectionManager.waitForConnected Cli= ent is connected to ZooKeeper [junit4:junit4] 2> 4617 T708 oazs.PrepRequestProcessor.pRequest2Txn Proce= ssed session termination for sessionid: 0x13ca51e72390005 [junit4:junit4] 2> 4618 T705 oazs.NIOServerCnxn.closeSock Closed socket c= onnection for client /127.0.0.1:49316 which had sessionid 0x13ca51e72390005 [junit4:junit4] 2> 4619 T742 oaz.ClientCnxn$EventThread.run EventThread s= hut down [junit4:junit4] 2> 4619 T703 oaz.ZooKeeper.close Session: 0x13ca51e723900= 05 closed [junit4:junit4] 2> 4620 T703 oascsi.HttpClientUtil.createClient Creating = new http client, config:maxConnections=3D500&maxConnectionsPerHost=3D16&soc= ketTimeout=3D60000&connTimeout=3D15000 [junit4:junit4] 2> 4630 T703 oaz.ZooKeeper. Initiating client conne= ction, connectString=3D127.0.0.1:49308/solr sessionTimeout=3D30000 watcher= =3Dorg.apache.solr.common.cloud.ConnectionManager@4c9adbe5 [junit4:junit4] 2> 4633 T703 oascc.ConnectionManager.waitForConnected Wai= ting for client to connect to ZooKeeper [junit4:junit4] 2> 4633 T743 oaz.ClientCnxn$SendThread.logStartConnect Op= ening socket connection to server localhost/127.0.0.1:49308. Will not attem= pt to authenticate using SASL (access denied ("javax.security.auth.AuthPerm= ission" "getLoginConfiguration")) [junit4:junit4] 2> 4634 T743 oaz.ClientCnxn$SendThread.primeConnection So= cket connection established to localhost/127.0.0.1:49308, initiating sessio= n [junit4:junit4] 2> 4635 T705 oazs.NIOServerCnxnFactory.run Accepted socke= t connection from /127.0.0.1:49317 [junit4:junit4] 2> 4635 T705 oazs.ZooKeeperServer.processConnectRequest C= lient attempting to establish new session at /127.0.0.1:49317 [junit4:junit4] 2> 4640 T707 oazs.ZooKeeperServer.finishSessionInit Estab= lished session 0x13ca51e72390006 with negotiated timeout 20000 for client /= 127.0.0.1:49317 [junit4:junit4] 2> 4640 T743 oaz.ClientCnxn$SendThread.onConnected Sessio= n establishment complete on server localhost/127.0.0.1:49308, sessionid =3D= 0x13ca51e72390006, negotiated timeout =3D 20000 [junit4:junit4] 2> 4641 T744 oascc.ConnectionManager.process Watcher org.= apache.solr.common.cloud.ConnectionManager@4c9adbe5 name:ZooKeeperConnectio= n Watcher:127.0.0.1:49308/solr got event WatchedEvent state:SyncConnected t= ype:None path:null path:null type:None [junit4:junit4] 2> 4641 T703 oascc.ConnectionManager.waitForConnected Cli= ent is connected to ZooKeeper [junit4:junit4] 2> 4642 T708 oazs.PrepRequestProcessor.pRequest Got user-= level KeeperException when processing sessionid:0x13ca51e72390006 type:crea= te cxid:0x1 zxid:0x49 txntype:-1 reqpath:n/a Error Path:/solr/overseer Erro= r:KeeperErrorCode =3D NodeExists for /solr/overseer [junit4:junit4] 2> 4645 T708 oazs.PrepRequestProcessor.pRequest Got user-= level KeeperException when processing sessionid:0x13ca51e72390006 type:crea= te cxid:0x2 zxid:0x4a txntype:-1 reqpath:n/a Error Path:/solr/overseer Erro= r:KeeperErrorCode =3D NodeExists for /solr/overseer [junit4:junit4] 2> 4647 T703 oasc.ZkController.createEphemeralLiveNode Re= gister node as live in ZooKeeper:/live_nodes/127.0.0.1:49315_ [junit4:junit4] 2> 4648 T708 oazs.PrepRequestProcessor.pRequest Got user-= level KeeperException when processing sessionid:0x13ca51e72390006 type:dele= te cxid:0x4 zxid:0x4b txntype:-1 reqpath:n/a Error Path:/solr/live_nodes/12= 7.0.0.1:49315_ Error:KeeperErrorCode =3D NoNode for /solr/live_nodes/127.0.= 0.1:49315_ [junit4:junit4] 2> 4649 T703 oascc.SolrZkClient.makePath makePath: /live_= nodes/127.0.0.1:49315_ [junit4:junit4] 2> 4656 T725 oascc.ZkStateReader$3.process Updating live = nodes... (2) [junit4:junit4] 2> 4656 T725 oascc.ZkStateReader$2.process A cluster stat= e change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/l= ive_nodes, has occurred - updating... (live nodes size: 2) [junit4:junit4] 2> 4657 T731 oascc.ZkStateReader$3.process Updating live = nodes... (2) [junit4:junit4] 2> 4667 T703 oascc.ZkStateReader.createClusterStateWatche= rsAndUpdate Updating cluster state from ZooKeeper...=20 [junit4:junit4] 2> 4689 T745 oasc.CoreContainer.create Creating SolrCore = 'collection1' using instanceDir: /Users/jenkins/jenkins-slave/workspace/Luc= ene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.= BasicDistributedZkTest-jetty1-1359979905725/collection1 [junit4:junit4] 2> 4689 T745 oasc.ZkController.createCollectionZkNode Che= ck for collection zkNode:collection1 [junit4:junit4] 2> 4691 T745 oasc.ZkController.createCollectionZkNode Col= lection zkNode exists [junit4:junit4] 2> 4691 T745 oasc.ZkController.readConfigName Load collec= tion config from:/collections/collection1 [junit4:junit4] 2> 4694 T745 oasc.SolrResourceLoader. new SolrResou= rceLoader for directory: '/Users/jenkins/jenkins-slave/workspace/Lucene-Sol= r-trunk-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDi= stributedZkTest-jetty1-1359979905725/collection1/' [junit4:junit4] 2> 4695 T745 oasc.SolrResourceLoader.replaceClassLoader A= dding 'file:/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX= /solr/build/solr-core/test/J0/org.apache.solr.cloud.BasicDistributedZkTest-= jetty1-1359979905725/collection1/lib/classes/' to classloader [junit4:junit4] 2> 4695 T745 oasc.SolrResourceLoader.replaceClassLoader A= dding 'file:/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX= /solr/build/solr-core/test/J0/org.apache.solr.cloud.BasicDistributedZkTest-= jetty1-1359979905725/collection1/lib/README' to classloader [junit4:junit4] 2> 4809 T745 oasc.SolrConfig. Using Lucene MatchVer= sion: LUCENE_50 [junit4:junit4] 2> 4907 T745 oasc.SolrConfig. Loaded SolrConfig: so= lrconfig.xml [junit4:junit4] 2> 4909 T745 oass.IndexSchema.readSchema Reading Solr Sch= ema [junit4:junit4] 2> 4918 T745 oass.IndexSchema.readSchema Schema name=3Dte= st [junit4:junit4] 2> 5720 T726 oascc.ZkStateReader.updateClusterState Updat= ing cloud state from ZooKeeper...=20 [junit4:junit4] 2> 5722 T726 oasc.Overseer$ClusterStateUpdater.updateStat= e Update state numShards=3D1 message=3D{ [junit4:junit4] 2> =09 "operation":"state", [junit4:junit4] 2> =09 "numShards":"1", [junit4:junit4] 2> =09 "shard":"shard1", [junit4:junit4] 2> =09 "roles":null, [junit4:junit4] 2> =09 "state":"active", [junit4:junit4] 2> =09 "core":"collection1", [junit4:junit4] 2> =09 "collection":"control_collection", [junit4:junit4] 2> =09 "node_name":"127.0.0.1:49311_", [junit4:junit4] 2> =09 "base_url":"http://127.0.0.1:49311"} [junit4:junit4] 2> 5736 T744 oascc.ZkStateReader$2.process A cluster stat= e change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clust= erstate.json, has occurred - updating... (live nodes size: 2) [junit4:junit4] 2> 5737 T731 oascc.ZkStateReader$2.process A cluster stat= e change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clust= erstate.json, has occurred - updating... (live nodes size: 2) [junit4:junit4] 2> 5737 T725 oascc.ZkStateReader$2.process A cluster stat= e change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clust= erstate.json, has occurred - updating... (live nodes size: 2) [junit4:junit4] 2> 5756 T745 oass.OpenExchangeRatesOrgProvider.init Initi= alized with rates=3Dopen-exchange-rates.json, refreshInterval=3D1440. [junit4:junit4] 2> 5768 T745 oass.IndexSchema.readSchema default search f= ield in schema is text [junit4:junit4] 2> 5773 T745 oass.IndexSchema.readSchema unique key field= : id [junit4:junit4] 2> 5816 T745 oass.FileExchangeRateProvider.reload Reloadi= ng exchange rates from file currency.xml [junit4:junit4] 2> 5824 T745 oass.FileExchangeRateProvider.reload Reloadi= ng exchange rates from file currency.xml [junit4:junit4] 2> 5834 T745 oass.OpenExchangeRatesOrgProvider.reload Rel= oading exchange rates from open-exchange-rates.json [junit4:junit4] 2> 5837 T745 oass.OpenExchangeRatesOrgProvider.reload Rel= oading exchange rates from open-exchange-rates.json [junit4:junit4] 2> 5840 T745 oasc.SolrCore. [collection1] Opening n= ew SolrCore at /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-Mac= OSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZk= Test-jetty1-1359979905725/collection1/, dataDir=3D./org.apache.solr.cloud.B= asicDistributedZkTest-1359979901483/jetty1/ [junit4:junit4] 2> 5840 T745 oasc.JmxMonitoredMap. JMX monitoring i= s enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBe= anServer@36298619 [junit4:junit4] 2> 5841 T745 oasc.SolrCore.initDirectoryFactory solr.NRTC= achingDirectoryFactory [junit4:junit4] 2> 5843 T745 oasc.CachingDirectoryFactory.get return new = directory for /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacO= SX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZkT= est-1359979901483/jetty1 forceNew:false [junit4:junit4] 2> 5844 T745 oasc.CachingDirectoryFactory.close Releasing= directory:/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/= solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZkTest= -1359979901483/jetty1 [junit4:junit4] 2> 5844 T745 oasc.SolrCore.getNewIndexDir New index direc= tory detected: old=3Dnull new=3D./org.apache.solr.cloud.BasicDistributedZkT= est-1359979901483/jetty1/index/ [junit4:junit4] 2> 5845 T745 oasc.SolrCore.initIndex WARNING [collection1= ] Solr index directory './org.apache.solr.cloud.BasicDistributedZkTest-1359= 979901483/jetty1/index' doesn't exist. Creating new index... [junit4:junit4] 2> 5847 T745 oasc.CachingDirectoryFactory.get return new = directory for /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacO= SX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZkT= est-1359979901483/jetty1/index forceNew:false [junit4:junit4] 2> 5854 T745 oasc.SolrDeletionPolicy.onCommit SolrDeletio= nPolicy.onCommit: commits:num=3D1 [junit4:junit4] 2> =09=09commit{dir=3DRateLimitedDirectoryWrapper(NRTCach= ingDirectory(org.apache.lucene.store.NIOFSDirectory@/Users/jenkins/jenkins-= slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/org.a= pache.solr.cloud.BasicDistributedZkTest-1359979901483/jetty1/index lockFact= ory=3Dorg.apache.lucene.store.NativeFSLockFactory@3e40cc10; maxCacheMB=3D48= .0 maxMergeSizeMB=3D4.0)),segFN=3Dsegments_1,generation=3D1,filenames=3D[se= gments_1] [junit4:junit4] 2> 5855 T745 oasc.SolrDeletionPolicy.updateCommits newest= commit =3D 1[segments_1] [junit4:junit4] 2> 5856 T745 oasc.CachingDirectoryFactory.close Releasing= directory:/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/= solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZkTest= -1359979901483/jetty1/index [junit4:junit4] 2> 5857 T745 oasc.SolrCore.initWriters created xml: solr.= XMLResponseWriter [junit4:junit4] 2> 5860 T745 oasup.UpdateRequestProcessorChain.init inser= ting DistributedUpdateProcessorFactory into updateRequestProcessorChain "de= dupe" [junit4:junit4] 2> 5861 T745 oasup.UpdateRequestProcessorChain.init inser= ting DistributedUpdateProcessorFactory into updateRequestProcessorChain "de= dupe-allfields" [junit4:junit4] 2> 5861 T745 oasup.UpdateRequestProcessorChain.init inser= ting DistributedUpdateProcessorFactory into updateRequestProcessorChain "st= ored_sig" [junit4:junit4] 2> 5862 T745 oasup.UpdateRequestProcessorChain.init inser= ting DistributedUpdateProcessorFactory into updateRequestProcessorChain "un= iq-fields" [junit4:junit4] 2> 5863 T745 oasup.UpdateRequestProcessorChain.init inser= ting DistributedUpdateProcessorFactory into updateRequestProcessorChain "di= strib-dup-test-chain-implicit" [junit4:junit4] 2> 5863 T745 oasc.RequestHandlers.initHandlersFromConfig = adding lazy requestHandler: solr.ReplicationHandler [junit4:junit4] 2> 5864 T745 oasc.RequestHandlers.initHandlersFromConfig = created /replication: solr.ReplicationHandler [junit4:junit4] 2> 5864 T745 oasc.RequestHandlers.initHandlersFromConfig = created standard: solr.StandardRequestHandler [junit4:junit4] 2> 5865 T745 oasc.RequestHandlers.initHandlersFromConfig = created /get: solr.RealTimeGetHandler [junit4:junit4] 2> 5867 T745 oasc.RequestHandlers.initHandlersFromConfig = created dismax: solr.SearchHandler [junit4:junit4] 2> 5868 T745 oasc.RequestHandlers.initHandlersFromConfig = created mock: org.apache.solr.core.MockQuerySenderListenerReqHandler [junit4:junit4] 2> 5868 T745 oasc.RequestHandlers.initHandlersFromConfig = created /admin/: org.apache.solr.handler.admin.AdminHandlers [junit4:junit4] 2> 5869 T745 oasc.RequestHandlers.initHandlersFromConfig = created defaults: solr.StandardRequestHandler [junit4:junit4] 2> 5869 T745 oasc.RequestHandlers.initHandlersFromConfig = adding lazy requestHandler: solr.StandardRequestHandler [junit4:junit4] 2> 5870 T745 oasc.RequestHandlers.initHandlersFromConfig = created lazy: solr.StandardRequestHandler [junit4:junit4] 2> 5871 T745 oasc.RequestHandlers.initHandlersFromConfig = created /update: solr.UpdateRequestHandler [junit4:junit4] 2> 5872 T745 oasc.RequestHandlers.initHandlersFromConfig = created /terms: org.apache.solr.handler.component.SearchHandler [junit4:junit4] 2> 5873 T745 oasc.RequestHandlers.initHandlersFromConfig = created spellCheckCompRH: org.apache.solr.handler.component.SearchHandler [junit4:junit4] 2> 5874 T745 oasc.RequestHandlers.initHandlersFromConfig = created spellCheckCompRH_Direct: org.apache.solr.handler.component.SearchHa= ndler [junit4:junit4] 2> 5874 T745 oasc.RequestHandlers.initHandlersFromConfig = created spellCheckWithWordbreak: org.apache.solr.handler.component.SearchHa= ndler [junit4:junit4] 2> 5875 T745 oasc.RequestHandlers.initHandlersFromConfig = created spellCheckWithWordbreak_Direct: org.apache.solr.handler.component.S= earchHandler [junit4:junit4] 2> 5876 T745 oasc.RequestHandlers.initHandlersFromConfig = created spellCheckCompRH1: org.apache.solr.handler.component.SearchHandler [junit4:junit4] 2> 5876 T745 oasc.RequestHandlers.initHandlersFromConfig = created mltrh: org.apache.solr.handler.component.SearchHandler [junit4:junit4] 2> 5877 T745 oasc.RequestHandlers.initHandlersFromConfig = created tvrh: org.apache.solr.handler.component.SearchHandler [junit4:junit4] 2> 5878 T745 oasc.RequestHandlers.initHandlersFromConfig = created /mlt: solr.MoreLikeThisHandler [junit4:junit4] 2> 5879 T745 oasc.RequestHandlers.initHandlersFromConfig = created /debug/dump: solr.DumpRequestHandler [junit4:junit4] 2> 5889 T745 oashl.XMLLoader.init xsltCacheLifetimeSecond= s=3D60 [junit4:junit4] 2> 5894 T745 oasc.SolrCore.initDeprecatedSupport WARNING = solrconfig.xml uses deprecated , Please update your co= nfig to use the ShowFileRequestHandler. [junit4:junit4] 2> 5896 T745 oasc.SolrCore.initDeprecatedSupport WARNING = adding ShowFileRequestHandler with hidden files: [SCHEMA.XML, OLD_SYNONYMS.= TXT, STOPWORDS.TXT, PROTWORDS.TXT, OPEN-EXCHANGE-RATES.JSON, SYNONYMS.TXT, = CURRENCY.XML, MAPPING-ISOLATIN1ACCENT.TXT] [junit4:junit4] 2> 5900 T745 oasc.CachingDirectoryFactory.close Releasing= directory:/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/= solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZkTest= -1359979901483/jetty1 [junit4:junit4] 2> 5902 T745 oass.SolrIndexSearcher. Opening Search= er@69f2fae4 main [junit4:junit4] 2> 5906 T745 oasu.CommitTracker. Hard AutoCommit: d= isabled [junit4:junit4] 2> 5908 T745 oasu.CommitTracker. Soft AutoCommit: d= isabled [junit4:junit4] 2> 5909 T745 oashc.SpellCheckComponent.inform Initializin= g spell checkers [junit4:junit4] 2> 5920 T745 oass.DirectSolrSpellChecker.init init: {name= =3Ddirect,classname=3DDirectSolrSpellChecker,field=3Dlowerfilt,minQueryLeng= th=3D3} [junit4:junit4] 2> 5960 T746 oasc.SolrCore.registerSearcher [collection1]= Registered new searcher Searcher@69f2fae4 main{StandardDirectoryReader(seg= ments_1:1)} [junit4:junit4] 2> 5974 T745 oasc.ZkController.publish publishing core=3D= collection1 state=3Ddown [junit4:junit4] 2> 5975 T745 oasc.ZkController.publish numShards not foun= d on descriptor - reading it from system property [junit4:junit4] 2> 7283 T726 oascc.ZkStateReader.updateClusterState Updat= ing cloud state from ZooKeeper...=20 [junit4:junit4] 2> 7284 T726 oasc.Overseer$ClusterStateUpdater.updateStat= e Update state numShards=3D2 message=3D{ [junit4:junit4] 2> =09 "operation":"state", [junit4:junit4] 2> =09 "numShards":"2", [junit4:junit4] 2> =09 "shard":null, [junit4:junit4] 2> =09 "roles":null, [junit4:junit4] 2> =09 "state":"down", [junit4:junit4] 2> =09 "core":"collection1", [junit4:junit4] 2> =09 "collection":"collection1", [junit4:junit4] 2> =09 "node_name":"127.0.0.1:49315_", [junit4:junit4] 2> =09 "base_url":"http://127.0.0.1:49315"} [junit4:junit4] 2> 7285 T726 oasc.Overseer$ClusterStateUpdater.createColl= ection Create collection collection1 with numShards 2 [junit4:junit4] 2> 7285 T726 oasc.Overseer$ClusterStateUpdater.updateStat= e Assigning new node to shard shard=3Dshard1 [junit4:junit4] 2> 7300 T731 oascc.ZkStateReader$2.process A cluster stat= e change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clust= erstate.json, has occurred - updating... (live nodes size: 2) [junit4:junit4] 2> 7301 T725 oascc.ZkStateReader$2.process A cluster stat= e change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clust= erstate.json, has occurred - updating... (live nodes size: 2) [junit4:junit4] 2> 7301 T744 oascc.ZkStateReader$2.process A cluster stat= e change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clust= erstate.json, has occurred - updating... (live nodes size: 2) [junit4:junit4] 2> 7980 T745 oasc.CoreContainer.registerCore registering = core: collection1 [junit4:junit4] 2> 7980 T745 oasc.ZkController.register Register replica = - core:collection1 address:http://127.0.0.1:49315 collection:collection1 sh= ard:shard1 [junit4:junit4] 2> 7982 T745 oascc.SolrZkClient.makePath makePath: /colle= ctions/collection1/leader_elect/shard1/election [junit4:junit4] 2> 8009 T708 oazs.PrepRequestProcessor.pRequest Got user-= level KeeperException when processing sessionid:0x13ca51e72390006 type:dele= te cxid:0x45 zxid:0x5b txntype:-1 reqpath:n/a Error Path:/solr/collections/= collection1/leaders Error:KeeperErrorCode =3D NoNode for /solr/collections/= collection1/leaders [junit4:junit4] 2> 8011 T745 oasc.ShardLeaderElectionContext.runLeaderPro= cess Running the leader process. [junit4:junit4] 2> 8012 T708 oazs.PrepRequestProcessor.pRequest Got user-= level KeeperException when processing sessionid:0x13ca51e72390006 type:crea= te cxid:0x46 zxid:0x5c txntype:-1 reqpath:n/a Error Path:/solr/overseer Err= or:KeeperErrorCode =3D NodeExists for /solr/overseer [junit4:junit4] 2> 8018 T745 oasc.ShardLeaderElectionContext.waitForRepli= casToComeUp Enough replicas found to continue. [junit4:junit4] 2> 8018 T745 oasc.ShardLeaderElectionContext.runLeaderPro= cess I may be the new leader - try and sync [junit4:junit4] 2> 8019 T745 oasc.SyncStrategy.sync Sync replicas to http= ://127.0.0.1:49315/collection1/ [junit4:junit4] 2> 8020 T745 oasc.SyncStrategy.syncReplicas Sync Success = - now sync replicas to me [junit4:junit4] 2> 8021 T745 oasc.SyncStrategy.syncToMe http://127.0.0.1:= 49315/collection1/ has no replicas [junit4:junit4] 2> 8021 T745 oasc.ShardLeaderElectionContext.runLeaderPro= cess I am the new leader: http://127.0.0.1:49315/collection1/ [junit4:junit4] 2> 8022 T745 oascc.SolrZkClient.makePath makePath: /colle= ctions/collection1/leaders/shard1 [junit4:junit4] 2> 8029 T708 oazs.PrepRequestProcessor.pRequest Got user-= level KeeperException when processing sessionid:0x13ca51e72390006 type:crea= te cxid:0x50 zxid:0x60 txntype:-1 reqpath:n/a Error Path:/solr/overseer Err= or:KeeperErrorCode =3D NodeExists for /solr/overseer [junit4:junit4] 2> 8813 T726 oascc.ZkStateReader.updateClusterState Updat= ing cloud state from ZooKeeper...=20 [junit4:junit4] 2> 8828 T744 oascc.ZkStateReader$2.process A cluster stat= e change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clust= erstate.json, has occurred - updating... (live nodes size: 2) [junit4:junit4] 2> 8830 T725 oascc.ZkStateReader$2.process A cluster stat= e change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clust= erstate.json, has occurred - updating... (live nodes size: 2) [junit4:junit4] 2> 8832 T731 oascc.ZkStateReader$2.process A cluster stat= e change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clust= erstate.json, has occurred - updating... (live nodes size: 2) [junit4:junit4] 2> 8860 T745 oasc.ZkController.register We are http://127= .0.0.1:49315/collection1/ and leader is http://127.0.0.1:49315/collection1/ [junit4:junit4] 2> 8860 T745 oasc.ZkController.register No LogReplay need= ed for core=3Dcollection1 baseURL=3Dhttp://127.0.0.1:49315 [junit4:junit4] 2> 8860 T745 oasc.ZkController.checkRecovery I am the lea= der, no recovery necessary [junit4:junit4] 2> 8861 T745 oasc.ZkController.publish publishing core=3D= collection1 state=3Dactive [junit4:junit4] 2> 8861 T745 oasc.ZkController.publish numShards not foun= d on descriptor - reading it from system property [junit4:junit4] 2> 8864 T745 oascc.ZkStateReader.updateClusterState Updat= ing cloud state from ZooKeeper...=20 [junit4:junit4] 2> 8866 T703 oass.SolrDispatchFilter.init user.dir=3D/Use= rs/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr= -core/test/J0 [junit4:junit4] 2> 8866 T703 oass.SolrDispatchFilter.init SolrDispatchFil= ter.init() done [junit4:junit4] 2> 8867 T703 oascsi.HttpClientUtil.createClient Creating = new http client, config:maxConnections=3D128&maxConnectionsPerHost=3D32&fol= lowRedirects=3Dfalse [junit4:junit4] 2> 9149 T703 oejs.Server.doStart jetty-8.1.8.v20121106 [junit4:junit4] 2> 9153 T703 oejs.AbstractConnector.doStart Started Selec= tChannelConnector@127.0.0.1:49318 [junit4:junit4] 2> 9154 T703 oass.SolrDispatchFilter.init SolrDispatchFil= ter.init() [junit4:junit4] 2> 9155 T703 oasc.SolrResourceLoader.locateSolrHome JNDI = not configured for solr (NoInitialContextEx) [junit4:junit4] 2> 9156 T703 oasc.SolrResourceLoader.locateSolrHome using= system property solr.solr.home: /Users/jenkins/jenkins-slave/workspace/Luc= ene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.= BasicDistributedZkTest-jetty2-1359979910342 [junit4:junit4] 2> 9156 T703 oasc.CoreContainer$Initializer.initialize lo= oking for solr.xml: /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trun= k-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistribu= tedZkTest-jetty2-1359979910342/solr.xml [junit4:junit4] 2> 9157 T703 oasc.CoreContainer. New CoreContainer = 1529885855 [junit4:junit4] 2> 9158 T703 oasc.CoreContainer.load Loading CoreContaine= r using Solr Home: '/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trun= k-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistribu= tedZkTest-jetty2-1359979910342/' [junit4:junit4] 2> 9158 T703 oasc.SolrResourceLoader. new SolrResou= rceLoader for directory: '/Users/jenkins/jenkins-slave/workspace/Lucene-Sol= r-trunk-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDi= stributedZkTest-jetty2-1359979910342/' [junit4:junit4] 2> 9252 T703 oashc.HttpShardHandlerFactory.getParameter S= etting socketTimeout to: 60000 [junit4:junit4] 2> 9253 T703 oashc.HttpShardHandlerFactory.getParameter S= etting urlScheme to: http:// [junit4:junit4] 2> 9253 T703 oashc.HttpShardHandlerFactory.getParameter S= etting connTimeout to: 15000 [junit4:junit4] 2> 9254 T703 oashc.HttpShardHandlerFactory.getParameter S= etting maxConnectionsPerHost to: 20 [junit4:junit4] 2> 9254 T703 oashc.HttpShardHandlerFactory.getParameter S= etting corePoolSize to: 0 [junit4:junit4] 2> 9255 T703 oashc.HttpShardHandlerFactory.getParameter S= etting maximumPoolSize to: 2147483647 [junit4:junit4] 2> 9255 T703 oashc.HttpShardHandlerFactory.getParameter S= etting maxThreadIdleTime to: 5 [junit4:junit4] 2> 9259 T703 oashc.HttpShardHandlerFactory.getParameter S= etting sizeOfQueue to: -1 [junit4:junit4] 2> 9260 T703 oashc.HttpShardHandlerFactory.getParameter S= etting fairnessPolicy to: false [junit4:junit4] 2> 9261 T703 oascsi.HttpClientUtil.createClient Creating = new http client, config:maxConnectionsPerHost=3D20&maxConnections=3D10000&s= ocketTimeout=3D60000&connTimeout=3D15000&retry=3Dfalse [junit4:junit4] 2> 9286 T703 oasc.CoreContainer.load Registering Log List= ener [junit4:junit4] 2> 9321 T703 oasc.CoreContainer.initZooKeeper Zookeeper c= lient=3D127.0.0.1:49308/solr [junit4:junit4] 2> 9322 T703 oasc.ZkController.checkChrootPath zkHost inc= ludes chroot [junit4:junit4] 2> 9322 T703 oaz.ZooKeeper. Initiating client conne= ction, connectString=3D127.0.0.1:49308 sessionTimeout=3D60000 watcher=3Dorg= .apache.solr.common.cloud.ConnectionManager@5677e40c [junit4:junit4] 2> 9323 T703 oascc.ConnectionManager.waitForConnected Wai= ting for client to connect to ZooKeeper [junit4:junit4] 2> 9324 T756 oaz.ClientCnxn$SendThread.logStartConnect Op= ening socket connection to server localhost/127.0.0.1:49308. Will not attem= pt to authenticate using SASL (access denied ("javax.security.auth.AuthPerm= ission" "getLoginConfiguration")) [junit4:junit4] 2> 9328 T756 oaz.ClientCnxn$SendThread.primeConnection So= cket connection established to localhost/127.0.0.1:49308, initiating sessio= n [junit4:junit4] 2> 9329 T705 oazs.NIOServerCnxnFactory.run Accepted socke= t connection from /127.0.0.1:49319 [junit4:junit4] 2> 9330 T705 oazs.ZooKeeperServer.processConnectRequest C= lient attempting to establish new session at /127.0.0.1:49319 [junit4:junit4] 2> 9525 T707 oazs.ZooKeeperServer.finishSessionInit Estab= lished session 0x13ca51e72390007 with negotiated timeout 20000 for client /= 127.0.0.1:49319 [junit4:junit4] 2> 9526 T756 oaz.ClientCnxn$SendThread.onConnected Sessio= n establishment complete on server localhost/127.0.0.1:49308, sessionid =3D= 0x13ca51e72390007, negotiated timeout =3D 20000 [junit4:junit4] 2> 9526 T757 oascc.ConnectionManager.process Watcher org.= apache.solr.common.cloud.ConnectionManager@5677e40c name:ZooKeeperConnectio= n Watcher:127.0.0.1:49308 got event WatchedEvent state:SyncConnected type:N= one path:null path:null type:None [junit4:junit4] 2> 9527 T703 oascc.ConnectionManager.waitForConnected Cli= ent is connected to ZooKeeper [junit4:junit4] 2> 9530 T708 oazs.PrepRequestProcessor.pRequest2Txn Proce= ssed session termination for sessionid: 0x13ca51e72390007 [junit4:junit4] 2> 9532 T757 oaz.ClientCnxn$EventThread.run EventThread s= hut down [junit4:junit4] 2> 9532 T705 oazs.NIOServerCnxn.doIO WARNING caught end o= f stream exception EndOfStreamException: Unable to read additional data fro= m client sessionid 0x13ca51e72390007, likely client has closed socket [junit4:junit4] 2> =09at org.apache.zookeeper.server.NIOServerCnxn.doIO(N= IOServerCnxn.java:220) [junit4:junit4] 2> =09at org.apache.zookeeper.server.NIOServerCnxnFactory= .run(NIOServerCnxnFactory.java:208) [junit4:junit4] 2> =09at java.lang.Thread.run(Thread.java:722) [junit4:junit4] 2>=20 [junit4:junit4] 2> 9532 T703 oaz.ZooKeeper.close Session: 0x13ca51e723900= 07 closed [junit4:junit4] 2> 9534 T705 oazs.NIOServerCnxn.closeSock Closed socket c= onnection for client /127.0.0.1:49319 which had sessionid 0x13ca51e72390007 [junit4:junit4] 2> 9534 T703 oascsi.HttpClientUtil.createClient Creating = new http client, config:maxConnections=3D500&maxConnectionsPerHost=3D16&soc= ketTimeout=3D60000&connTimeout=3D15000 [junit4:junit4] 2> 9545 T703 oaz.ZooKeeper. Initiating client conne= ction, connectString=3D127.0.0.1:49308/solr sessionTimeout=3D30000 watcher= =3Dorg.apache.solr.common.cloud.ConnectionManager@4fcfb70d [junit4:junit4] 2> 9547 T703 oascc.ConnectionManager.waitForConnected Wai= ting for client to connect to ZooKeeper [junit4:junit4] 2> 9549 T758 oaz.ClientCnxn$SendThread.logStartConnect Op= ening socket connection to server localhost/127.0.0.1:49308. Will not attem= pt to authenticate using SASL (access denied ("javax.security.auth.AuthPerm= ission" "getLoginConfiguration")) [junit4:junit4] 2> 9550 T758 oaz.ClientCnxn$SendThread.primeConnection So= cket connection established to localhost/127.0.0.1:49308, initiating sessio= n [junit4:junit4] 2> 9551 T705 oazs.NIOServerCnxnFactory.run Accepted socke= t connection from /127.0.0.1:49320 [junit4:junit4] 2> 9552 T705 oazs.ZooKeeperServer.processConnectRequest C= lient attempting to establish new session at /127.0.0.1:49320 [junit4:junit4] 2> 9553 T707 oazs.ZooKeeperServer.finishSessionInit Estab= lished session 0x13ca51e72390008 with negotiated timeout 20000 for client /= 127.0.0.1:49320 [junit4:junit4] 2> 9554 T758 oaz.ClientCnxn$SendThread.onConnected Sessio= n establishment complete on server localhost/127.0.0.1:49308, sessionid =3D= 0x13ca51e72390008, negotiated timeout =3D 20000 [junit4:junit4] 2> 9555 T759 oascc.ConnectionManager.process Watcher org.= apache.solr.common.cloud.ConnectionManager@4fcfb70d name:ZooKeeperConnectio= n Watcher:127.0.0.1:49308/solr got event WatchedEvent state:SyncConnected t= ype:None path:null path:null type:None [junit4:junit4] 2> 9555 T703 oascc.ConnectionManager.waitForConnected Cli= ent is connected to ZooKeeper [junit4:junit4] 2> 9557 T708 oazs.PrepRequestProcessor.pRequest Got user-= level KeeperException when processing sessionid:0x13ca51e72390008 type:crea= te cxid:0x1 zxid:0x6d txntype:-1 reqpath:n/a Error Path:/solr/overseer Erro= r:KeeperErrorCode =3D NodeExists for /solr/overseer [junit4:junit4] 2> 9559 T708 oazs.PrepRequestProcessor.pRequest Got user-= level KeeperException when processing sessionid:0x13ca51e72390008 type:crea= te cxid:0x2 zxid:0x6e txntype:-1 reqpath:n/a Error Path:/solr/overseer Erro= r:KeeperErrorCode =3D NodeExists for /solr/overseer [junit4:junit4] 2> 9562 T703 oasc.ZkController.createEphemeralLiveNode Re= gister node as live in ZooKeeper:/live_nodes/127.0.0.1:49318_ [junit4:junit4] 2> 9563 T708 oazs.PrepRequestProcessor.pRequest Got user-= level KeeperException when processing sessionid:0x13ca51e72390008 type:dele= te cxid:0x4 zxid:0x6f txntype:-1 reqpath:n/a Error Path:/solr/live_nodes/12= 7.0.0.1:49318_ Error:KeeperErrorCode =3D NoNode for /solr/live_nodes/127.0.= 0.1:49318_ [junit4:junit4] 2> 9565 T703 oascc.SolrZkClient.makePath makePath: /live_= nodes/127.0.0.1:49318_ [junit4:junit4] 2> 9585 T731 oascc.ZkStateReader$2.process A cluster stat= e change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/l= ive_nodes, has occurred - updating... (live nodes size: 2) [junit4:junit4] 2> 9585 T744 oascc.ZkStateReader$2.process A cluster stat= e change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/l= ive_nodes, has occurred - updating... (live nodes size: 2) [junit4:junit4] 2> 9585 T725 oascc.ZkStateReader$3.process Updating live = nodes... (3) [junit4:junit4] 2> 9586 T725 oascc.ZkStateReader$2.process A cluster stat= e change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/l= ive_nodes, has occurred - updating... (live nodes size: 3) [junit4:junit4] 2> 9598 T744 oascc.ZkStateReader$3.process Updating live = nodes... (3) [junit4:junit4] 2> 9599 T731 oascc.ZkStateReader$3.process Updating live = nodes... (3) [junit4:junit4] 2> 9602 T703 oascc.ZkStateReader.createClusterStateWatche= rsAndUpdate Updating cluster state from ZooKeeper...=20 [junit4:junit4] 2> 9613 T760 oasc.CoreContainer.create Creating SolrCore = 'collection1' using instanceDir: /Users/jenkins/jenkins-slave/workspace/Luc= ene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.= BasicDistributedZkTest-jetty2-1359979910342/collection1 [junit4:junit4] 2> 9614 T760 oasc.ZkController.createCollectionZkNode Che= ck for collection zkNode:collection1 [junit4:junit4] 2> 9616 T760 oasc.ZkController.createCollectionZkNode Col= lection zkNode exists [junit4:junit4] 2> 9616 T760 oasc.ZkController.readConfigName Load collec= tion config from:/collections/collection1 [junit4:junit4] 2> 9619 T760 oasc.SolrResourceLoader. new SolrResou= rceLoader for directory: '/Users/jenkins/jenkins-slave/workspace/Lucene-Sol= r-trunk-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDi= stributedZkTest-jetty2-1359979910342/collection1/' [junit4:junit4] 2> 9620 T760 oasc.SolrResourceLoader.replaceClassLoader A= dding 'file:/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX= /solr/build/solr-core/test/J0/org.apache.solr.cloud.BasicDistributedZkTest-= jetty2-1359979910342/collection1/lib/classes/' to classloader [junit4:junit4] 2> 9621 T760 oasc.SolrResourceLoader.replaceClassLoader A= dding 'file:/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX= /solr/build/solr-core/test/J0/org.apache.solr.cloud.BasicDistributedZkTest-= jetty2-1359979910342/collection1/lib/README' to classloader [junit4:junit4] 2> 9731 T760 oasc.SolrConfig. Using Lucene MatchVer= sion: LUCENE_50 [junit4:junit4] 2> 9882 T760 oasc.SolrConfig. Loaded SolrConfig: so= lrconfig.xml [junit4:junit4] 2> 9897 T760 oass.IndexSchema.readSchema Reading Solr Sch= ema [junit4:junit4] 2> 9922 T760 oass.IndexSchema.readSchema Schema name=3Dte= st [junit4:junit4] 2> 10355 T726 oascc.ZkStateReader.updateClusterState Upda= ting cloud state from ZooKeeper...=20 [junit4:junit4] 2> 10358 T726 oasc.Overseer$ClusterStateUpdater.updateSta= te Update state numShards=3D2 message=3D{ [junit4:junit4] 2> =09 "operation":"state", [junit4:junit4] 2> =09 "numShards":"2", [junit4:junit4] 2> =09 "shard":"shard1", [junit4:junit4] 2> =09 "roles":null, [junit4:junit4] 2> =09 "state":"active", [junit4:junit4] 2> =09 "core":"collection1", [junit4:junit4] 2> =09 "collection":"collection1", [junit4:junit4] 2> =09 "node_name":"127.0.0.1:49315_", [junit4:junit4] 2> =09 "base_url":"http://127.0.0.1:49315"} [junit4:junit4] 2> 10369 T731 oascc.ZkStateReader$2.process A cluster sta= te change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clus= terstate.json, has occurred - updating... (live nodes size: 3) [junit4:junit4] 2> 10369 T759 oascc.ZkStateReader$2.process A cluster sta= te change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clus= terstate.json, has occurred - updating... (live nodes size: 3) [junit4:junit4] 2> 10370 T725 oascc.ZkStateReader$2.process A cluster sta= te change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clus= terstate.json, has occurred - updating... (live nodes size: 3) [junit4:junit4] 2> 10370 T744 oascc.ZkStateReader$2.process A cluster sta= te change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clus= terstate.json, has occurred - updating... (live nodes size: 3) [junit4:junit4] 2> 11248 T760 oass.OpenExchangeRatesOrgProvider.init Init= ialized with rates=3Dopen-exchange-rates.json, refreshInterval=3D1440. [junit4:junit4] 2> 11287 T760 oass.IndexSchema.readSchema default search = field in schema is text [junit4:junit4] 2> 11297 T760 oass.IndexSchema.readSchema unique key fiel= d: id [junit4:junit4] 2> 11335 T760 oass.FileExchangeRateProvider.reload Reload= ing exchange rates from file currency.xml [junit4:junit4] 2> 11348 T760 oass.FileExchangeRateProvider.reload Reload= ing exchange rates from file currency.xml [junit4:junit4] 2> 11356 T760 oass.OpenExchangeRatesOrgProvider.reload Re= loading exchange rates from open-exchange-rates.json [junit4:junit4] 2> 11359 T760 oass.OpenExchangeRatesOrgProvider.reload Re= loading exchange rates from open-exchange-rates.json [junit4:junit4] 2> 11361 T760 oasc.SolrCore. [collection1] Opening = new SolrCore at /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-Ma= cOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZ= kTest-jetty2-1359979910342/collection1/, dataDir=3D./org.apache.solr.cloud.= BasicDistributedZkTest-1359979901483/jetty2/ [junit4:junit4] 2> 11361 T760 oasc.JmxMonitoredMap. JMX monitoring = is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMB= eanServer@36298619 [junit4:junit4] 2> 11362 T760 oasc.SolrCore.initDirectoryFactory solr.NRT= CachingDirectoryFactory [junit4:junit4] 2> 11362 T760 oasc.CachingDirectoryFactory.get return new= directory for /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-Mac= OSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZk= Test-1359979901483/jetty2 forceNew:false [junit4:junit4] 2> 11363 T760 oasc.CachingDirectoryFactory.close Releasin= g directory:/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX= /solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZkTes= t-1359979901483/jetty2 [junit4:junit4] 2> 11363 T760 oasc.SolrCore.getNewIndexDir New index dire= ctory detected: old=3Dnull new=3D./org.apache.solr.cloud.BasicDistributedZk= Test-1359979901483/jetty2/index/ [junit4:junit4] 2> 11364 T760 oasc.SolrCore.initIndex WARNING [collection= 1] Solr index directory './org.apache.solr.cloud.BasicDistributedZkTest-135= 9979901483/jetty2/index' doesn't exist. Creating new index... [junit4:junit4] 2> 11365 T760 oasc.CachingDirectoryFactory.get return new= directory for /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-Mac= OSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZk= Test-1359979901483/jetty2/index forceNew:false [junit4:junit4] 2> 11371 T760 oasc.SolrDeletionPolicy.onCommit SolrDeleti= onPolicy.onCommit: commits:num=3D1 [junit4:junit4] 2> =09=09commit{dir=3DRateLimitedDirectoryWrapper(NRTCach= ingDirectory(org.apache.lucene.store.NIOFSDirectory@/Users/jenkins/jenkins-= slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/org.a= pache.solr.cloud.BasicDistributedZkTest-1359979901483/jetty2/index lockFact= ory=3Dorg.apache.lucene.store.NativeFSLockFactory@684e8b72; maxCacheMB=3D48= .0 maxMergeSizeMB=3D4.0)),segFN=3Dsegments_1,generation=3D1,filenames=3D[se= gments_1] [junit4:junit4] 2> 11373 T760 oasc.SolrDeletionPolicy.updateCommits newes= t commit =3D 1[segments_1] [junit4:junit4] 2> 11378 T760 oasc.CachingDirectoryFactory.close Releasin= g directory:/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX= /solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZkTes= t-1359979901483/jetty2/index [junit4:junit4] 2> 11382 T760 oasc.SolrCore.initWriters created xml: solr= .XMLResponseWriter [junit4:junit4] 2> 11385 T760 oasup.UpdateRequestProcessorChain.init inse= rting DistributedUpdateProcessorFactory into updateRequestProcessorChain "d= edupe" [junit4:junit4] 2> 11385 T760 oasup.UpdateRequestProcessorChain.init inse= rting DistributedUpdateProcessorFactory into updateRequestProcessorChain "d= edupe-allfields" [junit4:junit4] 2> 11385 T760 oasup.UpdateRequestProcessorChain.init inse= rting DistributedUpdateProcessorFactory into updateRequestProcessorChain "s= tored_sig" [junit4:junit4] 2> 11386 T760 oasup.UpdateRequestProcessorChain.init inse= rting DistributedUpdateProcessorFactory into updateRequestProcessorChain "u= niq-fields" [junit4:junit4] 2> 11387 T760 oasup.UpdateRequestProcessorChain.init inse= rting DistributedUpdateProcessorFactory into updateRequestProcessorChain "d= istrib-dup-test-chain-implicit" [junit4:junit4] 2> 11387 T760 oasc.RequestHandlers.initHandlersFromConfig= adding lazy requestHandler: solr.ReplicationHandler [junit4:junit4] 2> 11387 T760 oasc.RequestHandlers.initHandlersFromConfig= created /replication: solr.ReplicationHandler [junit4:junit4] 2> 11388 T760 oasc.RequestHandlers.initHandlersFromConfig= created standard: solr.StandardRequestHandler [junit4:junit4] 2> 11389 T760 oasc.RequestHandlers.initHandlersFromConfig= created /get: solr.RealTimeGetHandler [junit4:junit4] 2> 11390 T760 oasc.RequestHandlers.initHandlersFromConfig= created dismax: solr.SearchHandler [junit4:junit4] 2> 11390 T760 oasc.RequestHandlers.initHandlersFromConfig= created mock: org.apache.solr.core.MockQuerySenderListenerReqHandler [junit4:junit4] 2> 11391 T760 oasc.RequestHandlers.initHandlersFromConfig= created /admin/: org.apache.solr.handler.admin.AdminHandlers [junit4:junit4] 2> 11392 T760 oasc.RequestHandlers.initHandlersFromConfig= created defaults: solr.StandardRequestHandler [junit4:junit4] 2> 11392 T760 oasc.RequestHandlers.initHandlersFromConfig= adding lazy requestHandler: solr.StandardRequestHandler [junit4:junit4] 2> 11392 T760 oasc.RequestHandlers.initHandlersFromConfig= created lazy: solr.StandardRequestHandler [junit4:junit4] 2> 11393 T760 oasc.RequestHandlers.initHandlersFromConfig= created /update: solr.UpdateRequestHandler [junit4:junit4] 2> 11394 T760 oasc.RequestHandlers.initHandlersFromConfig= created /terms: org.apache.solr.handler.component.SearchHandler [junit4:junit4] 2> 11395 T760 oasc.RequestHandlers.initHandlersFromConfig= created spellCheckCompRH: org.apache.solr.handler.component.SearchHandler [junit4:junit4] 2> 11395 T760 oasc.RequestHandlers.initHandlersFromConfig= created spellCheckCompRH_Direct: org.apache.solr.handler.component.SearchH= andler [junit4:junit4] 2> 11396 T760 oasc.RequestHandlers.initHandlersFromConfig= created spellCheckWithWordbreak: org.apache.solr.handler.component.SearchH= andler [junit4:junit4] 2> 11397 T760 oasc.RequestHandlers.initHandlersFromConfig= created spellCheckWithWordbreak_Direct: org.apache.solr.handler.component.= SearchHandler [junit4:junit4] 2> 11397 T760 oasc.RequestHandlers.initHandlersFromConfig= created spellCheckCompRH1: org.apache.solr.handler.component.SearchHandler [junit4:junit4] 2> 11398 T760 oasc.RequestHandlers.initHandlersFromConfig= created mltrh: org.apache.solr.handler.component.SearchHandler [junit4:junit4] 2> 11399 T760 oasc.RequestHandlers.initHandlersFromConfig= created tvrh: org.apache.solr.handler.component.SearchHandler [junit4:junit4] 2> 11399 T760 oasc.RequestHandlers.initHandlersFromConfig= created /mlt: solr.MoreLikeThisHandler [junit4:junit4] 2> 11400 T760 oasc.RequestHandlers.initHandlersFromConfig= created /debug/dump: solr.DumpRequestHandler [junit4:junit4] 2> 11411 T760 oashl.XMLLoader.init xsltCacheLifetimeSecon= ds=3D60 [junit4:junit4] 2> 11414 T760 oasc.SolrCore.initDeprecatedSupport WARNING= solrconfig.xml uses deprecated , Please update your c= onfig to use the ShowFileRequestHandler. [junit4:junit4] 2> 11427 T760 oasc.SolrCore.initDeprecatedSupport WARNING= adding ShowFileRequestHandler with hidden files: [SCHEMA.XML, OLD_SYNONYMS= .TXT, STOPWORDS.TXT, PROTWORDS.TXT, OPEN-EXCHANGE-RATES.JSON, SYNONYMS.TXT,= CURRENCY.XML, MAPPING-ISOLATIN1ACCENT.TXT] [junit4:junit4] 2> 11431 T760 oasc.CachingDirectoryFactory.close Releasin= g directory:/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX= /solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZkTes= t-1359979901483/jetty2 [junit4:junit4] 2> 11433 T760 oass.SolrIndexSearcher. Opening Searc= her@6b6a6cfa main [junit4:junit4] 2> 11435 T760 oasu.CommitTracker. Hard AutoCommit: = disabled [junit4:junit4] 2> 11435 T760 oasu.CommitTracker. Soft AutoCommit: = disabled [junit4:junit4] 2> 11436 T760 oashc.SpellCheckComponent.inform Initializi= ng spell checkers [junit4:junit4] 2> 11442 T760 oass.DirectSolrSpellChecker.init init: {nam= e=3Ddirect,classname=3DDirectSolrSpellChecker,field=3Dlowerfilt,minQueryLen= gth=3D3} [junit4:junit4] 2> 11566 T761 oasc.SolrCore.registerSearcher [collection1= ] Registered new searcher Searcher@6b6a6cfa main{StandardDirectoryReader(se= gments_1:1)} [junit4:junit4] 2> 11576 T760 oasc.ZkController.publish publishing core= =3Dcollection1 state=3Ddown [junit4:junit4] 2> 11576 T760 oasc.ZkController.publish numShards not fou= nd on descriptor - reading it from system property [junit4:junit4] 2> 11890 T726 oascc.ZkStateReader.updateClusterState Upda= ting cloud state from ZooKeeper...=20 [junit4:junit4] 2> 11892 T726 oasc.Overseer$ClusterStateUpdater.updateSta= te Update state numShards=3D2 message=3D{ [junit4:junit4] 2> =09 "operation":"state", [junit4:junit4] 2> =09 "numShards":"2", [junit4:junit4] 2> =09 "shard":null, [junit4:junit4] 2> =09 "roles":null, [junit4:junit4] 2> =09 "state":"down", [junit4:junit4] 2> =09 "core":"collection1", [junit4:junit4] 2> =09 "collection":"collection1", [junit4:junit4] 2> =09 "node_name":"127.0.0.1:49318_", [junit4:junit4] 2> =09 "base_url":"http://127.0.0.1:49318"} [junit4:junit4] 2> 11892 T726 oasc.Overseer$ClusterStateUpdater.updateSta= te Collection already exists with numShards=3D2 [junit4:junit4] 2> 11893 T726 oasc.Overseer$ClusterStateUpdater.updateSta= te Assigning new node to shard shard=3Dshard2 [junit4:junit4] 2> 11902 T759 oascc.ZkStateReader$2.process A cluster sta= te change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clus= terstate.json, has occurred - updating... (live nodes size: 3) [junit4:junit4] 2> 11902 T725 oascc.ZkStateReader$2.process A cluster sta= te change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clus= terstate.json, has occurred - updating... (live nodes size: 3) [junit4:junit4] 2> 11902 T731 oascc.ZkStateReader$2.process A cluster sta= te change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clus= terstate.json, has occurred - updating... (live nodes size: 3) [junit4:junit4] 2> 11903 T744 oascc.ZkStateReader$2.process A cluster sta= te change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clus= terstate.json, has occurred - updating... (live nodes size: 3) [junit4:junit4] 2> 12619 T760 oasc.CoreContainer.registerCore registering= core: collection1 [junit4:junit4] 2> 12619 T760 oasc.ZkController.register Register replica= - core:collection1 address:http://127.0.0.1:49318 collection:collection1 s= hard:shard2 [junit4:junit4] 2> 12620 T760 oascc.SolrZkClient.makePath makePath: /coll= ections/collection1/leader_elect/shard2/election [junit4:junit4] 2> 12633 T708 oazs.PrepRequestProcessor.pRequest Got user= -level KeeperException when processing sessionid:0x13ca51e72390008 type:del= ete cxid:0x44 zxid:0x7e txntype:-1 reqpath:n/a Error Path:/solr/collections= /collection1/leaders/shard2 Error:KeeperErrorCode =3D NoNode for /solr/coll= ections/collection1/leaders/shard2 [junit4:junit4] 2> 12634 T760 oasc.ShardLeaderElectionContext.runLeaderPr= ocess Running the leader process. [junit4:junit4] 2> 12635 T708 oazs.PrepRequestProcessor.pRequest Got user= -level KeeperException when processing sessionid:0x13ca51e72390008 type:cre= ate cxid:0x45 zxid:0x7f txntype:-1 reqpath:n/a Error Path:/solr/overseer Er= ror:KeeperErrorCode =3D NodeExists for /solr/overseer [junit4:junit4] 2> 12644 T760 oasc.ShardLeaderElectionContext.waitForRepl= icasToComeUp Enough replicas found to continue. [junit4:junit4] 2> 12644 T760 oasc.ShardLeaderElectionContext.runLeaderPr= ocess I may be the new leader - try and sync [junit4:junit4] 2> 12644 T760 oasc.SyncStrategy.sync Sync replicas to htt= p://127.0.0.1:49318/collection1/ [junit4:junit4] 2> 12644 T760 oasc.SyncStrategy.syncReplicas Sync Success= - now sync replicas to me [junit4:junit4] 2> 12645 T760 oasc.SyncStrategy.syncToMe http://127.0.0.1= :49318/collection1/ has no replicas [junit4:junit4] 2> 12645 T760 oasc.ShardLeaderElectionContext.runLeaderPr= ocess I am the new leader: http://127.0.0.1:49318/collection1/ [junit4:junit4] 2> 12645 T760 oascc.SolrZkClient.makePath makePath: /coll= ections/collection1/leaders/shard2 [junit4:junit4] 2> 12652 T708 oazs.PrepRequestProcessor.pRequest Got user= -level KeeperException when processing sessionid:0x13ca51e72390008 type:cre= ate cxid:0x4e zxid:0x82 txntype:-1 reqpath:n/a Error Path:/solr/overseer Er= ror:KeeperErrorCode =3D NodeExists for /solr/overseer [junit4:junit4] 2> 13420 T726 oascc.ZkStateReader.updateClusterState Upda= ting cloud state from ZooKeeper...=20 [junit4:junit4] 2> 13459 T759 oascc.ZkStateReader$2.process A cluster sta= te change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clus= terstate.json, has occurred - updating... (live nodes size: 3) [junit4:junit4] 2> 13463 T731 oascc.ZkStateReader$2.process A cluster sta= te change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clus= terstate.json, has occurred - updating... (live nodes size: 3) [junit4:junit4] 2> 13464 T744 oascc.ZkStateReader$2.process A cluster sta= te change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clus= terstate.json, has occurred - updating... (live nodes size: 3) [junit4:junit4] 2> 13464 T725 oascc.ZkStateReader$2.process A cluster sta= te change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clus= terstate.json, has occurred - updating... (live nodes size: 3) [junit4:junit4] 2> 13486 T760 oasc.ZkController.register We are http://12= 7.0.0.1:49318/collection1/ and leader is http://127.0.0.1:49318/collection1= / [junit4:junit4] 2> 13487 T760 oasc.ZkController.register No LogReplay nee= ded for core=3Dcollection1 baseURL=3Dhttp://127.0.0.1:49318 [junit4:junit4] 2> 13487 T760 oasc.ZkController.checkRecovery I am the le= ader, no recovery necessary [junit4:junit4] 2> 13488 T760 oasc.ZkController.publish publishing core= =3Dcollection1 state=3Dactive [junit4:junit4] 2> 13488 T760 oasc.ZkController.publish numShards not fou= nd on descriptor - reading it from system property [junit4:junit4] 2> 13492 T760 oascc.ZkStateReader.updateClusterState Upda= ting cloud state from ZooKeeper...=20 [junit4:junit4] 2> 13494 T703 oass.SolrDispatchFilter.init user.dir=3D/Us= ers/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/sol= r-core/test/J0 [junit4:junit4] 2> 13494 T703 oass.SolrDispatchFilter.init SolrDispatchFi= lter.init() done [junit4:junit4] 2> 13495 T703 oascsi.HttpClientUtil.createClient Creating= new http client, config:maxConnections=3D128&maxConnectionsPerHost=3D32&fo= llowRedirects=3Dfalse [junit4:junit4] 2> 13787 T703 oejs.Server.doStart jetty-8.1.8.v20121106 [junit4:junit4] 2> 13791 T703 oejs.AbstractConnector.doStart Started Sele= ctChannelConnector@127.0.0.1:49321 [junit4:junit4] 2> 13792 T703 oass.SolrDispatchFilter.init SolrDispatchFi= lter.init() [junit4:junit4] 2> 13793 T703 oasc.SolrResourceLoader.locateSolrHome JNDI= not configured for solr (NoInitialContextEx) [junit4:junit4] 2> 13793 T703 oasc.SolrResourceLoader.locateSolrHome usin= g system property solr.solr.home: /Users/jenkins/jenkins-slave/workspace/Lu= cene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud= .BasicDistributedZkTest-jetty3-1359979914979 [junit4:junit4] 2> 13794 T703 oasc.CoreContainer$Initializer.initialize l= ooking for solr.xml: /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-tru= nk-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistrib= utedZkTest-jetty3-1359979914979/solr.xml [junit4:junit4] 2> 13794 T703 oasc.CoreContainer. New CoreContainer= 656295850 [junit4:junit4] 2> 13795 T703 oasc.CoreContainer.load Loading CoreContain= er using Solr Home: '/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-tru= nk-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistrib= utedZkTest-jetty3-1359979914979/' [junit4:junit4] 2> 13795 T703 oasc.SolrResourceLoader. new SolrReso= urceLoader for directory: '/Users/jenkins/jenkins-slave/workspace/Lucene-So= lr-trunk-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicD= istributedZkTest-jetty3-1359979914979/' [junit4:junit4] 2> 13862 T703 oashc.HttpShardHandlerFactory.getParameter = Setting socketTimeout to: 60000 [junit4:junit4] 2> 13863 T703 oashc.HttpShardHandlerFactory.getParameter = Setting urlScheme to: http:// [junit4:junit4] 2> 13863 T703 oashc.HttpShardHandlerFactory.getParameter = Setting connTimeout to: 15000 [junit4:junit4] 2> 13864 T703 oashc.HttpShardHandlerFactory.getParameter = Setting maxConnectionsPerHost to: 20 [junit4:junit4] 2> 13864 T703 oashc.HttpShardHandlerFactory.getParameter = Setting corePoolSize to: 0 [junit4:junit4] 2> 13865 T703 oashc.HttpShardHandlerFactory.getParameter = Setting maximumPoolSize to: 2147483647 [junit4:junit4] 2> 13865 T703 oashc.HttpShardHandlerFactory.getParameter = Setting maxThreadIdleTime to: 5 [junit4:junit4] 2> 13866 T703 oashc.HttpShardHandlerFactory.getParameter = Setting sizeOfQueue to: -1 [junit4:junit4] 2> 13866 T703 oashc.HttpShardHandlerFactory.getParameter = Setting fairnessPolicy to: false [junit4:junit4] 2> 13866 T703 oascsi.HttpClientUtil.createClient Creating= new http client, config:maxConnectionsPerHost=3D20&maxConnections=3D10000&= socketTimeout=3D60000&connTimeout=3D15000&retry=3Dfalse [junit4:junit4] 2> 13896 T703 oasc.CoreContainer.load Registering Log Lis= tener [junit4:junit4] 2> 13913 T703 oasc.CoreContainer.initZooKeeper Zookeeper = client=3D127.0.0.1:49308/solr [junit4:junit4] 2> 13914 T703 oasc.ZkController.checkChrootPath zkHost in= cludes chroot [junit4:junit4] 2> 13914 T703 oaz.ZooKeeper. Initiating client conn= ection, connectString=3D127.0.0.1:49308 sessionTimeout=3D60000 watcher=3Dor= g.apache.solr.common.cloud.ConnectionManager@3c24867e [junit4:junit4] 2> 13916 T703 oascc.ConnectionManager.waitForConnected Wa= iting for client to connect to ZooKeeper [junit4:junit4] 2> 13917 T771 oaz.ClientCnxn$SendThread.logStartConnect O= pening socket connection to server localhost/127.0.0.1:49308. Will not atte= mpt to authenticate using SASL (access denied ("javax.security.auth.AuthPer= mission" "getLoginConfiguration")) [junit4:junit4] 2> 13917 T771 oaz.ClientCnxn$SendThread.primeConnection S= ocket connection established to localhost/127.0.0.1:49308, initiating sessi= on [junit4:junit4] 2> 13918 T705 oazs.NIOServerCnxnFactory.run Accepted sock= et connection from /127.0.0.1:49322 [junit4:junit4] 2> 13919 T705 oazs.ZooKeeperServer.processConnectRequest = Client attempting to establish new session at /127.0.0.1:49322 [junit4:junit4] 2> 13920 T707 oazs.ZooKeeperServer.finishSessionInit Esta= blished session 0x13ca51e72390009 with negotiated timeout 20000 for client = /127.0.0.1:49322 [junit4:junit4] 2> 13920 T771 oaz.ClientCnxn$SendThread.onConnected Sessi= on establishment complete on server localhost/127.0.0.1:49308, sessionid = =3D 0x13ca51e72390009, negotiated timeout =3D 20000 [junit4:junit4] 2> 13921 T772 oascc.ConnectionManager.process Watcher org= .apache.solr.common.cloud.ConnectionManager@3c24867e name:ZooKeeperConnecti= on Watcher:127.0.0.1:49308 got event WatchedEvent state:SyncConnected type:= None path:null path:null type:None [junit4:junit4] 2> 13921 T703 oascc.ConnectionManager.waitForConnected Cl= ient is connected to ZooKeeper [junit4:junit4] 2> 13924 T708 oazs.PrepRequestProcessor.pRequest2Txn Proc= essed session termination for sessionid: 0x13ca51e72390009 [junit4:junit4] 2> 13925 T705 oazs.NIOServerCnxn.closeSock Closed socket = connection for client /127.0.0.1:49322 which had sessionid 0x13ca51e7239000= 9 [junit4:junit4] 2> 13925 T772 oaz.ClientCnxn$EventThread.run EventThread = shut down [junit4:junit4] 2> 13925 T703 oaz.ZooKeeper.close Session: 0x13ca51e72390= 009 closed [junit4:junit4] 2> 13926 T703 oascsi.HttpClientUtil.createClient Creating= new http client, config:maxConnections=3D500&maxConnectionsPerHost=3D16&so= cketTimeout=3D60000&connTimeout=3D15000 [junit4:junit4] 2> 13932 T703 oaz.ZooKeeper. Initiating client conn= ection, connectString=3D127.0.0.1:49308/solr sessionTimeout=3D30000 watcher= =3Dorg.apache.solr.common.cloud.ConnectionManager@296f4446 [junit4:junit4] 2> 13934 T773 oaz.ClientCnxn$SendThread.logStartConnect O= pening socket connection to server localhost/127.0.0.1:49308. Will not atte= mpt to authenticate using SASL (access denied ("javax.security.auth.AuthPer= mission" "getLoginConfiguration")) [junit4:junit4] 2> 13934 T703 oascc.ConnectionManager.waitForConnected Wa= iting for client to connect to ZooKeeper [junit4:junit4] 2> 13935 T773 oaz.ClientCnxn$SendThread.primeConnection S= ocket connection established to localhost/127.0.0.1:49308, initiating sessi= on [junit4:junit4] 2> 13940 T705 oazs.NIOServerCnxnFactory.run Accepted sock= et connection from /127.0.0.1:49323 [junit4:junit4] 2> 13942 T705 oazs.ZooKeeperServer.processConnectRequest = Client attempting to establish new session at /127.0.0.1:49323 [junit4:junit4] 2> 13943 T707 oazs.ZooKeeperServer.finishSessionInit Esta= blished session 0x13ca51e7239000a with negotiated timeout 20000 for client = /127.0.0.1:49323 [junit4:junit4] 2> 13943 T773 oaz.ClientCnxn$SendThread.onConnected Sessi= on establishment complete on server localhost/127.0.0.1:49308, sessionid = =3D 0x13ca51e7239000a, negotiated timeout =3D 20000 [junit4:junit4] 2> 13944 T774 oascc.ConnectionManager.process Watcher org= .apache.solr.common.cloud.ConnectionManager@296f4446 name:ZooKeeperConnecti= on Watcher:127.0.0.1:49308/solr got event WatchedEvent state:SyncConnected = type:None path:null path:null type:None [junit4:junit4] 2> 13944 T703 oascc.ConnectionManager.waitForConnected Cl= ient is connected to ZooKeeper [junit4:junit4] 2> 13955 T708 oazs.PrepRequestProcessor.pRequest Got user= -level KeeperException when processing sessionid:0x13ca51e7239000a type:cre= ate cxid:0x1 zxid:0x8f txntype:-1 reqpath:n/a Error Path:/solr/overseer Err= or:KeeperErrorCode =3D NodeExists for /solr/overseer [junit4:junit4] 2> 13957 T708 oazs.PrepRequestProcessor.pRequest Got user= -level KeeperException when processing sessionid:0x13ca51e7239000a type:cre= ate cxid:0x2 zxid:0x90 txntype:-1 reqpath:n/a Error Path:/solr/overseer Err= or:KeeperErrorCode =3D NodeExists for /solr/overseer [junit4:junit4] 2> 13960 T703 oasc.ZkController.createEphemeralLiveNode R= egister node as live in ZooKeeper:/live_nodes/127.0.0.1:49321_ [junit4:junit4] 2> 13961 T708 oazs.PrepRequestProcessor.pRequest Got user= -level KeeperException when processing sessionid:0x13ca51e7239000a type:del= ete cxid:0x4 zxid:0x91 txntype:-1 reqpath:n/a Error Path:/solr/live_nodes/1= 27.0.0.1:49321_ Error:KeeperErrorCode =3D NoNode for /solr/live_nodes/127.0= .0.1:49321_ [junit4:junit4] 2> 14019 T703 oascc.SolrZkClient.makePath makePath: /live= _nodes/127.0.0.1:49321_ [junit4:junit4] 2> 14025 T744 oascc.ZkStateReader$2.process A cluster sta= te change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/= live_nodes, has occurred - updating... (live nodes size: 3) [junit4:junit4] 2> 14025 T759 oascc.ZkStateReader$2.process A cluster sta= te change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/= live_nodes, has occurred - updating... (live nodes size: 3) [junit4:junit4] 2> 14026 T731 oascc.ZkStateReader$2.process A cluster sta= te change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/= live_nodes, has occurred - updating... (live nodes size: 3) [junit4:junit4] 2> 14026 T725 oascc.ZkStateReader$3.process Updating live= nodes... (4) [junit4:junit4] 2> 14026 T725 oascc.ZkStateReader$2.process A cluster sta= te change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/= live_nodes, has occurred - updating... (live nodes size: 4) [junit4:junit4] 2> 14030 T759 oascc.ZkStateReader$3.process Updating live= nodes... (4) [junit4:junit4] 2> 14030 T731 oascc.ZkStateReader$3.process Updating live= nodes... (4) [junit4:junit4] 2> 14031 T744 oascc.ZkStateReader$3.process Updating live= nodes... (4) [junit4:junit4] 2> 14038 T703 oascc.ZkStateReader.createClusterStateWatch= ersAndUpdate Updating cluster state from ZooKeeper...=20 [junit4:junit4] 2> 14046 T775 oasc.CoreContainer.create Creating SolrCore= 'collection1' using instanceDir: /Users/jenkins/jenkins-slave/workspace/Lu= cene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud= .BasicDistributedZkTest-jetty3-1359979914979/collection1 [junit4:junit4] 2> 14046 T775 oasc.ZkController.createCollectionZkNode Ch= eck for collection zkNode:collection1 [junit4:junit4] 2> 14047 T775 oasc.ZkController.createCollectionZkNode Co= llection zkNode exists [junit4:junit4] 2> 14047 T775 oasc.ZkController.readConfigName Load colle= ction config from:/collections/collection1 [junit4:junit4] 2> 14049 T775 oasc.SolrResourceLoader. new SolrReso= urceLoader for directory: '/Users/jenkins/jenkins-slave/workspace/Lucene-So= lr-trunk-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicD= istributedZkTest-jetty3-1359979914979/collection1/' [junit4:junit4] 2> 14050 T775 oasc.SolrResourceLoader.replaceClassLoader = Adding 'file:/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOS= X/solr/build/solr-core/test/J0/org.apache.solr.cloud.BasicDistributedZkTest= -jetty3-1359979914979/collection1/lib/classes/' to classloader [junit4:junit4] 2> 14050 T775 oasc.SolrResourceLoader.replaceClassLoader = Adding 'file:/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOS= X/solr/build/solr-core/test/J0/org.apache.solr.cloud.BasicDistributedZkTest= -jetty3-1359979914979/collection1/lib/README' to classloader [junit4:junit4] 2> 14123 T775 oasc.SolrConfig. Using Lucene MatchVe= rsion: LUCENE_50 [junit4:junit4] 2> 14225 T775 oasc.SolrConfig. Loaded SolrConfig: s= olrconfig.xml [junit4:junit4] 2> 14227 T775 oass.IndexSchema.readSchema Reading Solr Sc= hema [junit4:junit4] 2> 14238 T775 oass.IndexSchema.readSchema Schema name=3Dt= est [junit4:junit4] 2> 14989 T726 oascc.ZkStateReader.updateClusterState Upda= ting cloud state from ZooKeeper...=20 [junit4:junit4] 2> 14991 T726 oasc.Overseer$ClusterStateUpdater.updateSta= te Update state numShards=3D2 message=3D{ [junit4:junit4] 2> =09 "operation":"state", [junit4:junit4] 2> =09 "numShards":"2", [junit4:junit4] 2> =09 "shard":"shard2", [junit4:junit4] 2> =09 "roles":null, [junit4:junit4] 2> =09 "state":"active", [junit4:junit4] 2> =09 "core":"collection1", [junit4:junit4] 2> =09 "collection":"collection1", [junit4:junit4] 2> =09 "node_name":"127.0.0.1:49318_", [junit4:junit4] 2> =09 "base_url":"http://127.0.0.1:49318"} [junit4:junit4] 2> 15029 T725 oascc.ZkStateReader$2.process A cluster sta= te change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clus= terstate.json, has occurred - updating... (live nodes size: 4) [junit4:junit4] 2> 15030 T731 oascc.ZkStateReader$2.process A cluster sta= te change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clus= terstate.json, has occurred - updating... (live nodes size: 4) [junit4:junit4] 2> 15038 T759 oascc.ZkStateReader$2.process A cluster sta= te change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clus= terstate.json, has occurred - updating... (live nodes size: 4) [junit4:junit4] 2> 15040 T744 oascc.ZkStateReader$2.process A cluster sta= te change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clus= terstate.json, has occurred - updating... (live nodes size: 4) [junit4:junit4] 2> 15041 T774 oascc.ZkStateReader$2.process A cluster sta= te change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clus= terstate.json, has occurred - updating... (live nodes size: 4) [junit4:junit4] 2> 15139 T775 oass.OpenExchangeRatesOrgProvider.init Init= ialized with rates=3Dopen-exchange-rates.json, refreshInterval=3D1440. [junit4:junit4] 2> 15160 T775 oass.IndexSchema.readSchema default search = field in schema is text [junit4:junit4] 2> 15168 T775 oass.IndexSchema.readSchema unique key fiel= d: id [junit4:junit4] 2> 15197 T775 oass.FileExchangeRateProvider.reload Reload= ing exchange rates from file currency.xml [junit4:junit4] 2> 15206 T775 oass.FileExchangeRateProvider.reload Reload= ing exchange rates from file currency.xml [junit4:junit4] 2> 15214 T775 oass.OpenExchangeRatesOrgProvider.reload Re= loading exchange rates from open-exchange-rates.json [junit4:junit4] 2> 15220 T775 oass.OpenExchangeRatesOrgProvider.reload Re= loading exchange rates from open-exchange-rates.json [junit4:junit4] 2> 15225 T775 oasc.SolrCore. [collection1] Opening = new SolrCore at /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-Ma= cOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZ= kTest-jetty3-1359979914979/collection1/, dataDir=3D./org.apache.solr.cloud.= BasicDistributedZkTest-1359979901483/jetty3/ [junit4:junit4] 2> 15226 T775 oasc.JmxMonitoredMap. JMX monitoring = is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMB= eanServer@36298619 [junit4:junit4] 2> 15226 T775 oasc.SolrCore.initDirectoryFactory solr.NRT= CachingDirectoryFactory [junit4:junit4] 2> 15227 T775 oasc.CachingDirectoryFactory.get return new= directory for /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-Mac= OSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZk= Test-1359979901483/jetty3 forceNew:false [junit4:junit4] 2> 15228 T775 oasc.CachingDirectoryFactory.close Releasin= g directory:/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX= /solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZkTes= t-1359979901483/jetty3 [junit4:junit4] 2> 15228 T775 oasc.SolrCore.getNewIndexDir New index dire= ctory detected: old=3Dnull new=3D./org.apache.solr.cloud.BasicDistributedZk= Test-1359979901483/jetty3/index/ [junit4:junit4] 2> 15228 T775 oasc.SolrCore.initIndex WARNING [collection= 1] Solr index directory './org.apache.solr.cloud.BasicDistributedZkTest-135= 9979901483/jetty3/index' doesn't exist. Creating new index... [junit4:junit4] 2> 15229 T775 oasc.CachingDirectoryFactory.get return new= directory for /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-Mac= OSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZk= Test-1359979901483/jetty3/index forceNew:false [junit4:junit4] 2> 15238 T775 oasc.SolrDeletionPolicy.onCommit SolrDeleti= onPolicy.onCommit: commits:num=3D1 [junit4:junit4] 2> =09=09commit{dir=3DRateLimitedDirectoryWrapper(NRTCach= ingDirectory(org.apache.lucene.store.NIOFSDirectory@/Users/jenkins/jenkins-= slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/org.a= pache.solr.cloud.BasicDistributedZkTest-1359979901483/jetty3/index lockFact= ory=3Dorg.apache.lucene.store.NativeFSLockFactory@491e2104; maxCacheMB=3D48= .0 maxMergeSizeMB=3D4.0)),segFN=3Dsegments_1,generation=3D1,filenames=3D[se= gments_1] [junit4:junit4] 2> 15239 T775 oasc.SolrDeletionPolicy.updateCommits newes= t commit =3D 1[segments_1] [junit4:junit4] 2> 15243 T775 oasc.CachingDirectoryFactory.close Releasin= g directory:/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX= /solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZkTes= t-1359979901483/jetty3/index [junit4:junit4] 2> 15244 T775 oasc.SolrCore.initWriters created xml: solr= .XMLResponseWriter [junit4:junit4] 2> 15246 T775 oasup.UpdateRequestProcessorChain.init inse= rting DistributedUpdateProcessorFactory into updateRequestProcessorChain "d= edupe" [junit4:junit4] 2> 15247 T775 oasup.UpdateRequestProcessorChain.init inse= rting DistributedUpdateProcessorFactory into updateRequestProcessorChain "d= edupe-allfields" [junit4:junit4] 2> 15247 T775 oasup.UpdateRequestProcessorChain.init inse= rting DistributedUpdateProcessorFactory into updateRequestProcessorChain "s= tored_sig" [junit4:junit4] 2> 15248 T775 oasup.UpdateRequestProcessorChain.init inse= rting DistributedUpdateProcessorFactory into updateRequestProcessorChain "u= niq-fields" [junit4:junit4] 2> 15248 T775 oasup.UpdateRequestProcessorChain.init inse= rting DistributedUpdateProcessorFactory into updateRequestProcessorChain "d= istrib-dup-test-chain-implicit" [junit4:junit4] 2> 15249 T775 oasc.RequestHandlers.initHandlersFromConfig= adding lazy requestHandler: solr.ReplicationHandler [junit4:junit4] 2> 15249 T775 oasc.RequestHandlers.initHandlersFromConfig= created /replication: solr.ReplicationHandler [junit4:junit4] 2> 15250 T775 oasc.RequestHandlers.initHandlersFromConfig= created standard: solr.StandardRequestHandler [junit4:junit4] 2> 15250 T775 oasc.RequestHandlers.initHandlersFromConfig= created /get: solr.RealTimeGetHandler [junit4:junit4] 2> 15251 T775 oasc.RequestHandlers.initHandlersFromConfig= created dismax: solr.SearchHandler [junit4:junit4] 2> 15252 T775 oasc.RequestHandlers.initHandlersFromConfig= created mock: org.apache.solr.core.MockQuerySenderListenerReqHandler [junit4:junit4] 2> 15252 T775 oasc.RequestHandlers.initHandlersFromConfig= created /admin/: org.apache.solr.handler.admin.AdminHandlers [junit4:junit4] 2> 15253 T775 oasc.RequestHandlers.initHandlersFromConfig= created defaults: solr.StandardRequestHandler [junit4:junit4] 2> 15253 T775 oasc.RequestHandlers.initHandlersFromConfig= adding lazy requestHandler: solr.StandardRequestHandler [junit4:junit4] 2> 15253 T775 oasc.RequestHandlers.initHandlersFromConfig= created lazy: solr.StandardRequestHandler [junit4:junit4] 2> 15255 T775 oasc.RequestHandlers.initHandlersFromConfig= created /update: solr.UpdateRequestHandler [junit4:junit4] 2> 15255 T775 oasc.RequestHandlers.initHandlersFromConfig= created /terms: org.apache.solr.handler.component.SearchHandler [junit4:junit4] 2> 15256 T775 oasc.RequestHandlers.initHandlersFromConfig= created spellCheckCompRH: org.apache.solr.handler.component.SearchHandler [junit4:junit4] 2> 15256 T775 oasc.RequestHandlers.initHandlersFromConfig= created spellCheckCompRH_Direct: org.apache.solr.handler.component.SearchH= andler [junit4:junit4] 2> 15257 T775 oasc.RequestHandlers.initHandlersFromConfig= created spellCheckWithWordbreak: org.apache.solr.handler.component.SearchH= andler [junit4:junit4] 2> 15258 T775 oasc.RequestHandlers.initHandlersFromConfig= created spellCheckWithWordbreak_Direct: org.apache.solr.handler.component.= SearchHandler [junit4:junit4] 2> 15258 T775 oasc.RequestHandlers.initHandlersFromConfig= created spellCheckCompRH1: org.apache.solr.handler.component.SearchHandler [junit4:junit4] 2> 15259 T775 oasc.RequestHandlers.initHandlersFromConfig= created mltrh: org.apache.solr.handler.component.SearchHandler [junit4:junit4] 2> 15260 T775 oasc.RequestHandlers.initHandlersFromConfig= created tvrh: org.apache.solr.handler.component.SearchHandler [junit4:junit4] 2> 15260 T775 oasc.RequestHandlers.initHandlersFromConfig= created /mlt: solr.MoreLikeThisHandler [junit4:junit4] 2> 15261 T775 oasc.RequestHandlers.initHandlersFromConfig= created /debug/dump: solr.DumpRequestHandler [junit4:junit4] 2> 15273 T775 oashl.XMLLoader.init xsltCacheLifetimeSecon= ds=3D60 [junit4:junit4] 2> 15276 T775 oasc.SolrCore.initDeprecatedSupport WARNING= solrconfig.xml uses deprecated , Please update your c= onfig to use the ShowFileRequestHandler. [junit4:junit4] 2> 15278 T775 oasc.SolrCore.initDeprecatedSupport WARNING= adding ShowFileRequestHandler with hidden files: [SCHEMA.XML, OLD_SYNONYMS= .TXT, STOPWORDS.TXT, PROTWORDS.TXT, OPEN-EXCHANGE-RATES.JSON, SYNONYMS.TXT,= CURRENCY.XML, MAPPING-ISOLATIN1ACCENT.TXT] [junit4:junit4] 2> 15281 T775 oasc.CachingDirectoryFactory.close Releasin= g directory:/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX= /solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZkTes= t-1359979901483/jetty3 [junit4:junit4] 2> 15282 T775 oass.SolrIndexSearcher. Opening Searc= her@590839ce main [junit4:junit4] 2> 15286 T775 oasu.CommitTracker. Hard AutoCommit: = disabled [junit4:junit4] 2> 15286 T775 oasu.CommitTracker. Soft AutoCommit: = disabled [junit4:junit4] 2> 15286 T775 oashc.SpellCheckComponent.inform Initializi= ng spell checkers [junit4:junit4] 2> 15293 T775 oass.DirectSolrSpellChecker.init init: {nam= e=3Ddirect,classname=3DDirectSolrSpellChecker,field=3Dlowerfilt,minQueryLen= gth=3D3} [junit4:junit4] 2> 15352 T775 oasc.ZkController.publish publishing core= =3Dcollection1 state=3Ddown [junit4:junit4] 2> 15352 T775 oasc.ZkController.publish numShards not fou= nd on descriptor - reading it from system property [junit4:junit4] 2> 15355 T776 oasc.SolrCore.registerSearcher [collection1= ] Registered new searcher Searcher@590839ce main{StandardDirectoryReader(se= gments_1:1)} [junit4:junit4] 2> 16556 T726 oascc.ZkStateReader.updateClusterState Upda= ting cloud state from ZooKeeper...=20 [junit4:junit4] 2> 16558 T726 oasc.Overseer$ClusterStateUpdater.updateSta= te Update state numShards=3D2 message=3D{ [junit4:junit4] 2> =09 "operation":"state", [junit4:junit4] 2> =09 "numShards":"2", [junit4:junit4] 2> =09 "shard":null, [junit4:junit4] 2> =09 "roles":null, [junit4:junit4] 2> =09 "state":"down", [junit4:junit4] 2> =09 "core":"collection1", [junit4:junit4] 2> =09 "collection":"collection1", [junit4:junit4] 2> =09 "node_name":"127.0.0.1:49321_", [junit4:junit4] 2> =09 "base_url":"http://127.0.0.1:49321"} [junit4:junit4] 2> 16559 T726 oasc.Overseer$ClusterStateUpdater.updateSta= te Collection already exists with numShards=3D2 [junit4:junit4] 2> 16559 T726 oasc.Overseer$ClusterStateUpdater.updateSta= te Assigning new node to shard shard=3Dshard1 [junit4:junit4] 2> 16572 T725 oascc.ZkStateReader$2.process A cluster sta= te change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clus= terstate.json, has occurred - updating... (live nodes size: 4) [junit4:junit4] 2> 16572 T731 oascc.ZkStateReader$2.process A cluster sta= te change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clus= terstate.json, has occurred - updating... (live nodes size: 4) [junit4:junit4] 2> 16573 T744 oascc.ZkStateReader$2.process A cluster sta= te change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clus= terstate.json, has occurred - updating... (live nodes size: 4) [junit4:junit4] 2> 16572 T774 oascc.ZkStateReader$2.process A cluster sta= te change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clus= terstate.json, has occurred - updating... (live nodes size: 4) [junit4:junit4] 2> 16573 T759 oascc.ZkStateReader$2.process A cluster sta= te change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clus= terstate.json, has occurred - updating... (live nodes size: 4) [junit4:junit4] 2> 17373 T775 oasc.CoreContainer.registerCore registering= core: collection1 [junit4:junit4] 2> 17374 T775 oasc.ZkController.register Register replica= - core:collection1 address:http://127.0.0.1:49321 collection:collection1 s= hard:shard1 [junit4:junit4] 2> 17379 T775 oasc.ZkController.register We are http://12= 7.0.0.1:49321/collection1/ and leader is http://127.0.0.1:49315/collection1= / [junit4:junit4] 2> 17379 T775 oasc.ZkController.register No LogReplay nee= ded for core=3Dcollection1 baseURL=3Dhttp://127.0.0.1:49321 [junit4:junit4] 2> 17380 T775 oasc.ZkController.checkRecovery Core needs = to recover:collection1 [junit4:junit4] 2> 17380 T775 oasu.DefaultSolrCoreState.doRecovery Runnin= g recovery - first canceling any ongoing recovery [junit4:junit4] 2> ASYNC NEW_CORE C49 name=3Dcollection1 org.apache.solr= .core.SolrCore@475b32ea url=3Dhttp://127.0.0.1:49321/collection1 node=3D127= .0.0.1:49321_ C49_STATE=3Dcoll:collection1 core:collection1 props:{shard=3D= null, roles=3Dnull, state=3Ddown, core=3Dcollection1, collection=3Dcollecti= on1, node_name=3D127.0.0.1:49321_, base_url=3Dhttp://127.0.0.1:49321} [junit4:junit4] 2> 17385 T777 C49 P49321 oasc.RecoveryStrategy.run Starti= ng recovery process. core=3Dcollection1 recoveringAfterStartup=3Dtrue [junit4:junit4] 2> 17388 T777 C49 P49321 oasc.RecoveryStrategy.doRecovery= ###### startupVersions=3D[] [junit4:junit4] 2> 17389 T777 C49 P49321 oasc.ZkController.publish publis= hing core=3Dcollection1 state=3Drecovering [junit4:junit4] 2> 17389 T777 C49 P49321 oasc.ZkController.publish numSha= rds not found on descriptor - reading it from system property [junit4:junit4] 2> 17391 T775 oascc.ZkStateReader.updateClusterState Upda= ting cloud state from ZooKeeper...=20 [junit4:junit4] 2> 17393 T777 C49 P49321 oascsi.HttpClientUtil.createClie= nt Creating new http client, config:maxConnections=3D128&maxConnectionsPerH= ost=3D32&followRedirects=3Dfalse [junit4:junit4] 2> 17393 T703 oass.SolrDispatchFilter.init user.dir=3D/Us= ers/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/sol= r-core/test/J0 [junit4:junit4] 2> 17394 T703 oass.SolrDispatchFilter.init SolrDispatchFi= lter.init() done [junit4:junit4] 2> 17394 T703 oascsi.HttpClientUtil.createClient Creating= new http client, config:maxConnections=3D128&maxConnectionsPerHost=3D32&fo= llowRedirects=3Dfalse [junit4:junit4] 2> 17610 T703 oejs.Server.doStart jetty-8.1.8.v20121106 [junit4:junit4] 2> 17619 T703 oejs.AbstractConnector.doStart Started Sele= ctChannelConnector@127.0.0.1:49325 [junit4:junit4] 2> 17620 T703 oass.SolrDispatchFilter.init SolrDispatchFi= lter.init() [junit4:junit4] 2> 17621 T703 oasc.SolrResourceLoader.locateSolrHome JNDI= not configured for solr (NoInitialContextEx) [junit4:junit4] 2> 17621 T703 oasc.SolrResourceLoader.locateSolrHome usin= g system property solr.solr.home: /Users/jenkins/jenkins-slave/workspace/Lu= cene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud= .BasicDistributedZkTest-jetty4-1359979918872 [junit4:junit4] 2> 17622 T703 oasc.CoreContainer$Initializer.initialize l= ooking for solr.xml: /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-tru= nk-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistrib= utedZkTest-jetty4-1359979918872/solr.xml [junit4:junit4] 2> 17622 T703 oasc.CoreContainer. New CoreContainer= 289047866 [junit4:junit4] 2> 17623 T703 oasc.CoreContainer.load Loading CoreContain= er using Solr Home: '/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-tru= nk-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistrib= utedZkTest-jetty4-1359979918872/' [junit4:junit4] 2> 17623 T703 oasc.SolrResourceLoader. new SolrReso= urceLoader for directory: '/Users/jenkins/jenkins-slave/workspace/Lucene-So= lr-trunk-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicD= istributedZkTest-jetty4-1359979918872/' [junit4:junit4] 2> 17675 T703 oashc.HttpShardHandlerFactory.getParameter = Setting socketTimeout to: 60000 [junit4:junit4] 2> 17676 T703 oashc.HttpShardHandlerFactory.getParameter = Setting urlScheme to: http:// [junit4:junit4] 2> 17677 T703 oashc.HttpShardHandlerFactory.getParameter = Setting connTimeout to: 15000 [junit4:junit4] 2> 17678 T703 oashc.HttpShardHandlerFactory.getParameter = Setting maxConnectionsPerHost to: 20 [junit4:junit4] 2> 17678 T703 oashc.HttpShardHandlerFactory.getParameter = Setting corePoolSize to: 0 [junit4:junit4] 2> 17679 T703 oashc.HttpShardHandlerFactory.getParameter = Setting maximumPoolSize to: 2147483647 [junit4:junit4] 2> 17680 T703 oashc.HttpShardHandlerFactory.getParameter = Setting maxThreadIdleTime to: 5 [junit4:junit4] 2> 17680 T703 oashc.HttpShardHandlerFactory.getParameter = Setting sizeOfQueue to: -1 [junit4:junit4] 2> 17681 T703 oashc.HttpShardHandlerFactory.getParameter = Setting fairnessPolicy to: false [junit4:junit4] 2> 17682 T703 oascsi.HttpClientUtil.createClient Creating= new http client, config:maxConnectionsPerHost=3D20&maxConnections=3D10000&= socketTimeout=3D60000&connTimeout=3D15000&retry=3Dfalse [junit4:junit4] 2> 17718 T703 oasc.CoreContainer.load Registering Log Lis= tener [junit4:junit4] 2> 17788 T703 oasc.CoreContainer.initZooKeeper Zookeeper = client=3D127.0.0.1:49308/solr [junit4:junit4] 2> 17789 T703 oasc.ZkController.checkChrootPath zkHost in= cludes chroot [junit4:junit4] 2> 17790 T703 oaz.ZooKeeper. Initiating client conn= ection, connectString=3D127.0.0.1:49308 sessionTimeout=3D60000 watcher=3Dor= g.apache.solr.common.cloud.ConnectionManager@52235873 [junit4:junit4] 2> 17792 T703 oascc.ConnectionManager.waitForConnected Wa= iting for client to connect to ZooKeeper [junit4:junit4] 2> 17792 T787 oaz.ClientCnxn$SendThread.logStartConnect O= pening socket connection to server localhost/127.0.0.1:49308. Will not atte= mpt to authenticate using SASL (access denied ("javax.security.auth.AuthPer= mission" "getLoginConfiguration")) [junit4:junit4] 2> 17794 T787 oaz.ClientCnxn$SendThread.primeConnection S= ocket connection established to localhost/127.0.0.1:49308, initiating sessi= on [junit4:junit4] 2> 17794 T705 oazs.NIOServerCnxnFactory.run Accepted sock= et connection from /127.0.0.1:49326 [junit4:junit4] 2> 17795 T705 oazs.ZooKeeperServer.processConnectRequest = Client attempting to establish new session at /127.0.0.1:49326 [junit4:junit4] 2> 17797 T707 oazs.ZooKeeperServer.finishSessionInit Esta= blished session 0x13ca51e7239000b with negotiated timeout 20000 for client = /127.0.0.1:49326 [junit4:junit4] 2> 17797 T787 oaz.ClientCnxn$SendThread.onConnected Sessi= on establishment complete on server localhost/127.0.0.1:49308, sessionid = =3D 0x13ca51e7239000b, negotiated timeout =3D 20000 [junit4:junit4] 2> 17797 T788 oascc.ConnectionManager.process Watcher org= .apache.solr.common.cloud.ConnectionManager@52235873 name:ZooKeeperConnecti= on Watcher:127.0.0.1:49308 got event WatchedEvent state:SyncConnected type:= None path:null path:null type:None [junit4:junit4] 2> 17801 T703 oascc.ConnectionManager.waitForConnected Cl= ient is connected to ZooKeeper [junit4:junit4] 2> 17804 T708 oazs.PrepRequestProcessor.pRequest2Txn Proc= essed session termination for sessionid: 0x13ca51e7239000b [junit4:junit4] 2> 17805 T705 oazs.NIOServerCnxn.closeSock Closed socket = connection for client /127.0.0.1:49326 which had sessionid 0x13ca51e7239000= b [junit4:junit4] 2> 17805 T788 oaz.ClientCnxn$EventThread.run EventThread = shut down [junit4:junit4] 2> 17805 T703 oaz.ZooKeeper.close Session: 0x13ca51e72390= 00b closed [junit4:junit4] 2> 17806 T703 oascsi.HttpClientUtil.createClient Creating= new http client, config:maxConnections=3D500&maxConnectionsPerHost=3D16&so= cketTimeout=3D60000&connTimeout=3D15000 [junit4:junit4] 2> 17817 T703 oaz.ZooKeeper. Initiating client conn= ection, connectString=3D127.0.0.1:49308/solr sessionTimeout=3D30000 watcher= =3Dorg.apache.solr.common.cloud.ConnectionManager@7de2d422 [junit4:junit4] 2> 17819 T703 oascc.ConnectionManager.waitForConnected Wa= iting for client to connect to ZooKeeper [junit4:junit4] 2> 17820 T789 oaz.ClientCnxn$SendThread.logStartConnect O= pening socket connection to server localhost/127.0.0.1:49308. Will not atte= mpt to authenticate using SASL (access denied ("javax.security.auth.AuthPer= mission" "getLoginConfiguration")) [junit4:junit4] 2> 17821 T789 oaz.ClientCnxn$SendThread.primeConnection S= ocket connection established to localhost/127.0.0.1:49308, initiating sessi= on [junit4:junit4] 2> 17822 T705 oazs.NIOServerCnxnFactory.run Accepted sock= et connection from /127.0.0.1:49327 [junit4:junit4] 2> 17823 T705 oazs.ZooKeeperServer.processConnectRequest = Client attempting to establish new session at /127.0.0.1:49327 [junit4:junit4] 2> 17825 T707 oazs.ZooKeeperServer.finishSessionInit Esta= blished session 0x13ca51e7239000c with negotiated timeout 20000 for client = /127.0.0.1:49327 [junit4:junit4] 2> 17825 T789 oaz.ClientCnxn$SendThread.onConnected Sessi= on establishment complete on server localhost/127.0.0.1:49308, sessionid = =3D 0x13ca51e7239000c, negotiated timeout =3D 20000 [junit4:junit4] 2> 17826 T790 oascc.ConnectionManager.process Watcher org= .apache.solr.common.cloud.ConnectionManager@7de2d422 name:ZooKeeperConnecti= on Watcher:127.0.0.1:49308/solr got event WatchedEvent state:SyncConnected = type:None path:null path:null type:None [junit4:junit4] 2> 17826 T703 oascc.ConnectionManager.waitForConnected Cl= ient is connected to ZooKeeper [junit4:junit4] 2> 17828 T708 oazs.PrepRequestProcessor.pRequest Got user= -level KeeperException when processing sessionid:0x13ca51e7239000c type:cre= ate cxid:0x1 zxid:0xa2 txntype:-1 reqpath:n/a Error Path:/solr/overseer Err= or:KeeperErrorCode =3D NodeExists for /solr/overseer [junit4:junit4] 2> 17830 T708 oazs.PrepRequestProcessor.pRequest Got user= -level KeeperException when processing sessionid:0x13ca51e7239000c type:cre= ate cxid:0x2 zxid:0xa3 txntype:-1 reqpath:n/a Error Path:/solr/overseer Err= or:KeeperErrorCode =3D NodeExists for /solr/overseer [junit4:junit4] 2> 17833 T703 oasc.ZkController.createEphemeralLiveNode R= egister node as live in ZooKeeper:/live_nodes/127.0.0.1:49325_ [junit4:junit4] 2> 17835 T708 oazs.PrepRequestProcessor.pRequest Got user= -level KeeperException when processing sessionid:0x13ca51e7239000c type:del= ete cxid:0x4 zxid:0xa4 txntype:-1 reqpath:n/a Error Path:/solr/live_nodes/1= 27.0.0.1:49325_ Error:KeeperErrorCode =3D NoNode for /solr/live_nodes/127.0= .0.1:49325_ [junit4:junit4] 2> 17837 T703 oascc.SolrZkClient.makePath makePath: /live= _nodes/127.0.0.1:49325_ [junit4:junit4] 2> 17842 T731 oascc.ZkStateReader$2.process A cluster sta= te change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/= live_nodes, has occurred - updating... (live nodes size: 4) [junit4:junit4] 2> 17844 T744 oascc.ZkStateReader$2.process A cluster sta= te change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/= live_nodes, has occurred - updating... (live nodes size: 4) [junit4:junit4] 2> 17845 T759 oascc.ZkStateReader$2.process A cluster sta= te change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/= live_nodes, has occurred - updating... (live nodes size: 4) [junit4:junit4] 2> 17847 T725 oascc.ZkStateReader$3.process Updating live= nodes... (5) [junit4:junit4] 2> 17848 T725 oascc.ZkStateReader$2.process A cluster sta= te change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/= live_nodes, has occurred - updating... (live nodes size: 5) [junit4:junit4] 2> 17859 T744 oascc.ZkStateReader$3.process Updating live= nodes... (5) [junit4:junit4] 2> 17862 T774 oascc.ZkStateReader$3.process Updating live= nodes... (5) [junit4:junit4] 2> 17862 T774 oascc.ZkStateReader$2.process A cluster sta= te change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/= live_nodes, has occurred - updating... (live nodes size: 5) [junit4:junit4] 2> 17863 T759 oascc.ZkStateReader$3.process Updating live= nodes... (5) [junit4:junit4] 2> 17865 T731 oascc.ZkStateReader$3.process Updating live= nodes... (5) [junit4:junit4] 2> 17886 T703 oascc.ZkStateReader.createClusterStateWatch= ersAndUpdate Updating cluster state from ZooKeeper...=20 [junit4:junit4] 2> 17896 T791 oasc.CoreContainer.create Creating SolrCore= 'collection1' using instanceDir: /Users/jenkins/jenkins-slave/workspace/Lu= cene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud= .BasicDistributedZkTest-jetty4-1359979918872/collection1 [junit4:junit4] 2> 17896 T791 oasc.ZkController.createCollectionZkNode Ch= eck for collection zkNode:collection1 [junit4:junit4] 2> 17897 T791 oasc.ZkController.createCollectionZkNode Co= llection zkNode exists [junit4:junit4] 2> 17898 T791 oasc.ZkController.readConfigName Load colle= ction config from:/collections/collection1 [junit4:junit4] 2> 17900 T791 oasc.SolrResourceLoader. new SolrReso= urceLoader for directory: '/Users/jenkins/jenkins-slave/workspace/Lucene-So= lr-trunk-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicD= istributedZkTest-jetty4-1359979918872/collection1/' [junit4:junit4] 2> 17901 T791 oasc.SolrResourceLoader.replaceClassLoader = Adding 'file:/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOS= X/solr/build/solr-core/test/J0/org.apache.solr.cloud.BasicDistributedZkTest= -jetty4-1359979918872/collection1/lib/classes/' to classloader [junit4:junit4] 2> 17901 T791 oasc.SolrResourceLoader.replaceClassLoader = Adding 'file:/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOS= X/solr/build/solr-core/test/J0/org.apache.solr.cloud.BasicDistributedZkTest= -jetty4-1359979918872/collection1/lib/README' to classloader [junit4:junit4] 2> 17952 T791 oasc.SolrConfig. Using Lucene MatchVe= rsion: LUCENE_50 [junit4:junit4] 2> 18056 T791 oasc.SolrConfig. Loaded SolrConfig: s= olrconfig.xml [junit4:junit4] 2> 18058 T791 oass.IndexSchema.readSchema Reading Solr Sc= hema [junit4:junit4] 2> 18063 T791 oass.IndexSchema.readSchema Schema name=3Dt= est [junit4:junit4] 2> 18095 T726 oascc.ZkStateReader.updateClusterState Upda= ting cloud state from ZooKeeper...=20 [junit4:junit4] 2> 18100 T726 oasc.Overseer$ClusterStateUpdater.updateSta= te Update state numShards=3D2 message=3D{ [junit4:junit4] 2> =09 "operation":"state", [junit4:junit4] 2> =09 "numShards":"2", [junit4:junit4] 2> =09 "shard":"shard1", [junit4:junit4] 2> =09 "roles":null, [junit4:junit4] 2> =09 "state":"recovering", [junit4:junit4] 2> =09 "core":"collection1", [junit4:junit4] 2> =09 "collection":"collection1", [junit4:junit4] 2> =09 "node_name":"127.0.0.1:49321_", [junit4:junit4] 2> =09 "base_url":"http://127.0.0.1:49321"} [junit4:junit4] 2> 18170 T725 oascc.ZkStateReader$2.process A cluster sta= te change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clus= terstate.json, has occurred - updating... (live nodes size: 5) [junit4:junit4] 2> 18172 T744 oascc.ZkStateReader$2.process A cluster sta= te change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clus= terstate.json, has occurred - updating... (live nodes size: 5) [junit4:junit4] 2> 18173 T731 oascc.ZkStateReader$2.process A cluster sta= te change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clus= terstate.json, has occurred - updating... (live nodes size: 5) [junit4:junit4] 2> 18173 T790 oascc.ZkStateReader$2.process A cluster sta= te change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clus= terstate.json, has occurred - updating... (live nodes size: 5) [junit4:junit4] 2> 18172 T759 oascc.ZkStateReader$2.process A cluster sta= te change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clus= terstate.json, has occurred - updating... (live nodes size: 5) [junit4:junit4] 2> 18173 T774 oascc.ZkStateReader$2.process A cluster sta= te change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clus= terstate.json, has occurred - updating... (live nodes size: 5) [junit4:junit4] 2> 19034 T791 oass.OpenExchangeRatesOrgProvider.init Init= ialized with rates=3Dopen-exchange-rates.json, refreshInterval=3D1440. [junit4:junit4] 2> 19050 T791 oass.IndexSchema.readSchema default search = field in schema is text [junit4:junit4] 2> 19055 T791 oass.IndexSchema.readSchema unique key fiel= d: id [junit4:junit4] 2> 19100 T791 oass.FileExchangeRateProvider.reload Reload= ing exchange rates from file currency.xml [junit4:junit4] 2> 19106 T791 oass.FileExchangeRateProvider.reload Reload= ing exchange rates from file currency.xml [junit4:junit4] 2> 19161 T791 oass.OpenExchangeRatesOrgProvider.reload Re= loading exchange rates from open-exchange-rates.json [junit4:junit4] 2> 19170 T791 oass.OpenExchangeRatesOrgProvider.reload Re= loading exchange rates from open-exchange-rates.json [junit4:junit4] 2> 19173 T791 oasc.SolrCore. [collection1] Opening = new SolrCore at /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-Ma= cOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZ= kTest-jetty4-1359979918872/collection1/, dataDir=3D./org.apache.solr.cloud.= BasicDistributedZkTest-1359979901483/jetty4/ [junit4:junit4] 2> 19173 T791 oasc.JmxMonitoredMap. JMX monitoring = is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMB= eanServer@36298619 [junit4:junit4] 2> 19174 T791 oasc.SolrCore.initDirectoryFactory solr.NRT= CachingDirectoryFactory [junit4:junit4] 2> 19175 T791 oasc.CachingDirectoryFactory.get return new= directory for /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-Mac= OSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZk= Test-1359979901483/jetty4 forceNew:false [junit4:junit4] 2> 19175 T791 oasc.CachingDirectoryFactory.close Releasin= g directory:/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX= /solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZkTes= t-1359979901483/jetty4 [junit4:junit4] 2> 19175 T791 oasc.SolrCore.getNewIndexDir New index dire= ctory detected: old=3Dnull new=3D./org.apache.solr.cloud.BasicDistributedZk= Test-1359979901483/jetty4/index/ [junit4:junit4] 2> 19176 T791 oasc.SolrCore.initIndex WARNING [collection= 1] Solr index directory './org.apache.solr.cloud.BasicDistributedZkTest-135= 9979901483/jetty4/index' doesn't exist. Creating new index... [junit4:junit4] 2> 19177 T791 oasc.CachingDirectoryFactory.get return new= directory for /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-Mac= OSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZk= Test-1359979901483/jetty4/index forceNew:false [junit4:junit4] 2> 19182 T791 oasc.SolrDeletionPolicy.onCommit SolrDeleti= onPolicy.onCommit: commits:num=3D1 [junit4:junit4] 2> =09=09commit{dir=3DRateLimitedDirectoryWrapper(NRTCach= ingDirectory(org.apache.lucene.store.NIOFSDirectory@/Users/jenkins/jenkins-= slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/org.a= pache.solr.cloud.BasicDistributedZkTest-1359979901483/jetty4/index lockFact= ory=3Dorg.apache.lucene.store.NativeFSLockFactory@a2b14bd; maxCacheMB=3D48.= 0 maxMergeSizeMB=3D4.0)),segFN=3Dsegments_1,generation=3D1,filenames=3D[seg= ments_1] [junit4:junit4] 2> 19183 T791 oasc.SolrDeletionPolicy.updateCommits newes= t commit =3D 1[segments_1] [junit4:junit4] 2> 19184 T791 oasc.CachingDirectoryFactory.close Releasin= g directory:/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX= /solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZkTes= t-1359979901483/jetty4/index [junit4:junit4] 2> 19185 T791 oasc.SolrCore.initWriters created xml: solr= .XMLResponseWriter [junit4:junit4] 2> 19188 T791 oasup.UpdateRequestProcessorChain.init inse= rting DistributedUpdateProcessorFactory into updateRequestProcessorChain "d= edupe" [junit4:junit4] 2> 19188 T791 oasup.UpdateRequestProcessorChain.init inse= rting DistributedUpdateProcessorFactory into updateRequestProcessorChain "d= edupe-allfields" [junit4:junit4] 2> 19189 T791 oasup.UpdateRequestProcessorChain.init inse= rting DistributedUpdateProcessorFactory into updateRequestProcessorChain "s= tored_sig" [junit4:junit4] 2> 19189 T791 oasup.UpdateRequestProcessorChain.init inse= rting DistributedUpdateProcessorFactory into updateRequestProcessorChain "u= niq-fields" [junit4:junit4] 2> 19190 T791 oasup.UpdateRequestProcessorChain.init inse= rting DistributedUpdateProcessorFactory into updateRequestProcessorChain "d= istrib-dup-test-chain-implicit" [junit4:junit4] 2> 19191 T791 oasc.RequestHandlers.initHandlersFromConfig= adding lazy requestHandler: solr.ReplicationHandler [junit4:junit4] 2> 19191 T791 oasc.RequestHandlers.initHandlersFromConfig= created /replication: solr.ReplicationHandler [junit4:junit4] 2> 19192 T791 oasc.RequestHandlers.initHandlersFromConfig= created standard: solr.StandardRequestHandler [junit4:junit4] 2> 19192 T791 oasc.RequestHandlers.initHandlersFromConfig= created /get: solr.RealTimeGetHandler [junit4:junit4] 2> 19193 T791 oasc.RequestHandlers.initHandlersFromConfig= created dismax: solr.SearchHandler [junit4:junit4] 2> 19194 T791 oasc.RequestHandlers.initHandlersFromConfig= created mock: org.apache.solr.core.MockQuerySenderListenerReqHandler [junit4:junit4] 2> 19195 T791 oasc.RequestHandlers.initHandlersFromConfig= created /admin/: org.apache.solr.handler.admin.AdminHandlers [junit4:junit4] 2> 19195 T791 oasc.RequestHandlers.initHandlersFromConfig= created defaults: solr.StandardRequestHandler [junit4:junit4] 2> 19195 T791 oasc.RequestHandlers.initHandlersFromConfig= adding lazy requestHandler: solr.StandardRequestHandler [junit4:junit4] 2> 19196 T791 oasc.RequestHandlers.initHandlersFromConfig= created lazy: solr.StandardRequestHandler [junit4:junit4] 2> 19197 T791 oasc.RequestHandlers.initHandlersFromConfig= created /update: solr.UpdateRequestHandler [junit4:junit4] 2> 19198 T791 oasc.RequestHandlers.initHandlersFromConfig= created /terms: org.apache.solr.handler.component.SearchHandler [junit4:junit4] 2> 19199 T791 oasc.RequestHandlers.initHandlersFromConfig= created spellCheckCompRH: org.apache.solr.handler.component.SearchHandler [junit4:junit4] 2> 19200 T791 oasc.RequestHandlers.initHandlersFromConfig= created spellCheckCompRH_Direct: org.apache.solr.handler.component.SearchH= andler [junit4:junit4] 2> 19201 T791 oasc.RequestHandlers.initHandlersFromConfig= created spellCheckWithWordbreak: org.apache.solr.handler.component.SearchH= andler [junit4:junit4] 2> 19201 T791 oasc.RequestHandlers.initHandlersFromConfig= created spellCheckWithWordbreak_Direct: org.apache.solr.handler.component.= SearchHandler [junit4:junit4] 2> 19202 T791 oasc.RequestHandlers.initHandlersFromConfig= created spellCheckCompRH1: org.apache.solr.handler.component.SearchHandler [junit4:junit4] 2> 19203 T791 oasc.RequestHandlers.initHandlersFromConfig= created mltrh: org.apache.solr.handler.component.SearchHandler [junit4:junit4] 2> 19203 T791 oasc.RequestHandlers.initHandlersFromConfig= created tvrh: org.apache.solr.handler.component.SearchHandler [junit4:junit4] 2> 19204 T791 oasc.RequestHandlers.initHandlersFromConfig= created /mlt: solr.MoreLikeThisHandler [junit4:junit4] 2> 19205 T791 oasc.RequestHandlers.initHandlersFromConfig= created /debug/dump: solr.DumpRequestHandler [junit4:junit4] 2> 19212 T791 oashl.XMLLoader.init xsltCacheLifetimeSecon= ds=3D60 [junit4:junit4] 2> 19215 T791 oasc.SolrCore.initDeprecatedSupport WARNING= solrconfig.xml uses deprecated , Please update your c= onfig to use the ShowFileRequestHandler. [junit4:junit4] 2> 19217 T791 oasc.SolrCore.initDeprecatedSupport WARNING= adding ShowFileRequestHandler with hidden files: [SCHEMA.XML, OLD_SYNONYMS= .TXT, STOPWORDS.TXT, PROTWORDS.TXT, OPEN-EXCHANGE-RATES.JSON, SYNONYMS.TXT,= CURRENCY.XML, MAPPING-ISOLATIN1ACCENT.TXT] [junit4:junit4] 2> 19219 T791 oasc.CachingDirectoryFactory.close Releasin= g directory:/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX= /solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZkTes= t-1359979901483/jetty4 [junit4:junit4] 2> 19220 T791 oass.SolrIndexSearcher. Opening Searc= her@ad54c5d main [junit4:junit4] 2> 19221 T791 oasu.CommitTracker. Hard AutoCommit: = disabled [junit4:junit4] 2> 19222 T791 oasu.CommitTracker. Soft AutoCommit: = disabled [junit4:junit4] 2> 19222 T791 oashc.SpellCheckComponent.inform Initializi= ng spell checkers [junit4:junit4] 2> 19236 T791 oass.DirectSolrSpellChecker.init init: {nam= e=3Ddirect,classname=3DDirectSolrSpellChecker,field=3Dlowerfilt,minQueryLen= gth=3D3} [junit4:junit4] 2> 19279 T792 oasc.SolrCore.registerSearcher [collection1= ] Registered new searcher Searcher@ad54c5d main{StandardDirectoryReader(seg= ments_1:1)} [junit4:junit4] 2> 19300 T791 oasc.ZkController.publish publishing core= =3Dcollection1 state=3Ddown [junit4:junit4] 2> 19301 T791 oasc.ZkController.publish numShards not fou= nd on descriptor - reading it from system property [junit4:junit4] 2> 19694 T726 oascc.ZkStateReader.updateClusterState Upda= ting cloud state from ZooKeeper...=20 [junit4:junit4] 2> 19695 T726 oasc.Overseer$ClusterStateUpdater.updateSta= te Update state numShards=3D2 message=3D{ [junit4:junit4] 2> =09 "operation":"state", [junit4:junit4] 2> =09 "numShards":"2", [junit4:junit4] 2> =09 "shard":null, [junit4:junit4] 2> =09 "roles":null, [junit4:junit4] 2> =09 "state":"down", [junit4:junit4] 2> =09 "core":"collection1", [junit4:junit4] 2> =09 "collection":"collection1", [junit4:junit4] 2> =09 "node_name":"127.0.0.1:49325_", [junit4:junit4] 2> =09 "base_url":"http://127.0.0.1:49325"} [junit4:junit4] 2> 19696 T726 oasc.Overseer$ClusterStateUpdater.updateSta= te Collection already exists with numShards=3D2 [junit4:junit4] 2> 19696 T726 oasc.Overseer$ClusterStateUpdater.updateSta= te Assigning new node to shard shard=3Dshard2 [junit4:junit4] 2> 19705 T725 oascc.ZkStateReader$2.process A cluster sta= te change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clus= terstate.json, has occurred - updating... (live nodes size: 5) [junit4:junit4] 2> 19705 T731 oascc.ZkStateReader$2.process A cluster sta= te change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clus= terstate.json, has occurred - updating... (live nodes size: 5) [junit4:junit4] 2> 19705 T790 oascc.ZkStateReader$2.process A cluster sta= te change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clus= terstate.json, has occurred - updating... (live nodes size: 5) [junit4:junit4] 2> 19711 T774 oascc.ZkStateReader$2.process A cluster sta= te change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clus= terstate.json, has occurred - updating... (live nodes size: 5) [junit4:junit4] 2> 19714 T759 oascc.ZkStateReader$2.process A cluster sta= te change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clus= terstate.json, has occurred - updating... (live nodes size: 5) [junit4:junit4] 2> 19718 T744 oascc.ZkStateReader$2.process A cluster sta= te change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clus= terstate.json, has occurred - updating... (live nodes size: 5) [junit4:junit4] 2> 20304 T791 oasc.CoreContainer.registerCore registering= core: collection1 [junit4:junit4] 2> 20305 T791 oasc.ZkController.register Register replica= - core:collection1 address:http://127.0.0.1:49325 collection:collection1 s= hard:shard2 [junit4:junit4] 2> 20311 T791 oasc.ZkController.register We are http://12= 7.0.0.1:49325/collection1/ and leader is http://127.0.0.1:49318/collection1= / [junit4:junit4] 2> 20312 T791 oasc.ZkController.register No LogReplay nee= ded for core=3Dcollection1 baseURL=3Dhttp://127.0.0.1:49325 [junit4:junit4] 2> 20312 T791 oasc.ZkController.checkRecovery Core needs = to recover:collection1 [junit4:junit4] 2> 20312 T791 oasu.DefaultSolrCoreState.doRecovery Runnin= g recovery - first canceling any ongoing recovery [junit4:junit4] 2> ASYNC NEW_CORE C50 name=3Dcollection1 org.apache.solr= .core.SolrCore@9c7edb6 url=3Dhttp://127.0.0.1:49325/collection1 node=3D127.= 0.0.1:49325_ C50_STATE=3Dcoll:collection1 core:collection1 props:{shard=3Dn= ull, roles=3Dnull, state=3Ddown, core=3Dcollection1, collection=3Dcollectio= n1, node_name=3D127.0.0.1:49325_, base_url=3Dhttp://127.0.0.1:49325} [junit4:junit4] 2> 20313 T793 C50 P49325 oasc.RecoveryStrategy.run Starti= ng recovery process. core=3Dcollection1 recoveringAfterStartup=3Dtrue [junit4:junit4] 2> 20313 T793 C50 P49325 oasc.RecoveryStrategy.doRecovery= ###### startupVersions=3D[] [junit4:junit4] 2> 20313 T793 C50 P49325 oasc.ZkController.publish publis= hing core=3Dcollection1 state=3Drecovering [junit4:junit4] 2> 20313 T793 C50 P49325 oasc.ZkController.publish numSha= rds not found on descriptor - reading it from system property [junit4:junit4] 2> 20315 T791 oascc.ZkStateReader.updateClusterState Upda= ting cloud state from ZooKeeper...=20 [junit4:junit4] 2> 20317 T793 C50 P49325 oascsi.HttpClientUtil.createClie= nt Creating new http client, config:maxConnections=3D128&maxConnectionsPerH= ost=3D32&followRedirects=3Dfalse [junit4:junit4] 2> 20317 T703 oass.SolrDispatchFilter.init user.dir=3D/Us= ers/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/sol= r-core/test/J0 [junit4:junit4] 2> 20329 T703 oass.SolrDispatchFilter.init SolrDispatchFi= lter.init() done [junit4:junit4] 2> 20329 T703 oascsi.HttpClientUtil.createClient Creating= new http client, config:maxConnections=3D128&maxConnectionsPerHost=3D32&fo= llowRedirects=3Dfalse [junit4:junit4] 2> 20335 T703 oascc.ZkStateReader.updateClusterState Upda= ting cloud state from ZooKeeper...=20 [junit4:junit4] 2> 20336 T703 oasc.AbstractDistribZkTestBase.waitForRecov= eriesToFinish Wait for recoveries to finish - collection: collection1 failO= nTimeout:true timeout (sec):230 [junit4:junit4] 2> 20337 T703 oascc.ZkStateReader.updateClusterState Upda= ting cloud state from ZooKeeper...=20 [junit4:junit4] 2> C49_STATE=3Dcoll:collection1 core:collection1 props:{= shard=3Dshard1, roles=3Dnull, state=3Drecovering, core=3Dcollection1, colle= ction=3Dcollection1, node_name=3D127.0.0.1:49321_, base_url=3Dhttp://127.0.= 0.1:49321} [junit4:junit4] 2> 20431 T777 C49 P49321 oasc.RecoveryStrategy.doRecovery= Attempting to PeerSync from http://127.0.0.1:49315/collection1/ core=3Dcol= lection1 - recoveringAfterStartup=3Dtrue [junit4:junit4] 2> 20446 T777 C49 P49321 oascsi.HttpClientUtil.createClie= nt Creating new http client, config:maxConnectionsPerHost=3D20&maxConnectio= ns=3D10000&connTimeout=3D30000&socketTimeout=3D30000&retry=3Dfalse [junit4:junit4] 2> 20469 T777 C49 P49321 oasu.PeerSync.sync PeerSync: cor= e=3Dcollection1 url=3Dhttp://127.0.0.1:49321 START replicas=3D[http://127.0= .0.1:49315/collection1/] nUpdates=3D100 [junit4:junit4] 2> 20470 T777 C49 P49321 oasu.PeerSync.sync WARNING no fr= ame of reference to tell of we've missed updates [junit4:junit4] 2> 20471 T777 C49 P49321 oasc.RecoveryStrategy.doRecovery= PeerSync Recovery was not successful - trying replication. core=3Dcollecti= on1 [junit4:junit4] 2> 20471 T777 C49 P49321 oasc.RecoveryStrategy.doRecovery= Starting Replication Recovery. core=3Dcollection1 [junit4:junit4] 2> 20472 T777 C49 P49321 oasc.RecoveryStrategy.doRecovery= Begin buffering updates. core=3Dcollection1 [junit4:junit4] 2> 20472 T777 C49 P49321 oasu.UpdateLog.bufferUpdates Sta= rting to buffer updates. FSUpdateLog{state=3DACTIVE, tlog=3Dnull} [junit4:junit4] 2> 20472 T777 C49 P49321 oasc.RecoveryStrategy.replicate = Attempting to replicate from http://127.0.0.1:49315/collection1/. core=3Dco= llection1 [junit4:junit4] 2> 20473 T777 C49 P49321 oascsi.HttpClientUtil.createClie= nt Creating new http client, config:maxConnections=3D128&maxConnectionsPerH= ost=3D32&followRedirects=3Dfalse [junit4:junit4] 2> ASYNC NEW_CORE C51 name=3Dcollection1 org.apache.solr= .core.SolrCore@762c92c1 url=3Dhttp://127.0.0.1:49315/collection1 node=3D127= .0.0.1:49315_ C51_STATE=3Dcoll:collection1 core:collection1 props:{shard=3D= shard1, roles=3Dnull, state=3Dactive, core=3Dcollection1, collection=3Dcoll= ection1, node_name=3D127.0.0.1:49315_, base_url=3Dhttp://127.0.0.1:49315, l= eader=3Dtrue} [junit4:junit4] 2> 20511 T740 C51 P49315 REQ /get {getVersions=3D100&dist= rib=3Dfalse&wt=3Djavabin&qt=3D/get&version=3D2} status=3D0 QTime=3D0=20 [junit4:junit4] 2> 20562 T739 C51 P49315 oasu.DirectUpdateHandler2.commit= start commit{,optimize=3Dfalse,openSearcher=3Dfalse,waitSearcher=3Dtrue,ex= pungeDeletes=3Dfalse,softCommit=3Dfalse} [junit4:junit4] 2> 20564 T739 C51 P49315 oasc.CachingDirectoryFactory.clo= se Releasing directory:/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-t= runk-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistr= ibutedZkTest-1359979901483/jetty1 [junit4:junit4] 2> 20568 T739 C51 P49315 oasc.SolrDeletionPolicy.onInit S= olrDeletionPolicy.onInit: commits:num=3D1 [junit4:junit4] 2> =09=09commit{dir=3DRateLimitedDirectoryWrapper(NRTCach= ingDirectory(org.apache.lucene.store.NIOFSDirectory@/Users/jenkins/jenkins-= slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/org.a= pache.solr.cloud.BasicDistributedZkTest-1359979901483/jetty1/index lockFact= ory=3Dorg.apache.lucene.store.NativeFSLockFactory@3e40cc10; maxCacheMB=3D48= .0 maxMergeSizeMB=3D4.0)),segFN=3Dsegments_1,generation=3D1,filenames=3D[se= gments_1] [junit4:junit4] 2> 20569 T739 C51 P49315 oasc.SolrDeletionPolicy.updateCo= mmits newest commit =3D 1[segments_1] [junit4:junit4] 2> 20574 T739 C51 P49315 oasc.SolrDeletionPolicy.onCommit= SolrDeletionPolicy.onCommit: commits:num=3D2 [junit4:junit4] 2> =09=09commit{dir=3DRateLimitedDirectoryWrapper(NRTCach= ingDirectory(org.apache.lucene.store.NIOFSDirectory@/Users/jenkins/jenkins-= slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/org.a= pache.solr.cloud.BasicDistributedZkTest-1359979901483/jetty1/index lockFact= ory=3Dorg.apache.lucene.store.NativeFSLockFactory@3e40cc10; maxCacheMB=3D48= .0 maxMergeSizeMB=3D4.0)),segFN=3Dsegments_1,generation=3D1,filenames=3D[se= gments_1] [junit4:junit4] 2> =09=09commit{dir=3DRateLimitedDirectoryWrapper(NRTCach= ingDirectory(org.apache.lucene.store.NIOFSDirectory@/Users/jenkins/jenkins-= slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/org.a= pache.solr.cloud.BasicDistributedZkTest-1359979901483/jetty1/index lockFact= ory=3Dorg.apache.lucene.store.NativeFSLockFactory@3e40cc10; maxCacheMB=3D48= .0 maxMergeSizeMB=3D4.0)),segFN=3Dsegments_2,generation=3D2,filenames=3D[se= gments_2] [junit4:junit4] 2> 20574 T739 C51 P49315 oasc.SolrDeletionPolicy.updateCo= mmits newest commit =3D 2[segments_2] [junit4:junit4] 2> 20576 T739 C51 P49315 oasc.CachingDirectoryFactory.clo= se Releasing directory:/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-t= runk-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistr= ibutedZkTest-1359979901483/jetty1 [junit4:junit4] 2> 20576 T739 C51 P49315 oass.SolrIndexSearcher. Op= ening Searcher@59d04f4c realtime [junit4:junit4] 2> 20576 T739 C51 P49315 oasu.DirectUpdateHandler2.commit= end_commit_flush [junit4:junit4] 2> 20577 T739 C51 P49315 /update {waitSearcher=3Dtrue&ope= nSearcher=3Dfalse&commit=3Dtrue&wt=3Djavabin&commit_end_point=3Dtrue&versio= n=3D2&softCommit=3Dfalse} {commit=3D} 0 67 [junit4:junit4] 2> 20579 T777 C49 P49321 oash.ReplicationHandler.inform C= ommits will be reserved for 10000 [junit4:junit4] 2> 20579 T777 C49 P49321 oash.SnapPuller. No value= set for 'pollInterval'. Timer Task not started. [junit4:junit4] 2> 20585 T737 C51 P49315 oash.ReplicationHandler.inform C= ommits will be reserved for 10000 [junit4:junit4] 2> 20586 T737 C51 P49315 REQ /replication {command=3Dinde= xversion&qt=3D/replication&wt=3Djavabin&version=3D2} status=3D0 QTime=3D2= =20 [junit4:junit4] 2> 20587 T777 C49 P49321 oash.SnapPuller.fetchLatestIndex= Master's generation: 2 [junit4:junit4] 2> 20587 T777 C49 P49321 oash.SnapPuller.fetchLatestIndex= Slave's generation: 1 [junit4:junit4] 2> 20587 T777 C49 P49321 oash.SnapPuller.fetchLatestIndex= Starting replication process [junit4:junit4] 2> 20591 T738 C51 P49315 oasc.CachingDirectoryFactory.clo= se Releasing directory:/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-t= runk-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistr= ibutedZkTest-1359979901483/jetty1 [junit4:junit4] 2> 20591 T738 C51 P49315 oasc.CachingDirectoryFactory.clo= se Releasing directory:/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-t= runk-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistr= ibutedZkTest-1359979901483/jetty1/index [junit4:junit4] 2> 20592 T738 C51 P49315 REQ /replication {command=3Dfile= list&qt=3D/replication&wt=3Djavabin&generation=3D2&version=3D2} status=3D0 = QTime=3D2=20 [junit4:junit4] 2> 20592 T777 C49 P49321 oash.SnapPuller.fetchLatestIndex= Number of files in latest index in master: 1 [junit4:junit4] 2> 20593 T777 C49 P49321 oasc.CachingDirectoryFactory.get= return new directory for /Users/jenkins/jenkins-slave/workspace/Lucene-Sol= r-trunk-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDi= stributedZkTest-1359979901483/jetty3/index.20130204061202061 forceNew:false [junit4:junit4] 2> 20594 T777 C49 P49321 oasc.CachingDirectoryFactory.clo= se Releasing directory:/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-t= runk-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistr= ibutedZkTest-1359979901483/jetty3 [junit4:junit4] 2> 20599 T777 C49 P49321 oash.SnapPuller.fetchLatestIndex= Starting download to RateLimitedDirectoryWrapper(NRTCachingDirectory(org.a= pache.lucene.store.NIOFSDirectory@/Users/jenkins/jenkins-slave/workspace/Lu= cene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/org.apache.solr.cloud.B= asicDistributedZkTest-1359979901483/jetty3/index.20130204061202061 lockFact= ory=3Dorg.apache.lucene.store.NativeFSLockFactory@4886521b; maxCacheMB=3D48= .0 maxMergeSizeMB=3D4.0)) fullCopy=3Dtrue [junit4:junit4] 2> 20602 T736 C51 P49315 REQ /replication {file=3Dsegment= s_2&command=3Dfilecontent&checksum=3Dtrue&wt=3Dfilestream&qt=3D/replication= &generation=3D2} status=3D0 QTime=3D0=20 [junit4:junit4] 2> 20607 T777 C49 P49321 oasc.CachingDirectoryFactory.clo= se Releasing directory:/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-t= runk-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistr= ibutedZkTest-1359979901483/jetty3/index [junit4:junit4] 2> 20609 T777 C49 P49321 oash.SnapPuller.fetchLatestIndex= Total time taken for download : 0 secs [junit4:junit4] 2> 20611 T777 C49 P49321 oash.SnapPuller.modifyIndexProps= New index installed. Updating index properties... index=3Dindex.2013020406= 1202061 [junit4:junit4] 2> 20620 T777 C49 P49321 oasc.CachingDirectoryFactory.clo= se Releasing directory:/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-t= runk-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistr= ibutedZkTest-1359979901483/jetty3 [junit4:junit4] 2> 20622 T777 C49 P49321 oasc.CachingDirectoryFactory.clo= se Releasing directory:/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-t= runk-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistr= ibutedZkTest-1359979901483/jetty3 [junit4:junit4] 2> 20623 T777 C49 P49321 oasc.SolrCore.getNewIndexDir New= index directory detected: old=3D./org.apache.solr.cloud.BasicDistributedZk= Test-1359979901483/jetty3/index/ new=3D./org.apache.solr.cloud.BasicDistrib= utedZkTest-1359979901483/jetty3/index.20130204061202061 [junit4:junit4] 2> 20627 T777 C49 P49321 oasc.SolrDeletionPolicy.onInit S= olrDeletionPolicy.onInit: commits:num=3D1 [junit4:junit4] 2> =09=09commit{dir=3DRateLimitedDirectoryWrapper(NRTCach= ingDirectory(org.apache.lucene.store.NIOFSDirectory@/Users/jenkins/jenkins-= slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/org.a= pache.solr.cloud.BasicDistributedZkTest-1359979901483/jetty3/index.20130204= 061202061 lockFactory=3Dorg.apache.lucene.store.NativeFSLockFactory@4886521= b; maxCacheMB=3D48.0 maxMergeSizeMB=3D4.0)),segFN=3Dsegments_2,generation= =3D2,filenames=3D[segments_2] [junit4:junit4] 2> 20628 T777 C49 P49321 oasc.SolrDeletionPolicy.updateCo= mmits newest commit =3D 2[segments_2] [junit4:junit4] 2> 20630 T777 C49 P49321 oasc.CachingDirectoryFactory.clo= se Releasing directory:/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-t= runk-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistr= ibutedZkTest-1359979901483/jetty3 [junit4:junit4] 2> 20631 T777 C49 P49321 oasu.DefaultSolrCoreState.newInd= exWriter Creating new IndexWriter... [junit4:junit4] 2> 20631 T777 C49 P49321 oasu.DefaultSolrCoreState.newInd= exWriter Waiting until IndexWriter is unused... core=3Dcollection1 [junit4:junit4] 2> 20631 T777 C49 P49321 oasu.DefaultSolrCoreState.newInd= exWriter Rollback old IndexWriter... core=3Dcollection1 [junit4:junit4] 2> 20633 T777 C49 P49321 oasc.CachingDirectoryFactory.clo= se Releasing directory:/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-t= runk-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistr= ibutedZkTest-1359979901483/jetty3/index.20130204061202061 [junit4:junit4] 2> 20633 T777 C49 P49321 oasc.CachingDirectoryFactory.clo= se Releasing directory:/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-t= runk-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistr= ibutedZkTest-1359979901483/jetty3 [junit4:junit4] 2> 20639 T777 C49 P49321 oasc.SolrDeletionPolicy.onInit S= olrDeletionPolicy.onInit: commits:num=3D1 [junit4:junit4] 2> =09=09commit{dir=3DRateLimitedDirectoryWrapper(NRTCach= ingDirectory(org.apache.lucene.store.NIOFSDirectory@/Users/jenkins/jenkins-= slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/org.a= pache.solr.cloud.BasicDistributedZkTest-1359979901483/jetty3/index.20130204= 061202061 lockFactory=3Dorg.apache.lucene.store.NativeFSLockFactory@4886521= b; maxCacheMB=3D48.0 maxMergeSizeMB=3D4.0)),segFN=3Dsegments_2,generation= =3D2,filenames=3D[segments_2] [junit4:junit4] 2> 20640 T777 C49 P49321 oasc.SolrDeletionPolicy.updateCo= mmits newest commit =3D 2[segments_2] [junit4:junit4] 2> 20640 T777 C49 P49321 oasu.DefaultSolrCoreState.newInd= exWriter New IndexWriter is ready to be used. [junit4:junit4] 2> 20641 T777 C49 P49321 oasc.CachingDirectoryFactory.clo= se Releasing directory:/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-t= runk-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistr= ibutedZkTest-1359979901483/jetty3 [junit4:junit4] 2> 20641 T777 C49 P49321 oass.SolrIndexSearcher. Op= ening Searcher@62b585b9 main [junit4:junit4] 2> 20644 T776 oasc.SolrCore.registerSearcher [collection1= ] Registered new searcher Searcher@62b585b9 main{StandardDirectoryReader(se= gments_2:1:nrt)} [junit4:junit4] 2> 20645 T776 oasc.CachingDirectoryFactory.close Releasin= g directory:/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX= /solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZkTes= t-1359979901483/jetty3/index [junit4:junit4] 2> 20645 T777 C49 P49321 oasu.DirectUpdateHandler2.commit= start commit{,optimize=3Dfalse,openSearcher=3Dfalse,waitSearcher=3Dfalse,e= xpungeDeletes=3Dfalse,softCommit=3Dfalse} [junit4:junit4] 2> 20649 T777 C49 P49321 oasc.SolrDeletionPolicy.onCommit= SolrDeletionPolicy.onCommit: commits:num=3D2 [junit4:junit4] 2> =09=09commit{dir=3DRateLimitedDirectoryWrapper(NRTCach= ingDirectory(org.apache.lucene.store.NIOFSDirectory@/Users/jenkins/jenkins-= slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/org.a= pache.solr.cloud.BasicDistributedZkTest-1359979901483/jetty3/index.20130204= 061202061 lockFactory=3Dorg.apache.lucene.store.NativeFSLockFactory@4886521= b; maxCacheMB=3D48.0 maxMergeSizeMB=3D4.0)),segFN=3Dsegments_2,generation= =3D2,filenames=3D[segments_2] [junit4:junit4] 2> =09=09commit{dir=3DRateLimitedDirectoryWrapper(NRTCach= ingDirectory(org.apache.lucene.store.NIOFSDirectory@/Users/jenkins/jenkins-= slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/org.a= pache.solr.cloud.BasicDistributedZkTest-1359979901483/jetty3/index.20130204= 061202061 lockFactory=3Dorg.apache.lucene.store.NativeFSLockFactory@4886521= b; maxCacheMB=3D48.0 maxMergeSizeMB=3D4.0)),segFN=3Dsegments_3,generation= =3D3,filenames=3D[segments_3] [junit4:junit4] 2> 20649 T777 C49 P49321 oasc.SolrDeletionPolicy.updateCo= mmits newest commit =3D 3[segments_3] [junit4:junit4] 2> 20650 T777 C49 P49321 oasc.CachingDirectoryFactory.clo= se Releasing directory:/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-t= runk-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistr= ibutedZkTest-1359979901483/jetty3 [junit4:junit4] 2> 20651 T777 C49 P49321 oasu.DirectUpdateHandler2.commit= end_commit_flush [junit4:junit4] 2> 20651 T777 C49 P49321 oasc.CachingDirectoryFactory.clo= se Releasing directory:/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-t= runk-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistr= ibutedZkTest-1359979901483/jetty3/index.20130204061202061 [junit4:junit4] 2> 20651 T777 C49 P49321 oasc.CachingDirectoryFactory.clo= se Releasing directory:/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-t= runk-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistr= ibutedZkTest-1359979901483/jetty3/index [junit4:junit4] 2> 20652 T777 C49 P49321 oasc.RecoveryStrategy.replay No = replay needed. core=3Dcollection1 [junit4:junit4] 2> 20652 T777 C49 P49321 oasc.RecoveryStrategy.doRecovery= Replication Recovery was successful - registering as Active. core=3Dcollec= tion1 [junit4:junit4] 2> 20652 T777 C49 P49321 oasc.ZkController.publish publis= hing core=3Dcollection1 state=3Dactive [junit4:junit4] 2> 20653 T777 C49 P49321 oasc.ZkController.publish numSha= rds not found on descriptor - reading it from system property [junit4:junit4] 2> 20660 T777 C49 P49321 oasc.RecoveryStrategy.doRecovery= Finished recovery process. core=3Dcollection1 [junit4:junit4] 2> 21248 T726 oascc.ZkStateReader.updateClusterState Upda= ting cloud state from ZooKeeper...=20 [junit4:junit4] 2> 21249 T726 oasc.Overseer$ClusterStateUpdater.updateSta= te Update state numShards=3D2 message=3D{ [junit4:junit4] 2> =09 "operation":"state", [junit4:junit4] 2> =09 "numShards":"2", [junit4:junit4] 2> =09 "shard":"shard2", [junit4:junit4] 2> =09 "roles":null, [junit4:junit4] 2> =09 "state":"recovering", [junit4:junit4] 2> =09 "core":"collection1", [junit4:junit4] 2> =09 "collection":"collection1", [junit4:junit4] 2> =09 "node_name":"127.0.0.1:49325_", [junit4:junit4] 2> =09 "base_url":"http://127.0.0.1:49325"} [junit4:junit4] 2> 21259 T726 oasc.Overseer$ClusterStateUpdater.updateSta= te Update state numShards=3D2 message=3D{ [junit4:junit4] 2> =09 "operation":"state", [junit4:junit4] 2> =09 "numShards":"2", [junit4:junit4] 2> =09 "shard":"shard1", [junit4:junit4] 2> =09 "roles":null, [junit4:junit4] 2> =09 "state":"active", [junit4:junit4] 2> =09 "core":"collection1", [junit4:junit4] 2> =09 "collection":"collection1", [junit4:junit4] 2> =09 "node_name":"127.0.0.1:49321_", [junit4:junit4] 2> =09 "base_url":"http://127.0.0.1:49321"} [junit4:junit4] 2> 21269 T731 oascc.ZkStateReader$2.process A cluster sta= te change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clus= terstate.json, has occurred - updating... (live nodes size: 5) [junit4:junit4] 2> 21269 T790 oascc.ZkStateReader$2.process A cluster sta= te change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clus= terstate.json, has occurred - updating... (live nodes size: 5) [junit4:junit4] 2> 21279 T774 oascc.ZkStateReader$2.process A cluster sta= te change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clus= terstate.json, has occurred - updating... (live nodes size: 5) [junit4:junit4] 2> 21282 T759 oascc.ZkStateReader$2.process A cluster sta= te change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clus= terstate.json, has occurred - updating... (live nodes size: 5) [junit4:junit4] 2> 21285 T744 oascc.ZkStateReader$2.process A cluster sta= te change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clus= terstate.json, has occurred - updating... (live nodes size: 5) [junit4:junit4] 2> 21288 T725 oascc.ZkStateReader$2.process A cluster sta= te change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clus= terstate.json, has occurred - updating... (live nodes size: 5) [junit4:junit4] 2> 21341 T703 oascc.ZkStateReader.updateClusterState Upda= ting cloud state from ZooKeeper...=20 [junit4:junit4] 2> 22354 T703 oascc.ZkStateReader.updateClusterState Upda= ting cloud state from ZooKeeper...=20 [junit4:junit4] 2> C50_STATE=3Dcoll:collection1 core:collection1 props:{= shard=3Dshard2, roles=3Dnull, state=3Drecovering, core=3Dcollection1, colle= ction=3Dcollection1, node_name=3D127.0.0.1:49325_, base_url=3Dhttp://127.0.= 0.1:49325} [junit4:junit4] 2> 23337 T793 C50 P49325 oasc.RecoveryStrategy.doRecovery= Attempting to PeerSync from http://127.0.0.1:49318/collection1/ core=3Dcol= lection1 - recoveringAfterStartup=3Dtrue [junit4:junit4] 2> 23337 T793 C50 P49325 oasu.PeerSync.sync PeerSync: cor= e=3Dcollection1 url=3Dhttp://127.0.0.1:49325 START replicas=3D[http://127.0= .0.1:49318/collection1/] nUpdates=3D100 [junit4:junit4] 2> 23338 T793 C50 P49325 oasu.PeerSync.sync WARNING no fr= ame of reference to tell of we've missed updates [junit4:junit4] 2> 23338 T793 C50 P49325 oasc.RecoveryStrategy.doRecovery= PeerSync Recovery was not successful - trying replication. core=3Dcollecti= on1 [junit4:junit4] 2> 23338 T793 C50 P49325 oasc.RecoveryStrategy.doRecovery= Starting Replication Recovery. core=3Dcollection1 [junit4:junit4] 2> 23338 T793 C50 P49325 oasc.RecoveryStrategy.doRecovery= Begin buffering updates. core=3Dcollection1 [junit4:junit4] 2> 23338 T793 C50 P49325 oasu.UpdateLog.bufferUpdates Sta= rting to buffer updates. FSUpdateLog{state=3DACTIVE, tlog=3Dnull} [junit4:junit4] 2> 23338 T793 C50 P49325 oasc.RecoveryStrategy.replicate = Attempting to replicate from http://127.0.0.1:49318/collection1/. core=3Dco= llection1 [junit4:junit4] 2> 23339 T793 C50 P49325 oascsi.HttpClientUtil.createClie= nt Creating new http client, config:maxConnections=3D128&maxConnectionsPerH= ost=3D32&followRedirects=3Dfalse [junit4:junit4] 2> ASYNC NEW_CORE C52 name=3Dcollection1 org.apache.solr= .core.SolrCore@6b11cbdc url=3Dhttp://127.0.0.1:49318/collection1 node=3D127= .0.0.1:49318_ C52_STATE=3Dcoll:collection1 core:collection1 props:{shard=3D= shard2, roles=3Dnull, state=3Dactive, core=3Dcollection1, collection=3Dcoll= ection1, node_name=3D127.0.0.1:49318_, base_url=3Dhttp://127.0.0.1:49318, l= eader=3Dtrue} [junit4:junit4] 2> 23382 T755 C52 P49318 REQ /get {getVersions=3D100&dist= rib=3Dfalse&wt=3Djavabin&qt=3D/get&version=3D2} status=3D0 QTime=3D1=20 [junit4:junit4] 2> 23384 T750 C52 P49318 oasu.DirectUpdateHandler2.commit= start commit{,optimize=3Dfalse,openSearcher=3Dfalse,waitSearcher=3Dtrue,ex= pungeDeletes=3Dfalse,softCommit=3Dfalse} [junit4:junit4] 2> 23386 T750 C52 P49318 oasc.CachingDirectoryFactory.clo= se Releasing directory:/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-t= runk-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistr= ibutedZkTest-1359979901483/jetty2 [junit4:junit4] 2> 23390 T750 C52 P49318 oasc.SolrDeletionPolicy.onInit S= olrDeletionPolicy.onInit: commits:num=3D1 [junit4:junit4] 2> =09=09commit{dir=3DRateLimitedDirectoryWrapper(NRTCach= ingDirectory(org.apache.lucene.store.NIOFSDirectory@/Users/jenkins/jenkins-= slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/org.a= pache.solr.cloud.BasicDistributedZkTest-1359979901483/jetty2/index lockFact= ory=3Dorg.apache.lucene.store.NativeFSLockFactory@684e8b72; maxCacheMB=3D48= .0 maxMergeSizeMB=3D4.0)),segFN=3Dsegments_1,generation=3D1,filenames=3D[se= gments_1] [junit4:junit4] 2> 23390 T750 C52 P49318 oasc.SolrDeletionPolicy.updateCo= mmits newest commit =3D 1[segments_1] [junit4:junit4] 2> 23394 T703 oascc.ZkStateReader.updateClusterState Upda= ting cloud state from ZooKeeper...=20 [junit4:junit4] 2> 23395 T750 C52 P49318 oasc.SolrDeletionPolicy.onCommit= SolrDeletionPolicy.onCommit: commits:num=3D2 [junit4:junit4] 2> =09=09commit{dir=3DRateLimitedDirectoryWrapper(NRTCach= ingDirectory(org.apache.lucene.store.NIOFSDirectory@/Users/jenkins/jenkins-= slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/org.a= pache.solr.cloud.BasicDistributedZkTest-1359979901483/jetty2/index lockFact= ory=3Dorg.apache.lucene.store.NativeFSLockFactory@684e8b72; maxCacheMB=3D48= .0 maxMergeSizeMB=3D4.0)),segFN=3Dsegments_1,generation=3D1,filenames=3D[se= gments_1] [junit4:junit4] 2> =09=09commit{dir=3DRateLimitedDirectoryWrapper(NRTCach= ingDirectory(org.apache.lucene.store.NIOFSDirectory@/Users/jenkins/jenkins-= slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/org.a= pache.solr.cloud.BasicDistributedZkTest-1359979901483/jetty2/index lockFact= ory=3Dorg.apache.lucene.store.NativeFSLockFactory@684e8b72; maxCacheMB=3D48= .0 maxMergeSizeMB=3D4.0)),segFN=3Dsegments_2,generation=3D2,filenames=3D[se= gments_2] [junit4:junit4] 2> 23395 T750 C52 P49318 oasc.SolrDeletionPolicy.updateCo= mmits newest commit =3D 2[segments_2] [junit4:junit4] 2> 23397 T750 C52 P49318 oasc.CachingDirectoryFactory.clo= se Releasing directory:/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-t= runk-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistr= ibutedZkTest-1359979901483/jetty2 [junit4:junit4] 2> 23398 T750 C52 P49318 oass.SolrIndexSearcher. Op= ening Searcher@7665ed1c realtime [junit4:junit4] 2> 23398 T750 C52 P49318 oasu.DirectUpdateHandler2.commit= end_commit_flush [junit4:junit4] 2> 23399 T750 C52 P49318 /update {waitSearcher=3Dtrue&ope= nSearcher=3Dfalse&commit=3Dtrue&wt=3Djavabin&commit_end_point=3Dtrue&versio= n=3D2&softCommit=3Dfalse} {commit=3D} 0 17 [junit4:junit4] 2> 23400 T793 C50 P49325 oash.ReplicationHandler.inform C= ommits will be reserved for 10000 [junit4:junit4] 2> 23401 T793 C50 P49325 oash.SnapPuller. No value= set for 'pollInterval'. Timer Task not started. [junit4:junit4] 2> 23405 T753 C52 P49318 oash.ReplicationHandler.inform C= ommits will be reserved for 10000 [junit4:junit4] 2> 23406 T753 C52 P49318 REQ /replication {command=3Dinde= xversion&qt=3D/replication&wt=3Djavabin&version=3D2} status=3D0 QTime=3D1= =20 [junit4:junit4] 2> 23407 T793 C50 P49325 oash.SnapPuller.fetchLatestIndex= Master's generation: 2 [junit4:junit4] 2> 23407 T793 C50 P49325 oash.SnapPuller.fetchLatestIndex= Slave's generation: 1 [junit4:junit4] 2> 23408 T793 C50 P49325 oash.SnapPuller.fetchLatestIndex= Starting replication process [junit4:junit4] 2> 23410 T754 C52 P49318 oasc.CachingDirectoryFactory.clo= se Releasing directory:/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-t= runk-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistr= ibutedZkTest-1359979901483/jetty2 [junit4:junit4] 2> 23411 T754 C52 P49318 oasc.CachingDirectoryFactory.clo= se Releasing directory:/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-t= runk-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistr= ibutedZkTest-1359979901483/jetty2/index [junit4:junit4] 2> 23411 T754 C52 P49318 REQ /replication {command=3Dfile= list&qt=3D/replication&wt=3Djavabin&generation=3D2&version=3D2} status=3D0 = QTime=3D1=20 [junit4:junit4] 2> 23412 T793 C50 P49325 oash.SnapPuller.fetchLatestIndex= Number of files in latest index in master: 1 [junit4:junit4] 2> 23413 T793 C50 P49325 oasc.CachingDirectoryFactory.get= return new directory for /Users/jenkins/jenkins-slave/workspace/Lucene-Sol= r-trunk-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDi= stributedZkTest-1359979901483/jetty4/index.20130204061204880 forceNew:false [junit4:junit4] 2> 23414 T793 C50 P49325 oasc.CachingDirectoryFactory.clo= se Releasing directory:/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-t= runk-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistr= ibutedZkTest-1359979901483/jetty4 [junit4:junit4] 2> 23416 T793 C50 P49325 oash.SnapPuller.fetchLatestIndex= Starting download to RateLimitedDirectoryWrapper(NRTCachingDirectory(org.a= pache.lucene.store.NIOFSDirectory@/Users/jenkins/jenkins-slave/workspace/Lu= cene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/org.apache.solr.cloud.B= asicDistributedZkTest-1359979901483/jetty4/index.20130204061204880 lockFact= ory=3Dorg.apache.lucene.store.NativeFSLockFactory@7f822e2; maxCacheMB=3D48.= 0 maxMergeSizeMB=3D4.0)) fullCopy=3Dtrue [junit4:junit4] 2> 23420 T752 C52 P49318 REQ /replication {file=3Dsegment= s_2&command=3Dfilecontent&checksum=3Dtrue&wt=3Dfilestream&qt=3D/replication= &generation=3D2} status=3D0 QTime=3D0=20 [junit4:junit4] 2> 23423 T793 C50 P49325 oasc.CachingDirectoryFactory.clo= se Releasing directory:/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-t= runk-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistr= ibutedZkTest-1359979901483/jetty4/index [junit4:junit4] 2> 23423 T793 C50 P49325 oash.SnapPuller.fetchLatestIndex= Total time taken for download : 0 secs [junit4:junit4] 2> 23424 T793 C50 P49325 oash.SnapPuller.modifyIndexProps= New index installed. Updating index properties... index=3Dindex.2013020406= 1204880 [junit4:junit4] 2> 23425 T793 C50 P49325 oasc.CachingDirectoryFactory.clo= se Releasing directory:/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-t= runk-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistr= ibutedZkTest-1359979901483/jetty4 [junit4:junit4] 2> 23426 T793 C50 P49325 oasc.CachingDirectoryFactory.clo= se Releasing directory:/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-t= runk-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistr= ibutedZkTest-1359979901483/jetty4 [junit4:junit4] 2> 23427 T793 C50 P49325 oasc.SolrCore.getNewIndexDir New= index directory detected: old=3D./org.apache.solr.cloud.BasicDistributedZk= Test-1359979901483/jetty4/index/ new=3D./org.apache.solr.cloud.BasicDistrib= utedZkTest-1359979901483/jetty4/index.20130204061204880 [junit4:junit4] 2> 23436 T793 C50 P49325 oasc.SolrDeletionPolicy.onInit S= olrDeletionPolicy.onInit: commits:num=3D1 [junit4:junit4] 2> =09=09commit{dir=3DRateLimitedDirectoryWrapper(NRTCach= ingDirectory(org.apache.lucene.store.NIOFSDirectory@/Users/jenkins/jenkins-= slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/org.a= pache.solr.cloud.BasicDistributedZkTest-1359979901483/jetty4/index.20130204= 061204880 lockFactory=3Dorg.apache.lucene.store.NativeFSLockFactory@7f822e2= ; maxCacheMB=3D48.0 maxMergeSizeMB=3D4.0)),segFN=3Dsegments_2,generation=3D= 2,filenames=3D[segments_2] [junit4:junit4] 2> 23437 T793 C50 P49325 oasc.SolrDeletionPolicy.updateCo= mmits newest commit =3D 2[segments_2] [junit4:junit4] 2> 23438 T793 C50 P49325 oasc.CachingDirectoryFactory.clo= se Releasing directory:/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-t= runk-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistr= ibutedZkTest-1359979901483/jetty4 [junit4:junit4] 2> 23439 T793 C50 P49325 oasu.DefaultSolrCoreState.newInd= exWriter Creating new IndexWriter... [junit4:junit4] 2> 23439 T793 C50 P49325 oasu.DefaultSolrCoreState.newInd= exWriter Waiting until IndexWriter is unused... core=3Dcollection1 [junit4:junit4] 2> 23439 T793 C50 P49325 oasu.DefaultSolrCoreState.newInd= exWriter Rollback old IndexWriter... core=3Dcollection1 [junit4:junit4] 2> 23440 T793 C50 P49325 oasc.CachingDirectoryFactory.clo= se Releasing directory:/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-t= runk-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistr= ibutedZkTest-1359979901483/jetty4/index.20130204061204880 [junit4:junit4] 2> 23441 T793 C50 P49325 oasc.CachingDirectoryFactory.clo= se Releasing directory:/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-t= runk-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistr= ibutedZkTest-1359979901483/jetty4 [junit4:junit4] 2> 23444 T793 C50 P49325 oasc.SolrDeletionPolicy.onInit S= olrDeletionPolicy.onInit: commits:num=3D1 [junit4:junit4] 2> =09=09commit{dir=3DRateLimitedDirectoryWrapper(NRTCach= ingDirectory(org.apache.lucene.store.NIOFSDirectory@/Users/jenkins/jenkins-= slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/org.a= pache.solr.cloud.BasicDistributedZkTest-1359979901483/jetty4/index.20130204= 061204880 lockFactory=3Dorg.apache.lucene.store.NativeFSLockFactory@7f822e2= ; maxCacheMB=3D48.0 maxMergeSizeMB=3D4.0)),segFN=3Dsegments_2,generation=3D= 2,filenames=3D[segments_2] [junit4:junit4] 2> 23444 T793 C50 P49325 oasc.SolrDeletionPolicy.updateCo= mmits newest commit =3D 2[segments_2] [junit4:junit4] 2> 23444 T793 C50 P49325 oasu.DefaultSolrCoreState.newInd= exWriter New IndexWriter is ready to be used. [junit4:junit4] 2> 23445 T793 C50 P49325 oasc.CachingDirectoryFactory.clo= se Releasing directory:/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-t= runk-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistr= ibutedZkTest-1359979901483/jetty4 [junit4:junit4] 2> 23446 T793 C50 P49325 oass.SolrIndexSearcher. Op= ening Searcher@26722fb6 main [junit4:junit4] 2> 23450 T792 oasc.SolrCore.registerSearcher [collection1= ] Registered new searcher Searcher@26722fb6 main{StandardDirectoryReader(se= gments_2:1:nrt)} [junit4:junit4] 2> 23451 T792 oasc.CachingDirectoryFactory.close Releasin= g directory:/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX= /solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZkTes= t-1359979901483/jetty4/index [junit4:junit4] 2> 23452 T793 C50 P49325 oasu.DirectUpdateHandler2.commit= start commit{,optimize=3Dfalse,openSearcher=3Dfalse,waitSearcher=3Dfalse,e= xpungeDeletes=3Dfalse,softCommit=3Dfalse} [junit4:junit4] 2> 23462 T793 C50 P49325 oasc.SolrDeletionPolicy.onCommit= SolrDeletionPolicy.onCommit: commits:num=3D2 [junit4:junit4] 2> =09=09commit{dir=3DRateLimitedDirectoryWrapper(NRTCach= ingDirectory(org.apache.lucene.store.NIOFSDirectory@/Users/jenkins/jenkins-= slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/org.a= pache.solr.cloud.BasicDistributedZkTest-1359979901483/jetty4/index.20130204= 061204880 lockFactory=3Dorg.apache.lucene.store.NativeFSLockFactory@7f822e2= ; maxCacheMB=3D48.0 maxMergeSizeMB=3D4.0)),segFN=3Dsegments_2,generation=3D= 2,filenames=3D[segments_2] [junit4:junit4] 2> =09=09commit{dir=3DRateLimitedDirectoryWrapper(NRTCach= ingDirectory(org.apache.lucene.store.NIOFSDirectory@/Users/jenkins/jenkins-= slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/org.a= pache.solr.cloud.BasicDistributedZkTest-1359979901483/jetty4/index.20130204= 061204880 lockFactory=3Dorg.apache.lucene.store.NativeFSLockFactory@7f822e2= ; maxCacheMB=3D48.0 maxMergeSizeMB=3D4.0)),segFN=3Dsegments_3,generation=3D= 3,filenames=3D[segments_3] [junit4:junit4] 2> 23462 T793 C50 P49325 oasc.SolrDeletionPolicy.updateCo= mmits newest commit =3D 3[segments_3] [junit4:junit4] 2> 23463 T793 C50 P49325 oasc.CachingDirectoryFactory.clo= se Releasing directory:/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-t= runk-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistr= ibutedZkTest-1359979901483/jetty4 [junit4:junit4] 2> 23464 T793 C50 P49325 oasu.DirectUpdateHandler2.commit= end_commit_flush [junit4:junit4] 2> 23464 T793 C50 P49325 oasc.CachingDirectoryFactory.clo= se Releasing directory:/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-t= runk-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistr= ibutedZkTest-1359979901483/jetty4/index.20130204061204880 [junit4:junit4] 2> 23464 T793 C50 P49325 oasc.CachingDirectoryFactory.clo= se Releasing directory:/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-t= runk-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistr= ibutedZkTest-1359979901483/jetty4/index [junit4:junit4] 2> 23465 T793 C50 P49325 oasc.RecoveryStrategy.replay No = replay needed. core=3Dcollection1 [junit4:junit4] 2> 23465 T793 C50 P49325 oasc.RecoveryStrategy.doRecovery= Replication Recovery was successful - registering as Active. core=3Dcollec= tion1 [junit4:junit4] 2> 23465 T793 C50 P49325 oasc.ZkController.publish publis= hing core=3Dcollection1 state=3Dactive [junit4:junit4] 2> 23465 T793 C50 P49325 oasc.ZkController.publish numSha= rds not found on descriptor - reading it from system property [junit4:junit4] 2> 23469 T793 C50 P49325 oasc.RecoveryStrategy.doRecovery= Finished recovery process. core=3Dcollection1 [junit4:junit4] 2> 24288 T726 oascc.ZkStateReader.updateClusterState Upda= ting cloud state from ZooKeeper...=20 [junit4:junit4] 2> 24289 T726 oasc.Overseer$ClusterStateUpdater.updateSta= te Update state numShards=3D2 message=3D{ [junit4:junit4] 2> =09 "operation":"state", [junit4:junit4] 2> =09 "numShards":"2", [junit4:junit4] 2> =09 "shard":"shard2", [junit4:junit4] 2> =09 "roles":null, [junit4:junit4] 2> =09 "state":"active", [junit4:junit4] 2> =09 "core":"collection1", [junit4:junit4] 2> =09 "collection":"collection1", [junit4:junit4] 2> =09 "node_name":"127.0.0.1:49325_", [junit4:junit4] 2> =09 "base_url":"http://127.0.0.1:49325"} [junit4:junit4] 2> 24305 T774 oascc.ZkStateReader$2.process A cluster sta= te change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clus= terstate.json, has occurred - updating... (live nodes size: 5) [junit4:junit4] 2> 24306 T725 oascc.ZkStateReader$2.process A cluster sta= te change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clus= terstate.json, has occurred - updating... (live nodes size: 5) [junit4:junit4] 2> 24306 T759 oascc.ZkStateReader$2.process A cluster sta= te change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clus= terstate.json, has occurred - updating... (live nodes size: 5) [junit4:junit4] 2> 24307 T744 oascc.ZkStateReader$2.process A cluster sta= te change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clus= terstate.json, has occurred - updating... (live nodes size: 5) [junit4:junit4] 2> 24307 T790 oascc.ZkStateReader$2.process A cluster sta= te change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clus= terstate.json, has occurred - updating... (live nodes size: 5) [junit4:junit4] 2> 24306 T731 oascc.ZkStateReader$2.process A cluster sta= te change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clus= terstate.json, has occurred - updating... (live nodes size: 5) [junit4:junit4] 2> 24406 T703 oascc.ZkStateReader.updateClusterState Upda= ting cloud state from ZooKeeper...=20 [junit4:junit4] 2> 24407 T703 oasc.AbstractDistribZkTestBase.waitForRecov= eriesToFinish Recoveries finished - collection: collection1 [junit4:junit4] 2> ASYNC NEW_CORE C53 name=3Dcollection1 org.apache.solr= .core.SolrCore@d8778c6 url=3Dhttp://127.0.0.1:49311/collection1 node=3D127.= 0.0.1:49311_ C53_STATE=3Dcoll:control_collection core:collection1 props:{sh= ard=3Dshard1, roles=3Dnull, state=3Dactive, core=3Dcollection1, collection= =3Dcontrol_collection, node_name=3D127.0.0.1:49311_, base_url=3Dhttp://127.= 0.0.1:49311, leader=3Dtrue} [junit4:junit4] 2> 24423 T720 C53 P49311 oasc.CachingDirectoryFactory.clo= se Releasing directory:/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-t= runk-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistr= ibutedZkTest-1359979901483/control/data [junit4:junit4] 2> 24434 T720 C53 P49311 oasc.SolrDeletionPolicy.onInit S= olrDeletionPolicy.onInit: commits:num=3D1 [junit4:junit4] 2> =09=09commit{dir=3DRateLimitedDirectoryWrapper(NRTCach= ingDirectory(org.apache.lucene.store.NIOFSDirectory@/Users/jenkins/jenkins-= slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/org.a= pache.solr.cloud.BasicDistributedZkTest-1359979901483/control/data/index lo= ckFactory=3Dorg.apache.lucene.store.NativeFSLockFactory@45f60505; maxCacheM= B=3D48.0 maxMergeSizeMB=3D4.0)),segFN=3Dsegments_1,generation=3D1,filenames= =3D[segments_1] [junit4:junit4] 2> 24436 T720 C53 P49311 oasc.SolrDeletionPolicy.updateCo= mmits newest commit =3D 1[segments_1] [junit4:junit4] 2> 24462 T720 C53 P49311 oasc.CachingDirectoryFactory.clo= se Releasing directory:/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-t= runk-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistr= ibutedZkTest-1359979901483/control/data [junit4:junit4] 2> 24463 T720 C53 P49311 oass.SolrIndexSearcher. Op= ening Searcher@618c90ec realtime [junit4:junit4] 2> 24465 T720 C53 P49311 /update {wt=3Djavabin&version=3D= 2} {deleteByQuery=3D*:* (-1426042310770032640)} 0 47 [junit4:junit4] 2> 24479 T735 C51 P49315 oasc.CachingDirectoryFactory.clo= se Releasing directory:/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-t= runk-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistr= ibutedZkTest-1359979901483/jetty1 [junit4:junit4] 2> 24502 T753 C52 P49318 oasc.CachingDirectoryFactory.clo= se Releasing directory:/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-t= runk-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistr= ibutedZkTest-1359979901483/jetty2 [junit4:junit4] 2> C49_STATE=3Dcoll:collection1 core:collection1 props:{= shard=3Dshard1, roles=3Dnull, state=3Dactive, core=3Dcollection1, collectio= n=3Dcollection1, node_name=3D127.0.0.1:49321_, base_url=3Dhttp://127.0.0.1:= 49321} [junit4:junit4] 2> 24522 T766 C49 P49321 oasc.CachingDirectoryFactory.clo= se Releasing directory:/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-t= runk-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistr= ibutedZkTest-1359979901483/jetty3 [junit4:junit4] 2> C50_STATE=3Dcoll:collection1 core:collection1 props:{= shard=3Dshard2, roles=3Dnull, state=3Dactive, core=3Dcollection1, collectio= n=3Dcollection1, node_name=3D127.0.0.1:49325_, base_url=3Dhttp://127.0.0.1:= 49325} [junit4:junit4] 2> 24524 T781 C50 P49325 oasc.CachingDirectoryFactory.clo= se Releasing directory:/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-t= runk-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistr= ibutedZkTest-1359979901483/jetty4 [junit4:junit4] 2> 24525 T766 C49 P49321 /update {update.distrib=3DFROMLE= ADER&_version_=3D-1426042310828752896&update.from=3Dhttp://127.0.0.1:49315/= collection1/&wt=3Djavabin&version=3D2} {deleteByQuery=3D*:* (-1426042310828= 752896)} 0 16 [junit4:junit4] 2> 24526 T781 C50 P49325 /update {update.distrib=3DFROMLE= ADER&_version_=3D-1426042310851821568&update.from=3Dhttp://127.0.0.1:49318/= collection1/&wt=3Djavabin&version=3D2} {deleteByQuery=3D*:* (-1426042310851= 821568)} 0 6 [junit4:junit4] 2> 24528 T753 C52 P49318 /update {update.distrib=3DTOLEAD= ER&wt=3Djavabin&version=3D2} {deleteByQuery=3D*:* (-1426042310851821568)} 0= 29 [junit4:junit4] 2> 24530 T735 C51 P49315 /update {wt=3Djavabin&version=3D= 2} {deleteByQuery=3D*:* (-1426042310828752896)} 0 59 [junit4:junit4] 2> 24568 T721 C53 P49311 /update {wt=3Djavabin&version=3D= 2} {add=3D[1 (1426042310910541824)]} 0 15 [junit4:junit4] 2> 24596 T767 C49 P49321 /update {distrib.from=3Dhttp://1= 27.0.0.1:49315/collection1/&update.distrib=3DFROMLEADER&wt=3Djavabin&versio= n=3D2} {add=3D[1 (1426042310927319040)]} 0 4 [junit4 [...truncated too long message...] DistributedZkTest -Dtests.method=3DtestDistribSearch -Dtests.seed=3D930688C= 156120156 -Dtests.slow=3Dtrue -Dtests.locale=3Dzh_HK -Dtests.timezone=3DAme= rica/Costa_Rica -Dtests.file.encoding=3DISO-8859-1 [junit4:junit4] FAILURE 427s | BasicDistributedZkTest.testDistribSearch <<= < [junit4:junit4] > Throwable #1: java.lang.AssertionError: There are stil= l nodes recoverying - waited for 230 seconds [junit4:junit4] > =09at __randomizedtesting.SeedInfo.seed([930688C156120= 156:12E006D9214D616A]:0) [junit4:junit4] > =09at org.junit.Assert.fail(Assert.java:93) [junit4:junit4] > =09at org.apache.solr.cloud.AbstractDistribZkTestBase.= waitForRecoveriesToFinish(AbstractDistribZkTestBase.java:168) [junit4:junit4] > =09at org.apache.solr.cloud.AbstractDistribZkTestBase.= waitForRecoveriesToFinish(AbstractDistribZkTestBase.java:126) [junit4:junit4] > =09at org.apache.solr.cloud.AbstractDistribZkTestBase.= waitForRecoveriesToFinish(AbstractDistribZkTestBase.java:121) [junit4:junit4] > =09at org.apache.solr.cloud.BasicDistributedZkTest.tes= tCoreUnloadAndLeaders(BasicDistributedZkTest.java:599) [junit4:junit4] > =09at org.apache.solr.cloud.BasicDistributedZkTest.doT= est(BasicDistributedZkTest.java:337) [junit4:junit4] > =09at org.apache.solr.BaseDistributedSearchTestCase.te= stDistribSearch(BaseDistributedSearchTestCase.java:794) [junit4:junit4] > =09at sun.reflect.NativeMethodAccessorImpl.invoke0(Nat= ive Method) [junit4:junit4] > =09at sun.reflect.NativeMethodAccessorImpl.invoke(Nati= veMethodAccessorImpl.java:57) [junit4:junit4] > =09at sun.reflect.DelegatingMethodAccessorImpl.invoke(= DelegatingMethodAccessorImpl.java:43) [junit4:junit4] > =09at java.lang.reflect.Method.invoke(Method.java:601) [junit4:junit4] > =09at com.carrotsearch.randomizedtesting.RandomizedRun= ner.invoke(RandomizedRunner.java:1559) [junit4:junit4] > =09at com.carrotsearch.randomizedtesting.RandomizedRun= ner.access$600(RandomizedRunner.java:79) [junit4:junit4] > =09at com.carrotsearch.randomizedtesting.RandomizedRun= ner$6.evaluate(RandomizedRunner.java:737) [junit4:junit4] > =09at com.carrotsearch.randomizedtesting.RandomizedRun= ner$7.evaluate(RandomizedRunner.java:773) [junit4:junit4] > =09at com.carrotsearch.randomizedtesting.RandomizedRun= ner$8.evaluate(RandomizedRunner.java:787) [junit4:junit4] > =09at com.carrotsearch.randomizedtesting.rules.SystemP= ropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:53) [junit4:junit4] > =09at org.apache.lucene.util.TestRuleSetupTeardownChai= ned$1.evaluate(TestRuleSetupTeardownChained.java:50) [junit4:junit4] > =09at org.apache.lucene.util.TestRuleFieldCacheSanity$= 1.evaluate(TestRuleFieldCacheSanity.java:51) [junit4:junit4] > =09at org.apache.lucene.util.AbstractBeforeAfterRule$1= .evaluate(AbstractBeforeAfterRule.java:46) [junit4:junit4] > =09at com.carrotsearch.randomizedtesting.rules.SystemP= ropertiesInvariantRule$1.evaluate(SystemPropertiesInvariantRule.java:55) [junit4:junit4] > =09at org.apache.lucene.util.TestRuleThreadAndTestName= $1.evaluate(TestRuleThreadAndTestName.java:49) [junit4:junit4] > =09at org.apache.lucene.util.TestRuleIgnoreAfterMaxFai= lures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:70) [junit4:junit4] > =09at org.apache.lucene.util.TestRuleMarkFailure$1.eva= luate(TestRuleMarkFailure.java:48) [junit4:junit4] > =09at com.carrotsearch.randomizedtesting.rules.Stateme= ntAdapter.evaluate(StatementAdapter.java:36) [junit4:junit4] > =09at com.carrotsearch.randomizedtesting.ThreadLeakCon= trol$StatementRunner.run(ThreadLeakControl.java:358) [junit4:junit4] > =09at com.carrotsearch.randomizedtesting.ThreadLeakCon= trol.forkTimeoutingTask(ThreadLeakControl.java:782) [junit4:junit4] > =09at com.carrotsearch.randomizedtesting.ThreadLeakCon= trol$3.evaluate(ThreadLeakControl.java:442) [junit4:junit4] > =09at com.carrotsearch.randomizedtesting.RandomizedRun= ner.runSingleTest(RandomizedRunner.java:746) [junit4:junit4] > =09at com.carrotsearch.randomizedtesting.RandomizedRun= ner$3.evaluate(RandomizedRunner.java:648) [junit4:junit4] > =09at com.carrotsearch.randomizedtesting.RandomizedRun= ner$4.evaluate(RandomizedRunner.java:682) [junit4:junit4] > =09at com.carrotsearch.randomizedtesting.RandomizedRun= ner$5.evaluate(RandomizedRunner.java:693) [junit4:junit4] > =09at com.carrotsearch.randomizedtesting.rules.Stateme= ntAdapter.evaluate(StatementAdapter.java:36) [junit4:junit4] > =09at com.carrotsearch.randomizedtesting.rules.SystemP= ropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:53) [junit4:junit4] > =09at org.apache.lucene.util.AbstractBeforeAfterRule$1= .evaluate(AbstractBeforeAfterRule.java:46) [junit4:junit4] > =09at org.apache.lucene.util.TestRuleStoreClassName$1.= evaluate(TestRuleStoreClassName.java:42) [junit4:junit4] > =09at com.carrotsearch.randomizedtesting.rules.SystemP= ropertiesInvariantRule$1.evaluate(SystemPropertiesInvariantRule.java:55) [junit4:junit4] > =09at com.carrotsearch.randomizedtesting.rules.NoShado= wingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule= .java:39) [junit4:junit4] > =09at com.carrotsearch.randomizedtesting.rules.NoShado= wingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule= .java:39) [junit4:junit4] > =09at com.carrotsearch.randomizedtesting.rules.Stateme= ntAdapter.evaluate(StatementAdapter.java:36) [junit4:junit4] > =09at org.apache.lucene.util.TestRuleAssertionsRequire= d$1.evaluate(TestRuleAssertionsRequired.java:43) [junit4:junit4] > =09at org.apache.lucene.util.TestRuleMarkFailure$1.eva= luate(TestRuleMarkFailure.java:48) [junit4:junit4] > =09at org.apache.lucene.util.TestRuleIgnoreAfterMaxFai= lures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:70) [junit4:junit4] > =09at org.apache.lucene.util.TestRuleIgnoreTestSuites$= 1.evaluate(TestRuleIgnoreTestSuites.java:55) [junit4:junit4] > =09at com.carrotsearch.randomizedtesting.rules.Stateme= ntAdapter.evaluate(StatementAdapter.java:36) [junit4:junit4] > =09at com.carrotsearch.randomizedtesting.ThreadLeakCon= trol$StatementRunner.run(ThreadLeakControl.java:358) [junit4:junit4] > =09at java.lang.Thread.run(Thread.java:722) [junit4:junit4] 2> 426792 T703 oas.SolrTestCaseJ4.deleteCore ###deleteCor= e [junit4:junit4] 2> NOTE: test params are: codec=3DLucene42: {n_f1=3DPosti= ngsFormat(name=3DNestedPulsing), foo_b=3DMockVariableIntBlock(baseBlockSize= =3D126), cat=3DPostingsFormat(name=3DAsserting), foo_d=3DLucene41(blocksize= =3D128), foo_f=3DMockVariableIntBlock(baseBlockSize=3D126), n_tl1=3DPosting= sFormat(name=3DNestedPulsing), n_d1=3DPostingsFormat(name=3DAsserting), rnd= _b=3DLucene41(blocksize=3D128), intDefault=3DPostingsFormat(name=3DNestedPu= lsing), n_td1=3DPostingsFormat(name=3DNestedPulsing), timestamp=3DPostingsF= ormat(name=3DAsserting), id=3DLucene41(blocksize=3D128), range_facet_sl=3DL= ucene41(blocksize=3D128), range_facet_si=3DPostingsFormat(name=3DAsserting)= , oddField_s=3DLucene41(blocksize=3D128), sequence_i=3DLucene41(blocksize= =3D128), name=3DLucene41(blocksize=3D128), foo_i=3DPostingsFormat(name=3DNe= stedPulsing), regex_dup_B_s=3DPostingsFormat(name=3DAsserting), multiDefaul= t=3DPostingsFormat(name=3DAsserting), n_tf1=3DPostingsFormat(name=3DAsserti= ng), n_dt1=3DPostingsFormat(name=3DNestedPulsing), genre_s=3DLucene41(block= size=3D128), author_t=3DPostingsFormat(name=3DNestedPulsing), n_ti1=3DLucen= e41(blocksize=3D128), range_facet_l=3DPostingsFormat(name=3DAsserting), tex= t=3DMockVariableIntBlock(baseBlockSize=3D126), _version_=3DPostingsFormat(n= ame=3DNestedPulsing), val_i=3DLucene41(blocksize=3D128), SubjectTerms_mface= t=3DPostingsFormat(name=3DNestedPulsing), series_t=3DPostingsFormat(name=3D= NestedPulsing), a_t=3DPostingsFormat(name=3DAsserting), n_tdt1=3DPostingsFo= rmat(name=3DNestedPulsing), regex_dup_A_s=3DMockVariableIntBlock(baseBlockS= ize=3D126), price=3DMockVariableIntBlock(baseBlockSize=3D126), other_tl1=3D= PostingsFormat(name=3DNestedPulsing), n_l1=3DPostingsFormat(name=3DAssertin= g), a_si=3DPostingsFormat(name=3DNestedPulsing), inStock=3DMockVariableIntB= lock(baseBlockSize=3D126)}, sim=3DRandomSimilarityProvider(queryNorm=3Dfals= e,coord=3Dyes): {}, locale=3Dzh_HK, timezone=3DAmerica/Costa_Rica [junit4:junit4] 2> NOTE: Mac OS X 10.8.2 x86_64/Oracle Corporation 1.7.0_= 10 (64-bit)/cpus=3D2,threads=3D1,free=3D53617144,total=3D143335424 [junit4:junit4] 2> NOTE: All tests run in this JVM: [TestCoreContainer, T= estReplicationHandler, TermVectorComponentTest, FieldAnalysisRequestHandler= Test, AutoCommitTest, AlternateDirectoryTest, TestStressRecovery, ShardRout= ingCustomTest, RequestHandlersTest, ZkSolrClientTest, TimeZoneUtilsTest, An= alysisAfterCoreReloadTest, TestSolrCoreProperties, TestCollationField, Test= IndexingPerformance, TestSolrQueryParser, ZkCLITest, DistributedSpellCheckC= omponentTest, BadComponentTest, TestPhraseSuggestions, IndexBasedSpellCheck= erTest, CurrencyFieldTest, LukeRequestHandlerTest, TestSystemIdResolver, So= lrInfoMBeanTest, TestQuerySenderListener, CSVRequestHandlerTest, BasicDistr= ibutedZkTest] [junit4:junit4] Completed in 427.26s, 1 test, 1 failure <<< FAILURES! [...truncated 678 lines...] BUILD FAILED /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/build.xml:3= 46: The following error occurred while executing this line: /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/build.xml:3= 9: The following error occurred while executing this line: /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build.= xml:178: The following error occurred while executing this line: /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/common= -build.xml:428: The following error occurred while executing this line: /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/lucene/comm= on-build.xml:1176: The following error occurred while executing this line: /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/lucene/comm= on-build.xml:841: There were test failures: 249 suites, 1038 tests, 1 failu= re, 14 ignored (3 assumptions) Total time: 67 minutes 50 seconds Build step 'Invoke Ant' marked build as failure Archiving artifacts Recording test results Description set: Java: 64bit/jdk1.7.0 -XX:+UseConcMarkSweepGC Email was triggered for: Failure Sending email for trigger: Failure ------=_Part_38_1931705201.1359981667568 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_38_1931705201.1359981667568--