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 BAE18ED07 for ; Sat, 2 Feb 2013 04:16:11 +0000 (UTC) Received: (qmail 69126 invoked by uid 500); 2 Feb 2013 04:16:10 -0000 Delivered-To: apmail-lucene-dev-archive@lucene.apache.org Received: (qmail 69031 invoked by uid 500); 2 Feb 2013 04:16:09 -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 69005 invoked by uid 99); 2 Feb 2013 04:16:08 -0000 Received: from athena.apache.org (HELO athena.apache.org) (140.211.11.136) by apache.org (qpsmtpd/0.29) with ESMTP; Sat, 02 Feb 2013 04:16:08 +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; Sat, 02 Feb 2013 04:15:59 +0000 Received: from serv1 (localhost.localdomain [127.0.0.1]) by mail.sd-datasolutions.de (Postfix) with ESMTP id 7EEBD14AA056 for ; Sat, 2 Feb 2013 04:15:35 +0000 (UTC) Date: Sat, 2 Feb 2013 04:15:13 +0000 (UTC) From: Policeman Jenkins Server To: dev@lucene.apache.org Message-ID: <1911897418.19.1359778535496.JavaMail.jenkins@serv1.sd-datasolutions.de> In-Reply-To: <148719997.17.1359761995304.JavaMail.jenkins@serv1.sd-datasolutions.de> References: <148719997.17.1359761995304.JavaMail.jenkins@serv1.sd-datasolutions.de> Subject: [JENKINS] Lucene-Solr-trunk-MacOSX (64bit/jdk1.7.0) - Build # 171 - Still Failing! MIME-Version: 1.0 Content-Type: multipart/mixed; boundary="----=_Part_18_1775913254.1359778513974" X-Jenkins-Job: Lucene-Solr-trunk-MacOSX X-Jenkins-Result: FAILURE X-Virus-Checked: Checked by ClamAV on apache.org ------=_Part_18_1775913254.1359778513974 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: quoted-printable Build: http://jenkins.thetaphi.de/job/Lucene-Solr-trunk-MacOSX/171/ Java: 64bit/jdk1.7.0 -XX:+UseSerialGC 4 tests failed. FAILED: junit.framework.TestSuite.org.apache.solr.cloud.BasicDistributedZk= Test Error Message: ERROR: SolrIndexSearcher opens=3D610 closes=3D609 Stack Trace: java.lang.AssertionError: ERROR: SolrIndexSearcher opens=3D610 closes=3D609 =09at __randomizedtesting.SeedInfo.seed([898A621A89DCE35B]:0) =09at org.junit.Assert.fail(Assert.java:93) =09at org.apache.solr.SolrTestCaseJ4.endTrackingSearchers(SolrTestCaseJ4.ja= va:246) =09at org.apache.solr.SolrTestCaseJ4.afterClass(SolrTestCaseJ4.java:97) =09at sun.reflect.GeneratedMethodAccessor17.invoke(Unknown Source) =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$5.evaluate(Random= izedRunner.java:700) =09at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(St= atementAdapter.java:36) =09at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$= 1.evaluate(SystemPropertiesRestoreRule.java:53) =09at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBef= oreAfterRule.java:46) =09at org.apache.lucene.util.TestRuleStoreClassName$1.evaluate(TestRuleStor= eClassName.java:42) =09at com.carrotsearch.randomizedtesting.rules.SystemPropertiesInvariantRul= e$1.evaluate(SystemPropertiesInvariantRule.java:55) =09at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMeth= odsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:39) =09at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMeth= odsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:39) =09at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(St= atementAdapter.java:36) =09at org.apache.lucene.util.TestRuleAssertionsRequired$1.evaluate(TestRule= AssertionsRequired.java:43) =09at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFai= lure.java:48) =09at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(Test= RuleIgnoreAfterMaxFailures.java:70) =09at org.apache.lucene.util.TestRuleIgnoreTestSuites$1.evaluate(TestRuleIg= noreTestSuites.java:55) =09at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(St= atementAdapter.java:36) =09at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.= run(ThreadLeakControl.java:358) =09at java.lang.Thread.run(Thread.java:722) FAILED: junit.framework.TestSuite.org.apache.solr.cloud.BasicDistributedZk= Test Error Message: 2 threads leaked from SUITE scope at org.apache.solr.cloud.BasicDistributed= ZkTest: 1) Thread[id=3D1980, name=3DsearcherExecutor-1104-thread-1, sta= te=3DWAITING, group=3DTGRP-BasicDistributedZkTest] at sun.misc.Unsa= fe.park(Native Method) at java.util.concurrent.locks.LockSupport.pa= rk(LockSupport.java:186) at java.util.concurrent.locks.AbstractQueu= edSynchronizer$ConditionObject.await(AbstractQueuedSynchronizer.java:2043) = at java.util.concurrent.LinkedBlockingQueue.take(LinkedBlockingQueu= e.java:442) at java.util.concurrent.ThreadPoolExecutor.getTask(Thre= adPoolExecutor.java:1043) at java.util.concurrent.ThreadPoolExecuto= r.runWorker(ThreadPoolExecutor.java:1103) at java.util.concurrent.T= hreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:603) at java.l= ang.Thread.run(Thread.java:722) 2) Thread[id=3D1992, name=3DRecoveryThre= ad, state=3DTIMED_WAITING, group=3DTGRP-BasicDistributedZkTest] at = java.lang.Thread.sleep(Native Method) at org.apache.solr.cloud.Reco= veryStrategy.doRecovery(RecoveryStrategy.java:490) at org.apache.so= lr.cloud.RecoveryStrategy.run(RecoveryStrategy.java:223) Stack Trace: com.carrotsearch.randomizedtesting.ThreadLeakError: 2 threads leaked from S= UITE scope at org.apache.solr.cloud.BasicDistributedZkTest:=20 1) Thread[id=3D1980, name=3DsearcherExecutor-1104-thread-1, state=3DWAIT= ING, group=3DTGRP-BasicDistributedZkTest] at sun.misc.Unsafe.park(Native Method) at java.util.concurrent.locks.LockSupport.park(LockSupport.java:186= ) at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionO= bject.await(AbstractQueuedSynchronizer.java:2043) at java.util.concurrent.LinkedBlockingQueue.take(LinkedBlockingQueu= e.java:442) at java.util.concurrent.ThreadPoolExecutor.getTask(ThreadPoolExecut= or.java:1043) at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExec= utor.java:1103) at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExe= cutor.java:603) at java.lang.Thread.run(Thread.java:722) 2) Thread[id=3D1992, name=3DRecoveryThread, state=3DTIMED_WAITING, group= =3DTGRP-BasicDistributedZkTest] at java.lang.Thread.sleep(Native Method) at org.apache.solr.cloud.RecoveryStrategy.doRecovery(RecoveryStrate= gy.java:490) at org.apache.solr.cloud.RecoveryStrategy.run(RecoveryStrategy.java= :223) =09at __randomizedtesting.SeedInfo.seed([898A621A89DCE35B]:0) FAILED: junit.framework.TestSuite.org.apache.solr.cloud.BasicDistributedZk= Test Error Message: There are still zombie threads that couldn't be terminated: 1) Thread[id= =3D1980, name=3DsearcherExecutor-1104-thread-1, state=3DWAITING, group=3DTG= RP-BasicDistributedZkTest] at sun.misc.Unsafe.park(Native Method) = at java.util.concurrent.locks.LockSupport.park(LockSupport.java:186)= at java.util.concurrent.locks.AbstractQueuedSynchronizer$Condition= Object.await(AbstractQueuedSynchronizer.java:2043) at java.util.con= current.LinkedBlockingQueue.take(LinkedBlockingQueue.java:442) at j= ava.util.concurrent.ThreadPoolExecutor.getTask(ThreadPoolExecutor.java:1043= ) at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolEx= ecutor.java:1103) at java.util.concurrent.ThreadPoolExecutor$Worker= .run(ThreadPoolExecutor.java:603) at java.lang.Thread.run(Thread.ja= va:722) 2) Thread[id=3D1992, name=3DRecoveryThread, state=3DWAITING, gro= up=3DTGRP-BasicDistributedZkTest] at java.lang.Object.wait(Native M= ethod) at java.lang.Thread.join(Thread.java:1258) at java.l= ang.Thread.join(Thread.java:1332) at org.apache.solr.update.Default= SolrCoreState.cancelRecovery(DefaultSolrCoreState.java:244) at org.= apache.solr.update.DefaultSolrCoreState.close(DefaultSolrCoreState.java:271= ) at org.apache.solr.core.SolrCore.decrefSolrCoreState(SolrCore.jav= a:888) at org.apache.solr.core.SolrCore.close(SolrCore.java:980) = at org.apache.solr.cloud.RecoveryStrategy.run(RecoveryStrategy.java:2= 35) Stack Trace: com.carrotsearch.randomizedtesting.ThreadLeakError: There are still zombie = threads that couldn't be terminated: 1) Thread[id=3D1980, name=3DsearcherExecutor-1104-thread-1, state=3DWAIT= ING, group=3DTGRP-BasicDistributedZkTest] at sun.misc.Unsafe.park(Native Method) at java.util.concurrent.locks.LockSupport.park(LockSupport.java:186= ) at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionO= bject.await(AbstractQueuedSynchronizer.java:2043) at java.util.concurrent.LinkedBlockingQueue.take(LinkedBlockingQueu= e.java:442) at java.util.concurrent.ThreadPoolExecutor.getTask(ThreadPoolExecut= or.java:1043) at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExec= utor.java:1103) at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExe= cutor.java:603) at java.lang.Thread.run(Thread.java:722) 2) Thread[id=3D1992, name=3DRecoveryThread, state=3DWAITING, group=3DTGR= P-BasicDistributedZkTest] at java.lang.Object.wait(Native Method) at java.lang.Thread.join(Thread.java:1258) at java.lang.Thread.join(Thread.java:1332) at org.apache.solr.update.DefaultSolrCoreState.cancelRecovery(Defau= ltSolrCoreState.java:244) at org.apache.solr.update.DefaultSolrCoreState.close(DefaultSolrCor= eState.java:271) at org.apache.solr.core.SolrCore.decrefSolrCoreState(SolrCore.java:= 888) at org.apache.solr.core.SolrCore.close(SolrCore.java:980) at org.apache.solr.cloud.RecoveryStrategy.run(RecoveryStrategy.java= :235) =09at __randomizedtesting.SeedInfo.seed([898A621A89DCE35B]:0) FAILED: org.apache.solr.cloud.BasicDistributedZkTest.testDistribSearch Error Message: No registered leader was found, collection:multiunload2 slice:shard1 Stack Trace: org.apache.solr.common.SolrException: No registered leader was found, colle= ction:multiunload2 slice:shard1 =09at org.apache.solr.common.cloud.ZkStateReader.getLeaderRetry(ZkStateRead= er.java:429) =09at org.apache.solr.cloud.BasicDistributedZkTest.testStopAndStartCoresInO= neInstance(BasicDistributedZkTest.java:678) =09at org.apache.solr.cloud.BasicDistributedZkTest.doTest(BasicDistributedZ= kTest.java:339) =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 8917 lines...] [junit4:junit4] Suite: org.apache.solr.cloud.BasicDistributedZkTest [junit4:junit4] 2> 0 T1633 oas.SolrTestCaseJ4.startTrackingSearchers WARN= ING startTrackingSearchers: numOpens=3D2 numCloses=3D2 [junit4:junit4] 2> 1 T1633 oas.BaseDistributedSearchTestCase.initHostCont= ext Setting hostContext system property: / [junit4:junit4] 2> 5 T1633 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-1359778067125 [junit4:junit4] 2> 6 T1633 oasc.ZkTestServer.run STARTING ZK TEST SERVER [junit4:junit4] 2> 6 T1634 oasc.ZkTestServer$ZKServerMain.runFromConfig S= tarting server [junit4:junit4] 2> 8 T1634 oazs.ZooKeeperServer.setTickTime tickTime set = to 1000 [junit4:junit4] 2> 8 T1634 oazs.ZooKeeperServer.setMinSessionTimeout minS= essionTimeout set to -1 [junit4:junit4] 2> 9 T1634 oazs.ZooKeeperServer.setMaxSessionTimeout maxS= essionTimeout set to -1 [junit4:junit4] 2> 9 T1634 oazs.NIOServerCnxnFactory.configure binding to= port 0.0.0.0/0.0.0.0:0 [junit4:junit4] 2> 10 T1634 oazsp.FileTxnSnapLog.save Snapshotting: 0x0 t= o /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/buil= d/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZkTest-13597780= 67125/zookeeper/server1/data/version-2/snapshot.0 [junit4:junit4] 2> 109 T1633 oasc.ZkTestServer.run start zk server on por= t:49648 [junit4:junit4] 2> 110 T1633 oaz.ZooKeeper. Initiating client conne= ction, connectString=3D127.0.0.1:49648 sessionTimeout=3D10000 watcher=3Dorg= .apache.solr.common.cloud.ConnectionManager@3812bd54 [junit4:junit4] 2> 112 T1633 oascc.ConnectionManager.waitForConnected Wai= ting for client to connect to ZooKeeper [junit4:junit4] 2> 112 T1639 oaz.ClientCnxn$SendThread.logStartConnect Op= ening socket connection to server localhost/127.0.0.1:49648. Will not attem= pt to authenticate using SASL (access denied ("javax.security.auth.AuthPerm= ission" "getLoginConfiguration")) [junit4:junit4] 2> 113 T1639 oaz.ClientCnxn$SendThread.primeConnection So= cket connection established to localhost/127.0.0.1:49648, initiating sessio= n [junit4:junit4] 2> 113 T1635 oazs.NIOServerCnxnFactory.run Accepted socke= t connection from /127.0.0.1:49649 [junit4:junit4] 2> 114 T1635 oazs.ZooKeeperServer.processConnectRequest C= lient attempting to establish new session at /127.0.0.1:49649 [junit4:junit4] 2> 114 T1637 oazsp.FileTxnLog.append Creating new log fil= e: log.1 [junit4:junit4] 2> 621 T1637 oazs.ZooKeeperServer.finishSessionInit Estab= lished session 0x13c9916b2bb0000 with negotiated timeout 10000 for client /= 127.0.0.1:49649 [junit4:junit4] 2> 621 T1639 oaz.ClientCnxn$SendThread.onConnected Sessio= n establishment complete on server localhost/127.0.0.1:49648, sessionid =3D= 0x13c9916b2bb0000, negotiated timeout =3D 10000 [junit4:junit4] 2> 622 T1640 oascc.ConnectionManager.process Watcher org.= apache.solr.common.cloud.ConnectionManager@3812bd54 name:ZooKeeperConnectio= n Watcher:127.0.0.1:49648 got event WatchedEvent state:SyncConnected type:N= one path:null path:null type:None [junit4:junit4] 2> 622 T1633 oascc.ConnectionManager.waitForConnected Cli= ent is connected to ZooKeeper [junit4:junit4] 2> 622 T1633 oascc.SolrZkClient.makePath makePath: /solr [junit4:junit4] 2> 629 T1638 oazs.PrepRequestProcessor.pRequest2Txn Proce= ssed session termination for sessionid: 0x13c9916b2bb0000 [junit4:junit4] 2> 634 T1635 oazs.NIOServerCnxn.closeSock Closed socket c= onnection for client /127.0.0.1:49649 which had sessionid 0x13c9916b2bb0000 [junit4:junit4] 2> 634 T1633 oaz.ZooKeeper.close Session: 0x13c9916b2bb00= 00 closed [junit4:junit4] 2> 634 T1640 oaz.ClientCnxn$EventThread.run EventThread s= hut down [junit4:junit4] 2> 634 T1633 oaz.ZooKeeper. Initiating client conne= ction, connectString=3D127.0.0.1:49648/solr sessionTimeout=3D10000 watcher= =3Dorg.apache.solr.common.cloud.ConnectionManager@49d743a0 [junit4:junit4] 2> 636 T1633 oascc.ConnectionManager.waitForConnected Wai= ting for client to connect to ZooKeeper [junit4:junit4] 2> 636 T1641 oaz.ClientCnxn$SendThread.logStartConnect Op= ening socket connection to server localhost/127.0.0.1:49648. Will not attem= pt to authenticate using SASL (access denied ("javax.security.auth.AuthPerm= ission" "getLoginConfiguration")) [junit4:junit4] 2> 637 T1641 oaz.ClientCnxn$SendThread.primeConnection So= cket connection established to localhost/127.0.0.1:49648, initiating sessio= n [junit4:junit4] 2> 637 T1635 oazs.NIOServerCnxnFactory.run Accepted socke= t connection from /127.0.0.1:49650 [junit4:junit4] 2> 637 T1635 oazs.ZooKeeperServer.processConnectRequest C= lient attempting to establish new session at /127.0.0.1:49650 [junit4:junit4] 2> 638 T1637 oazs.ZooKeeperServer.finishSessionInit Estab= lished session 0x13c9916b2bb0001 with negotiated timeout 10000 for client /= 127.0.0.1:49650 [junit4:junit4] 2> 638 T1641 oaz.ClientCnxn$SendThread.onConnected Sessio= n establishment complete on server localhost/127.0.0.1:49648, sessionid =3D= 0x13c9916b2bb0001, negotiated timeout =3D 10000 [junit4:junit4] 2> 639 T1642 oascc.ConnectionManager.process Watcher org.= apache.solr.common.cloud.ConnectionManager@49d743a0 name:ZooKeeperConnectio= n Watcher:127.0.0.1:49648/solr got event WatchedEvent state:SyncConnected t= ype:None path:null path:null type:None [junit4:junit4] 2> 639 T1633 oascc.ConnectionManager.waitForConnected Cli= ent is connected to ZooKeeper [junit4:junit4] 2> 639 T1633 oascc.SolrZkClient.makePath makePath: /colle= ctions/collection1 [junit4:junit4] 2> 646 T1633 oascc.SolrZkClient.makePath makePath: /colle= ctions/collection1/shards [junit4:junit4] 2> 652 T1633 oascc.SolrZkClient.makePath makePath: /colle= ctions/control_collection [junit4:junit4] 2> 656 T1633 oascc.SolrZkClient.makePath makePath: /colle= ctions/control_collection/shards [junit4:junit4] 2> 662 T1633 oasc.AbstractZkTestCase.putConfig put /Users= /jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-c= ore/test-files/solr/collection1/conf/solrconfig.xml to /configs/conf1/solrc= onfig.xml [junit4:junit4] 2> 663 T1633 oascc.SolrZkClient.makePath makePath: /confi= gs/conf1/solrconfig.xml [junit4:junit4] 2> 672 T1633 oasc.AbstractZkTestCase.putConfig put /Users= /jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-c= ore/test-files/solr/collection1/conf/schema.xml to /configs/conf1/schema.xm= l [junit4:junit4] 2> 673 T1633 oascc.SolrZkClient.makePath makePath: /confi= gs/conf1/schema.xml [junit4:junit4] 2> 680 T1633 oasc.AbstractZkTestCase.putConfig put /Users= /jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-c= ore/test-files/solr/collection1/conf/stopwords.txt to /configs/conf1/stopwo= rds.txt [junit4:junit4] 2> 681 T1633 oascc.SolrZkClient.makePath makePath: /confi= gs/conf1/stopwords.txt [junit4:junit4] 2> 687 T1633 oasc.AbstractZkTestCase.putConfig put /Users= /jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-c= ore/test-files/solr/collection1/conf/protwords.txt to /configs/conf1/protwo= rds.txt [junit4:junit4] 2> 688 T1633 oascc.SolrZkClient.makePath makePath: /confi= gs/conf1/protwords.txt [junit4:junit4] 2> 694 T1633 oasc.AbstractZkTestCase.putConfig put /Users= /jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-c= ore/test-files/solr/collection1/conf/currency.xml to /configs/conf1/currenc= y.xml [junit4:junit4] 2> 695 T1633 oascc.SolrZkClient.makePath makePath: /confi= gs/conf1/currency.xml [junit4:junit4] 2> 701 T1633 oasc.AbstractZkTestCase.putConfig put /Users= /jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-c= ore/test-files/solr/collection1/conf/open-exchange-rates.json to /configs/c= onf1/open-exchange-rates.json [junit4:junit4] 2> 702 T1633 oascc.SolrZkClient.makePath makePath: /confi= gs/conf1/open-exchange-rates.json [junit4:junit4] 2> 709 T1633 oasc.AbstractZkTestCase.putConfig put /Users= /jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-c= ore/test-files/solr/collection1/conf/mapping-ISOLatin1Accent.txt to /config= s/conf1/mapping-ISOLatin1Accent.txt [junit4:junit4] 2> 710 T1633 oascc.SolrZkClient.makePath makePath: /confi= gs/conf1/mapping-ISOLatin1Accent.txt [junit4:junit4] 2> 717 T1633 oasc.AbstractZkTestCase.putConfig put /Users= /jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-c= ore/test-files/solr/collection1/conf/old_synonyms.txt to /configs/conf1/old= _synonyms.txt [junit4:junit4] 2> 718 T1633 oascc.SolrZkClient.makePath makePath: /confi= gs/conf1/old_synonyms.txt [junit4:junit4] 2> 725 T1633 oasc.AbstractZkTestCase.putConfig put /Users= /jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-c= ore/test-files/solr/collection1/conf/synonyms.txt to /configs/conf1/synonym= s.txt [junit4:junit4] 2> 726 T1633 oascc.SolrZkClient.makePath makePath: /confi= gs/conf1/synonyms.txt [junit4:junit4] 2> 732 T1638 oazs.PrepRequestProcessor.pRequest2Txn Proce= ssed session termination for sessionid: 0x13c9916b2bb0001 [junit4:junit4] 2> 733 T1633 oaz.ZooKeeper.close Session: 0x13c9916b2bb00= 01 closed [junit4:junit4] 2> 733 T1635 oazs.NIOServerCnxn.closeSock Closed socket c= onnection for client /127.0.0.1:49650 which had sessionid 0x13c9916b2bb0001 [junit4:junit4] 2> 736 T1642 oaz.ClientCnxn$EventThread.run EventThread s= hut down [junit4:junit4] 2> 922 T1633 oejs.Server.doStart jetty-8.1.8.v20121106 [junit4:junit4] 2> 933 T1633 oejs.AbstractConnector.doStart Started Selec= tChannelConnector@127.0.0.1:49651 [junit4:junit4] 2> 934 T1633 oass.SolrDispatchFilter.init SolrDispatchFil= ter.init() [junit4:junit4] 2> 935 T1633 oasc.SolrResourceLoader.locateSolrHome JNDI = not configured for solr (NoInitialContextEx) [junit4:junit4] 2> 935 T1633 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-controljetty-1359778067853 [junit4:junit4] 2> 936 T1633 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-controljetty-1359778067853/solr.xml [junit4:junit4] 2> 936 T1633 oasc.CoreContainer. New CoreContainer = 649613482 [junit4:junit4] 2> 937 T1633 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-controljetty-1359778067853/' [junit4:junit4] 2> 937 T1633 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-1359778067853/' [junit4:junit4] 2> 969 T1633 oashc.HttpShardHandlerFactory.getParameter S= etting socketTimeout to: 60000 [junit4:junit4] 2> 969 T1633 oashc.HttpShardHandlerFactory.getParameter S= etting urlScheme to: http:// [junit4:junit4] 2> 970 T1633 oashc.HttpShardHandlerFactory.getParameter S= etting connTimeout to: 15000 [junit4:junit4] 2> 970 T1633 oashc.HttpShardHandlerFactory.getParameter S= etting maxConnectionsPerHost to: 20 [junit4:junit4] 2> 971 T1633 oashc.HttpShardHandlerFactory.getParameter S= etting corePoolSize to: 0 [junit4:junit4] 2> 971 T1633 oashc.HttpShardHandlerFactory.getParameter S= etting maximumPoolSize to: 2147483647 [junit4:junit4] 2> 972 T1633 oashc.HttpShardHandlerFactory.getParameter S= etting maxThreadIdleTime to: 5 [junit4:junit4] 2> 972 T1633 oashc.HttpShardHandlerFactory.getParameter S= etting sizeOfQueue to: -1 [junit4:junit4] 2> 972 T1633 oashc.HttpShardHandlerFactory.getParameter S= etting fairnessPolicy to: false [junit4:junit4] 2> 973 T1633 oascsi.HttpClientUtil.createClient Creating = new http client, config:maxConnectionsPerHost=3D20&maxConnections=3D10000&s= ocketTimeout=3D60000&connTimeout=3D15000&retry=3Dfalse [junit4:junit4] 2> 985 T1633 oasc.CoreContainer.load Registering Log List= ener [junit4:junit4] 2> 1001 T1633 oasc.CoreContainer.initZooKeeper Zookeeper = client=3D127.0.0.1:49648/solr [junit4:junit4] 2> 1001 T1633 oasc.ZkController.checkChrootPath zkHost in= cludes chroot [junit4:junit4] 2> 1002 T1633 oaz.ZooKeeper. Initiating client conn= ection, connectString=3D127.0.0.1:49648 sessionTimeout=3D60000 watcher=3Dor= g.apache.solr.common.cloud.ConnectionManager@465cd3d7 [junit4:junit4] 2> 1004 T1633 oascc.ConnectionManager.waitForConnected Wa= iting for client to connect to ZooKeeper [junit4:junit4] 2> 1004 T1652 oaz.ClientCnxn$SendThread.logStartConnect O= pening socket connection to server localhost/127.0.0.1:49648. Will not atte= mpt to authenticate using SASL (access denied ("javax.security.auth.AuthPer= mission" "getLoginConfiguration")) [junit4:junit4] 2> 1005 T1652 oaz.ClientCnxn$SendThread.primeConnection S= ocket connection established to localhost/127.0.0.1:49648, initiating sessi= on [junit4:junit4] 2> 1005 T1635 oazs.NIOServerCnxnFactory.run Accepted sock= et connection from /127.0.0.1:49652 [junit4:junit4] 2> 1006 T1635 oazs.ZooKeeperServer.processConnectRequest = Client attempting to establish new session at /127.0.0.1:49652 [junit4:junit4] 2> 1007 T1637 oazs.ZooKeeperServer.finishSessionInit Esta= blished session 0x13c9916b2bb0002 with negotiated timeout 20000 for client = /127.0.0.1:49652 [junit4:junit4] 2> 1007 T1652 oaz.ClientCnxn$SendThread.onConnected Sessi= on establishment complete on server localhost/127.0.0.1:49648, sessionid = =3D 0x13c9916b2bb0002, negotiated timeout =3D 20000 [junit4:junit4] 2> 1007 T1653 oascc.ConnectionManager.process Watcher org= .apache.solr.common.cloud.ConnectionManager@465cd3d7 name:ZooKeeperConnecti= on Watcher:127.0.0.1:49648 got event WatchedEvent state:SyncConnected type:= None path:null path:null type:None [junit4:junit4] 2> 1008 T1633 oascc.ConnectionManager.waitForConnected Cl= ient is connected to ZooKeeper [junit4:junit4] 2> 1010 T1638 oazs.PrepRequestProcessor.pRequest2Txn Proc= essed session termination for sessionid: 0x13c9916b2bb0002 [junit4:junit4] 2> 1011 T1635 oazs.NIOServerCnxn.closeSock Closed socket = connection for client /127.0.0.1:49652 which had sessionid 0x13c9916b2bb000= 2 [junit4:junit4] 2> 1011 T1633 oaz.ZooKeeper.close Session: 0x13c9916b2bb0= 002 closed [junit4:junit4] 2> 1011 T1653 oaz.ClientCnxn$EventThread.run EventThread = shut down [junit4:junit4] 2> 1011 T1633 oascsi.HttpClientUtil.createClient Creating= new http client, config:maxConnections=3D500&maxConnectionsPerHost=3D16&so= cketTimeout=3D60000&connTimeout=3D15000 [junit4:junit4] 2> 1016 T1633 oaz.ZooKeeper. Initiating client conn= ection, connectString=3D127.0.0.1:49648/solr sessionTimeout=3D30000 watcher= =3Dorg.apache.solr.common.cloud.ConnectionManager@9aa2a1b [junit4:junit4] 2> 1017 T1633 oascc.ConnectionManager.waitForConnected Wa= iting for client to connect to ZooKeeper [junit4:junit4] 2> 1018 T1654 oaz.ClientCnxn$SendThread.logStartConnect O= pening socket connection to server localhost/127.0.0.1:49648. Will not atte= mpt to authenticate using SASL (access denied ("javax.security.auth.AuthPer= mission" "getLoginConfiguration")) [junit4:junit4] 2> 1018 T1654 oaz.ClientCnxn$SendThread.primeConnection S= ocket connection established to localhost/127.0.0.1:49648, initiating sessi= on [junit4:junit4] 2> 1019 T1635 oazs.NIOServerCnxnFactory.run Accepted sock= et connection from /127.0.0.1:49653 [junit4:junit4] 2> 1019 T1635 oazs.ZooKeeperServer.processConnectRequest = Client attempting to establish new session at /127.0.0.1:49653 [junit4:junit4] 2> 1020 T1637 oazs.ZooKeeperServer.finishSessionInit Esta= blished session 0x13c9916b2bb0003 with negotiated timeout 20000 for client = /127.0.0.1:49653 [junit4:junit4] 2> 1021 T1654 oaz.ClientCnxn$SendThread.onConnected Sessi= on establishment complete on server localhost/127.0.0.1:49648, sessionid = =3D 0x13c9916b2bb0003, negotiated timeout =3D 20000 [junit4:junit4] 2> 1021 T1655 oascc.ConnectionManager.process Watcher org= .apache.solr.common.cloud.ConnectionManager@9aa2a1b name:ZooKeeperConnectio= n Watcher:127.0.0.1:49648/solr got event WatchedEvent state:SyncConnected t= ype:None path:null path:null type:None [junit4:junit4] 2> 1021 T1633 oascc.ConnectionManager.waitForConnected Cl= ient is connected to ZooKeeper [junit4:junit4] 2> 1025 T1638 oazs.PrepRequestProcessor.pRequest Got user= -level KeeperException when processing sessionid:0x13c9916b2bb0003 type:cre= ate cxid:0x2 zxid:0x1a txntype:-1 reqpath:n/a Error Path:/solr/overseer Err= or:KeeperErrorCode =3D NodeExists for /solr/overseer [junit4:junit4] 2> 1027 T1633 oascc.SolrZkClient.makePath makePath: /live= _nodes [junit4:junit4] 2> 1031 T1633 oasc.ZkController.createEphemeralLiveNode R= egister node as live in ZooKeeper:/live_nodes/127.0.0.1:49651_ [junit4:junit4] 2> 1032 T1638 oazs.PrepRequestProcessor.pRequest Got user= -level KeeperException when processing sessionid:0x13c9916b2bb0003 type:del= ete cxid:0x7 zxid:0x1c txntype:-1 reqpath:n/a Error Path:/solr/live_nodes/1= 27.0.0.1:49651_ Error:KeeperErrorCode =3D NoNode for /solr/live_nodes/127.0= .0.1:49651_ [junit4:junit4] 2> 1033 T1633 oascc.SolrZkClient.makePath makePath: /live= _nodes/127.0.0.1:49651_ [junit4:junit4] 2> 1040 T1633 oascc.SolrZkClient.makePath makePath: /over= seer_elect/election [junit4:junit4] 2> 1048 T1638 oazs.PrepRequestProcessor.pRequest Got user= -level KeeperException when processing sessionid:0x13c9916b2bb0003 type:del= ete cxid:0x15 zxid:0x21 txntype:-1 reqpath:n/a Error Path:/solr/overseer_el= ect/leader Error:KeeperErrorCode =3D NoNode for /solr/overseer_elect/leader [junit4:junit4] 2> 1050 T1633 oascc.SolrZkClient.makePath makePath: /over= seer_elect/leader [junit4:junit4] 2> 1054 T1633 oasc.Overseer.start Overseer (id=3D89114415= 407497219-127.0.0.1:49651_-n_0000000000) starting [junit4:junit4] 2> 1055 T1638 oazs.PrepRequestProcessor.pRequest Got user= -level KeeperException when processing sessionid:0x13c9916b2bb0003 type:cre= ate cxid:0x1a zxid:0x23 txntype:-1 reqpath:n/a Error Path:/solr/overseer Er= ror:KeeperErrorCode =3D NodeExists for /solr/overseer [junit4:junit4] 2> 1056 T1638 oazs.PrepRequestProcessor.pRequest Got user= -level KeeperException when processing sessionid:0x13c9916b2bb0003 type:cre= ate cxid:0x1b zxid:0x24 txntype:-1 reqpath:n/a Error Path:/solr/overseer Er= ror:KeeperErrorCode =3D NodeExists for /solr/overseer [junit4:junit4] 2> 1058 T1638 oazs.PrepRequestProcessor.pRequest Got user= -level KeeperException when processing sessionid:0x13c9916b2bb0003 type:cre= ate cxid:0x1c zxid:0x25 txntype:-1 reqpath:n/a Error Path:/solr/overseer Er= ror:KeeperErrorCode =3D NodeExists for /solr/overseer [junit4:junit4] 2> 1059 T1638 oazs.PrepRequestProcessor.pRequest Got user= -level KeeperException when processing sessionid:0x13c9916b2bb0003 type:cre= ate cxid:0x1d zxid:0x26 txntype:-1 reqpath:n/a Error Path:/solr/overseer Er= ror:KeeperErrorCode =3D NodeExists for /solr/overseer [junit4:junit4] 2> 1061 T1657 oasc.OverseerCollectionProcessor.run Proces= s current queue of collection creations [junit4:junit4] 2> 1062 T1633 oascc.SolrZkClient.makePath makePath: /clus= terstate.json [junit4:junit4] 2> 1067 T1633 oascc.ZkStateReader.createClusterStateWatch= ersAndUpdate Updating cluster state from ZooKeeper...=20 [junit4:junit4] 2> 1072 T1656 oasc.Overseer$ClusterStateUpdater.run Start= ing to work on the main queue [junit4:junit4] 2> 1076 T1658 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-controljetty-1359778067853/collection1 [junit4:junit4] 2> 1076 T1658 oasc.ZkController.createCollectionZkNode Ch= eck for collection zkNode:control_collection [junit4:junit4] 2> 1077 T1658 oasc.ZkController.createCollectionZkNode Co= llection zkNode exists [junit4:junit4] 2> 1077 T1658 oasc.ZkController.readConfigName Load colle= ction config from:/collections/control_collection [junit4:junit4] 2> 1080 T1658 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-controljetty-1359778067853/collection1/' [junit4:junit4] 2> 1081 T1658 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= -controljetty-1359778067853/collection1/lib/classes/' to classloader [junit4:junit4] 2> 1081 T1658 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= -controljetty-1359778067853/collection1/lib/README' to classloader [junit4:junit4] 2> 1137 T1658 oasc.SolrConfig. Using Lucene MatchVe= rsion: LUCENE_50 [junit4:junit4] 2> 1208 T1658 oasc.SolrConfig. Loaded SolrConfig: s= olrconfig.xml [junit4:junit4] 2> 1209 T1658 oass.IndexSchema.readSchema Reading Solr Sc= hema [junit4:junit4] 2> 1215 T1658 oass.IndexSchema.readSchema Schema name=3Dt= est [junit4:junit4] 2> 1749 T1658 oass.OpenExchangeRatesOrgProvider.init Init= ialized with rates=3Dopen-exchange-rates.json, refreshInterval=3D1440. [junit4:junit4] 2> 1757 T1658 oass.IndexSchema.readSchema default search = field in schema is text [junit4:junit4] 2> 1760 T1658 oass.IndexSchema.readSchema unique key fiel= d: id [junit4:junit4] 2> 1785 T1658 oass.FileExchangeRateProvider.reload Reload= ing exchange rates from file currency.xml [junit4:junit4] 2> 1790 T1658 oass.FileExchangeRateProvider.reload Reload= ing exchange rates from file currency.xml [junit4:junit4] 2> 1795 T1658 oass.OpenExchangeRatesOrgProvider.reload Re= loading exchange rates from open-exchange-rates.json [junit4:junit4] 2> 1797 T1658 oass.OpenExchangeRatesOrgProvider.reload Re= loading exchange rates from open-exchange-rates.json [junit4:junit4] 2> 1799 T1658 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-controljetty-1359778067853/collection1/, dataDir=3D./org.apache.solr.= cloud.BasicDistributedZkTest-1359778067125/control/data/ [junit4:junit4] 2> 1800 T1658 oasc.JmxMonitoredMap. JMX monitoring = is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMB= eanServer@656ca212 [junit4:junit4] 2> 1800 T1658 oasc.SolrCore.initDirectoryFactory solr.NRT= CachingDirectoryFactory [junit4:junit4] 2> 1801 T1658 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-1359778067125/control/data forceNew:false [junit4:junit4] 2> 1802 T1658 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-1359778067125/control/data [junit4:junit4] 2> 1802 T1658 oasc.SolrCore.getNewIndexDir New index dire= ctory detected: old=3Dnull new=3D./org.apache.solr.cloud.BasicDistributedZk= Test-1359778067125/control/data/index/ [junit4:junit4] 2> 1802 T1658 oasc.SolrCore.initIndex WARNING [collection= 1] Solr index directory './org.apache.solr.cloud.BasicDistributedZkTest-135= 9778067125/control/data/index' doesn't exist. Creating new index... [junit4:junit4] 2> 1803 T1658 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-1359778067125/control/data/index forceNew:false [junit4:junit4] 2> 1809 T1658 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-1359778067125/control/data/index lo= ckFactory=3Dorg.apache.lucene.store.NativeFSLockFactory@7b5b5000; maxCacheM= B=3D48.0 maxMergeSizeMB=3D4.0)),segFN=3Dsegments_1,generation=3D1,filenames= =3D[segments_1] [junit4:junit4] 2> 1809 T1658 oasc.SolrDeletionPolicy.updateCommits newes= t commit =3D 1[segments_1] [junit4:junit4] 2> 1810 T1658 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-1359778067125/control/data/index [junit4:junit4] 2> 1810 T1658 oasc.SolrCore.initWriters created xml: solr= .XMLResponseWriter [junit4:junit4] 2> 1812 T1658 oasup.UpdateRequestProcessorChain.init inse= rting DistributedUpdateProcessorFactory into updateRequestProcessorChain "d= edupe" [junit4:junit4] 2> 1813 T1658 oasup.UpdateRequestProcessorChain.init inse= rting DistributedUpdateProcessorFactory into updateRequestProcessorChain "d= edupe-allfields" [junit4:junit4] 2> 1813 T1658 oasup.UpdateRequestProcessorChain.init inse= rting DistributedUpdateProcessorFactory into updateRequestProcessorChain "s= tored_sig" [junit4:junit4] 2> 1813 T1658 oasup.UpdateRequestProcessorChain.init inse= rting DistributedUpdateProcessorFactory into updateRequestProcessorChain "u= niq-fields" [junit4:junit4] 2> 1814 T1658 oasup.UpdateRequestProcessorChain.init inse= rting DistributedUpdateProcessorFactory into updateRequestProcessorChain "d= istrib-dup-test-chain-implicit" [junit4:junit4] 2> 1814 T1658 oasc.RequestHandlers.initHandlersFromConfig= adding lazy requestHandler: solr.ReplicationHandler [junit4:junit4] 2> 1816 T1658 oasc.RequestHandlers.initHandlersFromConfig= created /replication: solr.ReplicationHandler [junit4:junit4] 2> 1816 T1658 oasc.RequestHandlers.initHandlersFromConfig= created standard: solr.StandardRequestHandler [junit4:junit4] 2> 1817 T1658 oasc.RequestHandlers.initHandlersFromConfig= created /get: solr.RealTimeGetHandler [junit4:junit4] 2> 1818 T1658 oasc.RequestHandlers.initHandlersFromConfig= created dismax: solr.SearchHandler [junit4:junit4] 2> 1818 T1658 oasc.RequestHandlers.initHandlersFromConfig= created mock: org.apache.solr.core.MockQuerySenderListenerReqHandler [junit4:junit4] 2> 1819 T1658 oasc.RequestHandlers.initHandlersFromConfig= created /admin/: org.apache.solr.handler.admin.AdminHandlers [junit4:junit4] 2> 1819 T1658 oasc.RequestHandlers.initHandlersFromConfig= created defaults: solr.StandardRequestHandler [junit4:junit4] 2> 1819 T1658 oasc.RequestHandlers.initHandlersFromConfig= adding lazy requestHandler: solr.StandardRequestHandler [junit4:junit4] 2> 1820 T1658 oasc.RequestHandlers.initHandlersFromConfig= created lazy: solr.StandardRequestHandler [junit4:junit4] 2> 1820 T1658 oasc.RequestHandlers.initHandlersFromConfig= created /update: solr.UpdateRequestHandler [junit4:junit4] 2> 1821 T1658 oasc.RequestHandlers.initHandlersFromConfig= created /terms: org.apache.solr.handler.component.SearchHandler [junit4:junit4] 2> 1821 T1658 oasc.RequestHandlers.initHandlersFromConfig= created spellCheckCompRH: org.apache.solr.handler.component.SearchHandler [junit4:junit4] 2> 1822 T1658 oasc.RequestHandlers.initHandlersFromConfig= created spellCheckCompRH_Direct: org.apache.solr.handler.component.SearchH= andler [junit4:junit4] 2> 1822 T1658 oasc.RequestHandlers.initHandlersFromConfig= created spellCheckWithWordbreak: org.apache.solr.handler.component.SearchH= andler [junit4:junit4] 2> 1823 T1658 oasc.RequestHandlers.initHandlersFromConfig= created spellCheckWithWordbreak_Direct: org.apache.solr.handler.component.= SearchHandler [junit4:junit4] 2> 1823 T1658 oasc.RequestHandlers.initHandlersFromConfig= created spellCheckCompRH1: org.apache.solr.handler.component.SearchHandler [junit4:junit4] 2> 1824 T1658 oasc.RequestHandlers.initHandlersFromConfig= created mltrh: org.apache.solr.handler.component.SearchHandler [junit4:junit4] 2> 1824 T1658 oasc.RequestHandlers.initHandlersFromConfig= created tvrh: org.apache.solr.handler.component.SearchHandler [junit4:junit4] 2> 1825 T1658 oasc.RequestHandlers.initHandlersFromConfig= created /mlt: solr.MoreLikeThisHandler [junit4:junit4] 2> 1825 T1658 oasc.RequestHandlers.initHandlersFromConfig= created /debug/dump: solr.DumpRequestHandler [junit4:junit4] 2> 1839 T1658 oashl.XMLLoader.init xsltCacheLifetimeSecon= ds=3D60 [junit4:junit4] 2> 1843 T1658 oasc.SolrCore.initDeprecatedSupport WARNING= solrconfig.xml uses deprecated , Please update your c= onfig to use the ShowFileRequestHandler. [junit4:junit4] 2> 1845 T1658 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> 1847 T1658 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-1359778067125/control/data [junit4:junit4] 2> 1849 T1658 oass.SolrIndexSearcher. Opening Searc= her@5f0f2fae main [junit4:junit4] 2> 1850 T1658 oasu.CommitTracker. Hard AutoCommit: = disabled [junit4:junit4] 2> 1850 T1658 oasu.CommitTracker. Soft AutoCommit: = disabled [junit4:junit4] 2> 1851 T1658 oashc.SpellCheckComponent.inform Initializi= ng spell checkers [junit4:junit4] 2> 1856 T1658 oass.DirectSolrSpellChecker.init init: {nam= e=3Ddirect,classname=3DDirectSolrSpellChecker,field=3Dlowerfilt,minQueryLen= gth=3D3} [junit4:junit4] 2> 1886 T1659 oasc.SolrCore.registerSearcher [collection1= ] Registered new searcher Searcher@5f0f2fae main{StandardDirectoryReader(se= gments_1:1)} [junit4:junit4] 2> 1892 T1658 oasc.ZkController.publish publishing core= =3Dcollection1 state=3Ddown [junit4:junit4] 2> 1893 T1658 oasc.ZkController.publish numShards not fou= nd on descriptor - reading it from system property [junit4:junit4] 2> 1894 T1638 oazs.PrepRequestProcessor.pRequest Got user= -level KeeperException when processing sessionid:0x13c9916b2bb0003 type:cre= ate cxid:0x50 zxid:0x29 txntype:-1 reqpath:n/a Error Path:/solr/overseer/qu= eue Error:KeeperErrorCode =3D NoNode for /solr/overseer/queue [junit4:junit4] 2> 2581 T1656 oascc.ZkStateReader.updateClusterState Upda= ting cloud state from ZooKeeper...=20 [junit4:junit4] 2> 2582 T1656 oasc.Overseer$ClusterStateUpdater.updateSta= te 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:49651_", [junit4:junit4] 2> =09 "base_url":"http://127.0.0.1:49651"} [junit4:junit4] 2> 2582 T1656 oasc.Overseer$ClusterStateUpdater.createCol= lection Create collection control_collection with numShards 1 [junit4:junit4] 2> 2583 T1656 oasc.Overseer$ClusterStateUpdater.updateSta= te Assigning new node to shard shard=3Dshard1 [junit4:junit4] 2> 2583 T1638 oazs.PrepRequestProcessor.pRequest Got user= -level KeeperException when processing sessionid:0x13c9916b2bb0003 type:cre= ate cxid:0x58 zxid:0x2c txntype:-1 reqpath:n/a Error Path:/solr/overseer/qu= eue-work Error:KeeperErrorCode =3D NoNode for /solr/overseer/queue-work [junit4:junit4] 2> 2593 T1655 oascc.ZkStateReader$2.process A cluster sta= te change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clus= terstate.json, has occurred - updating... (live nodes size: 1) [junit4:junit4] 2> 2898 T1658 oasc.CoreContainer.registerCore registering= core: collection1 [junit4:junit4] 2> 2899 T1658 oasc.ZkController.register Register replica= - core:collection1 address:http://127.0.0.1:49651 collection:control_colle= ction shard:shard1 [junit4:junit4] 2> 2900 T1658 oascc.SolrZkClient.makePath makePath: /coll= ections/control_collection/leader_elect/shard1/election [junit4:junit4] 2> 2913 T1638 oazs.PrepRequestProcessor.pRequest Got user= -level KeeperException when processing sessionid:0x13c9916b2bb0003 type:del= ete cxid:0x72 zxid:0x36 txntype:-1 reqpath:n/a Error Path:/solr/collections= /control_collection/leaders Error:KeeperErrorCode =3D NoNode for /solr/coll= ections/control_collection/leaders [junit4:junit4] 2> 2914 T1658 oasc.ShardLeaderElectionContext.runLeaderPr= ocess Running the leader process. [junit4:junit4] 2> 2915 T1638 oazs.PrepRequestProcessor.pRequest Got user= -level KeeperException when processing sessionid:0x13c9916b2bb0003 type:cre= ate cxid:0x73 zxid:0x37 txntype:-1 reqpath:n/a Error Path:/solr/overseer Er= ror:KeeperErrorCode =3D NodeExists for /solr/overseer [junit4:junit4] 2> 2918 T1658 oasc.ShardLeaderElectionContext.waitForRepl= icasToComeUp Enough replicas found to continue. [junit4:junit4] 2> 2919 T1658 oasc.ShardLeaderElectionContext.runLeaderPr= ocess I may be the new leader - try and sync [junit4:junit4] 2> 2919 T1658 oasc.SyncStrategy.sync Sync replicas to htt= p://127.0.0.1:49651/collection1/ [junit4:junit4] 2> 2919 T1658 oasc.SyncStrategy.syncReplicas Sync Success= - now sync replicas to me [junit4:junit4] 2> 2920 T1658 oasc.SyncStrategy.syncToMe http://127.0.0.1= :49651/collection1/ has no replicas [junit4:junit4] 2> 2920 T1658 oasc.ShardLeaderElectionContext.runLeaderPr= ocess I am the new leader: http://127.0.0.1:49651/collection1/ [junit4:junit4] 2> 2920 T1658 oascc.SolrZkClient.makePath makePath: /coll= ections/control_collection/leaders/shard1 [junit4:junit4] 2> 2928 T1638 oazs.PrepRequestProcessor.pRequest Got user= -level KeeperException when processing sessionid:0x13c9916b2bb0003 type:cre= ate cxid:0x7d zxid:0x3b txntype:-1 reqpath:n/a Error Path:/solr/overseer Er= ror:KeeperErrorCode =3D NodeExists for /solr/overseer [junit4:junit4] 2> 4105 T1656 oascc.ZkStateReader.updateClusterState Upda= ting cloud state from ZooKeeper...=20 [junit4:junit4] 2> 4118 T1655 oascc.ZkStateReader$2.process A cluster sta= te change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clus= terstate.json, has occurred - updating... (live nodes size: 1) [junit4:junit4] 2> 4129 T1658 oasc.ZkController.register We are http://12= 7.0.0.1:49651/collection1/ and leader is http://127.0.0.1:49651/collection1= / [junit4:junit4] 2> 4130 T1658 oasc.ZkController.register No LogReplay nee= ded for core=3Dcollection1 baseURL=3Dhttp://127.0.0.1:49651 [junit4:junit4] 2> 4130 T1658 oasc.ZkController.checkRecovery I am the le= ader, no recovery necessary [junit4:junit4] 2> 4130 T1658 oasc.ZkController.publish publishing core= =3Dcollection1 state=3Dactive [junit4:junit4] 2> 4130 T1658 oasc.ZkController.publish numShards not fou= nd on descriptor - reading it from system property [junit4:junit4] 2> 4133 T1658 oascc.ZkStateReader.updateClusterState Upda= ting cloud state from ZooKeeper...=20 [junit4:junit4] 2> 4134 T1633 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> 4134 T1633 oass.SolrDispatchFilter.init SolrDispatchFi= lter.init() done [junit4:junit4] 2> 4135 T1633 oascsi.HttpClientUtil.createClient Creating= new http client, config:maxConnections=3D128&maxConnectionsPerHost=3D32&fo= llowRedirects=3Dfalse [junit4:junit4] 2> 4140 T1633 oascsi.HttpClientUtil.createClient Creating= new http client, config: [junit4:junit4] 2> 4144 T1633 oaz.ZooKeeper. Initiating client conn= ection, connectString=3D127.0.0.1:49648/solr sessionTimeout=3D10000 watcher= =3Dorg.apache.solr.common.cloud.ConnectionManager@13aa00ce [junit4:junit4] 2> 4145 T1633 oascc.ConnectionManager.waitForConnected Wa= iting for client to connect to ZooKeeper [junit4:junit4] 2> 4145 T1660 oaz.ClientCnxn$SendThread.logStartConnect O= pening socket connection to server localhost/127.0.0.1:49648. Will not atte= mpt to authenticate using SASL (access denied ("javax.security.auth.AuthPer= mission" "getLoginConfiguration")) [junit4:junit4] 2> 4146 T1660 oaz.ClientCnxn$SendThread.primeConnection S= ocket connection established to localhost/127.0.0.1:49648, initiating sessi= on [junit4:junit4] 2> 4146 T1635 oazs.NIOServerCnxnFactory.run Accepted sock= et connection from /127.0.0.1:49654 [junit4:junit4] 2> 4146 T1635 oazs.ZooKeeperServer.processConnectRequest = Client attempting to establish new session at /127.0.0.1:49654 [junit4:junit4] 2> 4147 T1637 oazs.ZooKeeperServer.finishSessionInit Esta= blished session 0x13c9916b2bb0004 with negotiated timeout 10000 for client = /127.0.0.1:49654 [junit4:junit4] 2> 4148 T1660 oaz.ClientCnxn$SendThread.onConnected Sessi= on establishment complete on server localhost/127.0.0.1:49648, sessionid = =3D 0x13c9916b2bb0004, negotiated timeout =3D 10000 [junit4:junit4] 2> 4148 T1661 oascc.ConnectionManager.process Watcher org= .apache.solr.common.cloud.ConnectionManager@13aa00ce name:ZooKeeperConnecti= on Watcher:127.0.0.1:49648/solr got event WatchedEvent state:SyncConnected = type:None path:null path:null type:None [junit4:junit4] 2> 4148 T1633 oascc.ConnectionManager.waitForConnected Cl= ient is connected to ZooKeeper [junit4:junit4] 2> 4150 T1633 oascc.ZkStateReader.createClusterStateWatch= ersAndUpdate Updating cluster state from ZooKeeper...=20 [junit4:junit4] 2> 4153 T1633 oasc.ChaosMonkey.monkeyLog monkey: init - e= xpire sessions:true cause connection loss:true [junit4:junit4] 2> 4320 T1633 oejs.Server.doStart jetty-8.1.8.v20121106 [junit4:junit4] 2> 4323 T1633 oejs.AbstractConnector.doStart Started Sele= ctChannelConnector@127.0.0.1:49655 [junit4:junit4] 2> 4324 T1633 oass.SolrDispatchFilter.init SolrDispatchFi= lter.init() [junit4:junit4] 2> 4325 T1633 oasc.SolrResourceLoader.locateSolrHome JNDI= not configured for solr (NoInitialContextEx) [junit4:junit4] 2> 4325 T1633 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-jetty1-1359778071273 [junit4:junit4] 2> 4326 T1633 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-jetty1-1359778071273/solr.xml [junit4:junit4] 2> 4326 T1633 oasc.CoreContainer. New CoreContainer= 1578985675 [junit4:junit4] 2> 4327 T1633 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-jetty1-1359778071273/' [junit4:junit4] 2> 4327 T1633 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-jetty1-1359778071273/' [junit4:junit4] 2> 4361 T1633 oashc.HttpShardHandlerFactory.getParameter = Setting socketTimeout to: 60000 [junit4:junit4] 2> 4362 T1633 oashc.HttpShardHandlerFactory.getParameter = Setting urlScheme to: http:// [junit4:junit4] 2> 4363 T1633 oashc.HttpShardHandlerFactory.getParameter = Setting connTimeout to: 15000 [junit4:junit4] 2> 4364 T1633 oashc.HttpShardHandlerFactory.getParameter = Setting maxConnectionsPerHost to: 20 [junit4:junit4] 2> 4364 T1633 oashc.HttpShardHandlerFactory.getParameter = Setting corePoolSize to: 0 [junit4:junit4] 2> 4365 T1633 oashc.HttpShardHandlerFactory.getParameter = Setting maximumPoolSize to: 2147483647 [junit4:junit4] 2> 4366 T1633 oashc.HttpShardHandlerFactory.getParameter = Setting maxThreadIdleTime to: 5 [junit4:junit4] 2> 4366 T1633 oashc.HttpShardHandlerFactory.getParameter = Setting sizeOfQueue to: -1 [junit4:junit4] 2> 4367 T1633 oashc.HttpShardHandlerFactory.getParameter = Setting fairnessPolicy to: false [junit4:junit4] 2> 4367 T1633 oascsi.HttpClientUtil.createClient Creating= new http client, config:maxConnectionsPerHost=3D20&maxConnections=3D10000&= socketTimeout=3D60000&connTimeout=3D15000&retry=3Dfalse [junit4:junit4] 2> 4380 T1633 oasc.CoreContainer.load Registering Log Lis= tener [junit4:junit4] 2> 4399 T1633 oasc.CoreContainer.initZooKeeper Zookeeper = client=3D127.0.0.1:49648/solr [junit4:junit4] 2> 4400 T1633 oasc.ZkController.checkChrootPath zkHost in= cludes chroot [junit4:junit4] 2> 4401 T1633 oaz.ZooKeeper. Initiating client conn= ection, connectString=3D127.0.0.1:49648 sessionTimeout=3D60000 watcher=3Dor= g.apache.solr.common.cloud.ConnectionManager@601cfa38 [junit4:junit4] 2> 4402 T1633 oascc.ConnectionManager.waitForConnected Wa= iting for client to connect to ZooKeeper [junit4:junit4] 2> 4403 T1671 oaz.ClientCnxn$SendThread.logStartConnect O= pening socket connection to server localhost/127.0.0.1:49648. Will not atte= mpt to authenticate using SASL (access denied ("javax.security.auth.AuthPer= mission" "getLoginConfiguration")) [junit4:junit4] 2> 4404 T1671 oaz.ClientCnxn$SendThread.primeConnection S= ocket connection established to localhost/127.0.0.1:49648, initiating sessi= on [junit4:junit4] 2> 4405 T1635 oazs.NIOServerCnxnFactory.run Accepted sock= et connection from /127.0.0.1:49656 [junit4:junit4] 2> 4405 T1635 oazs.ZooKeeperServer.processConnectRequest = Client attempting to establish new session at /127.0.0.1:49656 [junit4:junit4] 2> 4407 T1637 oazs.ZooKeeperServer.finishSessionInit Esta= blished session 0x13c9916b2bb0005 with negotiated timeout 20000 for client = /127.0.0.1:49656 [junit4:junit4] 2> 4407 T1671 oaz.ClientCnxn$SendThread.onConnected Sessi= on establishment complete on server localhost/127.0.0.1:49648, sessionid = =3D 0x13c9916b2bb0005, negotiated timeout =3D 20000 [junit4:junit4] 2> 4408 T1672 oascc.ConnectionManager.process Watcher org= .apache.solr.common.cloud.ConnectionManager@601cfa38 name:ZooKeeperConnecti= on Watcher:127.0.0.1:49648 got event WatchedEvent state:SyncConnected type:= None path:null path:null type:None [junit4:junit4] 2> 4408 T1633 oascc.ConnectionManager.waitForConnected Cl= ient is connected to ZooKeeper [junit4:junit4] 2> 4411 T1638 oazs.PrepRequestProcessor.pRequest2Txn Proc= essed session termination for sessionid: 0x13c9916b2bb0005 [junit4:junit4] 2> 4412 T1635 oazs.NIOServerCnxn.closeSock Closed socket = connection for client /127.0.0.1:49656 which had sessionid 0x13c9916b2bb000= 5 [junit4:junit4] 2> 4413 T1672 oaz.ClientCnxn$EventThread.run EventThread = shut down [junit4:junit4] 2> 4412 T1633 oaz.ZooKeeper.close Session: 0x13c9916b2bb0= 005 closed [junit4:junit4] 2> 4414 T1633 oascsi.HttpClientUtil.createClient Creating= new http client, config:maxConnections=3D500&maxConnectionsPerHost=3D16&so= cketTimeout=3D60000&connTimeout=3D15000 [junit4:junit4] 2> 4420 T1633 oaz.ZooKeeper. Initiating client conn= ection, connectString=3D127.0.0.1:49648/solr sessionTimeout=3D30000 watcher= =3Dorg.apache.solr.common.cloud.ConnectionManager@169572d0 [junit4:junit4] 2> 4422 T1633 oascc.ConnectionManager.waitForConnected Wa= iting for client to connect to ZooKeeper [junit4:junit4] 2> 4422 T1673 oaz.ClientCnxn$SendThread.logStartConnect O= pening socket connection to server localhost/127.0.0.1:49648. Will not atte= mpt to authenticate using SASL (access denied ("javax.security.auth.AuthPer= mission" "getLoginConfiguration")) [junit4:junit4] 2> 4423 T1673 oaz.ClientCnxn$SendThread.primeConnection S= ocket connection established to localhost/127.0.0.1:49648, initiating sessi= on [junit4:junit4] 2> 4424 T1635 oazs.NIOServerCnxnFactory.run Accepted sock= et connection from /127.0.0.1:49657 [junit4:junit4] 2> 4424 T1635 oazs.ZooKeeperServer.processConnectRequest = Client attempting to establish new session at /127.0.0.1:49657 [junit4:junit4] 2> 4426 T1637 oazs.ZooKeeperServer.finishSessionInit Esta= blished session 0x13c9916b2bb0006 with negotiated timeout 20000 for client = /127.0.0.1:49657 [junit4:junit4] 2> 4426 T1673 oaz.ClientCnxn$SendThread.onConnected Sessi= on establishment complete on server localhost/127.0.0.1:49648, sessionid = =3D 0x13c9916b2bb0006, negotiated timeout =3D 20000 [junit4:junit4] 2> 4427 T1674 oascc.ConnectionManager.process Watcher org= .apache.solr.common.cloud.ConnectionManager@169572d0 name:ZooKeeperConnecti= on Watcher:127.0.0.1:49648/solr got event WatchedEvent state:SyncConnected = type:None path:null path:null type:None [junit4:junit4] 2> 4427 T1633 oascc.ConnectionManager.waitForConnected Cl= ient is connected to ZooKeeper [junit4:junit4] 2> 4429 T1638 oazs.PrepRequestProcessor.pRequest Got user= -level KeeperException when processing sessionid:0x13c9916b2bb0006 type:cre= ate cxid:0x1 zxid:0x49 txntype:-1 reqpath:n/a Error Path:/solr/overseer Err= or:KeeperErrorCode =3D NodeExists for /solr/overseer [junit4:junit4] 2> 4430 T1638 oazs.PrepRequestProcessor.pRequest Got user= -level KeeperException when processing sessionid:0x13c9916b2bb0006 type:cre= ate cxid:0x2 zxid:0x4a txntype:-1 reqpath:n/a Error Path:/solr/overseer Err= or:KeeperErrorCode =3D NodeExists for /solr/overseer [junit4:junit4] 2> 4433 T1633 oasc.ZkController.createEphemeralLiveNode R= egister node as live in ZooKeeper:/live_nodes/127.0.0.1:49655_ [junit4:junit4] 2> 4434 T1638 oazs.PrepRequestProcessor.pRequest Got user= -level KeeperException when processing sessionid:0x13c9916b2bb0006 type:del= ete cxid:0x4 zxid:0x4b txntype:-1 reqpath:n/a Error Path:/solr/live_nodes/1= 27.0.0.1:49655_ Error:KeeperErrorCode =3D NoNode for /solr/live_nodes/127.0= .0.1:49655_ [junit4:junit4] 2> 4435 T1633 oascc.SolrZkClient.makePath makePath: /live= _nodes/127.0.0.1:49655_ [junit4:junit4] 2> 4442 T1661 oascc.ZkStateReader$3.process Updating live= nodes... (2) [junit4:junit4] 2> 4442 T1655 oascc.ZkStateReader$3.process Updating live= nodes... (2) [junit4:junit4] 2> 4443 T1655 oascc.ZkStateReader$2.process A cluster sta= te change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/= live_nodes, has occurred - updating... (live nodes size: 2) [junit4:junit4] 2> 4450 T1633 oascc.ZkStateReader.createClusterStateWatch= ersAndUpdate Updating cluster state from ZooKeeper...=20 [junit4:junit4] 2> 4460 T1675 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-jetty1-1359778071273/collection1 [junit4:junit4] 2> 4460 T1675 oasc.ZkController.createCollectionZkNode Ch= eck for collection zkNode:collection1 [junit4:junit4] 2> 4462 T1675 oasc.ZkController.createCollectionZkNode Co= llection zkNode exists [junit4:junit4] 2> 4462 T1675 oasc.ZkController.readConfigName Load colle= ction config from:/collections/collection1 [junit4:junit4] 2> 4465 T1675 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-jetty1-1359778071273/collection1/' [junit4:junit4] 2> 4466 T1675 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= -jetty1-1359778071273/collection1/lib/classes/' to classloader [junit4:junit4] 2> 4466 T1675 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= -jetty1-1359778071273/collection1/lib/README' to classloader [junit4:junit4] 2> 4530 T1675 oasc.SolrConfig. Using Lucene MatchVe= rsion: LUCENE_50 [junit4:junit4] 2> 4606 T1675 oasc.SolrConfig. Loaded SolrConfig: s= olrconfig.xml [junit4:junit4] 2> 4608 T1675 oass.IndexSchema.readSchema Reading Solr Sc= hema [junit4:junit4] 2> 4614 T1675 oass.IndexSchema.readSchema Schema name=3Dt= est [junit4:junit4] 2> 5242 T1675 oass.OpenExchangeRatesOrgProvider.init Init= ialized with rates=3Dopen-exchange-rates.json, refreshInterval=3D1440. [junit4:junit4] 2> 5251 T1675 oass.IndexSchema.readSchema default search = field in schema is text [junit4:junit4] 2> 5255 T1675 oass.IndexSchema.readSchema unique key fiel= d: id [junit4:junit4] 2> 5285 T1675 oass.FileExchangeRateProvider.reload Reload= ing exchange rates from file currency.xml [junit4:junit4] 2> 5291 T1675 oass.FileExchangeRateProvider.reload Reload= ing exchange rates from file currency.xml [junit4:junit4] 2> 5298 T1675 oass.OpenExchangeRatesOrgProvider.reload Re= loading exchange rates from open-exchange-rates.json [junit4:junit4] 2> 5301 T1675 oass.OpenExchangeRatesOrgProvider.reload Re= loading exchange rates from open-exchange-rates.json [junit4:junit4] 2> 5303 T1675 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-jetty1-1359778071273/collection1/, dataDir=3D./org.apache.solr.cloud.= BasicDistributedZkTest-1359778067125/jetty1/ [junit4:junit4] 2> 5304 T1675 oasc.JmxMonitoredMap. JMX monitoring = is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMB= eanServer@656ca212 [junit4:junit4] 2> 5304 T1675 oasc.SolrCore.initDirectoryFactory solr.NRT= CachingDirectoryFactory [junit4:junit4] 2> 5305 T1675 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-1359778067125/jetty1 forceNew:false [junit4:junit4] 2> 5306 T1675 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-1359778067125/jetty1 [junit4:junit4] 2> 5306 T1675 oasc.SolrCore.getNewIndexDir New index dire= ctory detected: old=3Dnull new=3D./org.apache.solr.cloud.BasicDistributedZk= Test-1359778067125/jetty1/index/ [junit4:junit4] 2> 5306 T1675 oasc.SolrCore.initIndex WARNING [collection= 1] Solr index directory './org.apache.solr.cloud.BasicDistributedZkTest-135= 9778067125/jetty1/index' doesn't exist. Creating new index... [junit4:junit4] 2> 5308 T1675 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-1359778067125/jetty1/index forceNew:false [junit4:junit4] 2> 5313 T1675 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-1359778067125/jetty1/index lockFact= ory=3Dorg.apache.lucene.store.NativeFSLockFactory@56d61aac; maxCacheMB=3D48= .0 maxMergeSizeMB=3D4.0)),segFN=3Dsegments_1,generation=3D1,filenames=3D[se= gments_1] [junit4:junit4] 2> 5313 T1675 oasc.SolrDeletionPolicy.updateCommits newes= t commit =3D 1[segments_1] [junit4:junit4] 2> 5314 T1675 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-1359778067125/jetty1/index [junit4:junit4] 2> 5315 T1675 oasc.SolrCore.initWriters created xml: solr= .XMLResponseWriter [junit4:junit4] 2> 5317 T1675 oasup.UpdateRequestProcessorChain.init inse= rting DistributedUpdateProcessorFactory into updateRequestProcessorChain "d= edupe" [junit4:junit4] 2> 5318 T1675 oasup.UpdateRequestProcessorChain.init inse= rting DistributedUpdateProcessorFactory into updateRequestProcessorChain "d= edupe-allfields" [junit4:junit4] 2> 5318 T1675 oasup.UpdateRequestProcessorChain.init inse= rting DistributedUpdateProcessorFactory into updateRequestProcessorChain "s= tored_sig" [junit4:junit4] 2> 5319 T1675 oasup.UpdateRequestProcessorChain.init inse= rting DistributedUpdateProcessorFactory into updateRequestProcessorChain "u= niq-fields" [junit4:junit4] 2> 5319 T1675 oasup.UpdateRequestProcessorChain.init inse= rting DistributedUpdateProcessorFactory into updateRequestProcessorChain "d= istrib-dup-test-chain-implicit" [junit4:junit4] 2> 5320 T1675 oasc.RequestHandlers.initHandlersFromConfig= adding lazy requestHandler: solr.ReplicationHandler [junit4:junit4] 2> 5320 T1675 oasc.RequestHandlers.initHandlersFromConfig= created /replication: solr.ReplicationHandler [junit4:junit4] 2> 5321 T1675 oasc.RequestHandlers.initHandlersFromConfig= created standard: solr.StandardRequestHandler [junit4:junit4] 2> 5322 T1675 oasc.RequestHandlers.initHandlersFromConfig= created /get: solr.RealTimeGetHandler [junit4:junit4] 2> 5322 T1675 oasc.RequestHandlers.initHandlersFromConfig= created dismax: solr.SearchHandler [junit4:junit4] 2> 5323 T1675 oasc.RequestHandlers.initHandlersFromConfig= created mock: org.apache.solr.core.MockQuerySenderListenerReqHandler [junit4:junit4] 2> 5324 T1675 oasc.RequestHandlers.initHandlersFromConfig= created /admin/: org.apache.solr.handler.admin.AdminHandlers [junit4:junit4] 2> 5324 T1675 oasc.RequestHandlers.initHandlersFromConfig= created defaults: solr.StandardRequestHandler [junit4:junit4] 2> 5325 T1675 oasc.RequestHandlers.initHandlersFromConfig= adding lazy requestHandler: solr.StandardRequestHandler [junit4:junit4] 2> 5325 T1675 oasc.RequestHandlers.initHandlersFromConfig= created lazy: solr.StandardRequestHandler [junit4:junit4] 2> 5335 T1675 oasc.RequestHandlers.initHandlersFromConfig= created /update: solr.UpdateRequestHandler [junit4:junit4] 2> 5336 T1675 oasc.RequestHandlers.initHandlersFromConfig= created /terms: org.apache.solr.handler.component.SearchHandler [junit4:junit4] 2> 5336 T1675 oasc.RequestHandlers.initHandlersFromConfig= created spellCheckCompRH: org.apache.solr.handler.component.SearchHandler [junit4:junit4] 2> 5337 T1675 oasc.RequestHandlers.initHandlersFromConfig= created spellCheckCompRH_Direct: org.apache.solr.handler.component.SearchH= andler [junit4:junit4] 2> 5338 T1675 oasc.RequestHandlers.initHandlersFromConfig= created spellCheckWithWordbreak: org.apache.solr.handler.component.SearchH= andler [junit4:junit4] 2> 5338 T1675 oasc.RequestHandlers.initHandlersFromConfig= created spellCheckWithWordbreak_Direct: org.apache.solr.handler.component.= SearchHandler [junit4:junit4] 2> 5339 T1675 oasc.RequestHandlers.initHandlersFromConfig= created spellCheckCompRH1: org.apache.solr.handler.component.SearchHandler [junit4:junit4] 2> 5340 T1675 oasc.RequestHandlers.initHandlersFromConfig= created mltrh: org.apache.solr.handler.component.SearchHandler [junit4:junit4] 2> 5341 T1675 oasc.RequestHandlers.initHandlersFromConfig= created tvrh: org.apache.solr.handler.component.SearchHandler [junit4:junit4] 2> 5342 T1675 oasc.RequestHandlers.initHandlersFromConfig= created /mlt: solr.MoreLikeThisHandler [junit4:junit4] 2> 5343 T1675 oasc.RequestHandlers.initHandlersFromConfig= created /debug/dump: solr.DumpRequestHandler [junit4:junit4] 2> 5349 T1675 oashl.XMLLoader.init xsltCacheLifetimeSecon= ds=3D60 [junit4:junit4] 2> 5353 T1675 oasc.SolrCore.initDeprecatedSupport WARNING= solrconfig.xml uses deprecated , Please update your c= onfig to use the ShowFileRequestHandler. [junit4:junit4] 2> 5355 T1675 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> 5358 T1675 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-1359778067125/jetty1 [junit4:junit4] 2> 5359 T1675 oass.SolrIndexSearcher. Opening Searc= her@8627791 main [junit4:junit4] 2> 5360 T1675 oasu.CommitTracker. Hard AutoCommit: = disabled [junit4:junit4] 2> 5360 T1675 oasu.CommitTracker. Soft AutoCommit: = disabled [junit4:junit4] 2> 5361 T1675 oashc.SpellCheckComponent.inform Initializi= ng spell checkers [junit4:junit4] 2> 5367 T1675 oass.DirectSolrSpellChecker.init init: {nam= e=3Ddirect,classname=3DDirectSolrSpellChecker,field=3Dlowerfilt,minQueryLen= gth=3D3} [junit4:junit4] 2> 5402 T1676 oasc.SolrCore.registerSearcher [collection1= ] Registered new searcher Searcher@8627791 main{StandardDirectoryReader(seg= ments_1:1)} [junit4:junit4] 2> 5415 T1675 oasc.ZkController.publish publishing core= =3Dcollection1 state=3Ddown [junit4:junit4] 2> 5415 T1675 oasc.ZkController.publish numShards not fou= nd on descriptor - reading it from system property [junit4:junit4] 2> 5634 T1656 oascc.ZkStateReader.updateClusterState Upda= ting cloud state from ZooKeeper...=20 [junit4:junit4] 2> 5636 T1656 oasc.Overseer$ClusterStateUpdater.updateSta= te 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:49651_", [junit4:junit4] 2> =09 "base_url":"http://127.0.0.1:49651"} [junit4:junit4] 2> 5645 T1656 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:49655_", [junit4:junit4] 2> =09 "base_url":"http://127.0.0.1:49655"} [junit4:junit4] 2> 5645 T1656 oasc.Overseer$ClusterStateUpdater.createCol= lection Create collection collection1 with numShards 2 [junit4:junit4] 2> 5645 T1656 oasc.Overseer$ClusterStateUpdater.updateSta= te Assigning new node to shard shard=3Dshard1 [junit4:junit4] 2> 5655 T1661 oascc.ZkStateReader$2.process A cluster sta= te change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clus= terstate.json, has occurred - updating... (live nodes size: 2) [junit4:junit4] 2> 5655 T1655 oascc.ZkStateReader$2.process A cluster sta= te change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clus= terstate.json, has occurred - updating... (live nodes size: 2) [junit4:junit4] 2> 5656 T1674 oascc.ZkStateReader$2.process A cluster sta= te change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clus= terstate.json, has occurred - updating... (live nodes size: 2) [junit4:junit4] 2> 6418 T1675 oasc.CoreContainer.registerCore registering= core: collection1 [junit4:junit4] 2> 6419 T1675 oasc.ZkController.register Register replica= - core:collection1 address:http://127.0.0.1:49655 collection:collection1 s= hard:shard1 [junit4:junit4] 2> 6420 T1675 oascc.SolrZkClient.makePath makePath: /coll= ections/collection1/leader_elect/shard1/election [junit4:junit4] 2> 6435 T1638 oazs.PrepRequestProcessor.pRequest Got user= -level KeeperException when processing sessionid:0x13c9916b2bb0006 type:del= ete cxid:0x43 zxid:0x5a txntype:-1 reqpath:n/a Error Path:/solr/collections= /collection1/leaders Error:KeeperErrorCode =3D NoNode for /solr/collections= /collection1/leaders [junit4:junit4] 2> 6436 T1675 oasc.ShardLeaderElectionContext.runLeaderPr= ocess Running the leader process. [junit4:junit4] 2> 6437 T1638 oazs.PrepRequestProcessor.pRequest Got user= -level KeeperException when processing sessionid:0x13c9916b2bb0006 type:cre= ate cxid:0x44 zxid:0x5b txntype:-1 reqpath:n/a Error Path:/solr/overseer Er= ror:KeeperErrorCode =3D NodeExists for /solr/overseer [junit4:junit4] 2> 6441 T1675 oasc.ShardLeaderElectionContext.waitForRepl= icasToComeUp Enough replicas found to continue. [junit4:junit4] 2> 6442 T1675 oasc.ShardLeaderElectionContext.runLeaderPr= ocess I may be the new leader - try and sync [junit4:junit4] 2> 6442 T1675 oasc.SyncStrategy.sync Sync replicas to htt= p://127.0.0.1:49655/collection1/ [junit4:junit4] 2> 6442 T1675 oasc.SyncStrategy.syncReplicas Sync Success= - now sync replicas to me [junit4:junit4] 2> 6443 T1675 oasc.SyncStrategy.syncToMe http://127.0.0.1= :49655/collection1/ has no replicas [junit4:junit4] 2> 6443 T1675 oasc.ShardLeaderElectionContext.runLeaderPr= ocess I am the new leader: http://127.0.0.1:49655/collection1/ [junit4:junit4] 2> 6444 T1675 oascc.SolrZkClient.makePath makePath: /coll= ections/collection1/leaders/shard1 [junit4:junit4] 2> 6454 T1638 oazs.PrepRequestProcessor.pRequest Got user= -level KeeperException when processing sessionid:0x13c9916b2bb0006 type:cre= ate cxid:0x4e zxid:0x5f txntype:-1 reqpath:n/a Error Path:/solr/overseer Er= ror:KeeperErrorCode =3D NodeExists for /solr/overseer [junit4:junit4] 2> 7172 T1656 oascc.ZkStateReader.updateClusterState Upda= ting cloud state from ZooKeeper...=20 [junit4:junit4] 2> 7190 T1661 oascc.ZkStateReader$2.process A cluster sta= te change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clus= terstate.json, has occurred - updating... (live nodes size: 2) [junit4:junit4] 2> 7190 T1655 oascc.ZkStateReader$2.process A cluster sta= te change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clus= terstate.json, has occurred - updating... (live nodes size: 2) [junit4:junit4] 2> 7191 T1674 oascc.ZkStateReader$2.process A cluster sta= te change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clus= terstate.json, has occurred - updating... (live nodes size: 2) [junit4:junit4] 2> 7226 T1675 oasc.ZkController.register We are http://12= 7.0.0.1:49655/collection1/ and leader is http://127.0.0.1:49655/collection1= / [junit4:junit4] 2> 7227 T1675 oasc.ZkController.register No LogReplay nee= ded for core=3Dcollection1 baseURL=3Dhttp://127.0.0.1:49655 [junit4:junit4] 2> 7227 T1675 oasc.ZkController.checkRecovery I am the le= ader, no recovery necessary [junit4:junit4] 2> 7227 T1675 oasc.ZkController.publish publishing core= =3Dcollection1 state=3Dactive [junit4:junit4] 2> 7227 T1675 oasc.ZkController.publish numShards not fou= nd on descriptor - reading it from system property [junit4:junit4] 2> 7230 T1675 oascc.ZkStateReader.updateClusterState Upda= ting cloud state from ZooKeeper...=20 [junit4:junit4] 2> 7231 T1633 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> 7232 T1633 oass.SolrDispatchFilter.init SolrDispatchFi= lter.init() done [junit4:junit4] 2> 7232 T1633 oascsi.HttpClientUtil.createClient Creating= new http client, config:maxConnections=3D128&maxConnectionsPerHost=3D32&fo= llowRedirects=3Dfalse [junit4:junit4] 2> 7401 T1633 oejs.Server.doStart jetty-8.1.8.v20121106 [junit4:junit4] 2> 7405 T1633 oejs.AbstractConnector.doStart Started Sele= ctChannelConnector@127.0.0.1:49658 [junit4:junit4] 2> 7406 T1633 oass.SolrDispatchFilter.init SolrDispatchFi= lter.init() [junit4:junit4] 2> 7406 T1633 oasc.SolrResourceLoader.locateSolrHome JNDI= not configured for solr (NoInitialContextEx) [junit4:junit4] 2> 7407 T1633 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-jetty2-1359778074358 [junit4:junit4] 2> 7407 T1633 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-jetty2-1359778074358/solr.xml [junit4:junit4] 2> 7408 T1633 oasc.CoreContainer. New CoreContainer= 580707193 [junit4:junit4] 2> 7408 T1633 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-jetty2-1359778074358/' [junit4:junit4] 2> 7409 T1633 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-jetty2-1359778074358/' [junit4:junit4] 2> 7443 T1633 oashc.HttpShardHandlerFactory.getParameter = Setting socketTimeout to: 60000 [junit4:junit4] 2> 7444 T1633 oashc.HttpShardHandlerFactory.getParameter = Setting urlScheme to: http:// [junit4:junit4] 2> 7444 T1633 oashc.HttpShardHandlerFactory.getParameter = Setting connTimeout to: 15000 [junit4:junit4] 2> 7444 T1633 oashc.HttpShardHandlerFactory.getParameter = Setting maxConnectionsPerHost to: 20 [junit4:junit4] 2> 7445 T1633 oashc.HttpShardHandlerFactory.getParameter = Setting corePoolSize to: 0 [junit4:junit4] 2> 7446 T1633 oashc.HttpShardHandlerFactory.getParameter = Setting maximumPoolSize to: 2147483647 [junit4:junit4] 2> 7446 T1633 oashc.HttpShardHandlerFactory.getParameter = Setting maxThreadIdleTime to: 5 [junit4:junit4] 2> 7447 T1633 oashc.HttpShardHandlerFactory.getParameter = Setting sizeOfQueue to: -1 [junit4:junit4] 2> 7447 T1633 oashc.HttpShardHandlerFactory.getParameter = Setting fairnessPolicy to: false [junit4:junit4] 2> 7448 T1633 oascsi.HttpClientUtil.createClient Creating= new http client, config:maxConnectionsPerHost=3D20&maxConnections=3D10000&= socketTimeout=3D60000&connTimeout=3D15000&retry=3Dfalse [junit4:junit4] 2> 7459 T1633 oasc.CoreContainer.load Registering Log Lis= tener [junit4:junit4] 2> 7475 T1633 oasc.CoreContainer.initZooKeeper Zookeeper = client=3D127.0.0.1:49648/solr [junit4:junit4] 2> 7475 T1633 oasc.ZkController.checkChrootPath zkHost in= cludes chroot [junit4:junit4] 2> 7476 T1633 oaz.ZooKeeper. Initiating client conn= ection, connectString=3D127.0.0.1:49648 sessionTimeout=3D60000 watcher=3Dor= g.apache.solr.common.cloud.ConnectionManager@d8d0a81 [junit4:junit4] 2> 7477 T1633 oascc.ConnectionManager.waitForConnected Wa= iting for client to connect to ZooKeeper [junit4:junit4] 2> 7477 T1686 oaz.ClientCnxn$SendThread.logStartConnect O= pening socket connection to server localhost/127.0.0.1:49648. Will not atte= mpt to authenticate using SASL (access denied ("javax.security.auth.AuthPer= mission" "getLoginConfiguration")) [junit4:junit4] 2> 7478 T1686 oaz.ClientCnxn$SendThread.primeConnection S= ocket connection established to localhost/127.0.0.1:49648, initiating sessi= on [junit4:junit4] 2> 7479 T1635 oazs.NIOServerCnxnFactory.run Accepted sock= et connection from /127.0.0.1:49659 [junit4:junit4] 2> 7479 T1635 oazs.ZooKeeperServer.processConnectRequest = Client attempting to establish new session at /127.0.0.1:49659 [junit4:junit4] 2> 7556 T1637 oazs.ZooKeeperServer.finishSessionInit Esta= blished session 0x13c9916b2bb0007 with negotiated timeout 20000 for client = /127.0.0.1:49659 [junit4:junit4] 2> 7556 T1686 oaz.ClientCnxn$SendThread.onConnected Sessi= on establishment complete on server localhost/127.0.0.1:49648, sessionid = =3D 0x13c9916b2bb0007, negotiated timeout =3D 20000 [junit4:junit4] 2> 7557 T1687 oascc.ConnectionManager.process Watcher org= .apache.solr.common.cloud.ConnectionManager@d8d0a81 name:ZooKeeperConnectio= n Watcher:127.0.0.1:49648 got event WatchedEvent state:SyncConnected type:N= one path:null path:null type:None [junit4:junit4] 2> 7557 T1633 oascc.ConnectionManager.waitForConnected Cl= ient is connected to ZooKeeper [junit4:junit4] 2> 7559 T1638 oazs.PrepRequestProcessor.pRequest2Txn Proc= essed session termination for sessionid: 0x13c9916b2bb0007 [junit4:junit4] 2> 7560 T1635 oazs.NIOServerCnxn.closeSock Closed socket = connection for client /127.0.0.1:49659 which had sessionid 0x13c9916b2bb000= 7 [junit4:junit4] 2> 7560 T1633 oaz.ZooKeeper.close Session: 0x13c9916b2bb0= 007 closed [junit4:junit4] 2> 7561 T1687 oaz.ClientCnxn$EventThread.run EventThread = shut down [junit4:junit4] 2> 7561 T1633 oascsi.HttpClientUtil.createClient Creating= new http client, config:maxConnections=3D500&maxConnectionsPerHost=3D16&so= cketTimeout=3D60000&connTimeout=3D15000 [junit4:junit4] 2> 7567 T1633 oaz.ZooKeeper. Initiating client conn= ection, connectString=3D127.0.0.1:49648/solr sessionTimeout=3D30000 watcher= =3Dorg.apache.solr.common.cloud.ConnectionManager@11638f7e [junit4:junit4] 2> 7568 T1633 oascc.ConnectionManager.waitForConnected Wa= iting for client to connect to ZooKeeper [junit4:junit4] 2> 7569 T1688 oaz.ClientCnxn$SendThread.logStartConnect O= pening socket connection to server localhost/127.0.0.1:49648. Will not atte= mpt to authenticate using SASL (access denied ("javax.security.auth.AuthPer= mission" "getLoginConfiguration")) [junit4:junit4] 2> 7570 T1688 oaz.ClientCnxn$SendThread.primeConnection S= ocket connection established to localhost/127.0.0.1:49648, initiating sessi= on [junit4:junit4] 2> 7570 T1635 oazs.NIOServerCnxnFactory.run Accepted sock= et connection from /127.0.0.1:49660 [junit4:junit4] 2> 7570 T1635 oazs.ZooKeeperServer.processConnectRequest = Client attempting to establish new session at /127.0.0.1:49660 [junit4:junit4] 2> 7572 T1637 oazs.ZooKeeperServer.finishSessionInit Esta= blished session 0x13c9916b2bb0008 with negotiated timeout 20000 for client = /127.0.0.1:49660 [junit4:junit4] 2> 7572 T1688 oaz.ClientCnxn$SendThread.onConnected Sessi= on establishment complete on server localhost/127.0.0.1:49648, sessionid = =3D 0x13c9916b2bb0008, negotiated timeout =3D 20000 [junit4:junit4] 2> 7572 T1689 oascc.ConnectionManager.process Watcher org= .apache.solr.common.cloud.ConnectionManager@11638f7e name:ZooKeeperConnecti= on Watcher:127.0.0.1:49648/solr got event WatchedEvent state:SyncConnected = type:None path:null path:null type:None [junit4:junit4] 2> 7572 T1633 oascc.ConnectionManager.waitForConnected Cl= ient is connected to ZooKeeper [junit4:junit4] 2> 7574 T1638 oazs.PrepRequestProcessor.pRequest Got user= -level KeeperException when processing sessionid:0x13c9916b2bb0008 type:cre= ate cxid:0x1 zxid:0x6c txntype:-1 reqpath:n/a Error Path:/solr/overseer Err= or:KeeperErrorCode =3D NodeExists for /solr/overseer [junit4:junit4] 2> 7576 T1638 oazs.PrepRequestProcessor.pRequest Got user= -level KeeperException when processing sessionid:0x13c9916b2bb0008 type:cre= ate cxid:0x2 zxid:0x6d txntype:-1 reqpath:n/a Error Path:/solr/overseer Err= or:KeeperErrorCode =3D NodeExists for /solr/overseer [junit4:junit4] 2> 7578 T1633 oasc.ZkController.createEphemeralLiveNode R= egister node as live in ZooKeeper:/live_nodes/127.0.0.1:49658_ [junit4:junit4] 2> 7579 T1638 oazs.PrepRequestProcessor.pRequest Got user= -level KeeperException when processing sessionid:0x13c9916b2bb0008 type:del= ete cxid:0x4 zxid:0x6e txntype:-1 reqpath:n/a Error Path:/solr/live_nodes/1= 27.0.0.1:49658_ Error:KeeperErrorCode =3D NoNode for /solr/live_nodes/127.0= .0.1:49658_ [junit4:junit4] 2> 7580 T1633 oascc.SolrZkClient.makePath makePath: /live= _nodes/127.0.0.1:49658_ [junit4:junit4] 2> 7583 T1674 oascc.ZkStateReader$2.process A cluster sta= te change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/= live_nodes, has occurred - updating... (live nodes size: 2) [junit4:junit4] 2> 7585 T1655 oascc.ZkStateReader$3.process Updating live= nodes... (3) [junit4:junit4] 2> 7585 T1655 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> 7586 T1661 oascc.ZkStateReader$3.process Updating live= nodes... (3) [junit4:junit4] 2> 7586 T1661 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> 7589 T1674 oascc.ZkStateReader$3.process Updating live= nodes... (3) [junit4:junit4] 2> 7593 T1633 oascc.ZkStateReader.createClusterStateWatch= ersAndUpdate Updating cluster state from ZooKeeper...=20 [junit4:junit4] 2> 7602 T1690 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-jetty2-1359778074358/collection1 [junit4:junit4] 2> 7602 T1690 oasc.ZkController.createCollectionZkNode Ch= eck for collection zkNode:collection1 [junit4:junit4] 2> 7604 T1690 oasc.ZkController.createCollectionZkNode Co= llection zkNode exists [junit4:junit4] 2> 7604 T1690 oasc.ZkController.readConfigName Load colle= ction config from:/collections/collection1 [junit4:junit4] 2> 7618 T1690 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-jetty2-1359778074358/collection1/' [junit4:junit4] 2> 7619 T1690 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= -jetty2-1359778074358/collection1/lib/classes/' to classloader [junit4:junit4] 2> 7619 T1690 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= -jetty2-1359778074358/collection1/lib/README' to classloader [junit4:junit4] 2> 7666 T1690 oasc.SolrConfig. Using Lucene MatchVe= rsion: LUCENE_50 [junit4:junit4] 2> 7737 T1690 oasc.SolrConfig. Loaded SolrConfig: s= olrconfig.xml [junit4:junit4] 2> 7739 T1690 oass.IndexSchema.readSchema Reading Solr Sc= hema [junit4:junit4] 2> 7745 T1690 oass.IndexSchema.readSchema Schema name=3Dt= est [junit4:junit4] 2> 8333 T1690 oass.OpenExchangeRatesOrgProvider.init Init= ialized with rates=3Dopen-exchange-rates.json, refreshInterval=3D1440. [junit4:junit4] 2> 8344 T1690 oass.IndexSchema.readSchema default search = field in schema is text [junit4:junit4] 2> 8347 T1690 oass.IndexSchema.readSchema unique key fiel= d: id [junit4:junit4] 2> 8377 T1690 oass.FileExchangeRateProvider.reload Reload= ing exchange rates from file currency.xml [junit4:junit4] 2> 8383 T1690 oass.FileExchangeRateProvider.reload Reload= ing exchange rates from file currency.xml [junit4:junit4] 2> 8389 T1690 oass.OpenExchangeRatesOrgProvider.reload Re= loading exchange rates from open-exchange-rates.json [junit4:junit4] 2> 8399 T1690 oass.OpenExchangeRatesOrgProvider.reload Re= loading exchange rates from open-exchange-rates.json [junit4:junit4] 2> 8401 T1690 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-1359778074358/collection1/, dataDir=3D./org.apache.solr.cloud.= BasicDistributedZkTest-1359778067125/jetty2/ [junit4:junit4] 2> 8402 T1690 oasc.JmxMonitoredMap. JMX monitoring = is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMB= eanServer@656ca212 [junit4:junit4] 2> 8402 T1690 oasc.SolrCore.initDirectoryFactory solr.NRT= CachingDirectoryFactory [junit4:junit4] 2> 8403 T1690 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-1359778067125/jetty2 forceNew:false [junit4:junit4] 2> 8404 T1690 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-1359778067125/jetty2 [junit4:junit4] 2> 8404 T1690 oasc.SolrCore.getNewIndexDir New index dire= ctory detected: old=3Dnull new=3D./org.apache.solr.cloud.BasicDistributedZk= Test-1359778067125/jetty2/index/ [junit4:junit4] 2> 8404 T1690 oasc.SolrCore.initIndex WARNING [collection= 1] Solr index directory './org.apache.solr.cloud.BasicDistributedZkTest-135= 9778067125/jetty2/index' doesn't exist. Creating new index... [junit4:junit4] 2> 8405 T1690 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-1359778067125/jetty2/index forceNew:false [junit4:junit4] 2> 8411 T1690 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-1359778067125/jetty2/index lockFact= ory=3Dorg.apache.lucene.store.NativeFSLockFactory@3b05555e; maxCacheMB=3D48= .0 maxMergeSizeMB=3D4.0)),segFN=3Dsegments_1,generation=3D1,filenames=3D[se= gments_1] [junit4:junit4] 2> 8411 T1690 oasc.SolrDeletionPolicy.updateCommits newes= t commit =3D 1[segments_1] [junit4:junit4] 2> 8412 T1690 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-1359778067125/jetty2/index [junit4:junit4] 2> 8412 T1690 oasc.SolrCore.initWriters created xml: solr= .XMLResponseWriter [junit4:junit4] 2> 8415 T1690 oasup.UpdateRequestProcessorChain.init inse= rting DistributedUpdateProcessorFactory into updateRequestProcessorChain "d= edupe" [junit4:junit4] 2> 8416 T1690 oasup.UpdateRequestProcessorChain.init inse= rting DistributedUpdateProcessorFactory into updateRequestProcessorChain "d= edupe-allfields" [junit4:junit4] 2> 8416 T1690 oasup.UpdateRequestProcessorChain.init inse= rting DistributedUpdateProcessorFactory into updateRequestProcessorChain "s= tored_sig" [junit4:junit4] 2> 8417 T1690 oasup.UpdateRequestProcessorChain.init inse= rting DistributedUpdateProcessorFactory into updateRequestProcessorChain "u= niq-fields" [junit4:junit4] 2> 8417 T1690 oasup.UpdateRequestProcessorChain.init inse= rting DistributedUpdateProcessorFactory into updateRequestProcessorChain "d= istrib-dup-test-chain-implicit" [junit4:junit4] 2> 8418 T1690 oasc.RequestHandlers.initHandlersFromConfig= adding lazy requestHandler: solr.ReplicationHandler [junit4:junit4] 2> 8418 T1690 oasc.RequestHandlers.initHandlersFromConfig= created /replication: solr.ReplicationHandler [junit4:junit4] 2> 8419 T1690 oasc.RequestHandlers.initHandlersFromConfig= created standard: solr.StandardRequestHandler [junit4:junit4] 2> 8420 T1690 oasc.RequestHandlers.initHandlersFromConfig= created /get: solr.RealTimeGetHandler [junit4:junit4] 2> 8420 T1690 oasc.RequestHandlers.initHandlersFromConfig= created dismax: solr.SearchHandler [junit4:junit4] 2> 8421 T1690 oasc.RequestHandlers.initHandlersFromConfig= created mock: org.apache.solr.core.MockQuerySenderListenerReqHandler [junit4:junit4] 2> 8422 T1690 oasc.RequestHandlers.initHandlersFromConfig= created /admin/: org.apache.solr.handler.admin.AdminHandlers [junit4:junit4] 2> 8422 T1690 oasc.RequestHandlers.initHandlersFromConfig= created defaults: solr.StandardRequestHandler [junit4:junit4] 2> 8422 T1690 oasc.RequestHandlers.initHandlersFromConfig= adding lazy requestHandler: solr.StandardRequestHandler [junit4:junit4] 2> 8423 T1690 oasc.RequestHandlers.initHandlersFromConfig= created lazy: solr.StandardRequestHandler [junit4:junit4] 2> 8424 T1690 oasc.RequestHandlers.initHandlersFromConfig= created /update: solr.UpdateRequestHandler [junit4:junit4] 2> 8424 T1690 oasc.RequestHandlers.initHandlersFromConfig= created /terms: org.apache.solr.handler.component.SearchHandler [junit4:junit4] 2> 8425 T1690 oasc.RequestHandlers.initHandlersFromConfig= created spellCheckCompRH: org.apache.solr.handler.component.SearchHandler [junit4:junit4] 2> 8426 T1690 oasc.RequestHandlers.initHandlersFromConfig= created spellCheckCompRH_Direct: org.apache.solr.handler.component.SearchH= andler [junit4:junit4] 2> 8426 T1690 oasc.RequestHandlers.initHandlersFromConfig= created spellCheckWithWordbreak: org.apache.solr.handler.component.SearchH= andler [junit4:junit4] 2> 8427 T1690 oasc.RequestHandlers.initHandlersFromConfig= created spellCheckWithWordbreak_Direct: org.apache.solr.handler.component.= SearchHandler [junit4:junit4] 2> 8428 T1690 oasc.RequestHandlers.initHandlersFromConfig= created spellCheckCompRH1: org.apache.solr.handler.component.SearchHandler [junit4:junit4] 2> 8428 T1690 oasc.RequestHandlers.initHandlersFromConfig= created mltrh: org.apache.solr.handler.component.SearchHandler [junit4:junit4] 2> 8429 T1690 oasc.RequestHandlers.initHandlersFromConfig= created tvrh: org.apache.solr.handler.component.SearchHandler [junit4:junit4] 2> 8430 T1690 oasc.RequestHandlers.initHandlersFromConfig= created /mlt: solr.MoreLikeThisHandler [junit4:junit4] 2> 8431 T1690 oasc.RequestHandlers.initHandlersFromConfig= created /debug/dump: solr.DumpRequestHandler [junit4:junit4] 2> 8438 T1690 oashl.XMLLoader.init xsltCacheLifetimeSecon= ds=3D60 [junit4:junit4] 2> 8442 T1690 oasc.SolrCore.initDeprecatedSupport WARNING= solrconfig.xml uses deprecated , Please update your c= onfig to use the ShowFileRequestHandler. [junit4:junit4] 2> 8444 T1690 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> 8446 T1690 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-1359778067125/jetty2 [junit4:junit4] 2> 8447 T1690 oass.SolrIndexSearcher. Opening Searc= her@1c029382 main [junit4:junit4] 2> 8449 T1690 oasu.CommitTracker. Hard AutoCommit: = disabled [junit4:junit4] 2> 8449 T1690 oasu.CommitTracker. Soft AutoCommit: = disabled [junit4:junit4] 2> 8449 T1690 oashc.SpellCheckComponent.inform Initializi= ng spell checkers [junit4:junit4] 2> 8455 T1690 oass.DirectSolrSpellChecker.init init: {nam= e=3Ddirect,classname=3DDirectSolrSpellChecker,field=3Dlowerfilt,minQueryLen= gth=3D3} [junit4:junit4] 2> 8488 T1691 oasc.SolrCore.registerSearcher [collection1= ] Registered new searcher Searcher@1c029382 main{StandardDirectoryReader(se= gments_1:1)} [junit4:junit4] 2> 8495 T1690 oasc.ZkController.publish publishing core= =3Dcollection1 state=3Ddown [junit4:junit4] 2> 8495 T1690 oasc.ZkController.publish numShards not fou= nd on descriptor - reading it from system property [junit4:junit4] 2> 8709 T1656 oascc.ZkStateReader.updateClusterState Upda= ting cloud state from ZooKeeper...=20 [junit4:junit4] 2> 8711 T1656 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:49655_", [junit4:junit4] 2> =09 "base_url":"http://127.0.0.1:49655"} [junit4:junit4] 2> 8718 T1656 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:49658_", [junit4:junit4] 2> =09 "base_url":"http://127.0.0.1:49658"} [junit4:junit4] 2> 8718 T1656 oasc.Overseer$ClusterStateUpdater.updateSta= te Collection already exists with numShards=3D2 [junit4:junit4] 2> 8718 T1656 oasc.Overseer$ClusterStateUpdater.updateSta= te Assigning new node to shard shard=3Dshard2 [junit4:junit4] 2> 8726 T1689 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> 8726 T1661 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> 8726 T1655 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> 8728 T1674 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> 9499 T1690 oasc.CoreContainer.registerCore registering= core: collection1 [junit4:junit4] 2> 9499 T1690 oasc.ZkController.register Register replica= - core:collection1 address:http://127.0.0.1:49658 collection:collection1 s= hard:shard2 [junit4:junit4] 2> 9501 T1690 oascc.SolrZkClient.makePath makePath: /coll= ections/collection1/leader_elect/shard2/election [junit4:junit4] 2> 9513 T1638 oazs.PrepRequestProcessor.pRequest Got user= -level KeeperException when processing sessionid:0x13c9916b2bb0008 type:del= ete cxid:0x42 zxid:0x7c 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> 9515 T1690 oasc.ShardLeaderElectionContext.runLeaderPr= ocess Running the leader process. [junit4:junit4] 2> 9516 T1638 oazs.PrepRequestProcessor.pRequest Got user= -level KeeperException when processing sessionid:0x13c9916b2bb0008 type:cre= ate cxid:0x43 zxid:0x7d txntype:-1 reqpath:n/a Error Path:/solr/overseer Er= ror:KeeperErrorCode =3D NodeExists for /solr/overseer [junit4:junit4] 2> 9519 T1690 oasc.ShardLeaderElectionContext.waitForRepl= icasToComeUp Enough replicas found to continue. [junit4:junit4] 2> 9519 T1690 oasc.ShardLeaderElectionContext.runLeaderPr= ocess I may be the new leader - try and sync [junit4:junit4] 2> 9520 T1690 oasc.SyncStrategy.sync Sync replicas to htt= p://127.0.0.1:49658/collection1/ [junit4:junit4] 2> 9520 T1690 oasc.SyncStrategy.syncReplicas Sync Success= - now sync replicas to me [junit4:junit4] 2> 9520 T1690 oasc.SyncStrategy.syncToMe http://127.0.0.1= :49658/collection1/ has no replicas [junit4:junit4] 2> 9520 T1690 oasc.ShardLeaderElectionContext.runLeaderPr= ocess I am the new leader: http://127.0.0.1:49658/collection1/ [junit4:junit4] 2> 9521 T1690 oascc.SolrZkClient.makePath makePath: /coll= ections/collection1/leaders/shard2 [junit4:junit4] 2> 9532 T1638 oazs.PrepRequestProcessor.pRequest Got user= -level KeeperException when processing sessionid:0x13c9916b2bb0008 type:cre= ate cxid:0x4c zxid:0x80 txntype:-1 reqpath:n/a Error Path:/solr/overseer Er= ror:KeeperErrorCode =3D NodeExists for /solr/overseer [junit4:junit4] 2> 10241 T1656 oascc.ZkStateReader.updateClusterState Upd= ating cloud state from ZooKeeper...=20 [junit4:junit4] 2> 10259 T1689 oascc.ZkStateReader$2.process A cluster st= ate change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clu= sterstate.json, has occurred - updating... (live nodes size: 3) [junit4:junit4] 2> 10259 T1655 oascc.ZkStateReader$2.process A cluster st= ate change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clu= sterstate.json, has occurred - updating... (live nodes size: 3) [junit4:junit4] 2> 10260 T1674 oascc.ZkStateReader$2.process A cluster st= ate change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clu= sterstate.json, has occurred - updating... (live nodes size: 3) [junit4:junit4] 2> 10260 T1661 oascc.ZkStateReader$2.process A cluster st= ate change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clu= sterstate.json, has occurred - updating... (live nodes size: 3) [junit4:junit4] 2> 10276 T1690 oasc.ZkController.register We are http://1= 27.0.0.1:49658/collection1/ and leader is http://127.0.0.1:49658/collection= 1/ [junit4:junit4] 2> 10276 T1690 oasc.ZkController.register No LogReplay ne= eded for core=3Dcollection1 baseURL=3Dhttp://127.0.0.1:49658 [junit4:junit4] 2> 10277 T1690 oasc.ZkController.checkRecovery I am the l= eader, no recovery necessary [junit4:junit4] 2> 10277 T1690 oasc.ZkController.publish publishing core= =3Dcollection1 state=3Dactive [junit4:junit4] 2> 10277 T1690 oasc.ZkController.publish numShards not fo= und on descriptor - reading it from system property [junit4:junit4] 2> 10282 T1690 oascc.ZkStateReader.updateClusterState Upd= ating cloud state from ZooKeeper...=20 [junit4:junit4] 2> 10284 T1633 oass.SolrDispatchFilter.init user.dir=3D/U= sers/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/so= lr-core/test/J0 [junit4:junit4] 2> 10285 T1633 oass.SolrDispatchFilter.init SolrDispatchF= ilter.init() done [junit4:junit4] 2> 10286 T1633 oascsi.HttpClientUtil.createClient Creatin= g new http client, config:maxConnections=3D128&maxConnectionsPerHost=3D32&f= ollowRedirects=3Dfalse [junit4:junit4] 2> 10488 T1633 oejs.Server.doStart jetty-8.1.8.v20121106 [junit4:junit4] 2> 10493 T1633 oejs.AbstractConnector.doStart Started Sel= ectChannelConnector@127.0.0.1:49661 [junit4:junit4] 2> 10494 T1633 oass.SolrDispatchFilter.init SolrDispatchF= ilter.init() [junit4:junit4] 2> 10494 T1633 oasc.SolrResourceLoader.locateSolrHome JND= I not configured for solr (NoInitialContextEx) [junit4:junit4] 2> 10495 T1633 oasc.SolrResourceLoader.locateSolrHome usi= ng system property solr.solr.home: /Users/jenkins/jenkins-slave/workspace/L= ucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.clou= d.BasicDistributedZkTest-jetty3-1359778077417 [junit4:junit4] 2> 10495 T1633 oasc.CoreContainer$Initializer.initialize = looking for solr.xml: /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-tr= unk-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistri= butedZkTest-jetty3-1359778077417/solr.xml [junit4:junit4] 2> 10496 T1633 oasc.CoreContainer. New CoreContaine= r 1638102941 [junit4:junit4] 2> 10496 T1633 oasc.CoreContainer.load Loading CoreContai= ner using Solr Home: '/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-tr= unk-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistri= butedZkTest-jetty3-1359778077417/' [junit4:junit4] 2> 10497 T1633 oasc.SolrResourceLoader. new SolrRes= ourceLoader for directory: '/Users/jenkins/jenkins-slave/workspace/Lucene-S= olr-trunk-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.Basic= DistributedZkTest-jetty3-1359778077417/' [junit4:junit4] 2> 10535 T1633 oashc.HttpShardHandlerFactory.getParameter= Setting socketTimeout to: 60000 [junit4:junit4] 2> 10536 T1633 oashc.HttpShardHandlerFactory.getParameter= Setting urlScheme to: http:// [junit4:junit4] 2> 10537 T1633 oashc.HttpShardHandlerFactory.getParameter= Setting connTimeout to: 15000 [junit4:junit4] 2> 10537 T1633 oashc.HttpShardHandlerFactory.getParameter= Setting maxConnectionsPerHost to: 20 [junit4:junit4] 2> 10538 T1633 oashc.HttpShardHandlerFactory.getParameter= Setting corePoolSize to: 0 [junit4:junit4] 2> 10538 T1633 oashc.HttpShardHandlerFactory.getParameter= Setting maximumPoolSize to: 2147483647 [junit4:junit4] 2> 10539 T1633 oashc.HttpShardHandlerFactory.getParameter= Setting maxThreadIdleTime to: 5 [junit4:junit4] 2> 10540 T1633 oashc.HttpShardHandlerFactory.getParameter= Setting sizeOfQueue to: -1 [junit4:junit4] 2> 10540 T1633 oashc.HttpShardHandlerFactory.getParameter= Setting fairnessPolicy to: false [junit4:junit4] 2> 10541 T1633 oascsi.HttpClientUtil.createClient Creatin= g new http client, config:maxConnectionsPerHost=3D20&maxConnections=3D10000= &socketTimeout=3D60000&connTimeout=3D15000&retry=3Dfalse [junit4:junit4] 2> 10556 T1633 oasc.CoreContainer.load Registering Log Li= stener [junit4:junit4] 2> 10584 T1633 oasc.CoreContainer.initZooKeeper Zookeeper= client=3D127.0.0.1:49648/solr [junit4:junit4] 2> 10585 T1633 oasc.ZkController.checkChrootPath zkHost i= ncludes chroot [junit4:junit4] 2> 10586 T1633 oaz.ZooKeeper. Initiating client con= nection, connectString=3D127.0.0.1:49648 sessionTimeout=3D60000 watcher=3Do= rg.apache.solr.common.cloud.ConnectionManager@3c8639e2 [junit4:junit4] 2> 10587 T1633 oascc.ConnectionManager.waitForConnected W= aiting for client to connect to ZooKeeper [junit4:junit4] 2> 10588 T1701 oaz.ClientCnxn$SendThread.logStartConnect = Opening socket connection to server localhost/127.0.0.1:49648. Will not att= empt to authenticate using SASL (access denied ("javax.security.auth.AuthPe= rmission" "getLoginConfiguration")) [junit4:junit4] 2> 10590 T1701 oaz.ClientCnxn$SendThread.primeConnection = Socket connection established to localhost/127.0.0.1:49648, initiating sess= ion [junit4:junit4] 2> 10591 T1635 oazs.NIOServerCnxnFactory.run Accepted soc= ket connection from /127.0.0.1:49662 [junit4:junit4] 2> 10592 T1635 oazs.ZooKeeperServer.processConnectRequest= Client attempting to establish new session at /127.0.0.1:49662 [junit4:junit4] 2> 10593 T1637 oazs.ZooKeeperServer.finishSessionInit Est= ablished session 0x13c9916b2bb0009 with negotiated timeout 20000 for client= /127.0.0.1:49662 [junit4:junit4] 2> 10594 T1701 oaz.ClientCnxn$SendThread.onConnected Sess= ion establishment complete on server localhost/127.0.0.1:49648, sessionid = =3D 0x13c9916b2bb0009, negotiated timeout =3D 20000 [junit4:junit4] 2> 10594 T1702 oascc.ConnectionManager.process Watcher or= g.apache.solr.common.cloud.ConnectionManager@3c8639e2 name:ZooKeeperConnect= ion Watcher:127.0.0.1:49648 got event WatchedEvent state:SyncConnected type= :None path:null path:null type:None [junit4:junit4] 2> 10595 T1633 oascc.ConnectionManager.waitForConnected C= lient is connected to ZooKeeper [junit4:junit4] 2> 10598 T1638 oazs.PrepRequestProcessor.pRequest2Txn Pro= cessed session termination for sessionid: 0x13c9916b2bb0009 [junit4:junit4] 2> 10600 T1635 oazs.NIOServerCnxn.closeSock Closed socket= connection for client /127.0.0.1:49662 which had sessionid 0x13c9916b2bb00= 09 [junit4:junit4] 2> 10600 T1633 oaz.ZooKeeper.close Session: 0x13c9916b2bb= 0009 closed [junit4:junit4] 2> 10600 T1702 oaz.ClientCnxn$EventThread.run EventThread= shut down [junit4:junit4] 2> 10601 T1633 oascsi.HttpClientUtil.createClient Creatin= g new http client, config:maxConnections=3D500&maxConnectionsPerHost=3D16&s= ocketTimeout=3D60000&connTimeout=3D15000 [junit4:junit4] 2> 10611 T1633 oaz.ZooKeeper. Initiating client con= nection, connectString=3D127.0.0.1:49648/solr sessionTimeout=3D30000 watche= r=3Dorg.apache.solr.common.cloud.ConnectionManager@37731a8c [junit4:junit4] 2> 10613 T1703 oaz.ClientCnxn$SendThread.logStartConnect = Opening socket connection to server localhost/127.0.0.1:49648. Will not att= empt to authenticate using SASL (access denied ("javax.security.auth.AuthPe= rmission" "getLoginConfiguration")) [junit4:junit4] 2> 10613 T1633 oascc.ConnectionManager.waitForConnected W= aiting for client to connect to ZooKeeper [junit4:junit4] 2> 10614 T1703 oaz.ClientCnxn$SendThread.primeConnection = Socket connection established to localhost/127.0.0.1:49648, initiating sess= ion [junit4:junit4] 2> 10615 T1635 oazs.NIOServerCnxnFactory.run Accepted soc= ket connection from /127.0.0.1:49663 [junit4:junit4] 2> 10615 T1635 oazs.ZooKeeperServer.processConnectRequest= Client attempting to establish new session at /127.0.0.1:49663 [junit4:junit4] 2> 10617 T1637 oazs.ZooKeeperServer.finishSessionInit Est= ablished session 0x13c9916b2bb000a with negotiated timeout 20000 for client= /127.0.0.1:49663 [junit4:junit4] 2> 10617 T1703 oaz.ClientCnxn$SendThread.onConnected Sess= ion establishment complete on server localhost/127.0.0.1:49648, sessionid = =3D 0x13c9916b2bb000a, negotiated timeout =3D 20000 [junit4:junit4] 2> 10617 T1704 oascc.ConnectionManager.process Watcher or= g.apache.solr.common.cloud.ConnectionManager@37731a8c name:ZooKeeperConnect= ion Watcher:127.0.0.1:49648/solr got event WatchedEvent state:SyncConnected= type:None path:null path:null type:None [junit4:junit4] 2> 10617 T1633 oascc.ConnectionManager.waitForConnected C= lient is connected to ZooKeeper [junit4:junit4] 2> 10620 T1638 oazs.PrepRequestProcessor.pRequest Got use= r-level KeeperException when processing sessionid:0x13c9916b2bb000a type:cr= eate cxid:0x1 zxid:0x8d txntype:-1 reqpath:n/a Error Path:/solr/overseer Er= ror:KeeperErrorCode =3D NodeExists for /solr/overseer [junit4:junit4] 2> 10622 T1638 oazs.PrepRequestProcessor.pRequest Got use= r-level KeeperException when processing sessionid:0x13c9916b2bb000a type:cr= eate cxid:0x2 zxid:0x8e txntype:-1 reqpath:n/a Error Path:/solr/overseer Er= ror:KeeperErrorCode =3D NodeExists for /solr/overseer [junit4:junit4] 2> 10624 T1633 oasc.ZkController.createEphemeralLiveNode = Register node as live in ZooKeeper:/live_nodes/127.0.0.1:49661_ [junit4:junit4] 2> 10626 T1638 oazs.PrepRequestProcessor.pRequest Got use= r-level KeeperException when processing sessionid:0x13c9916b2bb000a type:de= lete cxid:0x4 zxid:0x8f txntype:-1 reqpath:n/a Error Path:/solr/live_nodes/= 127.0.0.1:49661_ Error:KeeperErrorCode =3D NoNode for /solr/live_nodes/127.= 0.0.1:49661_ [junit4:junit4] 2> 10627 T1633 oascc.SolrZkClient.makePath makePath: /liv= e_nodes/127.0.0.1:49661_ [junit4:junit4] 2> 10631 T1689 oascc.ZkStateReader$2.process A cluster st= ate change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:= /live_nodes, has occurred - updating... (live nodes size: 3) [junit4:junit4] 2> 10632 T1674 oascc.ZkStateReader$2.process A cluster st= ate change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:= /live_nodes, has occurred - updating... (live nodes size: 3) [junit4:junit4] 2> 10633 T1655 oascc.ZkStateReader$3.process Updating liv= e nodes... (4) [junit4:junit4] 2> 10633 T1655 oascc.ZkStateReader$2.process A cluster st= ate change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:= /live_nodes, has occurred - updating... (live nodes size: 4) [junit4:junit4] 2> 10634 T1661 oascc.ZkStateReader$3.process Updating liv= e nodes... (4) [junit4:junit4] 2> 10634 T1661 oascc.ZkStateReader$2.process A cluster st= ate change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:= /live_nodes, has occurred - updating... (live nodes size: 4) [junit4:junit4] 2> 10638 T1689 oascc.ZkStateReader$3.process Updating liv= e nodes... (4) [junit4:junit4] 2> 10639 T1674 oascc.ZkStateReader$3.process Updating liv= e nodes... (4) [junit4:junit4] 2> 10644 T1633 oascc.ZkStateReader.createClusterStateWatc= hersAndUpdate Updating cluster state from ZooKeeper...=20 [junit4:junit4] 2> 10662 T1705 oasc.CoreContainer.create Creating SolrCor= e 'collection1' using instanceDir: /Users/jenkins/jenkins-slave/workspace/L= ucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.clou= d.BasicDistributedZkTest-jetty3-1359778077417/collection1 [junit4:junit4] 2> 10663 T1705 oasc.ZkController.createCollectionZkNode C= heck for collection zkNode:collection1 [junit4:junit4] 2> 10664 T1705 oasc.ZkController.createCollectionZkNode C= ollection zkNode exists [junit4:junit4] 2> 10664 T1705 oasc.ZkController.readConfigName Load coll= ection config from:/collections/collection1 [junit4:junit4] 2> 10667 T1705 oasc.SolrResourceLoader. new SolrRes= ourceLoader for directory: '/Users/jenkins/jenkins-slave/workspace/Lucene-S= olr-trunk-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.Basic= DistributedZkTest-jetty3-1359778077417/collection1/' [junit4:junit4] 2> 10667 T1705 oasc.SolrResourceLoader.replaceClassLoader= Adding 'file:/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacO= SX/solr/build/solr-core/test/J0/org.apache.solr.cloud.BasicDistributedZkTes= t-jetty3-1359778077417/collection1/lib/classes/' to classloader [junit4:junit4] 2> 10668 T1705 oasc.SolrResourceLoader.replaceClassLoader= Adding 'file:/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacO= SX/solr/build/solr-core/test/J0/org.apache.solr.cloud.BasicDistributedZkTes= t-jetty3-1359778077417/collection1/lib/README' to classloader [junit4:junit4] 2> 10714 T1705 oasc.SolrConfig. Using Lucene MatchV= ersion: LUCENE_50 [junit4:junit4] 2> 10785 T1705 oasc.SolrConfig. Loaded SolrConfig: = solrconfig.xml [junit4:junit4] 2> 10786 T1705 oass.IndexSchema.readSchema Reading Solr S= chema [junit4:junit4] 2> 10793 T1705 oass.IndexSchema.readSchema Schema name=3D= test [junit4:junit4] 2> 11672 T1705 oass.OpenExchangeRatesOrgProvider.init Ini= tialized with rates=3Dopen-exchange-rates.json, refreshInterval=3D1440. [junit4:junit4] 2> 11680 T1705 oass.IndexSchema.readSchema default search= field in schema is text [junit4:junit4] 2> 11683 T1705 oass.IndexSchema.readSchema unique key fie= ld: id [junit4:junit4] 2> 11708 T1705 oass.FileExchangeRateProvider.reload Reloa= ding exchange rates from file currency.xml [junit4:junit4] 2> 11713 T1705 oass.FileExchangeRateProvider.reload Reloa= ding exchange rates from file currency.xml [junit4:junit4] 2> 11719 T1705 oass.OpenExchangeRatesOrgProvider.reload R= eloading exchange rates from open-exchange-rates.json [junit4:junit4] 2> 11721 T1705 oass.OpenExchangeRatesOrgProvider.reload R= eloading exchange rates from open-exchange-rates.json [junit4:junit4] 2> 11723 T1705 oasc.SolrCore. [collection1] Opening= new SolrCore at /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-M= acOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributed= ZkTest-jetty3-1359778077417/collection1/, dataDir=3D./org.apache.solr.cloud= .BasicDistributedZkTest-1359778067125/jetty3/ [junit4:junit4] 2> 11724 T1705 oasc.JmxMonitoredMap. JMX monitoring= is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxM= BeanServer@656ca212 [junit4:junit4] 2> 11724 T1705 oasc.SolrCore.initDirectoryFactory solr.NR= TCachingDirectoryFactory [junit4:junit4] 2> 11725 T1705 oasc.CachingDirectoryFactory.get return ne= w directory for /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-Ma= cOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZ= kTest-1359778067125/jetty3 forceNew:false [junit4:junit4] 2> 11725 T1705 oasc.CachingDirectoryFactory.close Releasi= ng directory:/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOS= X/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZkTe= st-1359778067125/jetty3 [junit4:junit4] 2> 11726 T1705 oasc.SolrCore.getNewIndexDir New index dir= ectory detected: old=3Dnull new=3D./org.apache.solr.cloud.BasicDistributedZ= kTest-1359778067125/jetty3/index/ [junit4:junit4] 2> 11726 T1705 oasc.SolrCore.initIndex WARNING [collectio= n1] Solr index directory './org.apache.solr.cloud.BasicDistributedZkTest-13= 59778067125/jetty3/index' doesn't exist. Creating new index... [junit4:junit4] 2> 11727 T1705 oasc.CachingDirectoryFactory.get return ne= w directory for /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-Ma= cOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZ= kTest-1359778067125/jetty3/index forceNew:false [junit4:junit4] 2> 11731 T1705 oasc.SolrDeletionPolicy.onCommit SolrDelet= ionPolicy.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-1359778067125/jetty3/index lockFact= ory=3Dorg.apache.lucene.store.NativeFSLockFactory@5091943e; maxCacheMB=3D48= .0 maxMergeSizeMB=3D4.0)),segFN=3Dsegments_1,generation=3D1,filenames=3D[se= gments_1] [junit4:junit4] 2> 11732 T1705 oasc.SolrDeletionPolicy.updateCommits newe= st commit =3D 1[segments_1] [junit4:junit4] 2> 11733 T1705 oasc.CachingDirectoryFactory.close Releasi= ng directory:/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOS= X/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZkTe= st-1359778067125/jetty3/index [junit4:junit4] 2> 11733 T1705 oasc.SolrCore.initWriters created xml: sol= r.XMLResponseWriter [junit4:junit4] 2> 11735 T1705 oasup.UpdateRequestProcessorChain.init ins= erting DistributedUpdateProcessorFactory into updateRequestProcessorChain "= dedupe" [junit4:junit4] 2> 11736 T1705 oasup.UpdateRequestProcessorChain.init ins= erting DistributedUpdateProcessorFactory into updateRequestProcessorChain "= dedupe-allfields" [junit4:junit4] 2> 11736 T1705 oasup.UpdateRequestProcessorChain.init ins= erting DistributedUpdateProcessorFactory into updateRequestProcessorChain "= stored_sig" [junit4:junit4] 2> 11737 T1705 oasup.UpdateRequestProcessorChain.init ins= erting DistributedUpdateProcessorFactory into updateRequestProcessorChain "= uniq-fields" [junit4:junit4] 2> 11737 T1705 oasup.UpdateRequestProcessorChain.init ins= erting DistributedUpdateProcessorFactory into updateRequestProcessorChain "= distrib-dup-test-chain-implicit" [junit4:junit4] 2> 11737 T1705 oasc.RequestHandlers.initHandlersFromConfi= g adding lazy requestHandler: solr.ReplicationHandler [junit4:junit4] 2> 11738 T1705 oasc.RequestHandlers.initHandlersFromConfi= g created /replication: solr.ReplicationHandler [junit4:junit4] 2> 11739 T1705 oasc.RequestHandlers.initHandlersFromConfi= g created standard: solr.StandardRequestHandler [junit4:junit4] 2> 11740 T1705 oasc.RequestHandlers.initHandlersFromConfi= g created /get: solr.RealTimeGetHandler [junit4:junit4] 2> 11740 T1705 oasc.RequestHandlers.initHandlersFromConfi= g created dismax: solr.SearchHandler [junit4:junit4] 2> 11741 T1705 oasc.RequestHandlers.initHandlersFromConfi= g created mock: org.apache.solr.core.MockQuerySenderListenerReqHandler [junit4:junit4] 2> 11741 T1705 oasc.RequestHandlers.initHandlersFromConfi= g created /admin/: org.apache.solr.handler.admin.AdminHandlers [junit4:junit4] 2> 11742 T1705 oasc.RequestHandlers.initHandlersFromConfi= g created defaults: solr.StandardRequestHandler [junit4:junit4] 2> 11742 T1705 oasc.RequestHandlers.initHandlersFromConfi= g adding lazy requestHandler: solr.StandardRequestHandler [junit4:junit4] 2> 11742 T1705 oasc.RequestHandlers.initHandlersFromConfi= g created lazy: solr.StandardRequestHandler [junit4:junit4] 2> 11743 T1705 oasc.RequestHandlers.initHandlersFromConfi= g created /update: solr.UpdateRequestHandler [junit4:junit4] 2> 11744 T1705 oasc.RequestHandlers.initHandlersFromConfi= g created /terms: org.apache.solr.handler.component.SearchHandler [junit4:junit4] 2> 11744 T1705 oasc.RequestHandlers.initHandlersFromConfi= g created spellCheckCompRH: org.apache.solr.handler.component.SearchHandler [junit4:junit4] 2> 11745 T1705 oasc.RequestHandlers.initHandlersFromConfi= g created spellCheckCompRH_Direct: org.apache.solr.handler.component.Search= Handler [junit4:junit4] 2> 11746 T1705 oasc.RequestHandlers.initHandlersFromConfi= g created spellCheckWithWordbreak: org.apache.solr.handler.component.Search= Handler [junit4:junit4] 2> 11746 T1705 oasc.RequestHandlers.initHandlersFromConfi= g created spellCheckWithWordbreak_Direct: org.apache.solr.handler.component= .SearchHandler [junit4:junit4] 2> 11747 T1705 oasc.RequestHandlers.initHandlersFromConfi= g created spellCheckCompRH1: org.apache.solr.handler.component.SearchHandle= r [junit4:junit4] 2> 11747 T1705 oasc.RequestHandlers.initHandlersFromConfi= g created mltrh: org.apache.solr.handler.component.SearchHandler [junit4:junit4] 2> 11748 T1705 oasc.RequestHandlers.initHandlersFromConfi= g created tvrh: org.apache.solr.handler.component.SearchHandler [junit4:junit4] 2> 11749 T1705 oasc.RequestHandlers.initHandlersFromConfi= g created /mlt: solr.MoreLikeThisHandler [junit4:junit4] 2> 11749 T1705 oasc.RequestHandlers.initHandlersFromConfi= g created /debug/dump: solr.DumpRequestHandler [junit4:junit4] 2> 11755 T1705 oashl.XMLLoader.init xsltCacheLifetimeSeco= nds=3D60 [junit4:junit4] 2> 11758 T1705 oasc.SolrCore.initDeprecatedSupport WARNIN= G solrconfig.xml uses deprecated , Please update your = config to use the ShowFileRequestHandler. [junit4:junit4] 2> 11760 T1705 oasc.SolrCore.initDeprecatedSupport WARNIN= G adding ShowFileRequestHandler with hidden files: [SCHEMA.XML, OLD_SYNONYM= S.TXT, STOPWORDS.TXT, PROTWORDS.TXT, OPEN-EXCHANGE-RATES.JSON, SYNONYMS.TXT= , CURRENCY.XML, MAPPING-ISOLATIN1ACCENT.TXT] [junit4:junit4] 2> 11762 T1705 oasc.CachingDirectoryFactory.close Releasi= ng directory:/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOS= X/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZkTe= st-1359778067125/jetty3 [junit4:junit4] 2> 11764 T1705 oass.SolrIndexSearcher. Opening Sear= cher@4dab082b main [junit4:junit4] 2> 11765 T1705 oasu.CommitTracker. Hard AutoCommit:= disabled [junit4:junit4] 2> 11765 T1705 oasu.CommitTracker. Soft AutoCommit:= disabled [junit4:junit4] 2> 11765 T1705 oashc.SpellCheckComponent.inform Initializ= ing spell checkers [junit4:junit4] 2> 11771 T1705 oass.DirectSolrSpellChecker.init init: {na= me=3Ddirect,classname=3DDirectSolrSpellChecker,field=3Dlowerfilt,minQueryLe= ngth=3D3} [junit4:junit4] 2> 11776 T1656 oascc.ZkStateReader.updateClusterState Upd= ating cloud state from ZooKeeper...=20 [junit4:junit4] 2> 11777 T1656 oasc.Overseer$ClusterStateUpdater.updateSt= ate 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:49658_", [junit4:junit4] 2> =09 "base_url":"http://127.0.0.1:49658"} [junit4:junit4] 2> 11785 T1655 oascc.ZkStateReader$2.process A cluster st= ate change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clu= sterstate.json, has occurred - updating... (live nodes size: 4) [junit4:junit4] 2> 11785 T1704 oascc.ZkStateReader$2.process A cluster st= ate change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clu= sterstate.json, has occurred - updating... (live nodes size: 4) [junit4:junit4] 2> 11786 T1674 oascc.ZkStateReader$2.process A cluster st= ate change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clu= sterstate.json, has occurred - updating... (live nodes size: 4) [junit4:junit4] 2> 11793 T1661 oascc.ZkStateReader$2.process A cluster st= ate change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clu= sterstate.json, has occurred - updating... (live nodes size: 4) [junit4:junit4] 2> 11793 T1689 oascc.ZkStateReader$2.process A cluster st= ate change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clu= sterstate.json, has occurred - updating... (live nodes size: 4) [junit4:junit4] 2> 11806 T1706 oasc.SolrCore.registerSearcher [collection= 1] Registered new searcher Searcher@4dab082b main{StandardDirectoryReader(s= egments_1:1)} [junit4:junit4] 2> 11814 T1705 oasc.ZkController.publish publishing core= =3Dcollection1 state=3Ddown [junit4:junit4] 2> 11814 T1705 oasc.ZkController.publish numShards not fo= und on descriptor - reading it from system property [junit4:junit4] 2> 13301 T1656 oascc.ZkStateReader.updateClusterState Upd= ating cloud state from ZooKeeper...=20 [junit4:junit4] 2> 13303 T1656 oasc.Overseer$ClusterStateUpdater.updateSt= ate 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:49661_", [junit4:junit4] 2> =09 "base_url":"http://127.0.0.1:49661"} [junit4:junit4] 2> 13303 T1656 oasc.Overseer$ClusterStateUpdater.updateSt= ate Collection already exists with numShards=3D2 [junit4:junit4] 2> 13303 T1656 oasc.Overseer$ClusterStateUpdater.updateSt= ate Assigning new node to shard shard=3Dshard1 [junit4:junit4] 2> 13312 T1655 oascc.ZkStateReader$2.process A cluster st= ate change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clu= sterstate.json, has occurred - updating... (live nodes size: 4) [junit4:junit4] 2> 13312 T1674 oascc.ZkStateReader$2.process A cluster st= ate change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clu= sterstate.json, has occurred - updating... (live nodes size: 4) [junit4:junit4] 2> 13313 T1704 oascc.ZkStateReader$2.process A cluster st= ate change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clu= sterstate.json, has occurred - updating... (live nodes size: 4) [junit4:junit4] 2> 13313 T1689 oascc.ZkStateReader$2.process A cluster st= ate change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clu= sterstate.json, has occurred - updating... (live nodes size: 4) [junit4:junit4] 2> 13314 T1661 oascc.ZkStateReader$2.process A cluster st= ate change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clu= sterstate.json, has occurred - updating... (live nodes size: 4) [junit4:junit4] 2> 13818 T1705 oasc.CoreContainer.registerCore registerin= g core: collection1 [junit4:junit4] 2> 13818 T1705 oasc.ZkController.register Register replic= a - core:collection1 address:http://127.0.0.1:49661 collection:collection1 = shard:shard1 [junit4:junit4] 2> 13826 T1705 oasc.ZkController.register We are http://1= 27.0.0.1:49661/collection1/ and leader is http://127.0.0.1:49655/collection= 1/ [junit4:junit4] 2> 13826 T1705 oasc.ZkController.register No LogReplay ne= eded for core=3Dcollection1 baseURL=3Dhttp://127.0.0.1:49661 [junit4:junit4] 2> 13826 T1705 oasc.ZkController.checkRecovery Core needs= to recover:collection1 [junit4:junit4] 2> 13826 T1705 oasu.DefaultSolrCoreState.doRecovery Runni= ng recovery - first canceling any ongoing recovery [junit4:junit4] 2> ASYNC NEW_CORE C122 name=3Dcollection1 org.apache.sol= r.core.SolrCore@64c7ef48 url=3Dhttp://127.0.0.1:49661/collection1 node=3D12= 7.0.0.1:49661_ C122_STATE=3Dcoll:collection1 core:collection1 props:{shard= =3Dnull, roles=3Dnull, state=3Ddown, core=3Dcollection1, collection=3Dcolle= ction1, node_name=3D127.0.0.1:49661_, base_url=3Dhttp://127.0.0.1:49661} [junit4:junit4] 2> 13828 T1707 C122 P49661 oasc.RecoveryStrategy.run Star= ting recovery process. core=3Dcollection1 recoveringAfterStartup=3Dtrue [junit4:junit4] 2> 13829 T1707 C122 P49661 oasc.RecoveryStrategy.doRecove= ry ###### startupVersions=3D[] [junit4:junit4] 2> 13830 T1707 C122 P49661 oasc.ZkController.publish publ= ishing core=3Dcollection1 state=3Drecovering [junit4:junit4] 2> 13830 T1705 oascc.ZkStateReader.updateClusterState Upd= ating cloud state from ZooKeeper...=20 [junit4:junit4] 2> 13831 T1707 C122 P49661 oasc.ZkController.publish numS= hards not found on descriptor - reading it from system property [junit4:junit4] 2> 13834 T1707 C122 P49661 oascsi.HttpClientUtil.createCl= ient Creating new http client, config:maxConnections=3D128&maxConnectionsPe= rHost=3D32&followRedirects=3Dfalse [junit4:junit4] 2> 13833 T1633 oass.SolrDispatchFilter.init user.dir=3D/U= sers/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/so= lr-core/test/J0 [junit4:junit4] 2> 13834 T1633 oass.SolrDispatchFilter.init SolrDispatchF= ilter.init() done [junit4:junit4] 2> 13835 T1633 oascsi.HttpClientUtil.createClient Creatin= g new http client, config:maxConnections=3D128&maxConnectionsPerHost=3D32&f= ollowRedirects=3Dfalse [junit4:junit4] 2> 14011 T1633 oejs.Server.doStart jetty-8.1.8.v20121106 [junit4:junit4] 2> 14027 T1633 oejs.AbstractConnector.doStart Started Sel= ectChannelConnector@127.0.0.1:49665 [junit4:junit4] 2> 14029 T1633 oass.SolrDispatchFilter.init SolrDispatchF= ilter.init() [junit4:junit4] 2> 14030 T1633 oasc.SolrResourceLoader.locateSolrHome JND= I not configured for solr (NoInitialContextEx) [junit4:junit4] 2> 14030 T1633 oasc.SolrResourceLoader.locateSolrHome usi= ng system property solr.solr.home: /Users/jenkins/jenkins-slave/workspace/L= ucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.clou= d.BasicDistributedZkTest-jetty4-1359778080965 [junit4:junit4] 2> 14031 T1633 oasc.CoreContainer$Initializer.initialize = looking for solr.xml: /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-tr= unk-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistri= butedZkTest-jetty4-1359778080965/solr.xml [junit4:junit4] 2> 14031 T1633 oasc.CoreContainer. New CoreContaine= r 384826232 [junit4:junit4] 2> 14032 T1633 oasc.CoreContainer.load Loading CoreContai= ner using Solr Home: '/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-tr= unk-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistri= butedZkTest-jetty4-1359778080965/' [junit4:junit4] 2> 14034 T1633 oasc.SolrResourceLoader. new SolrRes= ourceLoader for directory: '/Users/jenkins/jenkins-slave/workspace/Lucene-S= olr-trunk-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.Basic= DistributedZkTest-jetty4-1359778080965/' [junit4:junit4] 2> 14071 T1633 oashc.HttpShardHandlerFactory.getParameter= Setting socketTimeout to: 60000 [junit4:junit4] 2> 14071 T1633 oashc.HttpShardHandlerFactory.getParameter= Setting urlScheme to: http:// [junit4:junit4] 2> 14072 T1633 oashc.HttpShardHandlerFactory.getParameter= Setting connTimeout to: 15000 [junit4:junit4] 2> 14072 T1633 oashc.HttpShardHandlerFactory.getParameter= Setting maxConnectionsPerHost to: 20 [junit4:junit4] 2> 14073 T1633 oashc.HttpShardHandlerFactory.getParameter= Setting corePoolSize to: 0 [junit4:junit4] 2> 14073 T1633 oashc.HttpShardHandlerFactory.getParameter= Setting maximumPoolSize to: 2147483647 [junit4:junit4] 2> 14074 T1633 oashc.HttpShardHandlerFactory.getParameter= Setting maxThreadIdleTime to: 5 [junit4:junit4] 2> 14074 T1633 oashc.HttpShardHandlerFactory.getParameter= Setting sizeOfQueue to: -1 [junit4:junit4] 2> 14075 T1633 oashc.HttpShardHandlerFactory.getParameter= Setting fairnessPolicy to: false [junit4:junit4] 2> 14076 T1633 oascsi.HttpClientUtil.createClient Creatin= g new http client, config:maxConnectionsPerHost=3D20&maxConnections=3D10000= &socketTimeout=3D60000&connTimeout=3D15000&retry=3Dfalse [junit4:junit4] 2> 14089 T1633 oasc.CoreContainer.load Registering Log Li= stener [junit4:junit4] 2> 14108 T1633 oasc.CoreContainer.initZooKeeper Zookeeper= client=3D127.0.0.1:49648/solr [junit4:junit4] 2> 14109 T1633 oasc.ZkController.checkChrootPath zkHost i= ncludes chroot [junit4:junit4] 2> 14109 T1633 oaz.ZooKeeper. Initiating client con= nection, connectString=3D127.0.0.1:49648 sessionTimeout=3D60000 watcher=3Do= rg.apache.solr.common.cloud.ConnectionManager@7f165f17 [junit4:junit4] 2> 14111 T1633 oascc.ConnectionManager.waitForConnected W= aiting for client to connect to ZooKeeper [junit4:junit4] 2> 14111 T1717 oaz.ClientCnxn$SendThread.logStartConnect = Opening socket connection to server localhost/127.0.0.1:49648. Will not att= empt to authenticate using SASL (access denied ("javax.security.auth.AuthPe= rmission" "getLoginConfiguration")) [junit4:junit4] 2> 14112 T1717 oaz.ClientCnxn$SendThread.primeConnection = Socket connection established to localhost/127.0.0.1:49648, initiating sess= ion [junit4:junit4] 2> 14112 T1635 oazs.NIOServerCnxnFactory.run Accepted soc= ket connection from /127.0.0.1:49666 [junit4:junit4] 2> 14113 T1635 oazs.ZooKeeperServer.processConnectRequest= Client attempting to establish new session at /127.0.0.1:49666 [junit4:junit4] 2> 14114 T1637 oazs.ZooKeeperServer.finishSessionInit Est= ablished session 0x13c9916b2bb000b with negotiated timeout 20000 for client= /127.0.0.1:49666 [junit4:junit4] 2> 14114 T1717 oaz.ClientCnxn$SendThread.onConnected Sess= ion establishment complete on server localhost/127.0.0.1:49648, sessionid = =3D 0x13c9916b2bb000b, negotiated timeout =3D 20000 [junit4:junit4] 2> 14114 T1718 oascc.ConnectionManager.process Watcher or= g.apache.solr.common.cloud.ConnectionManager@7f165f17 name:ZooKeeperConnect= ion Watcher:127.0.0.1:49648 got event WatchedEvent state:SyncConnected type= :None path:null path:null type:None [junit4:junit4] 2> 14115 T1633 oascc.ConnectionManager.waitForConnected C= lient is connected to ZooKeeper [junit4:junit4] 2> 14117 T1638 oazs.PrepRequestProcessor.pRequest2Txn Pro= cessed session termination for sessionid: 0x13c9916b2bb000b [junit4:junit4] 2> 14118 T1635 oazs.NIOServerCnxn.closeSock Closed socket= connection for client /127.0.0.1:49666 which had sessionid 0x13c9916b2bb00= 0b [junit4:junit4] 2> 14118 T1718 oaz.ClientCnxn$EventThread.run EventThread= shut down [junit4:junit4] 2> 14118 T1633 oaz.ZooKeeper.close Session: 0x13c9916b2bb= 000b closed [junit4:junit4] 2> 14119 T1633 oascsi.HttpClientUtil.createClient Creatin= g new http client, config:maxConnections=3D500&maxConnectionsPerHost=3D16&s= ocketTimeout=3D60000&connTimeout=3D15000 [junit4:junit4] 2> 14124 T1633 oaz.ZooKeeper. Initiating client con= nection, connectString=3D127.0.0.1:49648/solr sessionTimeout=3D30000 watche= r=3Dorg.apache.solr.common.cloud.ConnectionManager@507fe04c [junit4:junit4] 2> 14126 T1633 oascc.ConnectionManager.waitForConnected W= aiting for client to connect to ZooKeeper [junit4:junit4] 2> 14126 T1719 oaz.ClientCnxn$SendThread.logStartConnect = Opening socket connection to server localhost/127.0.0.1:49648. Will not att= empt to authenticate using SASL (access denied ("javax.security.auth.AuthPe= rmission" "getLoginConfiguration")) [junit4:junit4] 2> 14127 T1719 oaz.ClientCnxn$SendThread.primeConnection = Socket connection established to localhost/127.0.0.1:49648, initiating sess= ion [junit4:junit4] 2> 14128 T1635 oazs.NIOServerCnxnFactory.run Accepted soc= ket connection from /127.0.0.1:49667 [junit4:junit4] 2> 14128 T1635 oazs.ZooKeeperServer.processConnectRequest= Client attempting to establish new session at /127.0.0.1:49667 [junit4:junit4] 2> 14129 T1637 oazs.ZooKeeperServer.finishSessionInit Est= ablished session 0x13c9916b2bb000c with negotiated timeout 20000 for client= /127.0.0.1:49667 [junit4:junit4] 2> 14129 T1719 oaz.ClientCnxn$SendThread.onConnected Sess= ion establishment complete on server localhost/127.0.0.1:49648, sessionid = =3D 0x13c9916b2bb000c, negotiated timeout =3D 20000 [junit4:junit4] 2> 14130 T1720 oascc.ConnectionManager.process Watcher or= g.apache.solr.common.cloud.ConnectionManager@507fe04c name:ZooKeeperConnect= ion Watcher:127.0.0.1:49648/solr got event WatchedEvent state:SyncConnected= type:None path:null path:null type:None [junit4:junit4] 2> 14130 T1633 oascc.ConnectionManager.waitForConnected C= lient is connected to ZooKeeper [junit4:junit4] 2> 14131 T1638 oazs.PrepRequestProcessor.pRequest Got use= r-level KeeperException when processing sessionid:0x13c9916b2bb000c type:cr= eate cxid:0x1 zxid:0xa0 txntype:-1 reqpath:n/a Error Path:/solr/overseer Er= ror:KeeperErrorCode =3D NodeExists for /solr/overseer [junit4:junit4] 2> 14133 T1638 oazs.PrepRequestProcessor.pRequest Got use= r-level KeeperException when processing sessionid:0x13c9916b2bb000c type:cr= eate cxid:0x2 zxid:0xa1 txntype:-1 reqpath:n/a Error Path:/solr/overseer Er= ror:KeeperErrorCode =3D NodeExists for /solr/overseer [junit4:junit4] 2> 14135 T1633 oasc.ZkController.createEphemeralLiveNode = Register node as live in ZooKeeper:/live_nodes/127.0.0.1:49665_ [junit4:junit4] 2> 14136 T1638 oazs.PrepRequestProcessor.pRequest Got use= r-level KeeperException when processing sessionid:0x13c9916b2bb000c type:de= lete cxid:0x4 zxid:0xa2 txntype:-1 reqpath:n/a Error Path:/solr/live_nodes/= 127.0.0.1:49665_ Error:KeeperErrorCode =3D NoNode for /solr/live_nodes/127.= 0.0.1:49665_ [junit4:junit4] 2> 14137 T1633 oascc.SolrZkClient.makePath makePath: /liv= e_nodes/127.0.0.1:49665_ [junit4:junit4] 2> 14141 T1689 oascc.ZkStateReader$2.process A cluster st= ate change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:= /live_nodes, has occurred - updating... (live nodes size: 4) [junit4:junit4] 2> 14141 T1674 oascc.ZkStateReader$2.process A cluster st= ate change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:= /live_nodes, has occurred - updating... (live nodes size: 4) [junit4:junit4] 2> 14144 T1661 oascc.ZkStateReader$3.process Updating liv= e nodes... (5) [junit4:junit4] 2> 14144 T1661 oascc.ZkStateReader$2.process A cluster st= ate change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:= /live_nodes, has occurred - updating... (live nodes size: 5) [junit4:junit4] 2> 14144 T1704 oascc.ZkStateReader$3.process Updating liv= e nodes... (5) [junit4:junit4] 2> 14144 T1655 oascc.ZkStateReader$3.process Updating liv= e nodes... (5) [junit4:junit4] 2> 14145 T1655 oascc.ZkStateReader$2.process A cluster st= ate change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:= /live_nodes, has occurred - updating... (live nodes size: 5) [junit4:junit4] 2> 14144 T1704 oascc.ZkStateReader$2.process A cluster st= ate change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:= /live_nodes, has occurred - updating... (live nodes size: 5) [junit4:junit4] 2> 14149 T1689 oascc.ZkStateReader$3.process Updating liv= e nodes... (5) [junit4:junit4] 2> 14150 T1674 oascc.ZkStateReader$3.process Updating liv= e nodes... (5) [junit4:junit4] 2> 14154 T1633 oascc.ZkStateReader.createClusterStateWatc= hersAndUpdate Updating cluster state from ZooKeeper...=20 [junit4:junit4] 2> 14163 T1721 oasc.CoreContainer.create Creating SolrCor= e 'collection1' using instanceDir: /Users/jenkins/jenkins-slave/workspace/L= ucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.clou= d.BasicDistributedZkTest-jetty4-1359778080965/collection1 [junit4:junit4] 2> 14163 T1721 oasc.ZkController.createCollectionZkNode C= heck for collection zkNode:collection1 [junit4:junit4] 2> 14164 T1721 oasc.ZkController.createCollectionZkNode C= ollection zkNode exists [junit4:junit4] 2> 14164 T1721 oasc.ZkController.readConfigName Load coll= ection config from:/collections/collection1 [junit4:junit4] 2> 14167 T1721 oasc.SolrResourceLoader. new SolrRes= ourceLoader for directory: '/Users/jenkins/jenkins-slave/workspace/Lucene-S= olr-trunk-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.Basic= DistributedZkTest-jetty4-1359778080965/collection1/' [junit4:junit4] 2> 14167 T1721 oasc.SolrResourceLoader.replaceClassLoader= Adding 'file:/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacO= SX/solr/build/solr-core/test/J0/org.apache.solr.cloud.BasicDistributedZkTes= t-jetty4-1359778080965/collection1/lib/classes/' to classloader [junit4:junit4] 2> 14168 T1721 oasc.SolrResourceLoader.replaceClassLoader= Adding 'file:/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacO= SX/solr/build/solr-core/test/J0/org.apache.solr.cloud.BasicDistributedZkTes= t-jetty4-1359778080965/collection1/lib/README' to classloader [junit4:junit4] 2> 14205 T1721 oasc.SolrConfig. Using Lucene MatchV= ersion: LUCENE_50 [junit4:junit4] 2> 14281 T1721 oasc.SolrConfig. Loaded SolrConfig: = solrconfig.xml [junit4:junit4] 2> 14283 T1721 oass.IndexSchema.readSchema Reading Solr S= chema [junit4:junit4] 2> 14289 T1721 oass.IndexSchema.readSchema Schema name=3D= test [junit4:junit4] 2> 14828 T1656 oascc.ZkStateReader.updateClusterState Upd= ating cloud state from ZooKeeper...=20 [junit4:junit4] 2> 14830 T1656 oasc.Overseer$ClusterStateUpdater.updateSt= ate 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:49661_", [junit4:junit4] 2> =09 "base_url":"http://127.0.0.1:49661"} [junit4:junit4] 2> 14838 T1655 oascc.ZkStateReader$2.process A cluster st= ate change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clu= sterstate.json, has occurred - updating... (live nodes size: 5) [junit4:junit4] 2> 14838 T1689 oascc.ZkStateReader$2.process A cluster st= ate change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clu= sterstate.json, has occurred - updating... (live nodes size: 5) [junit4:junit4] 2> 14849 T1661 oascc.ZkStateReader$2.process A cluster st= ate change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clu= sterstate.json, has occurred - updating... (live nodes size: 5) [junit4:junit4] 2> 14849 T1674 oascc.ZkStateReader$2.process A cluster st= ate change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clu= sterstate.json, has occurred - updating... (live nodes size: 5) [junit4:junit4] 2> 14850 T1720 oascc.ZkStateReader$2.process A cluster st= ate change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clu= sterstate.json, has occurred - updating... (live nodes size: 5) [junit4:junit4] 2> 14877 T1721 oass.OpenExchangeRatesOrgProvider.init Ini= tialized with rates=3Dopen-exchange-rates.json, refreshInterval=3D1440. [junit4:junit4] 2> 14878 T1704 oascc.ZkStateReader$2.process A cluster st= ate change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clu= sterstate.json, has occurred - updating... (live nodes size: 5) [junit4:junit4] 2> 14888 T1721 oass.IndexSchema.readSchema default search= field in schema is text [junit4:junit4] 2> 14892 T1721 oass.IndexSchema.readSchema unique key fie= ld: id [junit4:junit4] 2> 14934 T1721 oass.FileExchangeRateProvider.reload Reloa= ding exchange rates from file currency.xml [junit4:junit4] 2> 14940 T1721 oass.FileExchangeRateProvider.reload Reloa= ding exchange rates from file currency.xml [junit4:junit4] 2> 14946 T1721 oass.OpenExchangeRatesOrgProvider.reload R= eloading exchange rates from open-exchange-rates.json [junit4:junit4] 2> 14948 T1721 oass.OpenExchangeRatesOrgProvider.reload R= eloading exchange rates from open-exchange-rates.json [junit4:junit4] 2> 14950 T1721 oasc.SolrCore. [collection1] Opening= new SolrCore at /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-M= acOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributed= ZkTest-jetty4-1359778080965/collection1/, dataDir=3D./org.apache.solr.cloud= .BasicDistributedZkTest-1359778067125/jetty4/ [junit4:junit4] 2> 14951 T1721 oasc.JmxMonitoredMap. JMX monitoring= is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxM= BeanServer@656ca212 [junit4:junit4] 2> 14951 T1721 oasc.SolrCore.initDirectoryFactory solr.NR= TCachingDirectoryFactory [junit4:junit4] 2> 14952 T1721 oasc.CachingDirectoryFactory.get return ne= w directory for /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-Ma= cOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZ= kTest-1359778067125/jetty4 forceNew:false [junit4:junit4] 2> 14953 T1721 oasc.CachingDirectoryFactory.close Releasi= ng directory:/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOS= X/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZkTe= st-1359778067125/jetty4 [junit4:junit4] 2> 14953 T1721 oasc.SolrCore.getNewIndexDir New index dir= ectory detected: old=3Dnull new=3D./org.apache.solr.cloud.BasicDistributedZ= kTest-1359778067125/jetty4/index/ [junit4:junit4] 2> 14953 T1721 oasc.SolrCore.initIndex WARNING [collectio= n1] Solr index directory './org.apache.solr.cloud.BasicDistributedZkTest-13= 59778067125/jetty4/index' doesn't exist. Creating new index... [junit4:junit4] 2> 14954 T1721 oasc.CachingDirectoryFactory.get return ne= w directory for /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-Ma= cOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZ= kTest-1359778067125/jetty4/index forceNew:false [junit4:junit4] 2> 14959 T1721 oasc.SolrDeletionPolicy.onCommit SolrDelet= ionPolicy.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-1359778067125/jetty4/index lockFact= ory=3Dorg.apache.lucene.store.NativeFSLockFactory@31a55ddd; maxCacheMB=3D48= .0 maxMergeSizeMB=3D4.0)),segFN=3Dsegments_1,generation=3D1,filenames=3D[se= gments_1] [junit4:junit4] 2> 14960 T1721 oasc.SolrDeletionPolicy.updateCommits newe= st commit =3D 1[segments_1] [junit4:junit4] 2> 14960 T1721 oasc.CachingDirectoryFactory.close Releasi= ng directory:/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOS= X/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZkTe= st-1359778067125/jetty4/index [junit4:junit4] 2> 14961 T1721 oasc.SolrCore.initWriters created xml: sol= r.XMLResponseWriter [junit4:junit4] 2> 14963 T1721 oasup.UpdateRequestProcessorChain.init ins= erting DistributedUpdateProcessorFactory into updateRequestProcessorChain "= dedupe" [junit4:junit4] 2> 14964 T1721 oasup.UpdateRequestProcessorChain.init ins= erting DistributedUpdateProcessorFactory into updateRequestProcessorChain "= dedupe-allfields" [junit4:junit4] 2> 14964 T1721 oasup.UpdateRequestProcessorChain.init ins= erting DistributedUpdateProcessorFactory into updateRequestProcessorChain "= stored_sig" [junit4:junit4] 2> 14965 T1721 oasup.UpdateRequestProcessorChain.init ins= erting DistributedUpdateProcessorFactory into updateRequestProcessorChain "= uniq-fields" [junit4:junit4] 2> 14965 T1721 oasup.UpdateRequestProcessorChain.init ins= erting DistributedUpdateProcessorFactory into updateRequestProcessorChain "= distrib-dup-test-chain-implicit" [junit4:junit4] 2> 14966 T1721 oasc.RequestHandlers.initHandlersFromConfi= g adding lazy requestHandler: solr.ReplicationHandler [junit4:junit4] 2> 14966 T1721 oasc.RequestHandlers.initHandlersFromConfi= g created /replication: solr.ReplicationHandler [junit4:junit4] 2> 14967 T1721 oasc.RequestHandlers.initHandlersFromConfi= g created standard: solr.StandardRequestHandler [junit4:junit4] 2> 14968 T1721 oasc.RequestHandlers.initHandlersFromConfi= g created /get: solr.RealTimeGetHandler [junit4:junit4] 2> 14969 T1721 oasc.RequestHandlers.initHandlersFromConfi= g created dismax: solr.SearchHandler [junit4:junit4] 2> 14970 T1721 oasc.RequestHandlers.initHandlersFromConfi= g created mock: org.apache.solr.core.MockQuerySenderListenerReqHandler [junit4:junit4] 2> 14970 T1721 oasc.RequestHandlers.initHandlersFromConfi= g created /admin/: org.apache.solr.handler.admin.AdminHandlers [junit4:junit4] 2> 14971 T1721 oasc.RequestHandlers.initHandlersFromConfi= g created defaults: solr.StandardRequestHandler [junit4:junit4] 2> 14971 T1721 oasc.RequestHandlers.initHandlersFromConfi= g adding lazy requestHandler: solr.StandardRequestHandler [junit4:junit4] 2> 14971 T1721 oasc.RequestHandlers.initHandlersFromConfi= g created lazy: solr.StandardRequestHandler [junit4:junit4] 2> 14972 T1721 oasc.RequestHandlers.initHandlersFromConfi= g created /update: solr.UpdateRequestHandler [junit4:junit4] 2> 14973 T1721 oasc.RequestHandlers.initHandlersFromConfi= g created /terms: org.apache.solr.handler.component.SearchHandler [junit4:junit4] 2> 14973 T1721 oasc.RequestHandlers.initHandlersFromConfi= g created spellCheckCompRH: org.apache.solr.handler.component.SearchHandler [junit4:junit4] 2> 14974 T1721 oasc.RequestHandlers.initHandlersFromConfi= g created spellCheckCompRH_Direct: org.apache.solr.handler.component.Search= Handler [junit4:junit4] 2> 14974 T1721 oasc.RequestHandlers.initHandlersFromConfi= g created spellCheckWithWordbreak: org.apache.solr.handler.component.Search= Handler [junit4:junit4] 2> 14975 T1721 oasc.RequestHandlers.initHandlersFromConfi= g created spellCheckWithWordbreak_Direct: org.apache.solr.handler.component= .SearchHandler [junit4:junit4] 2> 14976 T1721 oasc.RequestHandlers.initHandlersFromConfi= g created spellCheckCompRH1: org.apache.solr.handler.component.SearchHandle= r [junit4:junit4] 2> 14976 T1721 oasc.RequestHandlers.initHandlersFromConfi= g created mltrh: org.apache.solr.handler.component.SearchHandler [junit4:junit4] 2> 14977 T1721 oasc.RequestHandlers.initHandlersFromConfi= g created tvrh: org.apache.solr.handler.component.SearchHandler [junit4:junit4] 2> 14977 T1721 oasc.RequestHandlers.initHandlersFromConfi= g created /mlt: solr.MoreLikeThisHandler [junit4:junit4] 2> 14978 T1721 oasc.RequestHandlers.initHandlersFromConfi= g created /debug/dump: solr.DumpRequestHandler [junit4:junit4] 2> 14984 T1721 oashl.XMLLoader.init xsltCacheLifetimeSeco= nds=3D60 [junit4:junit4] 2> 14987 T1721 oasc.SolrCore.initDeprecatedSupport WARNIN= G solrconfig.xml uses deprecated , Please update your = config to use the ShowFileRequestHandler. [junit4:junit4] 2> 14989 T1721 oasc.SolrCore.initDeprecatedSupport WARNIN= G adding ShowFileRequestHandler with hidden files: [SCHEMA.XML, OLD_SYNONYM= S.TXT, STOPWORDS.TXT, PROTWORDS.TXT, OPEN-EXCHANGE-RATES.JSON, SYNONYMS.TXT= , CURRENCY.XML, MAPPING-ISOLATIN1ACCENT.TXT] [junit4:junit4] 2> 14991 T1721 oasc.CachingDirectoryFactory.close Releasi= ng directory:/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOS= X/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZkTe= st-1359778067125/jetty4 [junit4:junit4] 2> 14994 T1721 oass.SolrIndexSearcher. Opening Sear= cher@530c6924 main [junit4:junit4] 2> 14996 T1721 oasu.CommitTracker. Hard AutoCommit:= disabled [junit4:junit4] 2> 14996 T1721 oasu.CommitTracker. Soft AutoCommit:= disabled [junit4:junit4] 2> 14996 T1721 oashc.SpellCheckComponent.inform Initializ= ing spell checkers [junit4:junit4] 2> 15001 T1721 oass.DirectSolrSpellChecker.init init: {na= me=3Ddirect,classname=3DDirectSolrSpellChecker,field=3Dlowerfilt,minQueryLe= ngth=3D3} [junit4:junit4] 2> 15032 T1722 oasc.SolrCore.registerSearcher [collection= 1] Registered new searcher Searcher@530c6924 main{StandardDirectoryReader(s= egments_1:1)} [junit4:junit4] 2> 15040 T1721 oasc.ZkController.publish publishing core= =3Dcollection1 state=3Ddown [junit4:junit4] 2> 15040 T1721 oasc.ZkController.publish numShards not fo= und on descriptor - reading it from system property [junit4:junit4] 2> 16385 T1656 oascc.ZkStateReader.updateClusterState Upd= ating cloud state from ZooKeeper...=20 [junit4:junit4] 2> 16387 T1656 oasc.Overseer$ClusterStateUpdater.updateSt= ate 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:49665_", [junit4:junit4] 2> =09 "base_url":"http://127.0.0.1:49665"} [junit4:junit4] 2> 16387 T1656 oasc.Overseer$ClusterStateUpdater.updateSt= ate Collection already exists with numShards=3D2 [junit4:junit4] 2> 16388 T1656 oasc.Overseer$ClusterStateUpdater.updateSt= ate Assigning new node to shard shard=3Dshard2 [junit4:junit4] 2> 16395 T1689 oascc.ZkStateReader$2.process A cluster st= ate change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clu= sterstate.json, has occurred - updating... (live nodes size: 5) [junit4:junit4] 2> 16397 T1655 oascc.ZkStateReader$2.process A cluster st= ate change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clu= sterstate.json, has occurred - updating... (live nodes size: 5) [junit4:junit4] 2> 16397 T1661 oascc.ZkStateReader$2.process A cluster st= ate change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clu= sterstate.json, has occurred - updating... (live nodes size: 5) [junit4:junit4] 2> 16397 T1704 oascc.ZkStateReader$2.process A cluster st= ate change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clu= sterstate.json, has occurred - updating... (live nodes size: 5) [junit4:junit4] 2> 16397 T1674 oascc.ZkStateReader$2.process A cluster st= ate change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clu= sterstate.json, has occurred - updating... (live nodes size: 5) [junit4:junit4] 2> 16397 T1720 oascc.ZkStateReader$2.process A cluster st= ate change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clu= sterstate.json, has occurred - updating... (live nodes size: 5) [junit4:junit4] 2> 17067 T1721 oasc.CoreContainer.registerCore registerin= g core: collection1 [junit4:junit4] 2> 17067 T1721 oasc.ZkController.register Register replic= a - core:collection1 address:http://127.0.0.1:49665 collection:collection1 = shard:shard2 [junit4:junit4] 2> 17074 T1721 oasc.ZkController.register We are http://1= 27.0.0.1:49665/collection1/ and leader is http://127.0.0.1:49658/collection= 1/ [junit4:junit4] 2> 17075 T1721 oasc.ZkController.register No LogReplay ne= eded for core=3Dcollection1 baseURL=3Dhttp://127.0.0.1:49665 [junit4:junit4] 2> 17075 T1721 oasc.ZkController.checkRecovery Core needs= to recover:collection1 [junit4:junit4] 2> 17075 T1721 oasu.DefaultSolrCoreState.doRecovery Runni= ng recovery - first canceling any ongoing recovery [junit4:junit4] 2> ASYNC NEW_CORE C123 name=3Dcollection1 org.apache.sol= r.core.SolrCore@27153b2 url=3Dhttp://127.0.0.1:49665/collection1 node=3D127= .0.0.1:49665_ C123_STATE=3Dcoll:collection1 core:collection1 props:{shard= =3Dnull, roles=3Dnull, state=3Ddown, core=3Dcollection1, collection=3Dcolle= ction1, node_name=3D127.0.0.1:49665_, base_url=3Dhttp://127.0.0.1:49665} [junit4:junit4] 2> 17076 T1723 C123 P49665 oasc.RecoveryStrategy.run Star= ting recovery process. core=3Dcollection1 recoveringAfterStartup=3Dtrue [junit4:junit4] 2> 17077 T1723 C123 P49665 oasc.RecoveryStrategy.doRecove= ry ###### startupVersions=3D[] [junit4:junit4] 2> 17077 T1721 oascc.ZkStateReader.updateClusterState Upd= ating cloud state from ZooKeeper...=20 [junit4:junit4] 2> 17077 T1723 C123 P49665 oasc.ZkController.publish publ= ishing core=3Dcollection1 state=3Drecovering [junit4:junit4] 2> 17077 T1723 C123 P49665 oasc.ZkController.publish numS= hards not found on descriptor - reading it from system property [junit4:junit4] 2> 17078 T1633 oass.SolrDispatchFilter.init user.dir=3D/U= sers/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/so= lr-core/test/J0 [junit4:junit4] 2> 17079 T1723 C123 P49665 oascsi.HttpClientUtil.createCl= ient Creating new http client, config:maxConnections=3D128&maxConnectionsPe= rHost=3D32&followRedirects=3Dfalse [junit4:junit4] 2> 17079 T1633 oass.SolrDispatchFilter.init SolrDispatchF= ilter.init() done [junit4:junit4] 2> 17080 T1633 oascsi.HttpClientUtil.createClient Creatin= g new http client, config:maxConnections=3D128&maxConnectionsPerHost=3D32&f= ollowRedirects=3Dfalse [junit4:junit4] 2> 17087 T1633 oascc.ZkStateReader.updateClusterState Upd= ating cloud state from ZooKeeper...=20 [junit4:junit4] 2> 17089 T1633 oasc.AbstractDistribZkTestBase.waitForReco= veriesToFinish Wait for recoveries to finish - collection: collection1 fail= OnTimeout:true timeout (sec):230 [junit4:junit4] 2> 17090 T1633 oascc.ZkStateReader.updateClusterState Upd= ating cloud state from ZooKeeper...=20 [junit4:junit4] 2> C122_STATE=3Dcoll:collection1 core:collection1 props:= {shard=3Dshard1, roles=3Dnull, state=3Drecovering, core=3Dcollection1, coll= ection=3Dcollection1, node_name=3D127.0.0.1:49661_, base_url=3Dhttp://127.0= .0.1:49661} [junit4:junit4] 2> 17853 T1707 C122 P49661 oasc.RecoveryStrategy.doRecove= ry Attempting to PeerSync from http://127.0.0.1:49655/collection1/ core=3Dc= ollection1 - recoveringAfterStartup=3Dtrue [junit4:junit4] 2> 17854 T1707 C122 P49661 oasu.PeerSync.sync PeerSync: c= ore=3Dcollection1 url=3Dhttp://127.0.0.1:49661 START replicas=3D[http://127= .0.0.1:49655/collection1/] nUpdates=3D100 [junit4:junit4] 2> 17854 T1707 C122 P49661 oasu.PeerSync.sync WARNING no = frame of reference to tell of we've missed updates [junit4:junit4] 2> 17855 T1707 C122 P49661 oasc.RecoveryStrategy.doRecove= ry PeerSync Recovery was not successful - trying replication. core=3Dcollec= tion1 [junit4:junit4] 2> 17855 T1707 C122 P49661 oasc.RecoveryStrategy.doRecove= ry Starting Replication Recovery. core=3Dcollection1 [junit4:junit4] 2> 17856 T1707 C122 P49661 oasc.RecoveryStrategy.doRecove= ry Begin buffering updates. core=3Dcollection1 [junit4:junit4] 2> 17856 T1707 C122 P49661 oasu.UpdateLog.bufferUpdates S= tarting to buffer updates. FSUpdateLog{state=3DACTIVE, tlog=3Dnull} [junit4:junit4] 2> 17856 T1707 C122 P49661 oasc.RecoveryStrategy.replicat= e Attempting to replicate from http://127.0.0.1:49655/collection1/. core=3D= collection1 [junit4:junit4] 2> 17857 T1707 C122 P49661 oascsi.HttpClientUtil.createCl= ient Creating new http client, config:maxConnections=3D128&maxConnectionsPe= rHost=3D32&followRedirects=3Dfalse [junit4:junit4] 2> ASYNC NEW_CORE C124 name=3Dcollection1 org.apache.sol= r.core.SolrCore@2639a53a url=3Dhttp://127.0.0.1:49655/collection1 node=3D12= 7.0.0.1:49655_ C124_STATE=3Dcoll:collection1 core:collection1 props:{shard= =3Dshard1, roles=3Dnull, state=3Dactive, core=3Dcollection1, collection=3Dc= ollection1, node_name=3D127.0.0.1:49655_, base_url=3Dhttp://127.0.0.1:49655= , leader=3Dtrue} [junit4:junit4] 2> 17866 T1669 C124 P49655 REQ /get {getVersions=3D100&di= strib=3Dfalse&wt=3Djavabin&qt=3D/get&version=3D2} status=3D0 QTime=3D0=20 [junit4:junit4] 2> 17870 T1665 C124 P49655 oasu.DirectUpdateHandler2.comm= it start commit{,optimize=3Dfalse,openSearcher=3Dfalse,waitSearcher=3Dtrue,= expungeDeletes=3Dfalse,softCommit=3Dfalse} [junit4:junit4] 2> 17871 T1665 C124 P49655 oasc.CachingDirectoryFactory.c= lose Releasing directory:/Users/jenkins/jenkins-slave/workspace/Lucene-Solr= -trunk-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDis= tributedZkTest-1359778067125/jetty1 [junit4:junit4] 2> 17874 T1665 C124 P49655 oasc.SolrDeletionPolicy.onInit= SolrDeletionPolicy.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-1359778067125/jetty1/index lockFact= ory=3Dorg.apache.lucene.store.NativeFSLockFactory@56d61aac; maxCacheMB=3D48= .0 maxMergeSizeMB=3D4.0)),segFN=3Dsegments_1,generation=3D1,filenames=3D[se= gments_1] [junit4:junit4] 2> 17874 T1665 C124 P49655 oasc.SolrDeletionPolicy.update= Commits newest commit =3D 1[segments_1] [junit4:junit4] 2> 17877 T1665 C124 P49655 oasc.SolrDeletionPolicy.onComm= it 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-1359778067125/jetty1/index lockFact= ory=3Dorg.apache.lucene.store.NativeFSLockFactory@56d61aac; 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-1359778067125/jetty1/index lockFact= ory=3Dorg.apache.lucene.store.NativeFSLockFactory@56d61aac; maxCacheMB=3D48= .0 maxMergeSizeMB=3D4.0)),segFN=3Dsegments_2,generation=3D2,filenames=3D[se= gments_2] [junit4:junit4] 2> 17877 T1665 C124 P49655 oasc.SolrDeletionPolicy.update= Commits newest commit =3D 2[segments_2] [junit4:junit4] 2> 17878 T1665 C124 P49655 oasc.CachingDirectoryFactory.c= lose Releasing directory:/Users/jenkins/jenkins-slave/workspace/Lucene-Solr= -trunk-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDis= tributedZkTest-1359778067125/jetty1 [junit4:junit4] 2> 17879 T1665 C124 P49655 oass.SolrIndexSearcher. = Opening Searcher@1121012a realtime [junit4:junit4] 2> 17879 T1665 C124 P49655 oasu.DirectUpdateHandler2.comm= it end_commit_flush [junit4:junit4] 2> 17879 T1665 C124 P49655 /update {waitSearcher=3Dtrue&o= penSearcher=3Dfalse&commit=3Dtrue&wt=3Djavabin&commit_end_point=3Dtrue&vers= ion=3D2&softCommit=3Dfalse} {commit=3D} 0 9 [junit4:junit4] 2> 17880 T1707 C122 P49661 oash.ReplicationHandler.inform= Commits will be reserved for 10000 [junit4:junit4] 2> 17881 T1707 C122 P49661 oash.SnapPuller. No val= ue set for 'pollInterval'. Timer Task not started. [junit4:junit4] 2> 17884 T1668 C124 P49655 oash.ReplicationHandler.inform= Commits will be reserved for 10000 [junit4:junit4] 2> 17885 T1668 C124 P49655 REQ /replication {command=3Din= dexversion&qt=3D/replication&wt=3Djavabin&version=3D2} status=3D0 QTime=3D2= =20 [junit4:junit4] 2> 17885 T1707 C122 P49661 oash.SnapPuller.fetchLatestInd= ex Master's generation: 2 [junit4:junit4] 2> 17885 T1707 C122 P49661 oash.SnapPuller.fetchLatestInd= ex Slave's generation: 1 [junit4:junit4] 2> 17886 T1707 C122 P49661 oash.SnapPuller.fetchLatestInd= ex Starting replication process [junit4:junit4] 2> 17889 T1670 C124 P49655 oasc.CachingDirectoryFactory.c= lose Releasing directory:/Users/jenkins/jenkins-slave/workspace/Lucene-Solr= -trunk-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDis= tributedZkTest-1359778067125/jetty1 [junit4:junit4] 2> 17889 T1670 C124 P49655 oasc.CachingDirectoryFactory.c= lose Releasing directory:/Users/jenkins/jenkins-slave/workspace/Lucene-Solr= -trunk-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDis= tributedZkTest-1359778067125/jetty1/index [junit4:junit4] 2> 17889 T1670 C124 P49655 REQ /replication {command=3Dfi= lelist&qt=3D/replication&wt=3Djavabin&generation=3D2&version=3D2} status=3D= 0 QTime=3D1=20 [junit4:junit4] 2> 17890 T1707 C122 P49661 oash.SnapPuller.fetchLatestInd= ex Number of files in latest index in master: 1 [junit4:junit4] 2> 17891 T1707 C122 P49661 oasc.CachingDirectoryFactory.g= et return new directory for /Users/jenkins/jenkins-slave/workspace/Lucene-S= olr-trunk-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.Basic= DistributedZkTest-1359778067125/jetty3/index.20130202040805010 forceNew:fal= se [junit4:junit4] 2> 17891 T1707 C122 P49661 oasc.CachingDirectoryFactory.c= lose Releasing directory:/Users/jenkins/jenkins-slave/workspace/Lucene-Solr= -trunk-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDis= tributedZkTest-1359778067125/jetty3 [junit4:junit4] 2> 17892 T1707 C122 P49661 oash.SnapPuller.fetchLatestInd= ex Starting download to RateLimitedDirectoryWrapper(NRTCachingDirectory(org= .apache.lucene.store.NIOFSDirectory@/Users/jenkins/jenkins-slave/workspace/= Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/org.apache.solr.cloud= .BasicDistributedZkTest-1359778067125/jetty3/index.20130202040805010 lockFa= ctory=3Dorg.apache.lucene.store.NativeFSLockFactory@762af674; maxCacheMB=3D= 48.0 maxMergeSizeMB=3D4.0)) fullCopy=3Dtrue [junit4:junit4] 2> 17895 T1669 C124 P49655 REQ /replication {file=3Dsegme= nts_2&command=3Dfilecontent&checksum=3Dtrue&wt=3Dfilestream&qt=3D/replicati= on&generation=3D2} status=3D0 QTime=3D0=20 [junit4:junit4] 2> 17897 T1707 C122 P49661 oasc.CachingDirectoryFactory.c= lose Releasing directory:/Users/jenkins/jenkins-slave/workspace/Lucene-Solr= -trunk-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDis= tributedZkTest-1359778067125/jetty3/index [junit4:junit4] 2> 17897 T1707 C122 P49661 oash.SnapPuller.fetchLatestInd= ex Total time taken for download : 0 secs [junit4:junit4] 2> 17897 T1707 C122 P49661 oash.SnapPuller.modifyIndexPro= ps New index installed. Updating index properties... index=3Dindex.20130202= 040805010 [junit4:junit4] 2> 17898 T1707 C122 P49661 oasc.CachingDirectoryFactory.c= lose Releasing directory:/Users/jenkins/jenkins-slave/workspace/Lucene-Solr= -trunk-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDis= tributedZkTest-1359778067125/jetty3 [junit4:junit4] 2> 17899 T1707 C122 P49661 oasc.CachingDirectoryFactory.c= lose Releasing directory:/Users/jenkins/jenkins-slave/workspace/Lucene-Solr= -trunk-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDis= tributedZkTest-1359778067125/jetty3 [junit4:junit4] 2> 17899 T1707 C122 P49661 oasc.SolrCore.getNewIndexDir N= ew index directory detected: old=3D./org.apache.solr.cloud.BasicDistributed= ZkTest-1359778067125/jetty3/index/ new=3D./org.apache.solr.cloud.BasicDistr= ibutedZkTest-1359778067125/jetty3/index.20130202040805010 [junit4:junit4] 2> 17901 T1707 C122 P49661 oasc.SolrDeletionPolicy.onInit= SolrDeletionPolicy.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-1359778067125/jetty3/index.20130202= 040805010 lockFactory=3Dorg.apache.lucene.store.NativeFSLockFactory@762af67= 4; maxCacheMB=3D48.0 maxMergeSizeMB=3D4.0)),segFN=3Dsegments_2,generation= =3D2,filenames=3D[segments_2] [junit4:junit4] 2> 17902 T1707 C122 P49661 oasc.SolrDeletionPolicy.update= Commits newest commit =3D 2[segments_2] [junit4:junit4] 2> 17903 T1707 C122 P49661 oasc.CachingDirectoryFactory.c= lose Releasing directory:/Users/jenkins/jenkins-slave/workspace/Lucene-Solr= -trunk-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDis= tributedZkTest-1359778067125/jetty3 [junit4:junit4] 2> 17904 T1707 C122 P49661 oasu.DefaultSolrCoreState.newI= ndexWriter Creating new IndexWriter... [junit4:junit4] 2> 17904 T1707 C122 P49661 oasu.DefaultSolrCoreState.newI= ndexWriter Waiting until IndexWriter is unused... core=3Dcollection1 [junit4:junit4] 2> 17904 T1707 C122 P49661 oasu.DefaultSolrCoreState.newI= ndexWriter Rollback old IndexWriter... core=3Dcollection1 [junit4:junit4] 2> 17905 T1707 C122 P49661 oasc.CachingDirectoryFactory.c= lose Releasing directory:/Users/jenkins/jenkins-slave/workspace/Lucene-Solr= -trunk-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDis= tributedZkTest-1359778067125/jetty3/index.20130202040805010 [junit4:junit4] 2> 17905 T1707 C122 P49661 oasc.CachingDirectoryFactory.c= lose Releasing directory:/Users/jenkins/jenkins-slave/workspace/Lucene-Solr= -trunk-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDis= tributedZkTest-1359778067125/jetty3 [junit4:junit4] 2> 17907 T1707 C122 P49661 oasc.SolrDeletionPolicy.onInit= SolrDeletionPolicy.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-1359778067125/jetty3/index.20130202= 040805010 lockFactory=3Dorg.apache.lucene.store.NativeFSLockFactory@762af67= 4; maxCacheMB=3D48.0 maxMergeSizeMB=3D4.0)),segFN=3Dsegments_2,generation= =3D2,filenames=3D[segments_2] [junit4:junit4] 2> 17908 T1707 C122 P49661 oasc.SolrDeletionPolicy.update= Commits newest commit =3D 2[segments_2] [junit4:junit4] 2> 17908 T1707 C122 P49661 oasu.DefaultSolrCoreState.newI= ndexWriter New IndexWriter is ready to be used. [junit4:junit4] 2> 17909 T1707 C122 P49661 oasc.CachingDirectoryFactory.c= lose Releasing directory:/Users/jenkins/jenkins-slave/workspace/Lucene-Solr= -trunk-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDis= tributedZkTest-1359778067125/jetty3 [junit4:junit4] 2> 17909 T1707 C122 P49661 oass.SolrIndexSearcher. = Opening Searcher@7326cbb1 main [junit4:junit4] 2> 17910 T1656 oascc.ZkStateReader.updateClusterState Upd= ating cloud state from ZooKeeper...=20 [junit4:junit4] 2> 17911 T1656 oasc.Overseer$ClusterStateUpdater.updateSt= ate 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:49665_", [junit4:junit4] 2> =09 "base_url":"http://127.0.0.1:49665"} [junit4:junit4] 2> 17912 T1706 oasc.SolrCore.registerSearcher [collection= 1] Registered new searcher Searcher@7326cbb1 main{StandardDirectoryReader(s= egments_2:1:nrt)} [junit4:junit4] 2> 17913 T1706 oasc.CachingDirectoryFactory.close Releasi= ng directory:/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOS= X/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZkTe= st-1359778067125/jetty3/index [junit4:junit4] 2> 17913 T1707 C122 P49661 oasu.DirectUpdateHandler2.comm= it start commit{,optimize=3Dfalse,openSearcher=3Dfalse,waitSearcher=3Dfalse= ,expungeDeletes=3Dfalse,softCommit=3Dfalse} [junit4:junit4] 2> 17917 T1707 C122 P49661 oasc.SolrDeletionPolicy.onComm= it 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-1359778067125/jetty3/index.20130202= 040805010 lockFactory=3Dorg.apache.lucene.store.NativeFSLockFactory@762af67= 4; 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-1359778067125/jetty3/index.20130202= 040805010 lockFactory=3Dorg.apache.lucene.store.NativeFSLockFactory@762af67= 4; maxCacheMB=3D48.0 maxMergeSizeMB=3D4.0)),segFN=3Dsegments_3,generation= =3D3,filenames=3D[segments_3] [junit4:junit4] 2> 17918 T1707 C122 P49661 oasc.SolrDeletionPolicy.update= Commits newest commit =3D 3[segments_3] [junit4:junit4] 2> 17919 T1707 C122 P49661 oasc.CachingDirectoryFactory.c= lose Releasing directory:/Users/jenkins/jenkins-slave/workspace/Lucene-Solr= -trunk-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDis= tributedZkTest-1359778067125/jetty3 [junit4:junit4] 2> 17919 T1707 C122 P49661 oasu.DirectUpdateHandler2.comm= it end_commit_flush [junit4:junit4] 2> 17920 T1707 C122 P49661 oasc.CachingDirectoryFactory.c= lose Releasing directory:/Users/jenkins/jenkins-slave/workspace/Lucene-Solr= -trunk-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDis= tributedZkTest-1359778067125/jetty3/index.20130202040805010 [junit4:junit4] 2> 17920 T1707 C122 P49661 oasc.CachingDirectoryFactory.c= lose Releasing directory:/Users/jenkins/jenkins-slave/workspace/Lucene-Solr= -trunk-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDis= tributedZkTest-1359778067125/jetty3/index [junit4:junit4] 2> 17920 T1704 oascc.ZkStateReader$2.process A cluster st= ate change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clu= sterstate.json, has occurred - updating... (live nodes size: 5) [junit4:junit4] 2> 17920 T1707 C122 P49661 oasc.RecoveryStrategy.replay N= o replay needed. core=3Dcollection1 [junit4:junit4] 2> 17920 T1707 C122 P49661 oasc.RecoveryStrategy.doRecove= ry Replication Recovery was successful - registering as Active. core=3Dcoll= ection1 [junit4:junit4] 2> 17921 T1707 C122 P49661 oasc.ZkController.publish publ= ishing core=3Dcollection1 state=3Dactive [junit4:junit4] 2> 17921 T1707 C122 P49661 oasc.ZkController.publish numS= hards not found on descriptor - reading it from system property [junit4:junit4] 2> 17920 T1720 oascc.ZkStateReader$2.process A cluster st= ate change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clu= sterstate.json, has occurred - updating... (live nodes size: 5) [junit4:junit4] 2> 17920 T1661 oascc.ZkStateReader$2.process A cluster st= ate change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clu= sterstate.json, has occurred - updating... (live nodes size: 5) [junit4:junit4] 2> 17922 T1655 oascc.ZkStateReader$2.process A cluster st= ate change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clu= sterstate.json, has occurred - updating... (live nodes size: 5) [junit4:junit4] 2> 17922 T1674 oascc.ZkStateReader$2.process A cluster st= ate change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clu= sterstate.json, has occurred - updating... (live nodes size: 5) [junit4:junit4] 2> 17922 T1689 oascc.ZkStateReader$2.process A cluster st= ate change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clu= sterstate.json, has occurred - updating... (live nodes size: 5) [junit4:junit4] 2> 17926 T1707 C122 P49661 oasc.RecoveryStrategy.doRecove= ry Finished recovery process. core=3Dcollection1 [junit4:junit4] 2> 18094 T1633 oascc.ZkStateReader.updateClusterState Upd= ating cloud state from ZooKeeper...=20 [junit4:junit4] 2> 19099 T1633 oascc.ZkStateReader.updateClusterState Upd= ating cloud state from ZooKeeper...=20 [junit4:junit4] 2> 19434 T1656 oascc.ZkStateReader.updateClusterState Upd= ating cloud state from ZooKeeper...=20 [junit4:junit4] 2> 19435 T1656 oasc.Overseer$ClusterStateUpdater.updateSt= ate 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:49661_", [junit4:junit4] 2> =09 "base_url":"http://127.0.0.1:49661"} [junit4:junit4] 2> 19443 T1655 oascc.ZkStateReader$2.process A cluster st= ate change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clu= sterstate.json, has occurred - updating... (live nodes size: 5) [junit4:junit4] 2> 19443 T1689 oascc.ZkStateReader$2.process A cluster st= ate change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clu= sterstate.json, has occurred - updating... (live nodes size: 5) [junit4:junit4] 2> 19444 T1704 oascc.ZkStateReader$2.process A cluster st= ate change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clu= sterstate.json, has occurred - updating... (live nodes size: 5) [junit4:junit4] 2> 19444 T1661 oascc.ZkStateReader$2.process A cluster st= ate change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clu= sterstate.json, has occurred - updating... (live nodes size: 5) [junit4:junit4] 2> 19445 T1674 oascc.ZkStateReader$2.process A cluster st= ate change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clu= sterstate.json, has occurred - updating... (live nodes size: 5) [junit4:junit4] 2> 19445 T1720 oascc.ZkStateReader$2.process A cluster st= ate change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clu= sterstate.json, has occurred - updating... (live nodes size: 5) [junit4:junit4] 2> C123_STATE=3Dcoll:collection1 core:collection1 props:= {shard=3Dshard2, roles=3Dnull, state=3Drecovering, core=3Dcollection1, coll= ection=3Dcollection1, node_name=3D127.0.0.1:49665_, base_url=3Dhttp://127.0= .0.1:49665} [junit4:junit4] 2> 20091 T1723 C123 P49665 oasc.RecoveryStrategy.doRecove= ry Attempting to PeerSync from http://127.0.0.1:49658/collection1/ core=3Dc= ollection1 - recoveringAfterStartup=3Dtrue [junit4:junit4] 2> 20091 T1723 C123 P49665 oasu.PeerSync.sync PeerSync: c= ore=3Dcollection1 url=3Dhttp://127.0.0.1:49665 START replicas=3D[http://127= .0.0.1:49658/collection1/] nUpdates=3D100 [junit4:junit4] 2> 20092 T1723 C123 P49665 oasu.PeerSync.sync WARNING no = frame of reference to tell of we've missed updates [junit4:junit4] 2> 20092 T1723 C123 P49665 oasc.RecoveryStrategy.doRecove= ry PeerSync Recovery was not successful - trying replication. core=3Dcollec= tion1 [junit4:junit4] 2> 20092 T1723 C123 P49665 oasc.RecoveryStrategy.doRecove= ry Starting Replication Recovery. core=3Dcollection1 [junit4:junit4] 2> 20093 T1723 C123 P49665 oasc.RecoveryStrategy.doRecove= ry Begin buffering updates. core=3Dcollection1 [junit4:junit4] 2> 20093 T1723 C123 P49665 oasu.UpdateLog.bufferUpdates S= tarting to buffer updates. FSUpdateLog{state=3DACTIVE, tlog=3Dnull} [junit4:junit4] 2> 20093 T1723 C123 P49665 oasc.RecoveryStrategy.replicat= e Attempting to replicate from http://127.0.0.1:49658/collection1/. core=3D= collection1 [junit4:junit4] 2> 20094 T1723 C123 P49665 oascsi.HttpClientUtil.createCl= ient Creating new http client, config:maxConnections=3D128&maxConnectionsPe= rHost=3D32&followRedirects=3Dfalse [junit4:junit4] 2> ASYNC NEW_CORE C125 name=3Dcollection1 org.apache.sol= r.core.SolrCore@276aca5d url=3Dhttp://127.0.0.1:49658/collection1 node=3D12= 7.0.0.1:49658_ C125_STATE=3Dcoll:collection1 core:collection1 props:{shard= =3Dshard2, roles=3Dnull, state=3Dactive, core=3Dcollection1, collection=3Dc= ollection1, node_name=3D127.0.0.1:49658_, base_url=3Dhttp://127.0.0.1:49658= , leader=3Dtrue} [junit4:junit4] 2> 20116 T1680 C125 P49658 REQ /get {getVersions=3D100&di= strib=3Dfalse&wt=3Djavabin&qt=3D/get&version=3D2} status=3D0 QTime=3D0=20 [junit4:junit4] 2> 20118 T1633 oascc.ZkStateReader.updateClusterState Upd= ating cloud state from ZooKeeper...=20 [junit4:junit4] 2> 20119 T1684 C125 P49658 oasu.DirectUpdateHandler2.comm= it start commit{,optimize=3Dfalse,openSearcher=3Dfalse,waitSearcher=3Dtrue,= expungeDeletes=3Dfalse,softCommit=3Dfalse} [junit4:junit4] 2> 20120 T1684 C125 P49658 oasc.CachingDirectoryFactory.c= lose Releasing directory:/Users/jenkins/jenkins-slave/workspace/Lucene-Solr= -trunk-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDis= tributedZkTest-1359778067125/jetty2 [junit4:junit4] 2> 20123 T1684 C125 P49658 oasc.SolrDeletionPolicy.onInit= SolrDeletionPolicy.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-1359778067125/jetty2/index lockFact= ory=3Dorg.apache.lucene.store.NativeFSLockFactory@3b05555e; maxCacheMB=3D48= .0 maxMergeSizeMB=3D4.0)),segFN=3Dsegments_1,generation=3D1,filenames=3D[se= gments_1] [junit4:junit4] 2> 20124 T1684 C125 P49658 oasc.SolrDeletionPolicy.update= Commits newest commit =3D 1[segments_1] [junit4:junit4] 2> 20128 T1684 C125 P49658 oasc.SolrDeletionPolicy.onComm= it 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-1359778067125/jetty2/index lockFact= ory=3Dorg.apache.lucene.store.NativeFSLockFactory@3b05555e; 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-1359778067125/jetty2/index lockFact= ory=3Dorg.apache.lucene.store.NativeFSLockFactory@3b05555e; maxCacheMB=3D48= .0 maxMergeSizeMB=3D4.0)),segFN=3Dsegments_2,generation=3D2,filenames=3D[se= gments_2] [junit4:junit4] 2> 20129 T1684 C125 P49658 oasc.SolrDeletionPolicy.update= Commits newest commit =3D 2[segments_2] [junit4:junit4] 2> 20129 T1684 C125 P49658 oasc.CachingDirectoryFactory.c= lose Releasing directory:/Users/jenkins/jenkins-slave/workspace/Lucene-Solr= -trunk-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDis= tributedZkTest-1359778067125/jetty2 [junit4:junit4] 2> 20130 T1684 C125 P49658 oass.SolrIndexSearcher. = Opening Searcher@38477d43 realtime [junit4:junit4] 2> 20131 T1684 C125 P49658 oasu.DirectUpdateHandler2.comm= it end_commit_flush [junit4:junit4] 2> 20131 T1684 C125 P49658 /update {waitSearcher=3Dtrue&o= penSearcher=3Dfalse&commit=3Dtrue&wt=3Djavabin&commit_end_point=3Dtrue&vers= ion=3D2&softCommit=3Dfalse} {commit=3D} 0 13 [junit4:junit4] 2> 20133 T1723 C123 P49665 oash.ReplicationHandler.inform= Commits will be reserved for 10000 [junit4:junit4] 2> 20133 T1723 C123 P49665 oash.SnapPuller. No val= ue set for 'pollInterval'. Timer Task not started. [junit4:junit4] 2> 20137 T1681 C125 P49658 oash.ReplicationHandler.inform= Commits will be reserved for 10000 [junit4:junit4] 2> 20138 T1681 C125 P49658 REQ /replication {command=3Din= dexversion&qt=3D/replication&wt=3Djavabin&version=3D2} status=3D0 QTime=3D2= =20 [junit4:junit4] 2> 20139 T1723 C123 P49665 oash.SnapPuller.fetchLatestInd= ex Master's generation: 2 [junit4:junit4] 2> 20139 T1723 C123 P49665 oash.SnapPuller.fetchLatestInd= ex Slave's generation: 1 [junit4:junit4] 2> 20139 T1723 C123 P49665 oash.SnapPuller.fetchLatestInd= ex Starting replication process [junit4:junit4] 2> 20145 T1682 C125 P49658 oasc.CachingDirectoryFactory.c= lose Releasing directory:/Users/jenkins/jenkins-slave/workspace/Lucene-Solr= -trunk-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDis= tributedZkTest-1359778067125/jetty2 [junit4:junit4] 2> 20146 T1682 C125 P49658 oasc.CachingDirectoryFactory.c= lose Releasing directory:/Users/jenkins/jenkins-slave/workspace/Lucene-Solr= -trunk-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDis= tributedZkTest-1359778067125/jetty2/index [junit4:junit4] 2> 20146 T1682 C125 P49658 REQ /replication {command=3Dfi= lelist&qt=3D/replication&wt=3Djavabin&generation=3D2&version=3D2} status=3D= 0 QTime=3D2=20 [junit4:junit4] 2> 20147 T1723 C123 P49665 oash.SnapPuller.fetchLatestInd= ex Number of files in latest index in master: 1 [junit4:junit4] 2> 20149 T1723 C123 P49665 oasc.CachingDirectoryFactory.g= et return new directory for /Users/jenkins/jenkins-slave/workspace/Lucene-S= olr-trunk-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.Basic= DistributedZkTest-1359778067125/jetty4/index.20130202040807268 forceNew:fal= se [junit4:junit4] 2> 20149 T1723 C123 P49665 oasc.CachingDirectoryFactory.c= lose Releasing directory:/Users/jenkins/jenkins-slave/workspace/Lucene-Solr= -trunk-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDis= tributedZkTest-1359778067125/jetty4 [junit4:junit4] 2> 20150 T1723 C123 P49665 oash.SnapPuller.fetchLatestInd= ex Starting download to RateLimitedDirectoryWrapper(NRTCachingDirectory(org= .apache.lucene.store.NIOFSDirectory@/Users/jenkins/jenkins-slave/workspace/= Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/org.apache.solr.cloud= .BasicDistributedZkTest-1359778067125/jetty4/index.20130202040807268 lockFa= ctory=3Dorg.apache.lucene.store.NativeFSLockFactory@3d7aff0f; maxCacheMB=3D= 48.0 maxMergeSizeMB=3D4.0)) fullCopy=3Dtrue [junit4:junit4] 2> 20156 T1680 C125 P49658 REQ /replication {file=3Dsegme= nts_2&command=3Dfilecontent&checksum=3Dtrue&wt=3Dfilestream&qt=3D/replicati= on&generation=3D2} status=3D0 QTime=3D1=20 [junit4:junit4] 2> 20158 T1723 C123 P49665 oasc.CachingDirectoryFactory.c= lose Releasing directory:/Users/jenkins/jenkins-slave/workspace/Lucene-Solr= -trunk-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDis= tributedZkTest-1359778067125/jetty4/index [junit4:junit4] 2> 20158 T1723 C123 P49665 oash.SnapPuller.fetchLatestInd= ex Total time taken for download : 0 secs [junit4:junit4] 2> 20159 T1723 C123 P49665 oash.SnapPuller.modifyIndexPro= ps New index installed. Updating index properties... index=3Dindex.20130202= 040807268 [junit4:junit4] 2> 20160 T1723 C123 P49665 oasc.CachingDirectoryFactory.c= lose Releasing directory:/Users/jenkins/jenkins-slave/workspace/Lucene-Solr= -trunk-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDis= tributedZkTest-1359778067125/jetty4 [junit4:junit4] 2> 20161 T1723 C123 P49665 oasc.CachingDirectoryFactory.c= lose Releasing directory:/Users/jenkins/jenkins-slave/workspace/Lucene-Solr= -trunk-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDis= tributedZkTest-1359778067125/jetty4 [junit4:junit4] 2> 20161 T1723 C123 P49665 oasc.SolrCore.getNewIndexDir N= ew index directory detected: old=3D./org.apache.solr.cloud.BasicDistributed= ZkTest-1359778067125/jetty4/index/ new=3D./org.apache.solr.cloud.BasicDistr= ibutedZkTest-1359778067125/jetty4/index.20130202040807268 [junit4:junit4] 2> 20164 T1723 C123 P49665 oasc.SolrDeletionPolicy.onInit= SolrDeletionPolicy.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-1359778067125/jetty4/index.20130202= 040807268 lockFactory=3Dorg.apache.lucene.store.NativeFSLockFactory@3d7aff0= f; maxCacheMB=3D48.0 maxMergeSizeMB=3D4.0)),segFN=3Dsegments_2,generation= =3D2,filenames=3D[segments_2] [junit4:junit4] 2> 20165 T1723 C123 P49665 oasc.SolrDeletionPolicy.update= Commits newest commit =3D 2[segments_2] [junit4:junit4] 2> 20166 T1723 C123 P49665 oasc.CachingDirectoryFactory.c= lose Releasing directory:/Users/jenkins/jenkins-slave/workspace/Lucene-Solr= -trunk-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDis= tributedZkTest-1359778067125/jetty4 [junit4:junit4] 2> 20167 T1723 C123 P49665 oasu.DefaultSolrCoreState.newI= ndexWriter Creating new IndexWriter... [junit4:junit4] 2> 20167 T1723 C123 P49665 oasu.DefaultSolrCoreState.newI= ndexWriter Waiting until IndexWriter is unused... core=3Dcollection1 [junit4:junit4] 2> 20167 T1723 C123 P49665 oasu.DefaultSolrCoreState.newI= ndexWriter Rollback old IndexWriter... core=3Dcollection1 [junit4:junit4] 2> 20168 T1723 C123 P49665 oasc.CachingDirectoryFactory.c= lose Releasing directory:/Users/jenkins/jenkins-slave/workspace/Lucene-Solr= -trunk-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDis= tributedZkTest-1359778067125/jetty4/index.20130202040807268 [junit4:junit4] 2> 20169 T1723 C123 P49665 oasc.CachingDirectoryFactory.c= lose Releasing directory:/Users/jenkins/jenkins-slave/workspace/Lucene-Solr= -trunk-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDis= tributedZkTest-1359778067125/jetty4 [junit4:junit4] 2> 20172 T1723 C123 P49665 oasc.SolrDeletionPolicy.onInit= SolrDeletionPolicy.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-1359778067125/jetty4/index.20130202= 040807268 lockFactory=3Dorg.apache.lucene.store.NativeFSLockFactory@3d7aff0= f; maxCacheMB=3D48.0 maxMergeSizeMB=3D4.0)),segFN=3Dsegments_2,generation= =3D2,filenames=3D[segments_2] [junit4:junit4] 2> 20172 T1723 C123 P49665 oasc.SolrDeletionPolicy.update= Commits newest commit =3D 2[segments_2] [junit4:junit4] 2> 20172 T1723 C123 P49665 oasu.DefaultSolrCoreState.newI= ndexWriter New IndexWriter is ready to be used. [junit4:junit4] 2> 20173 T1723 C123 P49665 oasc.CachingDirectoryFactory.c= lose Releasing directory:/Users/jenkins/jenkins-slave/workspace/Lucene-Solr= -trunk-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDis= tributedZkTest-1359778067125/jetty4 [junit4:junit4] 2> 20173 T1723 C123 P49665 oass.SolrIndexSearcher. = Opening Searcher@13697758 main [junit4:junit4] 2> 20176 T1722 oasc.SolrCore.registerSearcher [collection= 1] Registered new searcher Searcher@13697758 main{StandardDirectoryReader(s= egments_2:1:nrt)} [junit4:junit4] 2> 20177 T1722 oasc.CachingDirectoryFactory.close Releasi= ng directory:/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOS= X/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZkTe= st-1359778067125/jetty4/index [junit4:junit4] 2> 20177 T1723 C123 P49665 oasu.DirectUpdateHandler2.comm= it start commit{,optimize=3Dfalse,openSearcher=3Dfalse,waitSearcher=3Dfalse= ,expungeDeletes=3Dfalse,softCommit=3Dfalse} [junit4:junit4] 2> 20180 T1723 C123 P49665 oasc.SolrDeletionPolicy.onComm= it 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-1359778067125/jetty4/index.20130202= 040807268 lockFactory=3Dorg.apache.lucene.store.NativeFSLockFactory@3d7aff0= f; 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-1359778067125/jetty4/index.20130202= 040807268 lockFactory=3Dorg.apache.lucene.store.NativeFSLockFactory@3d7aff0= f; maxCacheMB=3D48.0 maxMergeSizeMB=3D4.0)),segFN=3Dsegments_3,generation= =3D3,filename [...truncated too long message...] t, TestQueryTypes, IndexSchemaTest, PreAnalyzedFieldTest, TestPropInject, B= inaryUpdateRequestHandlerTest, TestSolrXMLSerializer, TestSolr4Spatial, Doc= umentAnalysisRequestHandlerTest, ShardRoutingCustomTest, QueryEqualityTest,= NoCacheHeaderTest, DefaultValueUpdateProcessorTest, DOMUtilTest, TestSolrC= oreProperties, TestFuzzyAnalyzedSuggestions, DocumentBuilderTest, Stateless= ScriptUpdateProcessorFactoryTest, ReturnFieldsTest, OverseerCollectionProce= ssorTest, TimeZoneUtilsTest, ChaosMonkeyNothingIsSafeTest, TestPostingsSolr= Highlighter, SuggesterTSTTest, TestPropInjectDefaults, NotRequiredUniqueKey= Test, TestSolrJ, DistributedQueryElevationComponentTest, URLClassifyProcess= orTest, SolrCmdDistributorTest, TestStressReorder, TestQuerySenderNoQuery, = SpellCheckCollatorTest, PluginInfoTest, TestLFUCache, TestSolrIndexConfig, = NumericFieldsTest, UUIDFieldTest, SampleTest, TestUpdate, LegacyHTMLStripCh= arFilterTest, TestSolrDeletionPolicy1, FileBasedSpellCheckerTest, Suggester= Test, TestStressLucene, DebugComponentTest, TestReload, DirectUpdateHandler= Test, SOLR749Test, TestRemoteStreaming, TestSolrDeletionPolicy2, TestDocume= ntBuilder, XmlUpdateRequestHandlerTest, TestCodecSupport, ZkNodePropsTest, = ShardRoutingTest, TestCharFilters, TestJmxIntegration, TermsComponentTest, = TestFunctionQuery, CacheHeaderTest, ResourceLoaderTest, TestSort, SyncSlice= Test, TestXIncludeConfig, TestDistributedSearch, EchoParamsTest, AnalysisAf= terCoreReloadTest, HighlighterConfigTest, BasicDistributedZk2Test, SystemIn= foHandlerTest, ShowFileRequestHandlerTest, TestPseudoReturnFields, TestColl= ationField, HighlighterTest, SolrRequestParserTest, CSVRequestHandlerTest, = FieldAnalysisRequestHandlerTest, TestLMJelinekMercerSimilarityFactory, Test= IndexingPerformance, SoftAutoCommitTest, LukeRequestHandlerTest, PingReques= tHandlerTest, ClusterStateUpdateTest, TestBinaryField, BasicDistributedZkTe= st] [junit4:junit4] 2> NOTE: reproduce with: ant test -Dtestcase=3DBasicDist= ributedZkTest -Dtests.seed=3D898A621A89DCE35B -Dtests.slow=3Dtrue -Dtests.l= ocale=3Dzh_SG -Dtests.timezone=3DAfrica/El_Aaiun -Dtests.file.encoding=3DIS= O-8859-1 [junit4:junit4] ERROR 0.00s | BasicDistributedZkTest (suite) <<< [junit4:junit4] > Throwable #1: java.lang.AssertionError: ERROR: SolrInd= exSearcher opens=3D610 closes=3D609 [junit4:junit4] > =09at __randomizedtesting.SeedInfo.seed([898A621A89DCE= 35B]:0) [junit4:junit4] > =09at org.junit.Assert.fail(Assert.java:93) [junit4:junit4] > =09at org.apache.solr.SolrTestCaseJ4.endTrackingSearch= ers(SolrTestCaseJ4.java:246) [junit4:junit4] > =09at org.apache.solr.SolrTestCaseJ4.afterClass(SolrTe= stCaseJ4.java:97) [junit4:junit4] > =09at sun.reflect.GeneratedMethodAccessor17.invoke(Unk= nown Source) [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$5.evaluate(RandomizedRunner.java:700) [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] > Throwable #2: com.carrotsearch.randomizedtesting.Threa= dLeakError: 2 threads leaked from SUITE scope at org.apache.solr.cloud.Basi= cDistributedZkTest:=20 [junit4:junit4] > 1) Thread[id=3D1980, name=3DsearcherExecutor-1104-t= hread-1, state=3DWAITING, group=3DTGRP-BasicDistributedZkTest] [junit4:junit4] > at sun.misc.Unsafe.park(Native Method) [junit4:junit4] > at java.util.concurrent.locks.LockSupport.park= (LockSupport.java:186) [junit4:junit4] > at java.util.concurrent.locks.AbstractQueuedSy= nchronizer$ConditionObject.await(AbstractQueuedSynchronizer.java:2043) [junit4:junit4] > at java.util.concurrent.LinkedBlockingQueue.ta= ke(LinkedBlockingQueue.java:442) [junit4:junit4] > at java.util.concurrent.ThreadPoolExecutor.get= Task(ThreadPoolExecutor.java:1043) [junit4:junit4] > at java.util.concurrent.ThreadPoolExecutor.run= Worker(ThreadPoolExecutor.java:1103) [junit4:junit4] > at java.util.concurrent.ThreadPoolExecutor$Wor= ker.run(ThreadPoolExecutor.java:603) [junit4:junit4] > at java.lang.Thread.run(Thread.java:722) [junit4:junit4] > 2) Thread[id=3D1992, name=3DRecoveryThread, state= =3DTIMED_WAITING, group=3DTGRP-BasicDistributedZkTest] [junit4:junit4] > at java.lang.Thread.sleep(Native Method) [junit4:junit4] > at org.apache.solr.cloud.RecoveryStrategy.doRe= covery(RecoveryStrategy.java:490) [junit4:junit4] > at org.apache.solr.cloud.RecoveryStrategy.run(= RecoveryStrategy.java:223) [junit4:junit4] > =09at __randomizedtesting.SeedInfo.seed([898A621A89DCE= 35B]:0) [junit4:junit4] > Throwable #3: com.carrotsearch.randomizedtesting.Threa= dLeakError: There are still zombie threads that couldn't be terminated: [junit4:junit4] > 1) Thread[id=3D1980, name=3DsearcherExecutor-1104-t= hread-1, state=3DWAITING, group=3DTGRP-BasicDistributedZkTest] [junit4:junit4] > at sun.misc.Unsafe.park(Native Method) [junit4:junit4] > at java.util.concurrent.locks.LockSupport.park= (LockSupport.java:186) [junit4:junit4] > at java.util.concurrent.locks.AbstractQueuedSy= nchronizer$ConditionObject.await(AbstractQueuedSynchronizer.java:2043) [junit4:junit4] > at java.util.concurrent.LinkedBlockingQueue.ta= ke(LinkedBlockingQueue.java:442) [junit4:junit4] > at java.util.concurrent.ThreadPoolExecutor.get= Task(ThreadPoolExecutor.java:1043) [junit4:junit4] > at java.util.concurrent.ThreadPoolExecutor.run= Worker(ThreadPoolExecutor.java:1103) [junit4:junit4] > at java.util.concurrent.ThreadPoolExecutor$Wor= ker.run(ThreadPoolExecutor.java:603) [junit4:junit4] > at java.lang.Thread.run(Thread.java:722) [junit4:junit4] > 2) Thread[id=3D1992, name=3DRecoveryThread, state= =3DWAITING, group=3DTGRP-BasicDistributedZkTest] [junit4:junit4] > at java.lang.Object.wait(Native Method) [junit4:junit4] > at java.lang.Thread.join(Thread.java:1258) [junit4:junit4] > at java.lang.Thread.join(Thread.java:1332) [junit4:junit4] > at org.apache.solr.update.DefaultSolrCoreState= .cancelRecovery(DefaultSolrCoreState.java:244) [junit4:junit4] > at org.apache.solr.update.DefaultSolrCoreState= .close(DefaultSolrCoreState.java:271) [junit4:junit4] > at org.apache.solr.core.SolrCore.decrefSolrCor= eState(SolrCore.java:888) [junit4:junit4] > at org.apache.solr.core.SolrCore.close(SolrCor= e.java:980) [junit4:junit4] > at org.apache.solr.cloud.RecoveryStrategy.run(= RecoveryStrategy.java:235) [junit4:junit4] > =09at __randomizedtesting.SeedInfo.seed([898A621A89DCE= 35B]:0) [junit4:junit4] Completed in 382.70s, 1 test, 1 failure, 3 errors <<< FAILU= RES! [...truncated 442 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, 3 suite= -level errors, 1 error, 483 ignored (2 assumptions) Total time: 45 minutes 21 seconds Build step 'Invoke Ant' marked build as failure Archiving artifacts Recording test results Description set: Java: 64bit/jdk1.7.0 -XX:+UseSerialGC Email was triggered for: Failure Sending email for trigger: Failure ------=_Part_18_1775913254.1359778513974 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_18_1775913254.1359778513974--