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 75B91D6CD for ; Thu, 7 Mar 2013 01:19:03 +0000 (UTC) Received: (qmail 16377 invoked by uid 500); 7 Mar 2013 01:18:58 -0000 Delivered-To: apmail-lucene-dev-archive@lucene.apache.org Received: (qmail 16318 invoked by uid 500); 7 Mar 2013 01:18:58 -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 16303 invoked by uid 99); 7 Mar 2013 01:18:58 -0000 Received: from athena.apache.org (HELO athena.apache.org) (140.211.11.136) by apache.org (qpsmtpd/0.29) with ESMTP; Thu, 07 Mar 2013 01:18:58 +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; Thu, 07 Mar 2013 01:18:49 +0000 Received: from serv1 (localhost.localdomain [127.0.0.1]) by mail.sd-datasolutions.de (Postfix) with ESMTP id 9BADB14AA036; Thu, 7 Mar 2013 01:18:26 +0000 (UTC) Date: Thu, 7 Mar 2013 01:18:15 +0000 (UTC) From: Policeman Jenkins Server To: dev@lucene.apache.org, hossman@apache.org, erick@apache.org Message-ID: <1864834398.71.1362619106622.JavaMail.jenkins@serv1.sd-datasolutions.de> Subject: [JENKINS] Lucene-Solr-trunk-MacOSX (64bit/jdk1.6.0) - Build # 296 - Failure! MIME-Version: 1.0 Content-Type: multipart/mixed; boundary="----=_Part_70_526881153.1362619095371" X-Jenkins-Job: Lucene-Solr-trunk-MacOSX X-Jenkins-Result: FAILURE X-Virus-Checked: Checked by ClamAV on apache.org ------=_Part_70_526881153.1362619095371 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: quoted-printable Build: http://jenkins.thetaphi.de/job/Lucene-Solr-trunk-MacOSX/296/ Java: 64bit/jdk1.6.0 -XX:+UseParallelGC 3 tests failed. FAILED: junit.framework.TestSuite.org.apache.solr.cloud.ChaosMonkeySafeLea= derTest Error Message: ERROR: SolrIndexSearcher opens=3D40 closes=3D39 Stack Trace: java.lang.AssertionError: ERROR: SolrIndexSearcher opens=3D40 closes=3D39 =09at __randomizedtesting.SeedInfo.seed([3BB7A992A26D0C84]: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.GeneratedMethodAccessor21.invoke(Unknown Source) =09at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAcces= sorImpl.java:25) =09at java.lang.reflect.Method.invoke(Method.java:597) =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:680) FAILED: junit.framework.TestSuite.org.apache.solr.cloud.ChaosMonkeySafeLea= derTest Error Message: 2 threads leaked from SUITE scope at org.apache.solr.cloud.ChaosMonkeySafeL= eaderTest: 1) Thread[id=3D3309, name=3DsearcherExecutor-2230-thread-1, = state=3DWAITING, group=3DTGRP-ChaosMonkeySafeLeaderTest] at sun.mis= c.Unsafe.park(Native Method) at java.util.concurrent.locks.LockSupp= ort.park(LockSupport.java:156) at java.util.concurrent.locks.Abstra= ctQueuedSynchronizer$ConditionObject.await(AbstractQueuedSynchronizer.java:= 1987) at java.util.concurrent.LinkedBlockingQueue.take(LinkedBlocki= ngQueue.java:399) at java.util.concurrent.ThreadPoolExecutor.getTas= k(ThreadPoolExecutor.java:957) at java.util.concurrent.ThreadPoolEx= ecutor$Worker.run(ThreadPoolExecutor.java:917) at java.lang.Thread.= run(Thread.java:680) 2) Thread[id=3D3503, name=3DRecoveryThread, state= =3DTIMED_WAITING, group=3DTGRP-ChaosMonkeySafeLeaderTest] at java.l= ang.Thread.sleep(Native Method) at org.apache.solr.cloud.RecoverySt= rategy.doRecovery(RecoveryStrategy.java:490) at org.apache.solr.clo= ud.RecoveryStrategy.run(RecoveryStrategy.java:223) Stack Trace: com.carrotsearch.randomizedtesting.ThreadLeakError: 2 threads leaked from S= UITE scope at org.apache.solr.cloud.ChaosMonkeySafeLeaderTest:=20 1) Thread[id=3D3309, name=3DsearcherExecutor-2230-thread-1, state=3DWAIT= ING, group=3DTGRP-ChaosMonkeySafeLeaderTest] at sun.misc.Unsafe.park(Native Method) at java.util.concurrent.locks.LockSupport.park(LockSupport.java:156= ) at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionO= bject.await(AbstractQueuedSynchronizer.java:1987) at java.util.concurrent.LinkedBlockingQueue.take(LinkedBlockingQueu= e.java:399) at java.util.concurrent.ThreadPoolExecutor.getTask(ThreadPoolExecut= or.java:957) at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExe= cutor.java:917) at java.lang.Thread.run(Thread.java:680) 2) Thread[id=3D3503, name=3DRecoveryThread, state=3DTIMED_WAITING, group= =3DTGRP-ChaosMonkeySafeLeaderTest] 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([3BB7A992A26D0C84]:0) FAILED: junit.framework.TestSuite.org.apache.solr.cloud.ChaosMonkeySafeLea= derTest Error Message: There are still zombie threads that couldn't be terminated: 1) Thread[id= =3D3309, name=3DsearcherExecutor-2230-thread-1, state=3DWAITING, group=3DTG= RP-ChaosMonkeySafeLeaderTest] at sun.misc.Unsafe.park(Native Method= ) at java.util.concurrent.locks.LockSupport.park(LockSupport.java:1= 56) at java.util.concurrent.locks.AbstractQueuedSynchronizer$Condit= ionObject.await(AbstractQueuedSynchronizer.java:1987) at java.util.= concurrent.LinkedBlockingQueue.take(LinkedBlockingQueue.java:399) a= t java.util.concurrent.ThreadPoolExecutor.getTask(ThreadPoolExecutor.java:9= 57) at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoo= lExecutor.java:917) at java.lang.Thread.run(Thread.java:680) 2) = Thread[id=3D3503, name=3DRecoveryThread, state=3DWAITING, group=3DTGRP-Chao= sMonkeySafeLeaderTest] at java.lang.Object.wait(Native Method) = at java.lang.Thread.join(Thread.java:1210) at java.lang.Thread.= join(Thread.java:1263) at org.apache.solr.update.DefaultSolrCoreSta= te.cancelRecovery(DefaultSolrCoreState.java:250) at org.apache.solr= .update.DefaultSolrCoreState.close(DefaultSolrCoreState.java:277) a= t org.apache.solr.update.SolrCoreState.decrefSolrCoreState(SolrCoreState.ja= va:73) at org.apache.solr.core.SolrCore.close(SolrCore.java:975) = 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=3D3309, name=3DsearcherExecutor-2230-thread-1, state=3DWAIT= ING, group=3DTGRP-ChaosMonkeySafeLeaderTest] at sun.misc.Unsafe.park(Native Method) at java.util.concurrent.locks.LockSupport.park(LockSupport.java:156= ) at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionO= bject.await(AbstractQueuedSynchronizer.java:1987) at java.util.concurrent.LinkedBlockingQueue.take(LinkedBlockingQueu= e.java:399) at java.util.concurrent.ThreadPoolExecutor.getTask(ThreadPoolExecut= or.java:957) at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExe= cutor.java:917) at java.lang.Thread.run(Thread.java:680) 2) Thread[id=3D3503, name=3DRecoveryThread, state=3DWAITING, group=3DTGR= P-ChaosMonkeySafeLeaderTest] at java.lang.Object.wait(Native Method) at java.lang.Thread.join(Thread.java:1210) at java.lang.Thread.join(Thread.java:1263) at org.apache.solr.update.DefaultSolrCoreState.cancelRecovery(Defau= ltSolrCoreState.java:250) at org.apache.solr.update.DefaultSolrCoreState.close(DefaultSolrCor= eState.java:277) at org.apache.solr.update.SolrCoreState.decrefSolrCoreState(SolrCor= eState.java:73) at org.apache.solr.core.SolrCore.close(SolrCore.java:975) at org.apache.solr.cloud.RecoveryStrategy.run(RecoveryStrategy.java= :235) =09at __randomizedtesting.SeedInfo.seed([3BB7A992A26D0C84]:0) Build Log: [...truncated 8631 lines...] [junit4:junit4] Suite: org.apache.solr.cloud.ChaosMonkeySafeLeaderTest [junit4:junit4] 2> 2 T3180 oas.BaseDistributedSearchTestCase.initHostCont= ext Setting hostContext system property: / [junit4:junit4] 2> 7 T3180 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-ChaosMo= nkeySafeLeaderTest-1362618633035 [junit4:junit4] 2> 8 T3180 oasc.ZkTestServer.run STARTING ZK TEST SERVER [junit4:junit4] 2> 9 T3181 oasc.ZkTestServer$ZKServerMain.runFromConfig S= tarting server [junit4:junit4] 2> 12 T3181 oazs.ZooKeeperServer.setTickTime tickTime set= to 1000 [junit4:junit4] 2> 12 T3181 oazs.ZooKeeperServer.setMinSessionTimeout min= SessionTimeout set to -1 [junit4:junit4] 2> 12 T3181 oazs.ZooKeeperServer.setMaxSessionTimeout max= SessionTimeout set to -1 [junit4:junit4] 2> 13 T3181 oazs.NIOServerCnxnFactory.configure binding t= o port 0.0.0.0/0.0.0.0:0 [junit4:junit4] 2> 14 T3181 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.ChaosMonkeySafeLeaderTest-13626= 18633034/zookeeper/server1/data/version-2/snapshot.0 [junit4:junit4] 2> 110 T3180 oasc.ZkTestServer.run start zk server on por= t:50048 [junit4:junit4] 2> 111 T3180 oaz.ZooKeeper. Initiating client conne= ction, connectString=3D127.0.0.1:50048 sessionTimeout=3D10000 watcher=3Dorg= .apache.solr.common.cloud.ConnectionManager@4a99109b [junit4:junit4] 2> 112 T3180 oascc.ConnectionManager.waitForConnected Wai= ting for client to connect to ZooKeeper [junit4:junit4] 2> 113 T3186 oaz.ClientCnxn$SendThread.logStartConnect Op= ening socket connection to server 127.0.0.1/127.0.0.1:50048. Will not attem= pt to authenticate using SASL (access denied (javax.security.auth.AuthPermi= ssion getLoginConfiguration)) [junit4:junit4] 2> 114 T3186 oaz.ClientCnxn$SendThread.primeConnection So= cket connection established to 127.0.0.1/127.0.0.1:50048, initiating sessio= n [junit4:junit4] 2> 114 T3182 oazs.NIOServerCnxnFactory.run Accepted socke= t connection from /127.0.0.1:50049 [junit4:junit4] 2> 115 T3182 oazs.ZooKeeperServer.processConnectRequest C= lient attempting to establish new session at /127.0.0.1:50049 [junit4:junit4] 2> 116 T3184 oazsp.FileTxnLog.append Creating new log fil= e: log.1 [junit4:junit4] 2> 119 T3184 oazs.ZooKeeperServer.finishSessionInit Estab= lished session 0x13d42664b520000 with negotiated timeout 10000 for client /= 127.0.0.1:50049 [junit4:junit4] 2> 119 T3186 oaz.ClientCnxn$SendThread.onConnected Sessio= n establishment complete on server 127.0.0.1/127.0.0.1:50048, sessionid =3D= 0x13d42664b520000, negotiated timeout =3D 10000 [junit4:junit4] 2> 120 T3187 oascc.ConnectionManager.process Watcher org.= apache.solr.common.cloud.ConnectionManager@4a99109b name:ZooKeeperConnectio= n Watcher:127.0.0.1:50048 got event WatchedEvent state:SyncConnected type:N= one path:null path:null type:None [junit4:junit4] 2> 120 T3180 oascc.ConnectionManager.waitForConnected Cli= ent is connected to ZooKeeper [junit4:junit4] 2> 121 T3180 oascc.SolrZkClient.makePath makePath: /solr [junit4:junit4] 2> 127 T3185 oazs.PrepRequestProcessor.pRequest2Txn Proce= ssed session termination for sessionid: 0x13d42664b520000 [junit4:junit4] 2> 130 T3187 oaz.ClientCnxn$EventThread.run EventThread s= hut down [junit4:junit4] 2> 128 T3180 oaz.ZooKeeper.close Session: 0x13d42664b5200= 00 closed [junit4:junit4] 2> 139 T3182 oazs.NIOServerCnxn.closeSock Closed socket c= onnection for client /127.0.0.1:50049 which had sessionid 0x13d42664b520000 [junit4:junit4] 2> 139 T3180 oaz.ZooKeeper. Initiating client conne= ction, connectString=3D127.0.0.1:50048/solr sessionTimeout=3D10000 watcher= =3Dorg.apache.solr.common.cloud.ConnectionManager@17a7a00a [junit4:junit4] 2> 140 T3180 oascc.ConnectionManager.waitForConnected Wai= ting for client to connect to ZooKeeper [junit4:junit4] 2> 140 T3188 oaz.ClientCnxn$SendThread.logStartConnect Op= ening socket connection to server 127.0.0.1/127.0.0.1:50048. Will not attem= pt to authenticate using SASL (access denied (javax.security.auth.AuthPermi= ssion getLoginConfiguration)) [junit4:junit4] 2> 141 T3188 oaz.ClientCnxn$SendThread.primeConnection So= cket connection established to 127.0.0.1/127.0.0.1:50048, initiating sessio= n [junit4:junit4] 2> 142 T3182 oazs.NIOServerCnxnFactory.run Accepted socke= t connection from /127.0.0.1:50050 [junit4:junit4] 2> 142 T3182 oazs.ZooKeeperServer.processConnectRequest C= lient attempting to establish new session at /127.0.0.1:50050 [junit4:junit4] 2> 143 T3184 oazs.ZooKeeperServer.finishSessionInit Estab= lished session 0x13d42664b520001 with negotiated timeout 10000 for client /= 127.0.0.1:50050 [junit4:junit4] 2> 144 T3188 oaz.ClientCnxn$SendThread.onConnected Sessio= n establishment complete on server 127.0.0.1/127.0.0.1:50048, sessionid =3D= 0x13d42664b520001, negotiated timeout =3D 10000 [junit4:junit4] 2> 144 T3189 oascc.ConnectionManager.process Watcher org.= apache.solr.common.cloud.ConnectionManager@17a7a00a name:ZooKeeperConnectio= n Watcher:127.0.0.1:50048/solr got event WatchedEvent state:SyncConnected t= ype:None path:null path:null type:None [junit4:junit4] 2> 144 T3180 oascc.ConnectionManager.waitForConnected Cli= ent is connected to ZooKeeper [junit4:junit4] 2> 145 T3180 oascc.SolrZkClient.makePath makePath: /colle= ctions/collection1 [junit4:junit4] 2> 152 T3180 oascc.SolrZkClient.makePath makePath: /colle= ctions/collection1/shards [junit4:junit4] 2> 157 T3180 oascc.SolrZkClient.makePath makePath: /colle= ctions/control_collection [junit4:junit4] 2> 163 T3180 oascc.SolrZkClient.makePath makePath: /colle= ctions/control_collection/shards [junit4:junit4] 2> 169 T3180 oasc.AbstractZkTestCase.putConfig put /Users= /jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-c= ore/test-files/solr/collection1/conf/solrconfig-tlog.xml to /configs/conf1/= solrconfig.xml [junit4:junit4] 2> 170 T3180 oascc.SolrZkClient.makePath makePath: /confi= gs/conf1/solrconfig.xml [junit4:junit4] 2> 180 T3180 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> 181 T3180 oascc.SolrZkClient.makePath makePath: /confi= gs/conf1/schema.xml [junit4:junit4] 2> 189 T3180 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> 189 T3180 oascc.SolrZkClient.makePath makePath: /confi= gs/conf1/stopwords.txt [junit4:junit4] 2> 196 T3180 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> 197 T3180 oascc.SolrZkClient.makePath makePath: /confi= gs/conf1/protwords.txt [junit4:junit4] 2> 203 T3180 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> 204 T3180 oascc.SolrZkClient.makePath makePath: /confi= gs/conf1/currency.xml [junit4:junit4] 2> 211 T3180 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> 211 T3180 oascc.SolrZkClient.makePath makePath: /confi= gs/conf1/open-exchange-rates.json [junit4:junit4] 2> 218 T3180 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> 219 T3180 oascc.SolrZkClient.makePath makePath: /confi= gs/conf1/mapping-ISOLatin1Accent.txt [junit4:junit4] 2> 225 T3180 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> 226 T3180 oascc.SolrZkClient.makePath makePath: /confi= gs/conf1/old_synonyms.txt [junit4:junit4] 2> 233 T3180 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> 234 T3180 oascc.SolrZkClient.makePath makePath: /confi= gs/conf1/synonyms.txt [junit4:junit4] 2> 241 T3185 oazs.PrepRequestProcessor.pRequest2Txn Proce= ssed session termination for sessionid: 0x13d42664b520001 [junit4:junit4] 2> 242 T3182 oazs.NIOServerCnxn.closeSock Closed socket c= onnection for client /127.0.0.1:50050 which had sessionid 0x13d42664b520001 [junit4:junit4] 2> 242 T3180 oaz.ZooKeeper.close Session: 0x13d42664b5200= 01 closed [junit4:junit4] 2> 243 T3189 oaz.ClientCnxn$EventThread.run EventThread s= hut down [junit4:junit4] 2> 532 T3180 oejs.Server.doStart jetty-8.1.8.v20121106 [junit4:junit4] 2> 554 T3180 oejs.AbstractConnector.doStart Started Selec= tChannelConnector@127.0.0.1:50051 [junit4:junit4] 2> 555 T3180 oass.SolrDispatchFilter.init SolrDispatchFil= ter.init() [junit4:junit4] 2> 555 T3180 oasc.SolrResourceLoader.locateSolrHome JNDI = not configured for solr (NoInitialContextEx) [junit4:junit4] 2> 556 T3180 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.= ChaosMonkeySafeLeaderTest-controljetty-1362618633270 [junit4:junit4] 2> 556 T3180 oasc.CoreContainer$Initializer.initialize lo= oking for solr config file: /Users/jenkins/jenkins-slave/workspace/Lucene-S= olr-trunk-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.Chaos= MonkeySafeLeaderTest-controljetty-1362618633270/solr.xml [junit4:junit4] 2> 557 T3180 oasc.CoreContainer. New CoreContainer = 1545275304 [junit4:junit4] 2> 557 T3180 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.ChaosMonkeySa= feLeaderTest-controljetty-1362618633270/' [junit4:junit4] 2> 558 T3180 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.ChaosMo= nkeySafeLeaderTest-controljetty-1362618633270/' [junit4:junit4] 2> 615 T3180 oashc.HttpShardHandlerFactory.getParameter S= etting socketTimeout to: 120000 [junit4:junit4] 2> 616 T3180 oashc.HttpShardHandlerFactory.getParameter S= etting urlScheme to: http:// [junit4:junit4] 2> 616 T3180 oashc.HttpShardHandlerFactory.getParameter S= etting connTimeout to: 15000 [junit4:junit4] 2> 617 T3180 oashc.HttpShardHandlerFactory.getParameter S= etting maxConnectionsPerHost to: 20 [junit4:junit4] 2> 617 T3180 oashc.HttpShardHandlerFactory.getParameter S= etting corePoolSize to: 0 [junit4:junit4] 2> 618 T3180 oashc.HttpShardHandlerFactory.getParameter S= etting maximumPoolSize to: 2147483647 [junit4:junit4] 2> 618 T3180 oashc.HttpShardHandlerFactory.getParameter S= etting maxThreadIdleTime to: 5 [junit4:junit4] 2> 619 T3180 oashc.HttpShardHandlerFactory.getParameter S= etting sizeOfQueue to: -1 [junit4:junit4] 2> 619 T3180 oashc.HttpShardHandlerFactory.getParameter S= etting fairnessPolicy to: false [junit4:junit4] 2> 620 T3180 oascsi.HttpClientUtil.createClient Creating = new http client, config:maxConnectionsPerHost=3D20&maxConnections=3D10000&s= ocketTimeout=3D120000&connTimeout=3D15000&retry=3Dfalse [junit4:junit4] 2> 655 T3180 oasc.CoreContainer.load Registering Log List= ener [junit4:junit4] 2> 681 T3180 oasc.CoreContainer.initZooKeeper Zookeeper c= lient=3D127.0.0.1:50048/solr [junit4:junit4] 2> 681 T3180 oasc.ZkController.checkChrootPath zkHost inc= ludes chroot [junit4:junit4] 2> 682 T3180 oaz.ZooKeeper. Initiating client conne= ction, connectString=3D127.0.0.1:50048 sessionTimeout=3D60000 watcher=3Dorg= .apache.solr.common.cloud.ConnectionManager@47bbcdb7 [junit4:junit4] 2> 683 T3180 oascc.ConnectionManager.waitForConnected Wai= ting for client to connect to ZooKeeper [junit4:junit4] 2> 684 T3199 oaz.ClientCnxn$SendThread.logStartConnect Op= ening socket connection to server 127.0.0.1/127.0.0.1:50048. Will not attem= pt to authenticate using SASL (access denied (javax.security.auth.AuthPermi= ssion getLoginConfiguration)) [junit4:junit4] 2> 686 T3199 oaz.ClientCnxn$SendThread.primeConnection So= cket connection established to 127.0.0.1/127.0.0.1:50048, initiating sessio= n [junit4:junit4] 2> 687 T3182 oazs.NIOServerCnxnFactory.run Accepted socke= t connection from /127.0.0.1:50052 [junit4:junit4] 2> 688 T3182 oazs.ZooKeeperServer.processConnectRequest C= lient attempting to establish new session at /127.0.0.1:50052 [junit4:junit4] 2> 690 T3184 oazs.ZooKeeperServer.finishSessionInit Estab= lished session 0x13d42664b520002 with negotiated timeout 20000 for client /= 127.0.0.1:50052 [junit4:junit4] 2> 690 T3199 oaz.ClientCnxn$SendThread.onConnected Sessio= n establishment complete on server 127.0.0.1/127.0.0.1:50048, sessionid =3D= 0x13d42664b520002, negotiated timeout =3D 20000 [junit4:junit4] 2> 690 T3200 oascc.ConnectionManager.process Watcher org.= apache.solr.common.cloud.ConnectionManager@47bbcdb7 name:ZooKeeperConnectio= n Watcher:127.0.0.1:50048 got event WatchedEvent state:SyncConnected type:N= one path:null path:null type:None [junit4:junit4] 2> 691 T3180 oascc.ConnectionManager.waitForConnected Cli= ent is connected to ZooKeeper [junit4:junit4] 2> 693 T3185 oazs.PrepRequestProcessor.pRequest2Txn Proce= ssed session termination for sessionid: 0x13d42664b520002 [junit4:junit4] 2> 695 T3182 oazs.NIOServerCnxn.closeSock Closed socket c= onnection for client /127.0.0.1:50052 which had sessionid 0x13d42664b520002 [junit4:junit4] 2> 695 T3180 oaz.ZooKeeper.close Session: 0x13d42664b5200= 02 closed [junit4:junit4] 2> 695 T3200 oaz.ClientCnxn$EventThread.run EventThread s= hut down [junit4:junit4] 2> 695 T3180 oascsi.HttpClientUtil.createClient Creating = new http client, config:maxConnections=3D500&maxConnectionsPerHost=3D16&soc= ketTimeout=3D120000&connTimeout=3D15000 [junit4:junit4] 2> 720 T3180 oaz.ZooKeeper. Initiating client conne= ction, connectString=3D127.0.0.1:50048/solr sessionTimeout=3D30000 watcher= =3Dorg.apache.solr.common.cloud.ConnectionManager@2c420d48 [junit4:junit4] 2> 722 T3180 oascc.ConnectionManager.waitForConnected Wai= ting for client to connect to ZooKeeper [junit4:junit4] 2> 723 T3201 oaz.ClientCnxn$SendThread.logStartConnect Op= ening socket connection to server 127.0.0.1/127.0.0.1:50048. Will not attem= pt to authenticate using SASL (access denied (javax.security.auth.AuthPermi= ssion getLoginConfiguration)) [junit4:junit4] 2> 724 T3201 oaz.ClientCnxn$SendThread.primeConnection So= cket connection established to 127.0.0.1/127.0.0.1:50048, initiating sessio= n [junit4:junit4] 2> 725 T3182 oazs.NIOServerCnxnFactory.run Accepted socke= t connection from /127.0.0.1:50053 [junit4:junit4] 2> 725 T3182 oazs.ZooKeeperServer.processConnectRequest C= lient attempting to establish new session at /127.0.0.1:50053 [junit4:junit4] 2> 727 T3184 oazs.ZooKeeperServer.finishSessionInit Estab= lished session 0x13d42664b520003 with negotiated timeout 20000 for client /= 127.0.0.1:50053 [junit4:junit4] 2> 727 T3201 oaz.ClientCnxn$SendThread.onConnected Sessio= n establishment complete on server 127.0.0.1/127.0.0.1:50048, sessionid =3D= 0x13d42664b520003, negotiated timeout =3D 20000 [junit4:junit4] 2> 727 T3202 oascc.ConnectionManager.process Watcher org.= apache.solr.common.cloud.ConnectionManager@2c420d48 name:ZooKeeperConnectio= n Watcher:127.0.0.1:50048/solr got event WatchedEvent state:SyncConnected t= ype:None path:null path:null type:None [junit4:junit4] 2> 728 T3180 oascc.ConnectionManager.waitForConnected Cli= ent is connected to ZooKeeper [junit4:junit4] 2> 731 T3185 oazs.PrepRequestProcessor.pRequest Got user-= level KeeperException when processing sessionid:0x13d42664b520003 type:crea= te cxid:0x2 zxid:0x1a txntype:-1 reqpath:n/a Error Path:/solr/overseer Erro= r:KeeperErrorCode =3D NodeExists for /solr/overseer [junit4:junit4] 2> 735 T3180 oascc.SolrZkClient.makePath makePath: /live_= nodes [junit4:junit4] 2> 739 T3180 oasc.ZkController.createEphemeralLiveNode Re= gister node as live in ZooKeeper:/live_nodes/127.0.0.1:50051_ [junit4:junit4] 2> 740 T3185 oazs.PrepRequestProcessor.pRequest Got user-= level KeeperException when processing sessionid:0x13d42664b520003 type:dele= te cxid:0x8 zxid:0x1c txntype:-1 reqpath:n/a Error Path:/solr/live_nodes/12= 7.0.0.1:50051_ Error:KeeperErrorCode =3D NoNode for /solr/live_nodes/127.0.= 0.1:50051_ [junit4:junit4] 2> 741 T3180 oascc.SolrZkClient.makePath makePath: /live_= nodes/127.0.0.1:50051_ [junit4:junit4] 2> 749 T3180 oascc.SolrZkClient.makePath makePath: /overs= eer_elect/election [junit4:junit4] 2> 759 T3185 oazs.PrepRequestProcessor.pRequest Got user-= level KeeperException when processing sessionid:0x13d42664b520003 type:dele= te cxid:0x16 zxid:0x21 txntype:-1 reqpath:n/a Error Path:/solr/overseer_ele= ct/leader Error:KeeperErrorCode =3D NoNode for /solr/overseer_elect/leader [junit4:junit4] 2> 761 T3180 oascc.SolrZkClient.makePath makePath: /overs= eer_elect/leader [junit4:junit4] 2> 766 T3180 oasc.Overseer.start Overseer (id=3D893005747= 35040515-127.0.0.1:50051_-n_0000000000) starting [junit4:junit4] 2> 767 T3185 oazs.PrepRequestProcessor.pRequest Got user-= level KeeperException when processing sessionid:0x13d42664b520003 type:crea= te cxid:0x1b zxid:0x23 txntype:-1 reqpath:n/a Error Path:/solr/overseer Err= or:KeeperErrorCode =3D NodeExists for /solr/overseer [junit4:junit4] 2> 769 T3185 oazs.PrepRequestProcessor.pRequest Got user-= level KeeperException when processing sessionid:0x13d42664b520003 type:crea= te cxid:0x1c zxid:0x24 txntype:-1 reqpath:n/a Error Path:/solr/overseer Err= or:KeeperErrorCode =3D NodeExists for /solr/overseer [junit4:junit4] 2> 771 T3185 oazs.PrepRequestProcessor.pRequest Got user-= level KeeperException when processing sessionid:0x13d42664b520003 type:crea= te cxid:0x1d zxid:0x25 txntype:-1 reqpath:n/a Error Path:/solr/overseer Err= or:KeeperErrorCode =3D NodeExists for /solr/overseer [junit4:junit4] 2> 773 T3185 oazs.PrepRequestProcessor.pRequest Got user-= level KeeperException when processing sessionid:0x13d42664b520003 type:crea= te cxid:0x1e zxid:0x26 txntype:-1 reqpath:n/a Error Path:/solr/overseer Err= or:KeeperErrorCode =3D NodeExists for /solr/overseer [junit4:junit4] 2> 775 T3204 oasc.OverseerCollectionProcessor.run Process= current queue of collection creations [junit4:junit4] 2> 779 T3180 oascc.SolrZkClient.makePath makePath: /clust= erstate.json [junit4:junit4] 2> 784 T3180 oascc.ZkStateReader.createClusterStateWatche= rsAndUpdate Updating cluster state from ZooKeeper...=20 [junit4:junit4] 2> 789 T3203 oasc.Overseer$ClusterStateUpdater.run Starti= ng to work on the main queue [junit4:junit4] 2> 794 T3205 oasc.CoreContainer.create Creating SolrCore = 'collection1' using instanceDir: /Users/jenkins/jenkins-slave/workspace/Luc= ene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.= ChaosMonkeySafeLeaderTest-controljetty-1362618633270/collection1 [junit4:junit4] 2> 794 T3205 oasc.ZkController.createCollectionZkNode Che= ck for collection zkNode:control_collection [junit4:junit4] 2> 795 T3205 oasc.ZkController.createCollectionZkNode Col= lection zkNode exists [junit4:junit4] 2> 796 T3205 oasc.ZkController.readConfigName Load collec= tion config from:/collections/control_collection [junit4:junit4] 2> 798 T3205 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.ChaosMo= nkeySafeLeaderTest-controljetty-1362618633270/collection1/' [junit4:junit4] 2> 799 T3205 oasc.SolrResourceLoader.replaceClassLoader A= dding 'file:/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX= /solr/build/solr-core/test/J0/org.apache.solr.cloud.ChaosMonkeySafeLeaderTe= st-controljetty-1362618633270/collection1/lib/classes/' to classloader [junit4:junit4] 2> 800 T3205 oasc.SolrResourceLoader.replaceClassLoader A= dding 'file:/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX= /solr/build/solr-core/test/J0/org.apache.solr.cloud.ChaosMonkeySafeLeaderTe= st-controljetty-1362618633270/collection1/lib/README' to classloader [junit4:junit4] 2> 862 T3205 oasc.SolrConfig. Using Lucene MatchVer= sion: LUCENE_50 [junit4:junit4] 2> 941 T3205 oasc.SolrConfig. Loaded SolrConfig: so= lrconfig.xml [junit4:junit4] 2> 943 T3205 oass.IndexSchema.readSchema Reading Solr Sch= ema [junit4:junit4] 2> 950 T3205 oass.IndexSchema.readSchema Schema name=3Dte= st [junit4:junit4] 2> 1731 T3205 oass.OpenExchangeRatesOrgProvider.init Init= ialized with rates=3Dopen-exchange-rates.json, refreshInterval=3D1440. [junit4:junit4] 2> 1744 T3205 oass.IndexSchema.readSchema default search = field in schema is text [junit4:junit4] 2> 1749 T3205 oass.IndexSchema.readSchema unique key fiel= d: id [junit4:junit4] 2> 1785 T3205 oass.FileExchangeRateProvider.reload Reload= ing exchange rates from file currency.xml [junit4:junit4] 2> 1792 T3205 oass.FileExchangeRateProvider.reload Reload= ing exchange rates from file currency.xml [junit4:junit4] 2> 1798 T3205 oass.OpenExchangeRatesOrgProvider.reload Re= loading exchange rates from open-exchange-rates.json [junit4:junit4] 2> 1801 T3205 oass.OpenExchangeRatesOrgProvider$OpenExcha= ngeRates. WARNING Unknown key IMPORTANT NOTE [junit4:junit4] 2> 1801 T3205 oass.OpenExchangeRatesOrgProvider$OpenExcha= ngeRates. WARNING Expected key, got STRING [junit4:junit4] 2> 1801 T3205 oass.OpenExchangeRatesOrgProvider.reload Re= loading exchange rates from open-exchange-rates.json [junit4:junit4] 2> 1804 T3205 oass.OpenExchangeRatesOrgProvider$OpenExcha= ngeRates. WARNING Unknown key IMPORTANT NOTE [junit4:junit4] 2> 1804 T3205 oass.OpenExchangeRatesOrgProvider$OpenExcha= ngeRates. WARNING Expected key, got STRING [junit4:junit4] 2> 1804 T3205 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.ChaosMonkeySafeLe= aderTest-controljetty-1362618633270/collection1/, dataDir=3D./org.apache.so= lr.cloud.ChaosMonkeySafeLeaderTest-1362618633034/control/data/ [junit4:junit4] 2> 1805 T3205 oasc.JmxMonitoredMap. JMX monitoring = is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMB= eanServer@3209fa8f [junit4:junit4] 2> 1805 T3205 oasc.SolrCore.initDirectoryFactory solr.Sta= ndardDirectoryFactory [junit4:junit4] 2> 1838 T3205 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.ChaosMonkeySafeLea= derTest-1362618633034/control/data forceNew: false [junit4:junit4] 2> 1839 T3205 oasc.SolrCore.getNewIndexDir New index dire= ctory detected: old=3Dnull new=3D./org.apache.solr.cloud.ChaosMonkeySafeLea= derTest-1362618633034/control/data/index/ [junit4:junit4] 2> 1840 T3205 oasc.SolrCore.initIndex WARNING [collection= 1] Solr index directory './org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-= 1362618633034/control/data/index' doesn't exist. Creating new index... [junit4:junit4] 2> 1840 T3205 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.ChaosMonkeySafeLea= derTest-1362618633034/control/data/index forceNew: false [junit4:junit4] 2> 1847 T3205 oasc.SolrDeletionPolicy.onCommit SolrDeleti= onPolicy.onCommit: commits:num=3D1 [junit4:junit4] 2> =09=09commit{dir=3D/Users/jenkins/jenkins-slave/worksp= ace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/org.apache.solr.c= loud.ChaosMonkeySafeLeaderTest-1362618633034/control/data/index,segFN=3Dseg= ments_1,generation=3D1,filenames=3D[segments_1] [junit4:junit4] 2> 1847 T3205 oasc.SolrDeletionPolicy.updateCommits newes= t commit =3D 1[segments_1] [junit4:junit4] 2> 1850 T3205 oasup.UpdateRequestProcessorChain.init inse= rting DistributedUpdateProcessorFactory into updateRequestProcessorChain "d= edupe" [junit4:junit4] 2> 1850 T3205 oasup.UpdateRequestProcessorChain.init inse= rting DistributedUpdateProcessorFactory into updateRequestProcessorChain "s= tored_sig" [junit4:junit4] 2> 1851 T3205 oasup.UpdateRequestProcessorChain.init inse= rting DistributedUpdateProcessorFactory into updateRequestProcessorChain "d= istrib-dup-test-chain-implicit" [junit4:junit4] 2> 1852 T3205 oasc.RequestHandlers.initHandlersFromConfig= created standard: solr.StandardRequestHandler [junit4:junit4] 2> 1852 T3205 oasc.RequestHandlers.initHandlersFromConfig= created /get: solr.RealTimeGetHandler [junit4:junit4] 2> 1853 T3205 oasc.RequestHandlers.initHandlersFromConfig= adding lazy requestHandler: solr.ReplicationHandler [junit4:junit4] 2> 1853 T3205 oasc.RequestHandlers.initHandlersFromConfig= created /replication: solr.ReplicationHandler [junit4:junit4] 2> 1854 T3205 oasc.RequestHandlers.initHandlersFromConfig= created /update: solr.UpdateRequestHandler [junit4:junit4] 2> 1854 T3205 oasc.RequestHandlers.initHandlersFromConfig= created /admin/: org.apache.solr.handler.admin.AdminHandlers [junit4:junit4] 2> 1861 T3205 oashl.XMLLoader.init xsltCacheLifetimeSecon= ds=3D60 [junit4:junit4] 2> 1870 T3205 oass.SolrIndexSearcher. Opening Searc= her@54d1f0e7 main [junit4:junit4] 2> 1871 T3205 oasu.CommitTracker. Hard AutoCommit: = disabled [junit4:junit4] 2> 1872 T3205 oasu.CommitTracker. Soft AutoCommit: = disabled [junit4:junit4] 2> 1876 T3206 oasc.SolrCore.registerSearcher [collection1= ] Registered new searcher Searcher@54d1f0e7 main{StandardDirectoryReader(se= gments_1:1)} [junit4:junit4] 2> 1878 T3205 oasc.ZkController.publish publishing core= =3Dcollection1 state=3Ddown [junit4:junit4] 2> 1878 T3205 oasc.ZkController.publish numShards not fou= nd on descriptor - reading it from system property [junit4:junit4] 2> 1879 T3185 oazs.PrepRequestProcessor.pRequest Got user= -level KeeperException when processing sessionid:0x13d42664b520003 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> 2302 T3203 oascc.ZkStateReader.updateClusterState Upda= ting cloud state from ZooKeeper...=20 [junit4:junit4] 2> 2304 T3203 oasc.Overseer$ClusterStateUpdater.updateSta= te Update state numShards=3D1 message=3D{ [junit4:junit4] 2> =09 "operation":"state", [junit4:junit4] 2> =09 "core_node_name":null, [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:50051_", [junit4:junit4] 2> =09 "base_url":"http://127.0.0.1:50051"} [junit4:junit4] 2> 2304 T3203 oasc.Overseer$ClusterStateUpdater.createCol= lection Create collection control_collection with numShards 1 [junit4:junit4] 2> 2304 T3203 oasc.Overseer$ClusterStateUpdater.updateSta= te Assigning new node to shard shard=3Dshard1 [junit4:junit4] 2> 2305 T3185 oazs.PrepRequestProcessor.pRequest Got user= -level KeeperException when processing sessionid:0x13d42664b520003 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> 2315 T3202 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> 2885 T3205 oasc.CoreContainer.registerCore registering= core: collection1 [junit4:junit4] 2> 2886 T3205 oasc.ZkController.register Register replica= - core:collection1 address:http://127.0.0.1:50051 collection:control_colle= ction shard:shard1 [junit4:junit4] 2> 2887 T3205 oascc.SolrZkClient.makePath makePath: /coll= ections/control_collection/leader_elect/shard1/election [junit4:junit4] 2> 2902 T3185 oazs.PrepRequestProcessor.pRequest Got user= -level KeeperException when processing sessionid:0x13d42664b520003 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> 2903 T3205 oasc.ShardLeaderElectionContext.runLeaderPr= ocess Running the leader process. [junit4:junit4] 2> 2904 T3185 oazs.PrepRequestProcessor.pRequest Got user= -level KeeperException when processing sessionid:0x13d42664b520003 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> 2908 T3205 oasc.ShardLeaderElectionContext.waitForRepl= icasToComeUp Enough replicas found to continue. [junit4:junit4] 2> 2909 T3205 oasc.ShardLeaderElectionContext.runLeaderPr= ocess I may be the new leader - try and sync [junit4:junit4] 2> 2909 T3205 oasc.SyncStrategy.sync Sync replicas to htt= p://127.0.0.1:50051/collection1/ [junit4:junit4] 2> 2909 T3205 oasc.SyncStrategy.syncReplicas Sync Success= - now sync replicas to me [junit4:junit4] 2> 2909 T3205 oasc.SyncStrategy.syncToMe http://127.0.0.1= :50051/collection1/ has no replicas [junit4:junit4] 2> 2910 T3205 oasc.ShardLeaderElectionContext.runLeaderPr= ocess I am the new leader: http://127.0.0.1:50051/collection1/ [junit4:junit4] 2> 2910 T3205 oascc.SolrZkClient.makePath makePath: /coll= ections/control_collection/leaders/shard1 [junit4:junit4] 2> 2919 T3185 oazs.PrepRequestProcessor.pRequest Got user= -level KeeperException when processing sessionid:0x13d42664b520003 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> 3825 T3203 oascc.ZkStateReader.updateClusterState Upda= ting cloud state from ZooKeeper...=20 [junit4:junit4] 2> 3843 T3202 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> 3900 T3205 oasc.ZkController.register We are http://12= 7.0.0.1:50051/collection1/ and leader is http://127.0.0.1:50051/collection1= / [junit4:junit4] 2> 3901 T3205 oasc.ZkController.register No LogReplay nee= ded for core=3Dcollection1 baseURL=3Dhttp://127.0.0.1:50051 [junit4:junit4] 2> 3901 T3205 oasc.ZkController.checkRecovery I am the le= ader, no recovery necessary [junit4:junit4] 2> 3901 T3205 oasc.ZkController.publish publishing core= =3Dcollection1 state=3Dactive [junit4:junit4] 2> 3901 T3205 oasc.ZkController.publish numShards not fou= nd on descriptor - reading it from system property [junit4:junit4] 2> 3905 T3205 oascc.ZkStateReader.updateClusterState Upda= ting cloud state from ZooKeeper...=20 [junit4:junit4] 2> 3907 T3180 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> 3907 T3180 oass.SolrDispatchFilter.init SolrDispatchFi= lter.init() done [junit4:junit4] 2> 3908 T3180 oascsi.HttpClientUtil.createClient Creating= new http client, config:maxConnections=3D128&maxConnectionsPerHost=3D32&fo= llowRedirects=3Dfalse [junit4:junit4] 2> 3932 T3180 oascsi.HttpClientUtil.createClient Creating= new http client, config: [junit4:junit4] 2> 3933 T3180 oaz.ZooKeeper. Initiating client conn= ection, connectString=3D127.0.0.1:50048/solr sessionTimeout=3D10000 watcher= =3Dorg.apache.solr.common.cloud.ConnectionManager@4f2cef48 [junit4:junit4] 2> 3935 T3180 oascc.ConnectionManager.waitForConnected Wa= iting for client to connect to ZooKeeper [junit4:junit4] 2> 3935 T3208 oaz.ClientCnxn$SendThread.logStartConnect O= pening socket connection to server 127.0.0.1/127.0.0.1:50048. Will not atte= mpt to authenticate using SASL (access denied (javax.security.auth.AuthPerm= ission getLoginConfiguration)) [junit4:junit4] 2> 3937 T3208 oaz.ClientCnxn$SendThread.primeConnection S= ocket connection established to 127.0.0.1/127.0.0.1:50048, initiating sessi= on [junit4:junit4] 2> 3937 T3182 oazs.NIOServerCnxnFactory.run Accepted sock= et connection from /127.0.0.1:50054 [junit4:junit4] 2> 3937 T3182 oazs.ZooKeeperServer.processConnectRequest = Client attempting to establish new session at /127.0.0.1:50054 [junit4:junit4] 2> 3939 T3184 oazs.ZooKeeperServer.finishSessionInit Esta= blished session 0x13d42664b520004 with negotiated timeout 10000 for client = /127.0.0.1:50054 [junit4:junit4] 2> 3939 T3208 oaz.ClientCnxn$SendThread.onConnected Sessi= on establishment complete on server 127.0.0.1/127.0.0.1:50048, sessionid = =3D 0x13d42664b520004, negotiated timeout =3D 10000 [junit4:junit4] 2> 3939 T3209 oascc.ConnectionManager.process Watcher org= .apache.solr.common.cloud.ConnectionManager@4f2cef48 name:ZooKeeperConnecti= on Watcher:127.0.0.1:50048/solr got event WatchedEvent state:SyncConnected = type:None path:null path:null type:None [junit4:junit4] 2> 3939 T3180 oascc.ConnectionManager.waitForConnected Cl= ient is connected to ZooKeeper [junit4:junit4] 2> 3942 T3180 oascc.ZkStateReader.createClusterStateWatch= ersAndUpdate Updating cluster state from ZooKeeper...=20 [junit4:junit4] 2> 3945 T3180 oasc.ChaosMonkey.monkeyLog monkey: init - e= xpire sessions:true cause connection loss:true [junit4:junit4] 2> 4230 T3180 oejs.Server.doStart jetty-8.1.8.v20121106 [junit4:junit4] 2> 4234 T3180 oejs.AbstractConnector.doStart Started Sele= ctChannelConnector@127.0.0.1:50055 [junit4:junit4] 2> 4235 T3180 oass.SolrDispatchFilter.init SolrDispatchFi= lter.init() [junit4:junit4] 2> 4236 T3180 oasc.SolrResourceLoader.locateSolrHome JNDI= not configured for solr (NoInitialContextEx) [junit4:junit4] 2> 4236 T3180 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= .ChaosMonkeySafeLeaderTest-jetty1-1362618636972 [junit4:junit4] 2> 4237 T3180 oasc.CoreContainer$Initializer.initialize l= ooking for solr config file: /Users/jenkins/jenkins-slave/workspace/Lucene-= Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.Chao= sMonkeySafeLeaderTest-jetty1-1362618636972/solr.xml [junit4:junit4] 2> 4237 T3180 oasc.CoreContainer. New CoreContainer= 2019899268 [junit4:junit4] 2> 4238 T3180 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.ChaosMonkeyS= afeLeaderTest-jetty1-1362618636972/' [junit4:junit4] 2> 4239 T3180 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.ChaosM= onkeySafeLeaderTest-jetty1-1362618636972/' [junit4:junit4] 2> 4297 T3180 oashc.HttpShardHandlerFactory.getParameter = Setting socketTimeout to: 120000 [junit4:junit4] 2> 4297 T3180 oashc.HttpShardHandlerFactory.getParameter = Setting urlScheme to: http:// [junit4:junit4] 2> 4298 T3180 oashc.HttpShardHandlerFactory.getParameter = Setting connTimeout to: 15000 [junit4:junit4] 2> 4299 T3180 oashc.HttpShardHandlerFactory.getParameter = Setting maxConnectionsPerHost to: 20 [junit4:junit4] 2> 4299 T3180 oashc.HttpShardHandlerFactory.getParameter = Setting corePoolSize to: 0 [junit4:junit4] 2> 4300 T3180 oashc.HttpShardHandlerFactory.getParameter = Setting maximumPoolSize to: 2147483647 [junit4:junit4] 2> 4300 T3180 oashc.HttpShardHandlerFactory.getParameter = Setting maxThreadIdleTime to: 5 [junit4:junit4] 2> 4301 T3180 oashc.HttpShardHandlerFactory.getParameter = Setting sizeOfQueue to: -1 [junit4:junit4] 2> 4301 T3180 oashc.HttpShardHandlerFactory.getParameter = Setting fairnessPolicy to: false [junit4:junit4] 2> 4302 T3180 oascsi.HttpClientUtil.createClient Creating= new http client, config:maxConnectionsPerHost=3D20&maxConnections=3D10000&= socketTimeout=3D120000&connTimeout=3D15000&retry=3Dfalse [junit4:junit4] 2> 4334 T3180 oasc.CoreContainer.load Registering Log Lis= tener [junit4:junit4] 2> 4359 T3180 oasc.CoreContainer.initZooKeeper Zookeeper = client=3D127.0.0.1:50048/solr [junit4:junit4] 2> 4360 T3180 oasc.ZkController.checkChrootPath zkHost in= cludes chroot [junit4:junit4] 2> 4361 T3180 oaz.ZooKeeper. Initiating client conn= ection, connectString=3D127.0.0.1:50048 sessionTimeout=3D60000 watcher=3Dor= g.apache.solr.common.cloud.ConnectionManager@7e0b52dd [junit4:junit4] 2> 4363 T3180 oascc.ConnectionManager.waitForConnected Wa= iting for client to connect to ZooKeeper [junit4:junit4] 2> 4363 T3219 oaz.ClientCnxn$SendThread.logStartConnect O= pening socket connection to server 127.0.0.1/127.0.0.1:50048. Will not atte= mpt to authenticate using SASL (access denied (javax.security.auth.AuthPerm= ission getLoginConfiguration)) [junit4:junit4] 2> 4365 T3219 oaz.ClientCnxn$SendThread.primeConnection S= ocket connection established to 127.0.0.1/127.0.0.1:50048, initiating sessi= on [junit4:junit4] 2> 4366 T3182 oazs.NIOServerCnxnFactory.run Accepted sock= et connection from /127.0.0.1:50056 [junit4:junit4] 2> 4366 T3182 oazs.ZooKeeperServer.processConnectRequest = Client attempting to establish new session at /127.0.0.1:50056 [junit4:junit4] 2> 4368 T3184 oazs.ZooKeeperServer.finishSessionInit Esta= blished session 0x13d42664b520005 with negotiated timeout 20000 for client = /127.0.0.1:50056 [junit4:junit4] 2> 4368 T3219 oaz.ClientCnxn$SendThread.onConnected Sessi= on establishment complete on server 127.0.0.1/127.0.0.1:50048, sessionid = =3D 0x13d42664b520005, negotiated timeout =3D 20000 [junit4:junit4] 2> 4368 T3220 oascc.ConnectionManager.process Watcher org= .apache.solr.common.cloud.ConnectionManager@7e0b52dd name:ZooKeeperConnecti= on Watcher:127.0.0.1:50048 got event WatchedEvent state:SyncConnected type:= None path:null path:null type:None [junit4:junit4] 2> 4369 T3180 oascc.ConnectionManager.waitForConnected Cl= ient is connected to ZooKeeper [junit4:junit4] 2> 4372 T3185 oazs.PrepRequestProcessor.pRequest2Txn Proc= essed session termination for sessionid: 0x13d42664b520005 [junit4:junit4] 2> 4373 T3182 oazs.NIOServerCnxn.closeSock Closed socket = connection for client /127.0.0.1:50056 which had sessionid 0x13d42664b52000= 5 [junit4:junit4] 2> 4373 T3220 oaz.ClientCnxn$EventThread.run EventThread = shut down [junit4:junit4] 2> 4373 T3180 oaz.ZooKeeper.close Session: 0x13d42664b520= 005 closed [junit4:junit4] 2> 4376 T3180 oascsi.HttpClientUtil.createClient Creating= new http client, config:maxConnections=3D500&maxConnectionsPerHost=3D16&so= cketTimeout=3D120000&connTimeout=3D15000 [junit4:junit4] 2> 4393 T3180 oaz.ZooKeeper. Initiating client conn= ection, connectString=3D127.0.0.1:50048/solr sessionTimeout=3D30000 watcher= =3Dorg.apache.solr.common.cloud.ConnectionManager@5fb27c7c [junit4:junit4] 2> 4395 T3180 oascc.ConnectionManager.waitForConnected Wa= iting for client to connect to ZooKeeper [junit4:junit4] 2> 4395 T3221 oaz.ClientCnxn$SendThread.logStartConnect O= pening socket connection to server 127.0.0.1/127.0.0.1:50048. Will not atte= mpt to authenticate using SASL (access denied (javax.security.auth.AuthPerm= ission getLoginConfiguration)) [junit4:junit4] 2> 4397 T3221 oaz.ClientCnxn$SendThread.primeConnection S= ocket connection established to 127.0.0.1/127.0.0.1:50048, initiating sessi= on [junit4:junit4] 2> 4397 T3182 oazs.NIOServerCnxnFactory.run Accepted sock= et connection from /127.0.0.1:50057 [junit4:junit4] 2> 4398 T3182 oazs.ZooKeeperServer.processConnectRequest = Client attempting to establish new session at /127.0.0.1:50057 [junit4:junit4] 2> 4399 T3184 oazs.ZooKeeperServer.finishSessionInit Esta= blished session 0x13d42664b520006 with negotiated timeout 20000 for client = /127.0.0.1:50057 [junit4:junit4] 2> 4399 T3221 oaz.ClientCnxn$SendThread.onConnected Sessi= on establishment complete on server 127.0.0.1/127.0.0.1:50048, sessionid = =3D 0x13d42664b520006, negotiated timeout =3D 20000 [junit4:junit4] 2> 4400 T3222 oascc.ConnectionManager.process Watcher org= .apache.solr.common.cloud.ConnectionManager@5fb27c7c name:ZooKeeperConnecti= on Watcher:127.0.0.1:50048/solr got event WatchedEvent state:SyncConnected = type:None path:null path:null type:None [junit4:junit4] 2> 4400 T3180 oascc.ConnectionManager.waitForConnected Cl= ient is connected to ZooKeeper [junit4:junit4] 2> 4402 T3185 oazs.PrepRequestProcessor.pRequest Got user= -level KeeperException when processing sessionid:0x13d42664b520006 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> 4403 T3185 oazs.PrepRequestProcessor.pRequest Got user= -level KeeperException when processing sessionid:0x13d42664b520006 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> 4406 T3180 oascc.ZkStateReader.createClusterStateWatch= ersAndUpdate Updating cluster state from ZooKeeper...=20 [junit4:junit4] 2> 5356 T3203 oascc.ZkStateReader.updateClusterState Upda= ting cloud state from ZooKeeper...=20 [junit4:junit4] 2> 5358 T3203 oasc.Overseer$ClusterStateUpdater.updateSta= te Update state numShards=3D1 message=3D{ [junit4:junit4] 2> =09 "operation":"state", [junit4:junit4] 2> =09 "core_node_name":null, [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:50051_", [junit4:junit4] 2> =09 "base_url":"http://127.0.0.1:50051"} [junit4:junit4] 2> 5366 T3222 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> 5366 T3202 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> 5368 T3209 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> 5412 T3180 oasc.ZkController.createEphemeralLiveNode R= egister node as live in ZooKeeper:/live_nodes/127.0.0.1:50055_ [junit4:junit4] 2> 5413 T3185 oazs.PrepRequestProcessor.pRequest Got user= -level KeeperException when processing sessionid:0x13d42664b520006 type:del= ete cxid:0xb zxid:0x4f txntype:-1 reqpath:n/a Error Path:/solr/live_nodes/1= 27.0.0.1:50055_ Error:KeeperErrorCode =3D NoNode for /solr/live_nodes/127.0= .0.1:50055_ [junit4:junit4] 2> 5414 T3180 oascc.SolrZkClient.makePath makePath: /live= _nodes/127.0.0.1:50055_ [junit4:junit4] 2> 5419 T3222 oascc.ZkStateReader$2.process A cluster sta= te change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/= live_nodes, has occurred - updating... (live nodes size: 1) [junit4:junit4] 2> 5421 T3202 oascc.ZkStateReader$3.process Updating live= nodes... (2) [junit4:junit4] 2> 5421 T3209 oascc.ZkStateReader$3.process Updating live= nodes... (2) [junit4:junit4] 2> 5421 T3202 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> 5421 T3209 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> 5424 T3222 oascc.ZkStateReader$3.process Updating live= nodes... (2) [junit4:junit4] 2> 5434 T3223 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= .ChaosMonkeySafeLeaderTest-jetty1-1362618636972/collection1 [junit4:junit4] 2> 5435 T3223 oasc.ZkController.createCollectionZkNode Ch= eck for collection zkNode:collection1 [junit4:junit4] 2> 5436 T3223 oasc.ZkController.createCollectionZkNode Co= llection zkNode exists [junit4:junit4] 2> 5436 T3223 oasc.ZkController.readConfigName Load colle= ction config from:/collections/collection1 [junit4:junit4] 2> 5439 T3223 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.ChaosM= onkeySafeLeaderTest-jetty1-1362618636972/collection1/' [junit4:junit4] 2> 5440 T3223 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.ChaosMonkeySafeLeaderT= est-jetty1-1362618636972/collection1/lib/classes/' to classloader [junit4:junit4] 2> 5440 T3223 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.ChaosMonkeySafeLeaderT= est-jetty1-1362618636972/collection1/lib/README' to classloader [junit4:junit4] 2> 5501 T3223 oasc.SolrConfig. Using Lucene MatchVe= rsion: LUCENE_50 [junit4:junit4] 2> 5577 T3223 oasc.SolrConfig. Loaded SolrConfig: s= olrconfig.xml [junit4:junit4] 2> 5579 T3223 oass.IndexSchema.readSchema Reading Solr Sc= hema [junit4:junit4] 2> 5585 T3223 oass.IndexSchema.readSchema Schema name=3Dt= est [junit4:junit4] 2> 6364 T3223 oass.OpenExchangeRatesOrgProvider.init Init= ialized with rates=3Dopen-exchange-rates.json, refreshInterval=3D1440. [junit4:junit4] 2> 6376 T3223 oass.IndexSchema.readSchema default search = field in schema is text [junit4:junit4] 2> 6381 T3223 oass.IndexSchema.readSchema unique key fiel= d: id [junit4:junit4] 2> 6408 T3223 oass.FileExchangeRateProvider.reload Reload= ing exchange rates from file currency.xml [junit4:junit4] 2> 6415 T3223 oass.FileExchangeRateProvider.reload Reload= ing exchange rates from file currency.xml [junit4:junit4] 2> 6421 T3223 oass.OpenExchangeRatesOrgProvider.reload Re= loading exchange rates from open-exchange-rates.json [junit4:junit4] 2> 6423 T3223 oass.OpenExchangeRatesOrgProvider$OpenExcha= ngeRates. WARNING Unknown key IMPORTANT NOTE [junit4:junit4] 2> 6424 T3223 oass.OpenExchangeRatesOrgProvider$OpenExcha= ngeRates. WARNING Expected key, got STRING [junit4:junit4] 2> 6424 T3223 oass.OpenExchangeRatesOrgProvider.reload Re= loading exchange rates from open-exchange-rates.json [junit4:junit4] 2> 6427 T3223 oass.OpenExchangeRatesOrgProvider$OpenExcha= ngeRates. WARNING Unknown key IMPORTANT NOTE [junit4:junit4] 2> 6427 T3223 oass.OpenExchangeRatesOrgProvider$OpenExcha= ngeRates. WARNING Expected key, got STRING [junit4:junit4] 2> 6427 T3223 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.ChaosMonkeySafeLe= aderTest-jetty1-1362618636972/collection1/, dataDir=3D./org.apache.solr.clo= ud.ChaosMonkeySafeLeaderTest-1362618633034/jetty1/ [junit4:junit4] 2> 6428 T3223 oasc.JmxMonitoredMap. JMX monitoring = is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMB= eanServer@3209fa8f [junit4:junit4] 2> 6428 T3223 oasc.SolrCore.initDirectoryFactory solr.Sta= ndardDirectoryFactory [junit4:junit4] 2> 6430 T3223 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.ChaosMonkeySafeLea= derTest-1362618633034/jetty1 forceNew: false [junit4:junit4] 2> 6430 T3223 oasc.SolrCore.getNewIndexDir New index dire= ctory detected: old=3Dnull new=3D./org.apache.solr.cloud.ChaosMonkeySafeLea= derTest-1362618633034/jetty1/index/ [junit4:junit4] 2> 6431 T3223 oasc.SolrCore.initIndex WARNING [collection= 1] Solr index directory './org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-= 1362618633034/jetty1/index' doesn't exist. Creating new index... [junit4:junit4] 2> 6432 T3223 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.ChaosMonkeySafeLea= derTest-1362618633034/jetty1/index forceNew: false [junit4:junit4] 2> 6438 T3223 oasc.SolrDeletionPolicy.onCommit SolrDeleti= onPolicy.onCommit: commits:num=3D1 [junit4:junit4] 2> =09=09commit{dir=3D/Users/jenkins/jenkins-slave/worksp= ace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/org.apache.solr.c= loud.ChaosMonkeySafeLeaderTest-1362618633034/jetty1/index,segFN=3Dsegments_= 1,generation=3D1,filenames=3D[segments_1] [junit4:junit4] 2> 6438 T3223 oasc.SolrDeletionPolicy.updateCommits newes= t commit =3D 1[segments_1] [junit4:junit4] 2> 6442 T3223 oasup.UpdateRequestProcessorChain.init inse= rting DistributedUpdateProcessorFactory into updateRequestProcessorChain "d= edupe" [junit4:junit4] 2> 6442 T3223 oasup.UpdateRequestProcessorChain.init inse= rting DistributedUpdateProcessorFactory into updateRequestProcessorChain "s= tored_sig" [junit4:junit4] 2> 6443 T3223 oasup.UpdateRequestProcessorChain.init inse= rting DistributedUpdateProcessorFactory into updateRequestProcessorChain "d= istrib-dup-test-chain-implicit" [junit4:junit4] 2> 6444 T3223 oasc.RequestHandlers.initHandlersFromConfig= created standard: solr.StandardRequestHandler [junit4:junit4] 2> 6445 T3223 oasc.RequestHandlers.initHandlersFromConfig= created /get: solr.RealTimeGetHandler [junit4:junit4] 2> 6445 T3223 oasc.RequestHandlers.initHandlersFromConfig= adding lazy requestHandler: solr.ReplicationHandler [junit4:junit4] 2> 6446 T3223 oasc.RequestHandlers.initHandlersFromConfig= created /replication: solr.ReplicationHandler [junit4:junit4] 2> 6446 T3223 oasc.RequestHandlers.initHandlersFromConfig= created /update: solr.UpdateRequestHandler [junit4:junit4] 2> 6447 T3223 oasc.RequestHandlers.initHandlersFromConfig= created /admin/: org.apache.solr.handler.admin.AdminHandlers [junit4:junit4] 2> 6456 T3223 oashl.XMLLoader.init xsltCacheLifetimeSecon= ds=3D60 [junit4:junit4] 2> 6465 T3223 oass.SolrIndexSearcher. Opening Searc= her@6926895a main [junit4:junit4] 2> 6466 T3223 oasu.CommitTracker. Hard AutoCommit: = disabled [junit4:junit4] 2> 6466 T3223 oasu.CommitTracker. Soft AutoCommit: = disabled [junit4:junit4] 2> 6471 T3224 oasc.SolrCore.registerSearcher [collection1= ] Registered new searcher Searcher@6926895a main{StandardDirectoryReader(se= gments_1:1)} [junit4:junit4] 2> 6475 T3223 oasc.ZkController.publish publishing core= =3Dcollection1 state=3Ddown [junit4:junit4] 2> 6475 T3223 oasc.ZkController.publish numShards not fou= nd on descriptor - reading it from system property [junit4:junit4] 2> 6884 T3203 oascc.ZkStateReader.updateClusterState Upda= ting cloud state from ZooKeeper...=20 [junit4:junit4] 2> 6886 T3203 oasc.Overseer$ClusterStateUpdater.updateSta= te Update state numShards=3D3 message=3D{ [junit4:junit4] 2> =09 "operation":"state", [junit4:junit4] 2> =09 "core_node_name":null, [junit4:junit4] 2> =09 "numShards":"3", [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:50055_", [junit4:junit4] 2> =09 "base_url":"http://127.0.0.1:50055"} [junit4:junit4] 2> 6886 T3203 oasc.Overseer$ClusterStateUpdater.createCol= lection Create collection collection1 with numShards 3 [junit4:junit4] 2> 6886 T3203 oasc.Overseer$ClusterStateUpdater.updateSta= te Assigning new node to shard shard=3Dshard1 [junit4:junit4] 2> 6897 T3202 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> 6897 T3222 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> 6897 T3209 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> 7479 T3223 oasc.CoreContainer.registerCore registering= core: collection1 [junit4:junit4] 2> 7479 T3223 oasc.ZkController.register Register replica= - core:collection1 address:http://127.0.0.1:50055 collection:collection1 s= hard:shard1 [junit4:junit4] 2> 7480 T3223 oascc.SolrZkClient.makePath makePath: /coll= ections/collection1/leader_elect/shard1/election [junit4:junit4] 2> 7496 T3185 oazs.PrepRequestProcessor.pRequest Got user= -level KeeperException when processing sessionid:0x13d42664b520006 type:del= ete cxid:0x48 zxid:0x5b txntype:-1 reqpath:n/a Error Path:/solr/collections= /collection1/leaders Error:KeeperErrorCode =3D NoNode for /solr/collections= /collection1/leaders [junit4:junit4] 2> 7497 T3223 oasc.ShardLeaderElectionContext.runLeaderPr= ocess Running the leader process. [junit4:junit4] 2> 7497 T3185 oazs.PrepRequestProcessor.pRequest Got user= -level KeeperException when processing sessionid:0x13d42664b520006 type:cre= ate cxid:0x49 zxid:0x5c txntype:-1 reqpath:n/a Error Path:/solr/overseer Er= ror:KeeperErrorCode =3D NodeExists for /solr/overseer [junit4:junit4] 2> 7501 T3223 oasc.ShardLeaderElectionContext.waitForRepl= icasToComeUp Enough replicas found to continue. [junit4:junit4] 2> 7501 T3223 oasc.ShardLeaderElectionContext.runLeaderPr= ocess I may be the new leader - try and sync [junit4:junit4] 2> 7502 T3223 oasc.SyncStrategy.sync Sync replicas to htt= p://127.0.0.1:50055/collection1/ [junit4:junit4] 2> 7502 T3223 oasc.SyncStrategy.syncReplicas Sync Success= - now sync replicas to me [junit4:junit4] 2> 7502 T3223 oasc.SyncStrategy.syncToMe http://127.0.0.1= :50055/collection1/ has no replicas [junit4:junit4] 2> 7502 T3223 oasc.ShardLeaderElectionContext.runLeaderPr= ocess I am the new leader: http://127.0.0.1:50055/collection1/ [junit4:junit4] 2> 7503 T3223 oascc.SolrZkClient.makePath makePath: /coll= ections/collection1/leaders/shard1 [junit4:junit4] 2> 7511 T3185 oazs.PrepRequestProcessor.pRequest Got user= -level KeeperException when processing sessionid:0x13d42664b520006 type:cre= ate cxid:0x53 zxid:0x60 txntype:-1 reqpath:n/a Error Path:/solr/overseer Er= ror:KeeperErrorCode =3D NodeExists for /solr/overseer [junit4:junit4] 2> 8414 T3203 oascc.ZkStateReader.updateClusterState Upda= ting cloud state from ZooKeeper...=20 [junit4:junit4] 2> 8432 T3222 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> 8432 T3209 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> 8432 T3202 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> 8449 T3223 oasc.ZkController.register We are http://12= 7.0.0.1:50055/collection1/ and leader is http://127.0.0.1:50055/collection1= / [junit4:junit4] 2> 8449 T3223 oasc.ZkController.register No LogReplay nee= ded for core=3Dcollection1 baseURL=3Dhttp://127.0.0.1:50055 [junit4:junit4] 2> 8449 T3223 oasc.ZkController.checkRecovery I am the le= ader, no recovery necessary [junit4:junit4] 2> 8449 T3223 oasc.ZkController.publish publishing core= =3Dcollection1 state=3Dactive [junit4:junit4] 2> 8450 T3223 oasc.ZkController.publish numShards not fou= nd on descriptor - reading it from system property [junit4:junit4] 2> 8453 T3223 oascc.ZkStateReader.updateClusterState Upda= ting cloud state from ZooKeeper...=20 [junit4:junit4] 2> 8455 T3180 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> 8456 T3180 oass.SolrDispatchFilter.init SolrDispatchFi= lter.init() done [junit4:junit4] 2> 8456 T3180 oascsi.HttpClientUtil.createClient Creating= new http client, config:maxConnections=3D128&maxConnectionsPerHost=3D32&fo= llowRedirects=3Dfalse [junit4:junit4] 2> 8767 T3180 oejs.Server.doStart jetty-8.1.8.v20121106 [junit4:junit4] 2> 8772 T3180 oejs.AbstractConnector.doStart Started Sele= ctChannelConnector@127.0.0.1:50058 [junit4:junit4] 2> 8772 T3180 oass.SolrDispatchFilter.init SolrDispatchFi= lter.init() [junit4:junit4] 2> 8773 T3180 oasc.SolrResourceLoader.locateSolrHome JNDI= not configured for solr (NoInitialContextEx) [junit4:junit4] 2> 8774 T3180 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= .ChaosMonkeySafeLeaderTest-jetty2-1362618641503 [junit4:junit4] 2> 8774 T3180 oasc.CoreContainer$Initializer.initialize l= ooking for solr config file: /Users/jenkins/jenkins-slave/workspace/Lucene-= Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.Chao= sMonkeySafeLeaderTest-jetty2-1362618641503/solr.xml [junit4:junit4] 2> 8775 T3180 oasc.CoreContainer. New CoreContainer= 1281894287 [junit4:junit4] 2> 8775 T3180 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.ChaosMonkeyS= afeLeaderTest-jetty2-1362618641503/' [junit4:junit4] 2> 8776 T3180 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.ChaosM= onkeySafeLeaderTest-jetty2-1362618641503/' [junit4:junit4] 2> 8826 T3180 oashc.HttpShardHandlerFactory.getParameter = Setting socketTimeout to: 120000 [junit4:junit4] 2> 8827 T3180 oashc.HttpShardHandlerFactory.getParameter = Setting urlScheme to: http:// [junit4:junit4] 2> 8827 T3180 oashc.HttpShardHandlerFactory.getParameter = Setting connTimeout to: 15000 [junit4:junit4] 2> 8828 T3180 oashc.HttpShardHandlerFactory.getParameter = Setting maxConnectionsPerHost to: 20 [junit4:junit4] 2> 8829 T3180 oashc.HttpShardHandlerFactory.getParameter = Setting corePoolSize to: 0 [junit4:junit4] 2> 8829 T3180 oashc.HttpShardHandlerFactory.getParameter = Setting maximumPoolSize to: 2147483647 [junit4:junit4] 2> 8829 T3180 oashc.HttpShardHandlerFactory.getParameter = Setting maxThreadIdleTime to: 5 [junit4:junit4] 2> 8830 T3180 oashc.HttpShardHandlerFactory.getParameter = Setting sizeOfQueue to: -1 [junit4:junit4] 2> 8830 T3180 oashc.HttpShardHandlerFactory.getParameter = Setting fairnessPolicy to: false [junit4:junit4] 2> 8830 T3180 oascsi.HttpClientUtil.createClient Creating= new http client, config:maxConnectionsPerHost=3D20&maxConnections=3D10000&= socketTimeout=3D120000&connTimeout=3D15000&retry=3Dfalse [junit4:junit4] 2> 8864 T3180 oasc.CoreContainer.load Registering Log Lis= tener [junit4:junit4] 2> 8888 T3180 oasc.CoreContainer.initZooKeeper Zookeeper = client=3D127.0.0.1:50048/solr [junit4:junit4] 2> 8889 T3180 oasc.ZkController.checkChrootPath zkHost in= cludes chroot [junit4:junit4] 2> 8889 T3180 oaz.ZooKeeper. Initiating client conn= ection, connectString=3D127.0.0.1:50048 sessionTimeout=3D60000 watcher=3Dor= g.apache.solr.common.cloud.ConnectionManager@129a89e2 [junit4:junit4] 2> 8891 T3180 oascc.ConnectionManager.waitForConnected Wa= iting for client to connect to ZooKeeper [junit4:junit4] 2> 8891 T3235 oaz.ClientCnxn$SendThread.logStartConnect O= pening socket connection to server 127.0.0.1/127.0.0.1:50048. Will not atte= mpt to authenticate using SASL (access denied (javax.security.auth.AuthPerm= ission getLoginConfiguration)) [junit4:junit4] 2> 8894 T3235 oaz.ClientCnxn$SendThread.primeConnection S= ocket connection established to 127.0.0.1/127.0.0.1:50048, initiating sessi= on [junit4:junit4] 2> 8895 T3182 oazs.NIOServerCnxnFactory.run Accepted sock= et connection from /127.0.0.1:50059 [junit4:junit4] 2> 8895 T3182 oazs.ZooKeeperServer.processConnectRequest = Client attempting to establish new session at /127.0.0.1:50059 [junit4:junit4] 2> 8897 T3184 oazs.ZooKeeperServer.finishSessionInit Esta= blished session 0x13d42664b520007 with negotiated timeout 20000 for client = /127.0.0.1:50059 [junit4:junit4] 2> 8897 T3235 oaz.ClientCnxn$SendThread.onConnected Sessi= on establishment complete on server 127.0.0.1/127.0.0.1:50048, sessionid = =3D 0x13d42664b520007, negotiated timeout =3D 20000 [junit4:junit4] 2> 8897 T3236 oascc.ConnectionManager.process Watcher org= .apache.solr.common.cloud.ConnectionManager@129a89e2 name:ZooKeeperConnecti= on Watcher:127.0.0.1:50048 got event WatchedEvent state:SyncConnected type:= None path:null path:null type:None [junit4:junit4] 2> 8898 T3180 oascc.ConnectionManager.waitForConnected Cl= ient is connected to ZooKeeper [junit4:junit4] 2> 8901 T3185 oazs.PrepRequestProcessor.pRequest2Txn Proc= essed session termination for sessionid: 0x13d42664b520007 [junit4:junit4] 2> 8902 T3182 oazs.NIOServerCnxn.closeSock Closed socket = connection for client /127.0.0.1:50059 which had sessionid 0x13d42664b52000= 7 [junit4:junit4] 2> 8902 T3180 oaz.ZooKeeper.close Session: 0x13d42664b520= 007 closed [junit4:junit4] 2> 8903 T3236 oaz.ClientCnxn$EventThread.run EventThread = shut down [junit4:junit4] 2> 8903 T3180 oascsi.HttpClientUtil.createClient Creating= new http client, config:maxConnections=3D500&maxConnectionsPerHost=3D16&so= cketTimeout=3D120000&connTimeout=3D15000 [junit4:junit4] 2> 8925 T3180 oaz.ZooKeeper. Initiating client conn= ection, connectString=3D127.0.0.1:50048/solr sessionTimeout=3D30000 watcher= =3Dorg.apache.solr.common.cloud.ConnectionManager@7cc27d9c [junit4:junit4] 2> 8927 T3180 oascc.ConnectionManager.waitForConnected Wa= iting for client to connect to ZooKeeper [junit4:junit4] 2> 8927 T3237 oaz.ClientCnxn$SendThread.logStartConnect O= pening socket connection to server 127.0.0.1/127.0.0.1:50048. Will not atte= mpt to authenticate using SASL (access denied (javax.security.auth.AuthPerm= ission getLoginConfiguration)) [junit4:junit4] 2> 8928 T3237 oaz.ClientCnxn$SendThread.primeConnection S= ocket connection established to 127.0.0.1/127.0.0.1:50048, initiating sessi= on [junit4:junit4] 2> 8929 T3182 oazs.NIOServerCnxnFactory.run Accepted sock= et connection from /127.0.0.1:50060 [junit4:junit4] 2> 8930 T3182 oazs.ZooKeeperServer.processConnectRequest = Client attempting to establish new session at /127.0.0.1:50060 [junit4:junit4] 2> 8931 T3184 oazs.ZooKeeperServer.finishSessionInit Esta= blished session 0x13d42664b520008 with negotiated timeout 20000 for client = /127.0.0.1:50060 [junit4:junit4] 2> 8931 T3237 oaz.ClientCnxn$SendThread.onConnected Sessi= on establishment complete on server 127.0.0.1/127.0.0.1:50048, sessionid = =3D 0x13d42664b520008, negotiated timeout =3D 20000 [junit4:junit4] 2> 8932 T3238 oascc.ConnectionManager.process Watcher org= .apache.solr.common.cloud.ConnectionManager@7cc27d9c name:ZooKeeperConnecti= on Watcher:127.0.0.1:50048/solr got event WatchedEvent state:SyncConnected = type:None path:null path:null type:None [junit4:junit4] 2> 8933 T3180 oascc.ConnectionManager.waitForConnected Cl= ient is connected to ZooKeeper [junit4:junit4] 2> 8935 T3185 oazs.PrepRequestProcessor.pRequest Got user= -level KeeperException when processing sessionid:0x13d42664b520008 type:cre= ate cxid:0x1 zxid:0x6d txntype:-1 reqpath:n/a Error Path:/solr/overseer Err= or:KeeperErrorCode =3D NodeExists for /solr/overseer [junit4:junit4] 2> 8937 T3185 oazs.PrepRequestProcessor.pRequest Got user= -level KeeperException when processing sessionid:0x13d42664b520008 type:cre= ate cxid:0x2 zxid:0x6e txntype:-1 reqpath:n/a Error Path:/solr/overseer Err= or:KeeperErrorCode =3D NodeExists for /solr/overseer [junit4:junit4] 2> 8940 T3180 oascc.ZkStateReader.createClusterStateWatch= ersAndUpdate Updating cluster state from ZooKeeper...=20 [junit4:junit4] 2> 9946 T3180 oasc.ZkController.createEphemeralLiveNode R= egister node as live in ZooKeeper:/live_nodes/127.0.0.1:50058_ [junit4:junit4] 2> 9947 T3185 oazs.PrepRequestProcessor.pRequest Got user= -level KeeperException when processing sessionid:0x13d42664b520008 type:del= ete cxid:0x9 zxid:0x6f txntype:-1 reqpath:n/a Error Path:/solr/live_nodes/1= 27.0.0.1:50058_ Error:KeeperErrorCode =3D NoNode for /solr/live_nodes/127.0= .0.1:50058_ [junit4:junit4] 2> 9948 T3203 oascc.ZkStateReader.updateClusterState Upda= ting cloud state from ZooKeeper...=20 [junit4:junit4] 2> 9948 T3180 oascc.SolrZkClient.makePath makePath: /live= _nodes/127.0.0.1:50058_ [junit4:junit4] 2> 9950 T3203 oasc.Overseer$ClusterStateUpdater.updateSta= te Update state numShards=3D3 message=3D{ [junit4:junit4] 2> =09 "operation":"state", [junit4:junit4] 2> =09 "core_node_name":null, [junit4:junit4] 2> =09 "numShards":"3", [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:50055_", [junit4:junit4] 2> =09 "base_url":"http://127.0.0.1:50055"} [junit4:junit4] 2> 9953 T3222 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> 9956 T3209 oascc.ZkStateReader$3.process Updating live= nodes... (3) [junit4:junit4] 2> 9957 T3209 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> 9957 T3238 oascc.ZkStateReader$3.process Updating live= nodes... (3) [junit4:junit4] 2> 9961 T3222 oascc.ZkStateReader$3.process Updating live= nodes... (3) [junit4:junit4] 2> 9962 T3209 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> 9963 T3238 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> 9963 T3222 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> 9971 T3202 oascc.ZkStateReader$3.process Updating live= nodes... (3) [junit4:junit4] 2> 9971 T3202 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> 9973 T3202 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> 9974 T3239 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= .ChaosMonkeySafeLeaderTest-jetty2-1362618641503/collection1 [junit4:junit4] 2> 9975 T3239 oasc.ZkController.createCollectionZkNode Ch= eck for collection zkNode:collection1 [junit4:junit4] 2> 9976 T3239 oasc.ZkController.createCollectionZkNode Co= llection zkNode exists [junit4:junit4] 2> 9976 T3239 oasc.ZkController.readConfigName Load colle= ction config from:/collections/collection1 [junit4:junit4] 2> 9979 T3239 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.ChaosM= onkeySafeLeaderTest-jetty2-1362618641503/collection1/' [junit4:junit4] 2> 9980 T3239 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.ChaosMonkeySafeLeaderT= est-jetty2-1362618641503/collection1/lib/classes/' to classloader [junit4:junit4] 2> 9981 T3239 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.ChaosMonkeySafeLeaderT= est-jetty2-1362618641503/collection1/lib/README' to classloader [junit4:junit4] 2> 10051 T3239 oasc.SolrConfig. Using Lucene MatchV= ersion: LUCENE_50 [junit4:junit4] 2> 10128 T3239 oasc.SolrConfig. Loaded SolrConfig: = solrconfig.xml [junit4:junit4] 2> 10129 T3239 oass.IndexSchema.readSchema Reading Solr S= chema [junit4:junit4] 2> 10135 T3239 oass.IndexSchema.readSchema Schema name=3D= test [junit4:junit4] 2> 10912 T3239 oass.OpenExchangeRatesOrgProvider.init Ini= tialized with rates=3Dopen-exchange-rates.json, refreshInterval=3D1440. [junit4:junit4] 2> 10925 T3239 oass.IndexSchema.readSchema default search= field in schema is text [junit4:junit4] 2> 10929 T3239 oass.IndexSchema.readSchema unique key fie= ld: id [junit4:junit4] 2> 10958 T3239 oass.FileExchangeRateProvider.reload Reloa= ding exchange rates from file currency.xml [junit4:junit4] 2> 10965 T3239 oass.FileExchangeRateProvider.reload Reloa= ding exchange rates from file currency.xml [junit4:junit4] 2> 10972 T3239 oass.OpenExchangeRatesOrgProvider.reload R= eloading exchange rates from open-exchange-rates.json [junit4:junit4] 2> 10974 T3239 oass.OpenExchangeRatesOrgProvider$OpenExch= angeRates. WARNING Unknown key IMPORTANT NOTE [junit4:junit4] 2> 10975 T3239 oass.OpenExchangeRatesOrgProvider$OpenExch= angeRates. WARNING Expected key, got STRING [junit4:junit4] 2> 10975 T3239 oass.OpenExchangeRatesOrgProvider.reload R= eloading exchange rates from open-exchange-rates.json [junit4:junit4] 2> 10977 T3239 oass.OpenExchangeRatesOrgProvider$OpenExch= angeRates. WARNING Unknown key IMPORTANT NOTE [junit4:junit4] 2> 10978 T3239 oass.OpenExchangeRatesOrgProvider$OpenExch= angeRates. WARNING Expected key, got STRING [junit4:junit4] 2> 10978 T3239 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.ChaosMonkeySafeL= eaderTest-jetty2-1362618641503/collection1/, dataDir=3D./org.apache.solr.cl= oud.ChaosMonkeySafeLeaderTest-1362618633034/jetty2/ [junit4:junit4] 2> 10978 T3239 oasc.JmxMonitoredMap. JMX monitoring= is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxM= BeanServer@3209fa8f [junit4:junit4] 2> 10979 T3239 oasc.SolrCore.initDirectoryFactory solr.St= andardDirectoryFactory [junit4:junit4] 2> 10980 T3239 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.ChaosMonkeySafeLe= aderTest-1362618633034/jetty2 forceNew: false [junit4:junit4] 2> 10980 T3239 oasc.SolrCore.getNewIndexDir New index dir= ectory detected: old=3Dnull new=3D./org.apache.solr.cloud.ChaosMonkeySafeLe= aderTest-1362618633034/jetty2/index/ [junit4:junit4] 2> 10981 T3239 oasc.SolrCore.initIndex WARNING [collectio= n1] Solr index directory './org.apache.solr.cloud.ChaosMonkeySafeLeaderTest= -1362618633034/jetty2/index' doesn't exist. Creating new index... [junit4:junit4] 2> 10982 T3239 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.ChaosMonkeySafeLe= aderTest-1362618633034/jetty2/index forceNew: false [junit4:junit4] 2> 10987 T3239 oasc.SolrDeletionPolicy.onCommit SolrDelet= ionPolicy.onCommit: commits:num=3D1 [junit4:junit4] 2> =09=09commit{dir=3D/Users/jenkins/jenkins-slave/worksp= ace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/org.apache.solr.c= loud.ChaosMonkeySafeLeaderTest-1362618633034/jetty2/index,segFN=3Dsegments_= 1,generation=3D1,filenames=3D[segments_1] [junit4:junit4] 2> 10988 T3239 oasc.SolrDeletionPolicy.updateCommits newe= st commit =3D 1[segments_1] [junit4:junit4] 2> 10991 T3239 oasup.UpdateRequestProcessorChain.init ins= erting DistributedUpdateProcessorFactory into updateRequestProcessorChain "= dedupe" [junit4:junit4] 2> 10991 T3239 oasup.UpdateRequestProcessorChain.init ins= erting DistributedUpdateProcessorFactory into updateRequestProcessorChain "= stored_sig" [junit4:junit4] 2> 10992 T3239 oasup.UpdateRequestProcessorChain.init ins= erting DistributedUpdateProcessorFactory into updateRequestProcessorChain "= distrib-dup-test-chain-implicit" [junit4:junit4] 2> 10993 T3239 oasc.RequestHandlers.initHandlersFromConfi= g created standard: solr.StandardRequestHandler [junit4:junit4] 2> 10993 T3239 oasc.RequestHandlers.initHandlersFromConfi= g created /get: solr.RealTimeGetHandler [junit4:junit4] 2> 10994 T3239 oasc.RequestHandlers.initHandlersFromConfi= g adding lazy requestHandler: solr.ReplicationHandler [junit4:junit4] 2> 10994 T3239 oasc.RequestHandlers.initHandlersFromConfi= g created /replication: solr.ReplicationHandler [junit4:junit4] 2> 10995 T3239 oasc.RequestHandlers.initHandlersFromConfi= g created /update: solr.UpdateRequestHandler [junit4:junit4] 2> 10996 T3239 oasc.RequestHandlers.initHandlersFromConfi= g created /admin/: org.apache.solr.handler.admin.AdminHandlers [junit4:junit4] 2> 11003 T3239 oashl.XMLLoader.init xsltCacheLifetimeSeco= nds=3D60 [junit4:junit4] 2> 11011 T3239 oass.SolrIndexSearcher. Opening Sear= cher@339475e2 main [junit4:junit4] 2> 11012 T3239 oasu.CommitTracker. Hard AutoCommit:= disabled [junit4:junit4] 2> 11012 T3239 oasu.CommitTracker. Soft AutoCommit:= disabled [junit4:junit4] 2> 11018 T3240 oasc.SolrCore.registerSearcher [collection= 1] Registered new searcher Searcher@339475e2 main{StandardDirectoryReader(s= egments_1:1)} [junit4:junit4] 2> 11021 T3239 oasc.ZkController.publish publishing core= =3Dcollection1 state=3Ddown [junit4:junit4] 2> 11021 T3239 oasc.ZkController.publish numShards not fo= und on descriptor - reading it from system property [junit4:junit4] 2> 11476 T3203 oascc.ZkStateReader.updateClusterState Upd= ating cloud state from ZooKeeper...=20 [junit4:junit4] 2> 11478 T3203 oasc.Overseer$ClusterStateUpdater.updateSt= ate Update state numShards=3D3 message=3D{ [junit4:junit4] 2> =09 "operation":"state", [junit4:junit4] 2> =09 "core_node_name":null, [junit4:junit4] 2> =09 "numShards":"3", [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:50058_", [junit4:junit4] 2> =09 "base_url":"http://127.0.0.1:50058"} [junit4:junit4] 2> 11478 T3203 oasc.Overseer$ClusterStateUpdater.updateSt= ate Collection already exists with numShards=3D3 [junit4:junit4] 2> 11478 T3203 oasc.Overseer$ClusterStateUpdater.updateSt= ate Assigning new node to shard shard=3Dshard2 [junit4:junit4] 2> 11486 T3209 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> 11487 T3222 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> 11487 T3202 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> 11488 T3238 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> 12025 T3239 oasc.CoreContainer.registerCore registerin= g core: collection1 [junit4:junit4] 2> 12025 T3239 oasc.ZkController.register Register replic= a - core:collection1 address:http://127.0.0.1:50058 collection:collection1 = shard:shard2 [junit4:junit4] 2> 12027 T3239 oascc.SolrZkClient.makePath makePath: /col= lections/collection1/leader_elect/shard2/election [junit4:junit4] 2> 12042 T3185 oazs.PrepRequestProcessor.pRequest Got use= r-level KeeperException when processing sessionid:0x13d42664b520008 type:de= lete cxid:0x45 zxid:0x7e txntype:-1 reqpath:n/a Error Path:/solr/collection= s/collection1/leaders/shard2 Error:KeeperErrorCode =3D NoNode for /solr/col= lections/collection1/leaders/shard2 [junit4:junit4] 2> 12043 T3239 oasc.ShardLeaderElectionContext.runLeaderP= rocess Running the leader process. [junit4:junit4] 2> 12044 T3185 oazs.PrepRequestProcessor.pRequest Got use= r-level KeeperException when processing sessionid:0x13d42664b520008 type:cr= eate cxid:0x46 zxid:0x7f txntype:-1 reqpath:n/a Error Path:/solr/overseer E= rror:KeeperErrorCode =3D NodeExists for /solr/overseer [junit4:junit4] 2> 12048 T3239 oasc.ShardLeaderElectionContext.waitForRep= licasToComeUp Enough replicas found to continue. [junit4:junit4] 2> 12048 T3239 oasc.ShardLeaderElectionContext.runLeaderP= rocess I may be the new leader - try and sync [junit4:junit4] 2> 12048 T3239 oasc.SyncStrategy.sync Sync replicas to ht= tp://127.0.0.1:50058/collection1/ [junit4:junit4] 2> 12048 T3239 oasc.SyncStrategy.syncReplicas Sync Succes= s - now sync replicas to me [junit4:junit4] 2> 12049 T3239 oasc.SyncStrategy.syncToMe http://127.0.0.= 1:50058/collection1/ has no replicas [junit4:junit4] 2> 12049 T3239 oasc.ShardLeaderElectionContext.runLeaderP= rocess I am the new leader: http://127.0.0.1:50058/collection1/ [junit4:junit4] 2> 12049 T3239 oascc.SolrZkClient.makePath makePath: /col= lections/collection1/leaders/shard2 [junit4:junit4] 2> 12057 T3185 oazs.PrepRequestProcessor.pRequest Got use= r-level KeeperException when processing sessionid:0x13d42664b520008 type:cr= eate cxid:0x4f zxid:0x82 txntype:-1 reqpath:n/a Error Path:/solr/overseer E= rror:KeeperErrorCode =3D NodeExists for /solr/overseer [junit4:junit4] 2> 12999 T3203 oascc.ZkStateReader.updateClusterState Upd= ating cloud state from ZooKeeper...=20 [junit4:junit4] 2> 13016 T3222 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> 13016 T3209 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> 13017 T3238 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> 13016 T3202 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> 13056 T3239 oasc.ZkController.register We are http://1= 27.0.0.1:50058/collection1/ and leader is http://127.0.0.1:50058/collection= 1/ [junit4:junit4] 2> 13057 T3239 oasc.ZkController.register No LogReplay ne= eded for core=3Dcollection1 baseURL=3Dhttp://127.0.0.1:50058 [junit4:junit4] 2> 13057 T3239 oasc.ZkController.checkRecovery I am the l= eader, no recovery necessary [junit4:junit4] 2> 13057 T3239 oasc.ZkController.publish publishing core= =3Dcollection1 state=3Dactive [junit4:junit4] 2> 13057 T3239 oasc.ZkController.publish numShards not fo= und on descriptor - reading it from system property [junit4:junit4] 2> 13061 T3239 oascc.ZkStateReader.updateClusterState Upd= ating cloud state from ZooKeeper...=20 [junit4:junit4] 2> 13063 T3180 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> 13063 T3180 oass.SolrDispatchFilter.init SolrDispatchF= ilter.init() done [junit4:junit4] 2> 13064 T3180 oascsi.HttpClientUtil.createClient Creatin= g new http client, config:maxConnections=3D128&maxConnectionsPerHost=3D32&f= ollowRedirects=3Dfalse [junit4:junit4] 2> 13375 T3180 oejs.Server.doStart jetty-8.1.8.v20121106 [junit4:junit4] 2> 13380 T3180 oejs.AbstractConnector.doStart Started Sel= ectChannelConnector@127.0.0.1:50061 [junit4:junit4] 2> 13380 T3180 oass.SolrDispatchFilter.init SolrDispatchF= ilter.init() [junit4:junit4] 2> 13381 T3180 oasc.SolrResourceLoader.locateSolrHome JND= I not configured for solr (NoInitialContextEx) [junit4:junit4] 2> 13381 T3180 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.ChaosMonkeySafeLeaderTest-jetty3-1362618646113 [junit4:junit4] 2> 13382 T3180 oasc.CoreContainer$Initializer.initialize = looking for solr config file: /Users/jenkins/jenkins-slave/workspace/Lucene= -Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.Cha= osMonkeySafeLeaderTest-jetty3-1362618646113/solr.xml [junit4:junit4] 2> 13382 T3180 oasc.CoreContainer. New CoreContaine= r 585449618 [junit4:junit4] 2> 13383 T3180 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.ChaosMonkey= SafeLeaderTest-jetty3-1362618646113/' [junit4:junit4] 2> 13384 T3180 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.Chaos= MonkeySafeLeaderTest-jetty3-1362618646113/' [junit4:junit4] 2> 13429 T3180 oashc.HttpShardHandlerFactory.getParameter= Setting socketTimeout to: 120000 [junit4:junit4] 2> 13430 T3180 oashc.HttpShardHandlerFactory.getParameter= Setting urlScheme to: http:// [junit4:junit4] 2> 13431 T3180 oashc.HttpShardHandlerFactory.getParameter= Setting connTimeout to: 15000 [junit4:junit4] 2> 13432 T3180 oashc.HttpShardHandlerFactory.getParameter= Setting maxConnectionsPerHost to: 20 [junit4:junit4] 2> 13432 T3180 oashc.HttpShardHandlerFactory.getParameter= Setting corePoolSize to: 0 [junit4:junit4] 2> 13433 T3180 oashc.HttpShardHandlerFactory.getParameter= Setting maximumPoolSize to: 2147483647 [junit4:junit4] 2> 13433 T3180 oashc.HttpShardHandlerFactory.getParameter= Setting maxThreadIdleTime to: 5 [junit4:junit4] 2> 13434 T3180 oashc.HttpShardHandlerFactory.getParameter= Setting sizeOfQueue to: -1 [junit4:junit4] 2> 13435 T3180 oashc.HttpShardHandlerFactory.getParameter= Setting fairnessPolicy to: false [junit4:junit4] 2> 13435 T3180 oascsi.HttpClientUtil.createClient Creatin= g new http client, config:maxConnectionsPerHost=3D20&maxConnections=3D10000= &socketTimeout=3D120000&connTimeout=3D15000&retry=3Dfalse [junit4:junit4] 2> 13469 T3180 oasc.CoreContainer.load Registering Log Li= stener [junit4:junit4] 2> 13495 T3180 oasc.CoreContainer.initZooKeeper Zookeeper= client=3D127.0.0.1:50048/solr [junit4:junit4] 2> 13496 T3180 oasc.ZkController.checkChrootPath zkHost i= ncludes chroot [junit4:junit4] 2> 13497 T3180 oaz.ZooKeeper. Initiating client con= nection, connectString=3D127.0.0.1:50048 sessionTimeout=3D60000 watcher=3Do= rg.apache.solr.common.cloud.ConnectionManager@6915ecdd [junit4:junit4] 2> 13498 T3180 oascc.ConnectionManager.waitForConnected W= aiting for client to connect to ZooKeeper [junit4:junit4] 2> 13499 T3251 oaz.ClientCnxn$SendThread.logStartConnect = Opening socket connection to server 127.0.0.1/127.0.0.1:50048. Will not att= empt to authenticate using SASL (access denied (javax.security.auth.AuthPer= mission getLoginConfiguration)) [junit4:junit4] 2> 13500 T3251 oaz.ClientCnxn$SendThread.primeConnection = Socket connection established to 127.0.0.1/127.0.0.1:50048, initiating sess= ion [junit4:junit4] 2> 13501 T3182 oazs.NIOServerCnxnFactory.run Accepted soc= ket connection from /127.0.0.1:50062 [junit4:junit4] 2> 13502 T3182 oazs.ZooKeeperServer.processConnectRequest= Client attempting to establish new session at /127.0.0.1:50062 [junit4:junit4] 2> 13523 T3184 oazs.ZooKeeperServer.finishSessionInit Est= ablished session 0x13d42664b520009 with negotiated timeout 20000 for client= /127.0.0.1:50062 [junit4:junit4] 2> 13523 T3251 oaz.ClientCnxn$SendThread.onConnected Sess= ion establishment complete on server 127.0.0.1/127.0.0.1:50048, sessionid = =3D 0x13d42664b520009, negotiated timeout =3D 20000 [junit4:junit4] 2> 13524 T3252 oascc.ConnectionManager.process Watcher or= g.apache.solr.common.cloud.ConnectionManager@6915ecdd name:ZooKeeperConnect= ion Watcher:127.0.0.1:50048 got event WatchedEvent state:SyncConnected type= :None path:null path:null type:None [junit4:junit4] 2> 13524 T3180 oascc.ConnectionManager.waitForConnected C= lient is connected to ZooKeeper [junit4:junit4] 2> 13527 T3185 oazs.PrepRequestProcessor.pRequest2Txn Pro= cessed session termination for sessionid: 0x13d42664b520009 [junit4:junit4] 2> 13528 T3182 oazs.NIOServerCnxn.closeSock Closed socket= connection for client /127.0.0.1:50062 which had sessionid 0x13d42664b5200= 09 [junit4:junit4] 2> 13528 T3180 oaz.ZooKeeper.close Session: 0x13d42664b52= 0009 closed [junit4:junit4] 2> 13529 T3252 oaz.ClientCnxn$EventThread.run EventThread= shut down [junit4:junit4] 2> 13529 T3180 oascsi.HttpClientUtil.createClient Creatin= g new http client, config:maxConnections=3D500&maxConnectionsPerHost=3D16&s= ocketTimeout=3D120000&connTimeout=3D15000 [junit4:junit4] 2> 13553 T3180 oaz.ZooKeeper. Initiating client con= nection, connectString=3D127.0.0.1:50048/solr sessionTimeout=3D30000 watche= r=3Dorg.apache.solr.common.cloud.ConnectionManager@6bda3885 [junit4:junit4] 2> 13555 T3180 oascc.ConnectionManager.waitForConnected W= aiting for client to connect to ZooKeeper [junit4:junit4] 2> 13556 T3253 oaz.ClientCnxn$SendThread.logStartConnect = Opening socket connection to server 127.0.0.1/127.0.0.1:50048. Will not att= empt to authenticate using SASL (access denied (javax.security.auth.AuthPer= mission getLoginConfiguration)) [junit4:junit4] 2> 13557 T3253 oaz.ClientCnxn$SendThread.primeConnection = Socket connection established to 127.0.0.1/127.0.0.1:50048, initiating sess= ion [junit4:junit4] 2> 13557 T3182 oazs.NIOServerCnxnFactory.run Accepted soc= ket connection from /127.0.0.1:50063 [junit4:junit4] 2> 13558 T3182 oazs.ZooKeeperServer.processConnectRequest= Client attempting to establish new session at /127.0.0.1:50063 [junit4:junit4] 2> 13560 T3184 oazs.ZooKeeperServer.finishSessionInit Est= ablished session 0x13d42664b52000a with negotiated timeout 20000 for client= /127.0.0.1:50063 [junit4:junit4] 2> 13560 T3253 oaz.ClientCnxn$SendThread.onConnected Sess= ion establishment complete on server 127.0.0.1/127.0.0.1:50048, sessionid = =3D 0x13d42664b52000a, negotiated timeout =3D 20000 [junit4:junit4] 2> 13561 T3254 oascc.ConnectionManager.process Watcher or= g.apache.solr.common.cloud.ConnectionManager@6bda3885 name:ZooKeeperConnect= ion Watcher:127.0.0.1:50048/solr got event WatchedEvent state:SyncConnected= type:None path:null path:null type:None [junit4:junit4] 2> 13561 T3180 oascc.ConnectionManager.waitForConnected C= lient is connected to ZooKeeper [junit4:junit4] 2> 13563 T3185 oazs.PrepRequestProcessor.pRequest Got use= r-level KeeperException when processing sessionid:0x13d42664b52000a type:cr= eate cxid:0x1 zxid:0x8f txntype:-1 reqpath:n/a Error Path:/solr/overseer Er= ror:KeeperErrorCode =3D NodeExists for /solr/overseer [junit4:junit4] 2> 13565 T3185 oazs.PrepRequestProcessor.pRequest Got use= r-level KeeperException when processing sessionid:0x13d42664b52000a type:cr= eate cxid:0x2 zxid:0x90 txntype:-1 reqpath:n/a Error Path:/solr/overseer Er= ror:KeeperErrorCode =3D NodeExists for /solr/overseer [junit4:junit4] 2> 13569 T3180 oascc.ZkStateReader.createClusterStateWatc= hersAndUpdate Updating cluster state from ZooKeeper...=20 [junit4:junit4] 2> 14532 T3203 oascc.ZkStateReader.updateClusterState Upd= ating cloud state from ZooKeeper...=20 [junit4:junit4] 2> 14533 T3203 oasc.Overseer$ClusterStateUpdater.updateSt= ate Update state numShards=3D3 message=3D{ [junit4:junit4] 2> =09 "operation":"state", [junit4:junit4] 2> =09 "core_node_name":null, [junit4:junit4] 2> =09 "numShards":"3", [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:50058_", [junit4:junit4] 2> =09 "base_url":"http://127.0.0.1:50058"} [junit4:junit4] 2> 14542 T3254 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> 14542 T3209 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> 14544 T3202 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> 14545 T3222 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> 14546 T3238 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> 14579 T3180 oasc.ZkController.createEphemeralLiveNode = Register node as live in ZooKeeper:/live_nodes/127.0.0.1:50061_ [junit4:junit4] 2> 14580 T3185 oazs.PrepRequestProcessor.pRequest Got use= r-level KeeperException when processing sessionid:0x13d42664b52000a type:de= lete cxid:0xb zxid:0x95 txntype:-1 reqpath:n/a Error Path:/solr/live_nodes/= 127.0.0.1:50061_ Error:KeeperErrorCode =3D NoNode for /solr/live_nodes/127.= 0.0.1:50061_ [junit4:junit4] 2> 14582 T3180 oascc.SolrZkClient.makePath makePath: /liv= e_nodes/127.0.0.1:50061_ [junit4:junit4] 2> 14586 T3222 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> 14587 T3238 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> 14589 T3254 oascc.ZkStateReader$3.process Updating liv= e nodes... (4) [junit4:junit4] 2> 14589 T3254 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> 14590 T3202 oascc.ZkStateReader$3.process Updating liv= e nodes... (4) [junit4:junit4] 2> 14590 T3202 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> 14590 T3209 oascc.ZkStateReader$3.process Updating liv= e nodes... (4) [junit4:junit4] 2> 14591 T3209 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> 14594 T3238 oascc.ZkStateReader$3.process Updating liv= e nodes... (4) [junit4:junit4] 2> 14596 T3222 oascc.ZkStateReader$3.process Updating liv= e nodes... (4) [junit4:junit4] 2> 14604 T3255 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.ChaosMonkeySafeLeaderTest-jetty3-1362618646113/collection1 [junit4:junit4] 2> 14605 T3255 oasc.ZkController.createCollectionZkNode C= heck for collection zkNode:collection1 [junit4:junit4] 2> 14606 T3255 oasc.ZkController.createCollectionZkNode C= ollection zkNode exists [junit4:junit4] 2> 14607 T3255 oasc.ZkController.readConfigName Load coll= ection config from:/collections/collection1 [junit4:junit4] 2> 14610 T3255 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.Chaos= MonkeySafeLeaderTest-jetty3-1362618646113/collection1/' [junit4:junit4] 2> 14612 T3255 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.ChaosMonkeySafeLeader= Test-jetty3-1362618646113/collection1/lib/classes/' to classloader [junit4:junit4] 2> 14613 T3255 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.ChaosMonkeySafeLeader= Test-jetty3-1362618646113/collection1/lib/README' to classloader [junit4:junit4] 2> 14678 T3255 oasc.SolrConfig. Using Lucene MatchV= ersion: LUCENE_50 [junit4:junit4] 2> 14757 T3255 oasc.SolrConfig. Loaded SolrConfig: = solrconfig.xml [junit4:junit4] 2> 14760 T3255 oass.IndexSchema.readSchema Reading Solr S= chema [junit4:junit4] 2> 14766 T3255 oass.IndexSchema.readSchema Schema name=3D= test [junit4:junit4] 2> 15598 T3255 oass.OpenExchangeRatesOrgProvider.init Ini= tialized with rates=3Dopen-exchange-rates.json, refreshInterval=3D1440. [junit4:junit4] 2> 15612 T3255 oass.IndexSchema.readSchema default search= field in schema is text [junit4:junit4] 2> 15616 T3255 oass.IndexSchema.readSchema unique key fie= ld: id [junit4:junit4] 2> 15650 T3255 oass.FileExchangeRateProvider.reload Reloa= ding exchange rates from file currency.xml [junit4:junit4] 2> 15660 T3255 oass.FileExchangeRateProvider.reload Reloa= ding exchange rates from file currency.xml [junit4:junit4] 2> 15671 T3255 oass.OpenExchangeRatesOrgProvider.reload R= eloading exchange rates from open-exchange-rates.json [junit4:junit4] 2> 15674 T3255 oass.OpenExchangeRatesOrgProvider$OpenExch= angeRates. WARNING Unknown key IMPORTANT NOTE [junit4:junit4] 2> 15675 T3255 oass.OpenExchangeRatesOrgProvider$OpenExch= angeRates. WARNING Expected key, got STRING [junit4:junit4] 2> 15676 T3255 oass.OpenExchangeRatesOrgProvider.reload R= eloading exchange rates from open-exchange-rates.json [junit4:junit4] 2> 15678 T3255 oass.OpenExchangeRatesOrgProvider$OpenExch= angeRates. WARNING Unknown key IMPORTANT NOTE [junit4:junit4] 2> 15679 T3255 oass.OpenExchangeRatesOrgProvider$OpenExch= angeRates. WARNING Expected key, got STRING [junit4:junit4] 2> 15679 T3255 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.ChaosMonkeySafeL= eaderTest-jetty3-1362618646113/collection1/, dataDir=3D./org.apache.solr.cl= oud.ChaosMonkeySafeLeaderTest-1362618633034/jetty3/ [junit4:junit4] 2> 15680 T3255 oasc.JmxMonitoredMap. JMX monitoring= is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxM= BeanServer@3209fa8f [junit4:junit4] 2> 15681 T3255 oasc.SolrCore.initDirectoryFactory solr.St= andardDirectoryFactory [junit4:junit4] 2> 15682 T3255 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.ChaosMonkeySafeLe= aderTest-1362618633034/jetty3 forceNew: false [junit4:junit4] 2> 15683 T3255 oasc.SolrCore.getNewIndexDir New index dir= ectory detected: old=3Dnull new=3D./org.apache.solr.cloud.ChaosMonkeySafeLe= aderTest-1362618633034/jetty3/index/ [junit4:junit4] 2> 15684 T3255 oasc.SolrCore.initIndex WARNING [collectio= n1] Solr index directory './org.apache.solr.cloud.ChaosMonkeySafeLeaderTest= -1362618633034/jetty3/index' doesn't exist. Creating new index... [junit4:junit4] 2> 15685 T3255 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.ChaosMonkeySafeLe= aderTest-1362618633034/jetty3/index forceNew: false [junit4:junit4] 2> 15693 T3255 oasc.SolrDeletionPolicy.onCommit SolrDelet= ionPolicy.onCommit: commits:num=3D1 [junit4:junit4] 2> =09=09commit{dir=3D/Users/jenkins/jenkins-slave/worksp= ace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/org.apache.solr.c= loud.ChaosMonkeySafeLeaderTest-1362618633034/jetty3/index,segFN=3Dsegments_= 1,generation=3D1,filenames=3D[segments_1] [junit4:junit4] 2> 15694 T3255 oasc.SolrDeletionPolicy.updateCommits newe= st commit =3D 1[segments_1] [junit4:junit4] 2> 15697 T3255 oasup.UpdateRequestProcessorChain.init ins= erting DistributedUpdateProcessorFactory into updateRequestProcessorChain "= dedupe" [junit4:junit4] 2> 15697 T3255 oasup.UpdateRequestProcessorChain.init ins= erting DistributedUpdateProcessorFactory into updateRequestProcessorChain "= stored_sig" [junit4:junit4] 2> 15699 T3255 oasup.UpdateRequestProcessorChain.init ins= erting DistributedUpdateProcessorFactory into updateRequestProcessorChain "= distrib-dup-test-chain-implicit" [junit4:junit4] 2> 15700 T3255 oasc.RequestHandlers.initHandlersFromConfi= g created standard: solr.StandardRequestHandler [junit4:junit4] 2> 15700 T3255 oasc.RequestHandlers.initHandlersFromConfi= g created /get: solr.RealTimeGetHandler [junit4:junit4] 2> 15701 T3255 oasc.RequestHandlers.initHandlersFromConfi= g adding lazy requestHandler: solr.ReplicationHandler [junit4:junit4] 2> 15701 T3255 oasc.RequestHandlers.initHandlersFromConfi= g created /replication: solr.ReplicationHandler [junit4:junit4] 2> 15702 T3255 oasc.RequestHandlers.initHandlersFromConfi= g created /update: solr.UpdateRequestHandler [junit4:junit4] 2> 15702 T3255 oasc.RequestHandlers.initHandlersFromConfi= g created /admin/: org.apache.solr.handler.admin.AdminHandlers [junit4:junit4] 2> 15710 T3255 oashl.XMLLoader.init xsltCacheLifetimeSeco= nds=3D60 [junit4:junit4] 2> 15719 T3255 oass.SolrIndexSearcher. Opening Sear= cher@521352d8 main [junit4:junit4] 2> 15720 T3255 oasu.CommitTracker. Hard AutoCommit:= disabled [junit4:junit4] 2> 15721 T3255 oasu.CommitTracker. Soft AutoCommit:= disabled [junit4:junit4] 2> 15726 T3256 oasc.SolrCore.registerSearcher [collection= 1] Registered new searcher Searcher@521352d8 main{StandardDirectoryReader(s= egments_1:1)} [junit4:junit4] 2> 15729 T3255 oasc.ZkController.publish publishing core= =3Dcollection1 state=3Ddown [junit4:junit4] 2> 15729 T3255 oasc.ZkController.publish numShards not fo= und on descriptor - reading it from system property [junit4:junit4] 2> 16067 T3203 oascc.ZkStateReader.updateClusterState Upd= ating cloud state from ZooKeeper...=20 [junit4:junit4] 2> 16068 T3203 oasc.Overseer$ClusterStateUpdater.updateSt= ate Update state numShards=3D3 message=3D{ [junit4:junit4] 2> =09 "operation":"state", [junit4:junit4] 2> =09 "core_node_name":null, [junit4:junit4] 2> =09 "numShards":"3", [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:50061_", [junit4:junit4] 2> =09 "base_url":"http://127.0.0.1:50061"} [junit4:junit4] 2> 16071 T3203 oasc.Overseer$ClusterStateUpdater.updateSt= ate Collection already exists with numShards=3D3 [junit4:junit4] 2> 16071 T3203 oasc.Overseer$ClusterStateUpdater.updateSt= ate Assigning new node to shard shard=3Dshard3 [junit4:junit4] 2> 16088 T3254 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> 16089 T3209 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> 16089 T3202 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> 16089 T3222 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> 16089 T3238 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> 16734 T3255 oasc.CoreContainer.registerCore registerin= g core: collection1 [junit4:junit4] 2> 16734 T3255 oasc.ZkController.register Register replic= a - core:collection1 address:http://127.0.0.1:50061 collection:collection1 = shard:shard3 [junit4:junit4] 2> 16736 T3255 oascc.SolrZkClient.makePath makePath: /col= lections/collection1/leader_elect/shard3/election [junit4:junit4] 2> 16749 T3185 oazs.PrepRequestProcessor.pRequest Got use= r-level KeeperException when processing sessionid:0x13d42664b52000a type:de= lete cxid:0x47 zxid:0xa0 txntype:-1 reqpath:n/a Error Path:/solr/collection= s/collection1/leaders/shard3 Error:KeeperErrorCode =3D NoNode for /solr/col= lections/collection1/leaders/shard3 [junit4:junit4] 2> 16750 T3255 oasc.ShardLeaderElectionContext.runLeaderP= rocess Running the leader process. [junit4:junit4] 2> 16752 T3185 oazs.PrepRequestProcessor.pRequest Got use= r-level KeeperException when processing sessionid:0x13d42664b52000a type:cr= eate cxid:0x48 zxid:0xa1 txntype:-1 reqpath:n/a Error Path:/solr/overseer E= rror:KeeperErrorCode =3D NodeExists for /solr/overseer [junit4:junit4] 2> 16756 T3255 oasc.ShardLeaderElectionContext.waitForRep= licasToComeUp Enough replicas found to continue. [junit4:junit4] 2> 16756 T3255 oasc.ShardLeaderElectionContext.runLeaderP= rocess I may be the new leader - try and sync [junit4:junit4] 2> 16757 T3255 oasc.SyncStrategy.sync Sync replicas to ht= tp://127.0.0.1:50061/collection1/ [junit4:junit4] 2> 16757 T3255 oasc.SyncStrategy.syncReplicas Sync Succes= s - now sync replicas to me [junit4:junit4] 2> 16757 T3255 oasc.SyncStrategy.syncToMe http://127.0.0.= 1:50061/collection1/ has no replicas [junit4:junit4] 2> 16758 T3255 oasc.ShardLeaderElectionContext.runLeaderP= rocess I am the new leader: http://127.0.0.1:50061/collection1/ [junit4:junit4] 2> 16758 T3255 oascc.SolrZkClient.makePath makePath: /col= lections/collection1/leaders/shard3 [junit4:junit4] 2> 16767 T3185 oazs.PrepRequestProcessor.pRequest Got use= r-level KeeperException when processing sessionid:0x13d42664b52000a type:cr= eate cxid:0x51 zxid:0xa4 txntype:-1 reqpath:n/a Error Path:/solr/overseer E= rror:KeeperErrorCode =3D NodeExists for /solr/overseer [junit4:junit4] 2> 17608 T3203 oascc.ZkStateReader.updateClusterState Upd= ating cloud state from ZooKeeper...=20 [junit4:junit4] 2> 17627 T3209 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> 17628 T3222 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> 17628 T3254 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> 17628 T3238 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> 17628 T3202 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> 17660 T3255 oasc.ZkController.register We are http://1= 27.0.0.1:50061/collection1/ and leader is http://127.0.0.1:50061/collection= 1/ [junit4:junit4] 2> 17661 T3255 oasc.ZkController.register No LogReplay ne= eded for core=3Dcollection1 baseURL=3Dhttp://127.0.0.1:50061 [junit4:junit4] 2> 17661 T3255 oasc.ZkController.checkRecovery I am the l= eader, no recovery necessary [junit4:junit4] 2> 17661 T3255 oasc.ZkController.publish publishing core= =3Dcollection1 state=3Dactive [junit4:junit4] 2> 17662 T3255 oasc.ZkController.publish numShards not fo= und on descriptor - reading it from system property [junit4:junit4] 2> 17665 T3255 oascc.ZkStateReader.updateClusterState Upd= ating cloud state from ZooKeeper...=20 [junit4:junit4] 2> 17668 T3180 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> 17669 T3180 oass.SolrDispatchFilter.init SolrDispatchF= ilter.init() done [junit4:junit4] 2> 17669 T3180 oascsi.HttpClientUtil.createClient Creatin= g new http client, config:maxConnections=3D128&maxConnectionsPerHost=3D32&f= ollowRedirects=3Dfalse [junit4:junit4] 2> 17999 T3180 oejs.Server.doStart jetty-8.1.8.v20121106 [junit4:junit4] 2> 18003 T3180 oejs.AbstractConnector.doStart Started Sel= ectChannelConnector@127.0.0.1:50064 [junit4:junit4] 2> 18004 T3180 oass.SolrDispatchFilter.init SolrDispatchF= ilter.init() [junit4:junit4] 2> 18005 T3180 oasc.SolrResourceLoader.locateSolrHome JND= I not configured for solr (NoInitialContextEx) [junit4:junit4] 2> 18005 T3180 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.ChaosMonkeySafeLeaderTest-jetty4-1362618650723 [junit4:junit4] 2> 18006 T3180 oasc.CoreContainer$Initializer.initialize = looking for solr config file: /Users/jenkins/jenkins-slave/workspace/Lucene= -Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.Cha= osMonkeySafeLeaderTest-jetty4-1362618650723/solr.xml [junit4:junit4] 2> 18006 T3180 oasc.CoreContainer. New CoreContaine= r 1716570442 [junit4:junit4] 2> 18007 T3180 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.ChaosMonkey= SafeLeaderTest-jetty4-1362618650723/' [junit4:junit4] 2> 18007 T3180 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.Chaos= MonkeySafeLeaderTest-jetty4-1362618650723/' [junit4:junit4] 2> 18060 T3180 oashc.HttpShardHandlerFactory.getParameter= Setting socketTimeout to: 120000 [junit4:junit4] 2> 18061 T3180 oashc.HttpShardHandlerFactory.getParameter= Setting urlScheme to: http:// [junit4:junit4] 2> 18061 T3180 oashc.HttpShardHandlerFactory.getParameter= Setting connTimeout to: 15000 [junit4:junit4] 2> 18062 T3180 oashc.HttpShardHandlerFactory.getParameter= Setting maxConnectionsPerHost to: 20 [junit4:junit4] 2> 18062 T3180 oashc.HttpShardHandlerFactory.getParameter= Setting corePoolSize to: 0 [junit4:junit4] 2> 18063 T3180 oashc.HttpShardHandlerFactory.getParameter= Setting maximumPoolSize to: 2147483647 [junit4:junit4] 2> 18063 T3180 oashc.HttpShardHandlerFactory.getParameter= Setting maxThreadIdleTime to: 5 [junit4:junit4] 2> 18064 T3180 oashc.HttpShardHandlerFactory.getParameter= Setting sizeOfQueue to: -1 [junit4:junit4] 2> 18064 T3180 oashc.HttpShardHandlerFactory.getParameter= Setting fairnessPolicy to: false [junit4:junit4] 2> 18065 T3180 oascsi.HttpClientUtil.createClient Creatin= g new http client, config:maxConnectionsPerHost=3D20&maxConnections=3D10000= &socketTimeout=3D120000&connTimeout=3D15000&retry=3Dfalse [junit4:junit4] 2> 18095 T3180 oasc.CoreContainer.load Registering Log Li= stener [junit4:junit4] 2> 18121 T3180 oasc.CoreContainer.initZooKeeper Zookeeper= client=3D127.0.0.1:50048/solr [junit4:junit4] 2> 18121 T3180 oasc.ZkController.checkChrootPath zkHost i= ncludes chroot [junit4:junit4] 2> 18122 T3180 oaz.ZooKeeper. Initiating client con= nection, connectString=3D127.0.0.1:50048 sessionTimeout=3D60000 watcher=3Do= rg.apache.solr.common.cloud.ConnectionManager@10f99a01 [junit4:junit4] 2> 18123 T3180 oascc.ConnectionManager.waitForConnected W= aiting for client to connect to ZooKeeper [junit4:junit4] 2> 18124 T3267 oaz.ClientCnxn$SendThread.logStartConnect = Opening socket connection to server 127.0.0.1/127.0.0.1:50048. Will not att= empt to authenticate using SASL (access denied (javax.security.auth.AuthPer= mission getLoginConfiguration)) [junit4:junit4] 2> 18126 T3267 oaz.ClientCnxn$SendThread.primeConnection = Socket connection established to 127.0.0.1/127.0.0.1:50048, initiating sess= ion [junit4:junit4] 2> 18127 T3182 oazs.NIOServerCnxnFactory.run Accepted soc= ket connection from /127.0.0.1:50065 [junit4:junit4] 2> 18127 T3182 oazs.ZooKeeperServer.processConnectRequest= Client attempting to establish new session at /127.0.0.1:50065 [junit4:junit4] 2> 18129 T3184 oazs.ZooKeeperServer.finishSessionInit Est= ablished session 0x13d42664b52000b with negotiated timeout 20000 for client= /127.0.0.1:50065 [junit4:junit4] 2> 18129 T3267 oaz.ClientCnxn$SendThread.onConnected Sess= ion establishment complete on server 127.0.0.1/127.0.0.1:50048, sessionid = =3D 0x13d42664b52000b, negotiated timeout =3D 20000 [junit4:junit4] 2> 18129 T3268 oascc.ConnectionManager.process Watcher or= g.apache.solr.common.cloud.ConnectionManager@10f99a01 name:ZooKeeperConnect= ion Watcher:127.0.0.1:50048 got event WatchedEvent state:SyncConnected type= :None path:null path:null type:None [junit4:junit4] 2> 18129 T3180 oascc.ConnectionManager.waitForConnected C= lient is connected to ZooKeeper [junit4:junit4] 2> 18132 T3185 oazs.PrepRequestProcessor.pRequest2Txn Pro= cessed session termination for sessionid: 0x13d42664b52000b [junit4:junit4] 2> 18133 T3182 oazs.NIOServerCnxn.closeSock Closed socket= connection for client /127.0.0.1:50065 which had sessionid 0x13d42664b5200= 0b [junit4:junit4] 2> 18133 T3180 oaz.ZooKeeper.close Session: 0x13d42664b52= 000b closed [junit4:junit4] 2> 18134 T3268 oaz.ClientCnxn$EventThread.run EventThread= shut down [junit4:junit4] 2> 18134 T3180 oascsi.HttpClientUtil.createClient Creatin= g new http client, config:maxConnections=3D500&maxConnectionsPerHost=3D16&s= ocketTimeout=3D120000&connTimeout=3D15000 [junit4:junit4] 2> 18159 T3180 oaz.ZooKeeper. Initiating client con= nection, connectString=3D127.0.0.1:50048/solr sessionTimeout=3D30000 watche= r=3Dorg.apache.solr.common.cloud.ConnectionManager@3fcc55e4 [junit4:junit4] 2> 18163 T3180 oascc.ConnectionManager.waitForConnected W= aiting for client to connect to ZooKeeper [junit4:junit4] 2> 18164 T3269 oaz.ClientCnxn$SendThread.logStartConnect = Opening socket connection to server 127.0.0.1/127.0.0.1:50048. Will not att= empt to authenticate using SASL (access denied (javax.security.auth.AuthPer= mission getLoginConfiguration)) [junit4:junit4] 2> 18165 T3269 oaz.ClientCnxn$SendThread.primeConnection = Socket connection established to 127.0.0.1/127.0.0.1:50048, initiating sess= ion [junit4:junit4] 2> 18166 T3182 oazs.NIOServerCnxnFactory.run Accepted soc= ket connection from /127.0.0.1:50066 [junit4:junit4] 2> 18167 T3182 oazs.ZooKeeperServer.processConnectRequest= Client attempting to establish new session at /127.0.0.1:50066 [junit4:junit4] 2> 18168 T3184 oazs.ZooKeeperServer.finishSessionInit Est= ablished session 0x13d42664b52000c with negotiated timeout 20000 for client= /127.0.0.1:50066 [junit4:junit4] 2> 18168 T3269 oaz.ClientCnxn$SendThread.onConnected Sess= ion establishment complete on server 127.0.0.1/127.0.0.1:50048, sessionid = =3D 0x13d42664b52000c, negotiated timeout =3D 20000 [junit4:junit4] 2> 18169 T3270 oascc.ConnectionManager.process Watcher or= g.apache.solr.common.cloud.ConnectionManager@3fcc55e4 name:ZooKeeperConnect= ion Watcher:127.0.0.1:50048/solr got event WatchedEvent state:SyncConnected= type:None path:null path:null type:None [junit4:junit4] 2> 18169 T3180 oascc.ConnectionManager.waitForConnected C= lient is connected to ZooKeeper [junit4:junit4] 2> 18171 T3185 oazs.PrepRequestProcessor.pRequest Got use= r-level KeeperException when processing sessionid:0x13d42664b52000c type:cr= eate cxid:0x1 zxid:0xb1 txntype:-1 reqpath:n/a Error Path:/solr/overseer Er= ror:KeeperErrorCode =3D NodeExists for /solr/overseer [junit4:junit4] 2> 18173 T3185 oazs.PrepRequestProcessor.pRequest Got use= r-level KeeperException when processing sessionid:0x13d42664b52000c type:cr= eate cxid:0x2 zxid:0xb2 txntype:-1 reqpath:n/a Error Path:/solr/overseer Er= ror:KeeperErrorCode =3D NodeExists for /solr/overseer [junit4:junit4] 2> 18177 T3180 oascc.ZkStateReader.createClusterStateWatc= hersAndUpdate Updating cluster state from ZooKeeper...=20 [junit4:junit4] 2> 19145 T3203 oascc.ZkStateReader.updateClusterState Upd= ating cloud state from ZooKeeper...=20 [junit4:junit4] 2> 19147 T3203 oasc.Overseer$ClusterStateUpdater.updateSt= ate Update state numShards=3D3 message=3D{ [junit4:junit4] 2> =09 "operation":"state", [junit4:junit4] 2> =09 "core_node_name":null, [junit4:junit4] 2> =09 "numShards":"3", [junit4:junit4] 2> =09 "shard":"shard3", [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:50061_", [junit4:junit4] 2> =09 "base_url":"http://127.0.0.1:50061"} [junit4:junit4] 2> 19160 T3209 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> 19160 T3254 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> 19161 T3270 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> 19166 T3202 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> 19166 T3238 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> 19166 T3222 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> 19183 T3180 oasc.ZkController.createEphemeralLiveNode = Register node as live in ZooKeeper:/live_nodes/127.0.0.1:50064_ [junit4:junit4] 2> 19184 T3185 oazs.PrepRequestProcessor.pRequest Got use= r-level KeeperException when processing sessionid:0x13d42664b52000c type:de= lete cxid:0xb zxid:0xb7 txntype:-1 reqpath:n/a Error Path:/solr/live_nodes/= 127.0.0.1:50064_ Error:KeeperErrorCode =3D NoNode for /solr/live_nodes/127.= 0.0.1:50064_ [junit4:junit4] 2> 19186 T3180 oascc.SolrZkClient.makePath makePath: /liv= e_nodes/127.0.0.1:50064_ [junit4:junit4] 2> 19193 T3222 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> 19193 T3238 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> 19195 T3209 oascc.ZkStateReader$3.process Updating liv= e nodes... (5) [junit4:junit4] 2> 19196 T3209 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> 19196 T3254 oascc.ZkStateReader$3.process Updating liv= e nodes... (5) [junit4:junit4] 2> 19197 T3202 oascc.ZkStateReader$3.process Updating liv= e nodes... (5) [junit4:junit4] 2> 19196 T3270 oascc.ZkStateReader$3.process Updating liv= e nodes... (5) [junit4:junit4] 2> 19197 T3270 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> 19197 T3254 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> 19197 T3202 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> 19204 T3222 oascc.ZkStateReader$3.process Updating liv= e nodes... (5) [junit4:junit4] 2> 19204 T3238 oascc.ZkStateReader$3.process Updating liv= e nodes... (5) [junit4:junit4] 2> 19216 T3271 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.ChaosMonkeySafeLeaderTest-jetty4-1362618650723/collection1 [junit4:junit4] 2> 19216 T3271 oasc.ZkController.createCollectionZkNode C= heck for collection zkNode:collection1 [junit4:junit4] 2> 19218 T3271 oasc.ZkController.createCollectionZkNode C= ollection zkNode exists [junit4:junit4] 2> 19218 T3271 oasc.ZkController.readConfigName Load coll= ection config from:/collections/collection1 [junit4:junit4] 2> 19221 T3271 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.Chaos= MonkeySafeLeaderTest-jetty4-1362618650723/collection1/' [junit4:junit4] 2> 19222 T3271 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.ChaosMonkeySafeLeader= Test-jetty4-1362618650723/collection1/lib/classes/' to classloader [junit4:junit4] 2> 19222 T3271 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.ChaosMonkeySafeLeader= Test-jetty4-1362618650723/collection1/lib/README' to classloader [junit4:junit4] 2> 19285 T3271 oasc.SolrConfig. Using Lucene MatchV= ersion: LUCENE_50 [junit4:junit4] 2> 19363 T3271 oasc.SolrConfig. Loaded SolrConfig: = solrconfig.xml [junit4:junit4] 2> 19365 T3271 oass.IndexSchema.readSchema Reading Solr S= chema [junit4:junit4] 2> 19371 T3271 oass.IndexSchema.readSchema Schema name=3D= test [junit4:junit4] 2> 20211 T3271 oass.OpenExchangeRatesOrgProvider.init Ini= tialized with rates=3Dopen-exchange-rates.json, refreshInterval=3D1440. [junit4:junit4] 2> 20222 T3271 oass.IndexSchema.readSchema default search= field in schema is text [junit4:junit4] 2> 20227 T3271 oass.IndexSchema.readSchema unique key fie= ld: id [junit4:junit4] 2> 20261 T3271 oass.FileExchangeRateProvider.reload Reloa= ding exchange rates from file currency.xml [junit4:junit4] 2> 20275 T3271 oass.FileExchangeRateProvider.reload Reloa= ding exchange rates from file currency.xml [junit4:junit4] 2> 20285 T3271 oass.OpenExchangeRatesOrgProvider.reload R= eloading exchange rates from open-exchange-rates.json [junit4:junit4] 2> 20289 T3271 oass.OpenExchangeRatesOrgProvider$OpenExch= angeRates. WARNING Unknown key IMPORTANT NOTE [junit4:junit4] 2> 20290 T3271 oass.OpenExchangeRatesOrgProvider$OpenExch= angeRates. WARNING Expected key, got STRING [junit4:junit4] 2> 20291 T3271 oass.OpenExchangeRatesOrgProvider.reload R= eloading exchange rates from open-exchange-rates.json [junit4:junit4] 2> 20293 T3271 oass.OpenExchangeRatesOrgProvider$OpenExch= angeRates. WARNING Unknown key IMPORTANT NOTE [junit4:junit4] 2> 20294 T3271 oass.OpenExchangeRatesOrgProvider$OpenExch= angeRates. WARNING Expected key, got STRING [junit4:junit4] 2> 20295 T3271 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.ChaosMonkeySafeL= eaderTest-jetty4-1362618650723/collection1/, dataDir=3D./org.apache.solr.cl= oud.ChaosMonkeySafeLeaderTest-1362618633034/jetty4/ [junit4:junit4] 2> 20295 T3271 oasc.JmxMonitoredMap. JMX monitoring= is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxM= BeanServer@3209fa8f [junit4:junit4] 2> 20296 T3271 oasc.SolrCore.initDirectoryFactory solr.St= andardDirectoryFactory [junit4:junit4] 2> 20298 T3271 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.ChaosMonkeySafeLe= aderTest-1362618633034/jetty4 forceNew: false [junit4:junit4] 2> 20299 T3271 oasc.SolrCore.getNewIndexDir New index dir= ectory detected: old=3Dnull new=3D./org.apache.solr.cloud.ChaosMonkeySafeLe= aderTest-1362618633034/jetty4/index/ [junit4:junit4] 2> 20300 T3271 oasc.SolrCore.initIndex WARNING [collectio= n1] Solr index directory './org.apache.solr.cloud.ChaosMonkeySafeLeaderTest= -1362618633034/jetty4/index' doesn't exist. Creating new index... [junit4:junit4] 2> 20301 T3271 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.ChaosMonkeySafeLe= aderTest-1362618633034/jetty4/index forceNew: false [junit4:junit4] 2> 20309 T3271 oasc.SolrDeletionPolicy.onCommit SolrDelet= ionPolicy.onCommit: commits:num=3D1 [junit4:junit4] 2> =09=09commit{dir=3D/Users/jenkins/jenkins-slave/worksp= ace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/org.apache.solr.c= loud.ChaosMonkeySafeLeaderTest-1362618633034/jetty4/index,segFN=3Dsegments_= 1,generation=3D1,filenames=3D[segments_1] [junit4:junit4] 2> 20310 T3271 oasc.SolrDeletionPolicy.updateCommits newe= st commit =3D 1[segments_1] [junit4:junit4] 2> 20316 T3271 oasup.UpdateRequestProcessorChain.init ins= erting DistributedUpdateProcessorFactory into updateRequestProcessorChain "= dedupe" [junit4:junit4] 2> 20317 T3271 oasup.UpdateRequestProcessorChain.init ins= erting DistributedUpdateProcessorFactory into updateRequestProcessorChain "= stored_sig" [junit4:junit4] 2> 20318 T3271 oasup.UpdateRequestProcessorChain.init ins= erting DistributedUpdateProcessorFactory into updateRequestProcessorChain "= distrib-dup-test-chain-implicit" [junit4:junit4] 2> 20319 T3271 oasc.RequestHandlers.initHandlersFromConfi= g created standard: solr.StandardRequestHandler [junit4:junit4] 2> 20320 T3271 oasc.RequestHandlers.initHandlersFromConfi= g created /get: solr.RealTimeGetHandler [junit4:junit4] 2> 20321 T3271 oasc.RequestHandlers.initHandlersFromConfi= g adding lazy requestHandler: solr.ReplicationHandler [junit4:junit4] 2> 20322 T3271 oasc.RequestHandlers.initHandlersFromConfi= g created /replication: solr.ReplicationHandler [junit4:junit4] 2> 20323 T3271 oasc.RequestHandlers.initHandlersFromConfi= g created /update: solr.UpdateRequestHandler [junit4:junit4] 2> 20323 T3271 oasc.RequestHandlers.initHandlersFromConfi= g created /admin/: org.apache.solr.handler.admin.AdminHandlers [junit4:junit4] 2> 20336 T3271 oashl.XMLLoader.init xsltCacheLifetimeSeco= nds=3D60 [junit4:junit4] 2> 20348 T3271 oass.SolrIndexSearcher. Opening Sear= cher@29541264 main [junit4:junit4] 2> 20350 T3271 oasu.CommitTracker. Hard AutoCommit:= disabled [junit4:junit4] 2> 20350 T3271 oasu.CommitTracker. Soft AutoCommit:= disabled [junit4:junit4] 2> 20355 T3272 oasc.SolrCore.registerSearcher [collection= 1] Registered new searcher Searcher@29541264 main{StandardDirectoryReader(s= egments_1:1)} [junit4:junit4] 2> 20357 T3271 oasc.ZkController.publish publishing core= =3Dcollection1 state=3Ddown [junit4:junit4] 2> 20357 T3271 oasc.ZkController.publish numShards not fo= und on descriptor - reading it from system property [junit4:junit4] 2> 20686 T3203 oascc.ZkStateReader.updateClusterState Upd= ating cloud state from ZooKeeper...=20 [junit4:junit4] 2> 20688 T3203 oasc.Overseer$ClusterStateUpdater.updateSt= ate Update state numShards=3D3 message=3D{ [junit4:junit4] 2> =09 "operation":"state", [junit4:junit4] 2> =09 "core_node_name":null, [junit4:junit4] 2> =09 "numShards":"3", [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:50064_", [junit4:junit4] 2> =09 "base_url":"http://127.0.0.1:50064"} [junit4:junit4] 2> 20688 T3203 oasc.Overseer$ClusterStateUpdater.updateSt= ate Collection already exists with numShards=3D3 [junit4:junit4] 2> 20689 T3203 oasc.Overseer$ClusterStateUpdater.updateSt= ate Assigning new node to shard shard=3Dshard1 [junit4:junit4] 2> 20699 T3209 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> 20700 T3254 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> 20701 T3222 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> 20701 T3270 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> 20701 T3238 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> 20702 T3202 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> 21366 T3271 oasc.CoreContainer.registerCore registerin= g core: collection1 [junit4:junit4] 2> 21366 T3271 oasc.ZkController.register Register replic= a - core:collection1 address:http://127.0.0.1:50064 collection:collection1 = shard:shard1 [junit4:junit4] 2> 21374 T3271 oasc.ZkController.register We are http://1= 27.0.0.1:50064/collection1/ and leader is http://127.0.0.1:50055/collection= 1/ [junit4:junit4] 2> 21374 T3271 oasc.ZkController.register No LogReplay ne= eded for core=3Dcollection1 baseURL=3Dhttp://127.0.0.1:50064 [junit4:junit4] 2> 21374 T3271 oasc.ZkController.checkRecovery Core needs= to recover:collection1 [junit4:junit4] 2> 21374 T3271 oasu.DefaultSolrCoreState.doRecovery Runni= ng recovery - first canceling any ongoing recovery [junit4:junit4] 2> ASYNC NEW_CORE C334 name=3Dcollection1 org.apache.sol= r.core.SolrCore@c01caab url=3Dhttp://127.0.0.1:50064/collection1 node=3D127= .0.0.1:50064_ C334_STATE=3Dcoll:collection1 core:collection1 props:{state= =3Ddown, core=3Dcollection1, collection=3Dcollection1, node_name=3D127.0.0.= 1:50064_, base_url=3Dhttp://127.0.0.1:50064} [junit4:junit4] 2> 21375 T3273 C334 P50064 oasc.RecoveryStrategy.run Star= ting recovery process. core=3Dcollection1 recoveringAfterStartup=3Dtrue [junit4:junit4] 2> 21379 T3273 C334 P50064 oasc.RecoveryStrategy.doRecove= ry ###### startupVersions=3D[] [junit4:junit4] 2> 21379 T3271 oascc.ZkStateReader.updateClusterState Upd= ating cloud state from ZooKeeper...=20 [junit4:junit4] 2> 21379 T3273 C334 P50064 oasc.ZkController.publish publ= ishing core=3Dcollection1 state=3Drecovering [junit4:junit4] 2> 21380 T3273 C334 P50064 oasc.ZkController.publish numS= hards not found on descriptor - reading it from system property [junit4:junit4] 2> 21382 T3180 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> 21382 T3273 C334 P50064 oascsi.HttpClientUtil.createCl= ient Creating new http client, config:maxConnections=3D128&maxConnectionsPe= rHost=3D32&followRedirects=3Dfalse [junit4:junit4] 2> 21383 T3180 oass.SolrDispatchFilter.init SolrDispatchF= ilter.init() done [junit4:junit4] 2> 21383 T3180 oascsi.HttpClientUtil.createClient Creatin= g new http client, config:maxConnections=3D128&maxConnectionsPerHost=3D32&f= ollowRedirects=3Dfalse [junit4:junit4] 2> 21804 T3180 oejs.Server.doStart jetty-8.1.8.v20121106 [junit4:junit4] 2> 21809 T3180 oejs.AbstractConnector.doStart Started Sel= ectChannelConnector@127.0.0.1:50068 [junit4:junit4] 2> 21811 T3180 oass.SolrDispatchFilter.init SolrDispatchF= ilter.init() [junit4:junit4] 2> 21812 T3180 oasc.SolrResourceLoader.locateSolrHome JND= I not configured for solr (NoInitialContextEx) [junit4:junit4] 2> 21813 T3180 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.ChaosMonkeySafeLeaderTest-jetty5-1362618654445 [junit4:junit4] 2> 21814 T3180 oasc.CoreContainer$Initializer.initialize = looking for solr config file: /Users/jenkins/jenkins-slave/workspace/Lucene= -Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.Cha= osMonkeySafeLeaderTest-jetty5-1362618654445/solr.xml [junit4:junit4] 2> 21814 T3180 oasc.CoreContainer. New CoreContaine= r 1426296502 [junit4:junit4] 2> 21816 T3180 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.ChaosMonkey= SafeLeaderTest-jetty5-1362618654445/' [junit4:junit4] 2> 21816 T3180 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.Chaos= MonkeySafeLeaderTest-jetty5-1362618654445/' [junit4:junit4] 2> 21877 T3180 oashc.HttpShardHandlerFactory.getParameter= Setting socketTimeout to: 120000 [junit4:junit4] 2> 21878 T3180 oashc.HttpShardHandlerFactory.getParameter= Setting urlScheme to: http:// [junit4:junit4] 2> 21878 T3180 oashc.HttpShardHandlerFactory.getParameter= Setting connTimeout to: 15000 [junit4:junit4] 2> 21879 T3180 oashc.HttpShardHandlerFactory.getParameter= Setting maxConnectionsPerHost to: 20 [junit4:junit4] 2> 21879 T3180 oashc.HttpShardHandlerFactory.getParameter= Setting corePoolSize to: 0 [junit4:junit4] 2> 21880 T3180 oashc.HttpShardHandlerFactory.getParameter= Setting maximumPoolSize to: 2147483647 [junit4:junit4] 2> 21880 T3180 oashc.HttpShardHandlerFactory.getParameter= Setting maxThreadIdleTime to: 5 [junit4:junit4] 2> 21881 T3180 oashc.HttpShardHandlerFactory.getParameter= Setting sizeOfQueue to: -1 [junit4:junit4] 2> 21881 T3180 oashc.HttpShardHandlerFactory.getParameter= Setting fairnessPolicy to: false [junit4:junit4] 2> 21882 T3180 oascsi.HttpClientUtil.createClient Creatin= g new http client, config:maxConnectionsPerHost=3D20&maxConnections=3D10000= &socketTimeout=3D120000&connTimeout=3D15000&retry=3Dfalse [junit4:junit4] 2> 21911 T3180 oasc.CoreContainer.load Registering Log Li= stener [junit4:junit4] 2> 21936 T3180 oasc.CoreContainer.initZooKeeper Zookeeper= client=3D127.0.0.1:50048/solr [junit4:junit4] 2> 21937 T3180 oasc.ZkController.checkChrootPath zkHost i= ncludes chroot [junit4:junit4] 2> 21937 T3180 oaz.ZooKeeper. Initiating client con= nection, connectString=3D127.0.0.1:50048 sessionTimeout=3D60000 watcher=3Do= rg.apache.solr.common.cloud.ConnectionManager@e015045 [junit4:junit4] 2> 21940 T3180 oascc.ConnectionManager.waitForConnected W= aiting for client to connect to ZooKeeper [junit4:junit4] 2> 21941 T3284 oaz.ClientCnxn$SendThread.logStartConnect = Opening socket connection to server 127.0.0.1/127.0.0.1:50048. Will not att= empt to authenticate using SASL (access denied (javax.security.auth.AuthPer= mission getLoginConfiguration)) [junit4:junit4] 2> 21944 T3284 oaz.ClientCnxn$SendThread.primeConnection = Socket connection established to 127.0.0.1/127.0.0.1:50048, initiating sess= ion [junit4:junit4] 2> 21944 T3182 oazs.NIOServerCnxnFactory.run Accepted soc= ket connection from /127.0.0.1:50069 [junit4:junit4] 2> 21945 T3182 oazs.ZooKeeperServer.processConnectRequest= Client attempting to establish new session at /127.0.0.1:50069 [junit4:junit4] 2> 21947 T3184 oazs.ZooKeeperServer.finishSessionInit Est= ablished session 0x13d42664b52000d with negotiated timeout 20000 for client= /127.0.0.1:50069 [junit4:junit4] 2> 21947 T3284 oaz.ClientCnxn$SendThread.onConnected Sess= ion establishment complete on server 127.0.0.1/127.0.0.1:50048, sessionid = =3D 0x13d42664b52000d, negotiated timeout =3D 20000 [junit4:junit4] 2> 21948 T3285 oascc.ConnectionManager.process Watcher or= g.apache.solr.common.cloud.ConnectionManager@e015045 name:ZooKeeperConnecti= on Watcher:127.0.0.1:50048 got event WatchedEvent state:SyncConnected type:= None path:null path:null type:None [junit4:junit4] 2> 21949 T3180 oascc.ConnectionManager.waitForConnected C= lient is connected to ZooKeeper [junit4:junit4] 2> 21952 T3185 oazs.PrepRequestProcessor.pRequest2Txn Pro= cessed session termination for sessionid: 0x13d42664b52000d [junit4:junit4] 2> 21954 T3182 oazs.NIOServerCnxn.closeSock Closed socket= connection for client /127.0.0.1:50069 which had sessionid 0x13d42664b5200= 0d [junit4:junit4] 2> 21954 T3180 oaz.ZooKeeper.close Session: 0x13d42664b52= 000d closed [junit4:junit4] 2> 21954 T3285 oaz.ClientCnxn$EventThread.run EventThread= shut down [junit4:junit4] 2> 21955 T3180 oascsi.HttpClientUtil.createClient Creatin= g new http client, config:maxConnections=3D500&maxConnectionsPerHost=3D16&s= ocketTimeout=3D120000&connTimeout=3D15000 [junit4:junit4] 2> 21973 T3180 oaz.ZooKeeper. Initiating client con= nection, connectString=3D127.0.0.1:50048/solr sessionTimeout=3D30000 watche= r=3Dorg.apache.solr.common.cloud.ConnectionManager@27f2182c [junit4:junit4] 2> 21975 T3180 oascc.ConnectionManager.waitForConnected W= aiting for client to connect to ZooKeeper [junit4:junit4] 2> 21976 T3286 oaz.ClientCnxn$SendThread.logStartConnect = Opening socket connection to server 127.0.0.1/127.0.0.1:50048. Will not att= empt to authenticate using SASL (access denied (javax.security.auth.AuthPer= mission getLoginConfiguration)) [junit4:junit4] 2> 21978 T3286 oaz.ClientCnxn$SendThread.primeConnection = Socket connection established to 127.0.0.1/127.0.0.1:50048, initiating sess= ion [junit4:junit4] 2> 21978 T3182 oazs.NIOServerCnxnFactory.run Accepted soc= ket connection from /127.0.0.1:50070 [junit4:junit4] 2> 21979 T3182 oazs.ZooKeeperServer.processConnectRequest= Client attempting to establish new session at /127.0.0.1:50070 [junit4:junit4] 2> 21982 T3184 oazs.ZooKeeperServer.finishSessionInit Est= ablished session 0x13d42664b52000e with negotiated timeout 20000 for client= /127.0.0.1:50070 [junit4:junit4] 2> 21982 T3286 oaz.ClientCnxn$SendThread.onConnected Sess= ion establishment complete on server 127.0.0.1/127.0.0.1:50048, sessionid = =3D 0x13d42664b52000e, negotiated timeout =3D 20000 [junit4:junit4] 2> 21983 T3287 oascc.ConnectionManager.process Watcher or= g.apache.solr.common.cloud.ConnectionManager@27f2182c name:ZooKeeperConnect= ion Watcher:127.0.0.1:50048/solr got event WatchedEvent state:SyncConnected= type:None path:null path:null type:None [junit4:junit4] 2> 21984 T3180 oascc.ConnectionManager.waitForConnected C= lient is connected to ZooKeeper [junit4:junit4] 2> 21987 T3185 oazs.PrepRequestProcessor.pRequest Got use= r-level KeeperException when processing sessionid:0x13d42664b52000e type:cr= eate cxid:0x1 zxid:0xc4 txntype:-1 reqpath:n/a Error Path:/solr/overseer Er= ror:KeeperErrorCode =3D NodeExists for /solr/overseer [junit4:junit4] 2> 21989 T3185 oazs.PrepRequestProcessor.pRequest Got use= r-level KeeperException when processing sessionid:0x13d42664b52000e type:cr= eate cxid:0x2 zxid:0xc5 txntype:-1 reqpath:n/a Error Path:/solr/overseer Er= ror:KeeperErrorCode =3D NodeExists for /solr/overseer [junit4:junit4] 2> 21994 T3180 oascc.ZkStateReader.createClusterStateWatc= hersAndUpdate Updating cluster state from ZooKeeper...=20 [junit4:junit4] 2> 22219 T3203 oascc.ZkStateReader.updateClusterState Upd= ating cloud state from ZooKeeper...=20 [junit4:junit4] 2> 22221 T3203 oasc.Overseer$ClusterStateUpdater.updateSt= ate Update state numShards=3D3 message=3D{ [junit4:junit4] 2> =09 "operation":"state", [junit4:junit4] 2> =09 "core_node_name":null, [junit4:junit4] 2> =09 "numShards":"3", [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:50064_", [junit4:junit4] 2> =09 "base_url":"http://127.0.0.1:50064"} [junit4:junit4] 2> 22231 T3202 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> 22231 T3287 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> 22231 T3238 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> 22239 T3209 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> 22239 T3254 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> 22240 T3270 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> 22239 T3222 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> 22425 T3218 oass.SolrDispatchFilter.handleAdminRequest= /admin/cores {coreNodeName=3D127.0.0.1:50064__collection1&state=3Drecoveri= ng&nodeName=3D127.0.0.1:50064_&action=3DPREPRECOVERY&checkLive=3Dtrue&core= =3Dcollection1&wt=3Djavabin&onlyIfLeader=3Dtrue&version=3D2} status=3D0 QTi= me=3D1002=20 [junit4:junit4] 2> 23001 T3180 oasc.ZkController.createEphemeralLiveNode = Register node as live in ZooKeeper:/live_nodes/127.0.0.1:50068_ [junit4:junit4] 2> 23003 T3185 oazs.PrepRequestProcessor.pRequest Got use= r-level KeeperException when processing sessionid:0x13d42664b52000e type:de= lete cxid:0xb zxid:0xca txntype:-1 reqpath:n/a Error Path:/solr/live_nodes/= 127.0.0.1:50068_ Error:KeeperErrorCode =3D NoNode for /solr/live_nodes/127.= 0.0.1:50068_ [junit4:junit4] 2> 23005 T3180 oascc.SolrZkClient.makePath makePath: /liv= e_nodes/127.0.0.1:50068_ [junit4:junit4] 2> 23010 T3287 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> 23011 T3222 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> 23011 T3238 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> 23016 T3202 oascc.ZkStateReader$3.process Updating liv= e nodes... (6) [junit4:junit4] 2> 23016 T3202 oascc.ZkStateReader$2.process A cluster st= ate change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:= /live_nodes, has occurred - updating... (live nodes size: 6) [junit4:junit4] 2> 23016 T3209 oascc.ZkStateReader$3.process Updating liv= e nodes... (6) [junit4:junit4] 2> 23016 T3209 oascc.ZkStateReader$2.process A cluster st= ate change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:= /live_nodes, has occurred - updating... (live nodes size: 6) [junit4:junit4] 2> 23017 T3270 oascc.ZkStateReader$3.process Updating liv= e nodes... (6) [junit4:junit4] 2> 23017 T3254 oascc.ZkStateReader$3.process Updating liv= e nodes... (6) [junit4:junit4] 2> 23017 T3254 oascc.ZkStateReader$2.process A cluster st= ate change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:= /live_nodes, has occurred - updating... (live nodes size: 6) [junit4:junit4] 2> 23017 T3270 oascc.ZkStateReader$2.process A cluster st= ate change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:= /live_nodes, has occurred - updating... (live nodes size: 6) [junit4:junit4] 2> 23022 T3287 oascc.ZkStateReader$3.process Updating liv= e nodes... (6) [junit4:junit4] 2> 23025 T3222 oascc.ZkStateReader$3.process Updating liv= e nodes... (6) [junit4:junit4] 2> 23025 T3238 oascc.ZkStateReader$3.process Updating liv= e nodes... (6) [junit4:junit4] 2> 23039 T3288 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.ChaosMonkeySafeLeaderTest-jetty5-1362618654445/collection1 [junit4:junit4] 2> 23039 T3288 oasc.ZkController.createCollectionZkNode C= heck for collection zkNode:collection1 [junit4:junit4] 2> 23041 T3288 oasc.ZkController.createCollectionZkNode C= ollection zkNode exists [junit4:junit4] 2> 23041 T3288 oasc.ZkController.readConfigName Load coll= ection config from:/collections/collection1 [junit4:junit4] 2> 23044 T3288 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.Chaos= MonkeySafeLeaderTest-jetty5-1362618654445/collection1/' [junit4:junit4] 2> 23045 T3288 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.ChaosMonkeySafeLeader= Test-jetty5-1362618654445/collection1/lib/classes/' to classloader [junit4:junit4] 2> 23046 T3288 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.ChaosMonkeySafeLeader= Test-jetty5-1362618654445/collection1/lib/README' to classloader [junit4:junit4] 2> 23111 T3288 oasc.SolrConfig. Using Lucene MatchV= ersion: LUCENE_50 [junit4:junit4] 2> 23194 T3288 oasc.SolrConfig. Loaded SolrConfig: = solrconfig.xml [junit4:junit4] 2> 23196 T3288 oass.IndexSchema.readSchema Reading Solr S= chema [junit4:junit4] 2> 23206 T3288 oass.IndexSchema.readSchema Schema name=3D= test [junit4:junit4] 2> 24073 T3288 oass.OpenExchangeRatesOrgProvider.init Ini= tialized with rates=3Dopen-exchange-rates.json, refreshInterval=3D1440. [junit4:junit4] 2> 24089 T3288 oass.IndexSchema.readSchema default search= field in schema is text [junit4:junit4] 2> 24095 T3288 oass.IndexSchema.readSchema unique key fie= ld: id [junit4:junit4] 2> 24130 T3288 oass.FileExchangeRateProvider.reload Reloa= ding exchange rates from file currency.xml [junit4:junit4] 2> 24141 T3288 oass.FileExchangeRateProvider.reload Reloa= ding exchange rates from file currency.xml [junit4:junit4] 2> 24151 T3288 oass.OpenExchangeRatesOrgProvider.reload R= eloading exchange rates from open-exchange-rates.json [junit4:junit4] 2> 24155 T3288 oass.OpenExchangeRatesOrgProvider$OpenExch= angeRates. WARNING Unknown key IMPORTANT NOTE [junit4:junit4] 2> 24156 T3288 oass.OpenExchangeRatesOrgProvider$OpenExch= angeRates. WARNING Expected key, got STRING [junit4:junit4] 2> 24157 T3288 oass.OpenExchangeRatesOrgProvider.reload R= eloading exchange rates from open-exchange-rates.json [junit4:junit4] 2> 24160 T3288 oass.OpenExchangeRatesOrgProvider$OpenExch= angeRates. WARNING Unknown key IMPORTANT NOTE [junit4:junit4] 2> 24160 T3288 oass.OpenExchangeRatesOrgProvider$OpenExch= angeRates. WARNING Expected key, got STRING [junit4:junit4] 2> 24161 T3288 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.ChaosMonkeySafeL= eaderTest-jetty5-1362618654445/collection1/, dataDir=3D./org.apache.solr.cl= oud.ChaosMonkeySafeLeaderTest-1362618633034/jetty5/ [junit4:junit4] 2> 24161 T3288 oasc.JmxMonitoredMap. JMX monitoring= is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxM= BeanServer@3209fa8f [junit4:junit4] 2> 24162 T3288 oasc.SolrCore.initDirectoryFactory solr.St= andardDirectoryFactory [junit4:junit4] 2> 24165 T3288 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.ChaosMonkeySafeLe= aderTest-1362618633034/jetty5 forceNew: false [junit4:junit4] 2> 24165 T3288 oasc.SolrCore.getNewIndexDir New index dir= ectory detected: old=3Dnull new=3D./org.apache.solr.cloud.ChaosMonkeySafeLe= aderTest-1362618633034/jetty5/index/ [junit4:junit4] 2> 24167 T3288 oasc.SolrCore.initIndex WARNING [collectio= n1] Solr index directory './org.apache.solr.cloud.ChaosMonkeySafeLeaderTest= -1362618633034/jetty5/index' doesn't exist. Creating new index... [junit4:junit4] 2> 24168 T3288 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.ChaosMonkeySafeLe= aderTest-1362618633034/jetty5/index forceNew: false [junit4:junit4] 2> 24176 T3288 oasc.SolrDeletionPolicy.onCommit SolrDelet= ionPolicy.onCommit: commits:num=3D1 [junit4:junit4] 2> =09=09commit{dir=3D/Users/jenkins/jenkins-slave/worksp= ace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/org.apache.solr.c= loud.ChaosMonkeySafeLeaderTest-1362618633034/jetty5/index,segFN=3Dsegments_= 1,generation=3D1,filenames=3D[segments_1] [junit4:junit4] 2> 24176 T3288 oasc.SolrDeletionPolicy.updateCommits newe= st commit =3D 1[segments_1] [junit4:junit4] 2> 24183 T3288 oasup.UpdateRequestProcessorChain.init ins= erting DistributedUpdateProcessorFactory into updateRequestProcessorChain "= dedupe" [junit4:junit4] 2> 24184 T3288 oasup.UpdateRequestProcessorChain.init ins= erting DistributedUpdateProcessorFactory into updateRequestProcessorChain "= stored_sig" [junit4:junit4] 2> 24185 T3288 oasup.UpdateRequestProcessorChain.init ins= erting DistributedUpdateProcessorFactory into updateRequestProcessorChain "= distrib-dup-test-chain-implicit" [junit4:junit4] 2> 24187 T3288 oasc.RequestHandlers.initHandlersFromConfi= g created standard: solr.StandardRequestHandler [junit4:junit4] 2> 24188 T3288 oasc.RequestHandlers.initHandlersFromConfi= g created /get: solr.RealTimeGetHandler [junit4:junit4] 2> 24188 T3288 oasc.RequestHandlers.initHandlersFromConfi= g adding lazy requestHandler: solr.ReplicationHandler [junit4:junit4] 2> 24189 T3288 oasc.RequestHandlers.initHandlersFromConfi= g created /replication: solr.ReplicationHandler [junit4:junit4] 2> 24190 T3288 oasc.RequestHandlers.initHandlersFromConfi= g created /update: solr.UpdateRequestHandler [junit4:junit4] 2> 24191 T3288 oasc.RequestHandlers.initHandlersFromConfi= g created /admin/: org.apache.solr.handler.admin.AdminHandlers [junit4:junit4] 2> 24203 T3288 oashl.XMLLoader.init xsltCacheLifetimeSeco= nds=3D60 [junit4:junit4] 2> 24227 T3288 oass.SolrIndexSearcher. Opening Sear= cher@3e376dba main [junit4:junit4] 2> 24229 T3288 oasu.CommitTracker. Hard AutoCommit:= disabled [junit4:junit4] 2> 24229 T3288 oasu.CommitTracker. Soft AutoCommit:= disabled [junit4:junit4] 2> 24237 T3289 oasc.SolrCore.registerSearcher [collection= 1] Registered new searcher Searcher@3e376dba main{StandardDirectoryReader(s= egments_1:1)} [junit4:junit4] 2> 24241 T3288 oasc.ZkController.publish publishing core= =3Dcollection1 state=3Ddown [junit4:junit4] 2> 24242 T3288 oasc.ZkController.publish numShards not fo= und on descriptor - reading it from system property [junit4:junit4] 2> C334_STATE=3Dcoll:collection1 core:collection1 props:= {shard=3Dshard1, state=3Drecovering, core=3Dcollection1, collection=3Dcolle= ction1, node_name=3D127.0.0.1:50064_, base_url=3Dhttp://127.0.0.1:50064} [junit4:junit4] 2> 24428 T3273 C334 P50064 oasc.RecoveryStrategy.doRecove= ry Attempting to PeerSync from http://127.0.0.1:50055/collection1/ core=3Dc= ollection1 - recoveringAfterStartup=3Dtrue [junit4:junit4] 2> 24428 T3273 C334 P50064 oasu.PeerSync.sync PeerSync: c= ore=3Dcollection1 url=3Dhttp://127.0.0.1:50064 START replicas=3D[http://127= .0.0.1:50055/collection1/] nUpdates=3D100 [junit4:junit4] 2> 24429 T3273 C334 P50064 oasu.PeerSync.sync WARNING no = frame of reference to tell of we've missed updates [junit4:junit4] 2> 24432 T3273 C334 P50064 oasc.RecoveryStrategy.doRecove= ry PeerSync Recovery was not successful - trying replication. core=3Dcollec= tion1 [junit4:junit4] 2> 24432 T3273 C334 P50064 oasc.RecoveryStrategy.doRecove= ry Starting Replication Recovery. core=3Dcollection1 [junit4:junit4] 2> 24435 T3273 C334 P50064 oasc.RecoveryStrategy.doRecove= ry Begin buffering updates. core=3Dcollection1 [junit4:junit4] 2> 24435 T3273 C334 P50064 oasu.UpdateLog.bufferUpdates S= tarting to buffer updates. FSUpdateLog{state=3DACTIVE, tlog=3Dnull} [junit4:junit4] 2> 24436 T3273 C334 P50064 oasc.RecoveryStrategy.replicat= e Attempting to replicate from http://127.0.0.1:50055/collection1/. core=3D= collection1 [junit4:junit4] 2> 24437 T3273 C334 P50064 oascsi.HttpClientUtil.createCl= ient Creating new http client, config:maxConnections=3D128&maxConnectionsPe= rHost=3D32&followRedirects=3Dfalse [junit4:junit4] 2> ASYNC NEW_CORE C335 name=3Dcollection1 org.apache.sol= r.core.SolrCore@17a19310 url=3Dhttp://127.0.0.1:50055/collection1 node=3D12= 7.0.0.1:50055_ C335_STATE=3Dcoll:collection1 core:collection1 props:{shard= =3Dshard1, state=3Dactive, core=3Dcollection1, collection=3Dcollection1, no= de_name=3D127.0.0.1:50055_, base_url=3Dhttp://127.0.0.1:50055, leader=3Dtru= e} [junit4:junit4] 2> 24451 T3215 C335 P50055 REQ /get {getVersions=3D100&di= strib=3Dfalse&wt=3Djavabin&qt=3D/get&version=3D2} status=3D0 QTime=3D2=20 [junit4:junit4] 2> 24470 T3216 C335 P50055 oasu.DirectUpdateHandler2.comm= it start commit{,optimize=3Dfalse,openSearcher=3Dfalse,waitSearcher=3Dtrue,= expungeDeletes=3Dfalse,softCommit=3Dfalse,prepareCommit=3Dfalse} [junit4:junit4] 2> 24476 T3216 C335 P50055 oasc.SolrDeletionPolicy.onInit= SolrDeletionPolicy.onInit: commits:num=3D1 [junit4:junit4] 2> =09=09commit{dir=3D/Users/jenkins/jenkins-slave/worksp= ace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/org.apache.solr.c= loud.ChaosMonkeySafeLeaderTest-1362618633034/jetty1/index,segFN=3Dsegments_= 1,generation=3D1,filenames=3D[segments_1] [junit4:junit4] 2> 24477 T3216 C335 P50055 oasc.SolrDeletionPolicy.update= Commits newest commit =3D 1[segments_1] [junit4:junit4] 2> 24480 T3216 C335 P50055 oasc.SolrDeletionPolicy.onComm= it SolrDeletionPolicy.onCommit: commits:num=3D2 [junit4:junit4] 2> =09=09commit{dir=3D/Users/jenkins/jenkins-slave/worksp= ace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/org.apache.solr.c= loud.ChaosMonkeySafeLeaderTest-1362618633034/jetty1/index,segFN=3Dsegments_= 1,generation=3D1,filenames=3D[segments_1] [junit4:junit4] 2> =09=09commit{dir=3D/Users/jenkins/jenkins-slave/worksp= ace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/org.apache.solr.c= loud.ChaosMonkeySafeLeaderTest-1362618633034/jetty1/index,segFN=3Dsegments_= 2,generation=3D2,filenames=3D[segments_2] [junit4:junit4] 2> 24481 T3216 C335 P50055 oasc.SolrDeletionPolicy.update= Commits newest commit =3D 2[segments_2] [junit4:junit4] 2> 24483 T3216 C335 P50055 oass.SolrIndexSearcher. = Opening Searcher@42670d54 realtime [junit4:junit4] 2> 24483 T3216 C335 P50055 oasu.DirectUpdateHandler2.comm= it end_commit_flush [junit4:junit4] 2> 24484 T3216 C335 P50055 /update {waitSearcher=3Dtrue&o= penSearcher=3Dfalse&commit=3Dtrue&wt=3Djavabin&commit_end_point=3Dtrue&vers= ion=3D2&softCommit=3Dfalse} {commit=3D} 0 14 [junit4:junit4] 2> 24485 T3273 C334 P50064 oash.ReplicationHandler.inform= Commits will be reserved for 10000 [junit4:junit4] 2> 24486 T3273 C334 P50064 oash.SnapPuller. No val= ue set for 'pollInterval'. Timer Task not started. [junit4:junit4] 2> 24492 T3213 C335 P50055 oash.ReplicationHandler.inform= Commits will be reserved for 10000 [junit4:junit4] 2> 24493 T3213 C335 P50055 REQ /replication {command=3Din= dexversion&qt=3D/replication&wt=3Djavabin&version=3D2} status=3D0 QTime=3D2= =20 [junit4:junit4] 2> 24494 T3273 C334 P50064 oash.SnapPuller.fetchLatestInd= ex Master's generation: 2 [junit4:junit4] 2> 24495 T3273 C334 P50064 oash.SnapPuller.fetchLatestInd= ex Slave's generation: 1 [junit4:junit4] 2> 24495 T3273 C334 P50064 oash.SnapPuller.fetchLatestInd= ex Starting replication process [junit4:junit4] 2> 24499 T3214 C335 P50055 REQ /replication {command=3Dfi= lelist&qt=3D/replication&wt=3Djavabin&generation=3D2&version=3D2} status=3D= 0 QTime=3D0=20 [junit4:junit4] 2> 24501 T3273 C334 P50064 oash.SnapPuller.fetchLatestInd= ex Number of files in latest index in master: 1 [junit4:junit4] 2> 24502 T3273 C334 P50064 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.Chaos= MonkeySafeLeaderTest-1362618633034/jetty4/index.20130306201057528 forceNew:= false [junit4:junit4] 2> 24503 T3273 C334 P50064 oash.SnapPuller.fetchLatestInd= ex Starting download to org.apache.lucene.store.NIOFSDirectory@/Users/jenki= ns/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/te= st/J0/org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1362618633034/jetty4/= index.20130306201057528 lockFactory=3Dorg.apache.lucene.store.NativeFSLockF= actory@305e0ade fullCopy=3Dfalse [junit4:junit4] 2> 24507 T3218 C335 P50055 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> 24510 T3273 C334 P50064 oash.SnapPuller.fetchLatestInd= ex Total time taken for download : 0 secs [junit4:junit4] 2> 24512 T3273 C334 P50064 oasu.DefaultSolrCoreState.newI= ndexWriter Creating new IndexWriter... [junit4:junit4] 2> 24513 T3273 C334 P50064 oasu.DefaultSolrCoreState.newI= ndexWriter Waiting until IndexWriter is unused... core=3Dcollection1 [junit4:junit4] 2> 24518 T3273 C334 P50064 oasc.SolrDeletionPolicy.onInit= SolrDeletionPolicy.onInit: commits:num=3D2 [junit4:junit4] 2> =09=09commit{dir=3D/Users/jenkins/jenkins-slave/worksp= ace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/org.apache.solr.c= loud.ChaosMonkeySafeLeaderTest-1362618633034/jetty4/index,segFN=3Dsegments_= 1,generation=3D1,filenames=3D[segments_1] [junit4:junit4] 2> =09=09commit{dir=3D/Users/jenkins/jenkins-slave/worksp= ace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/org.apache.solr.c= loud.ChaosMonkeySafeLeaderTest-1362618633034/jetty4/index,segFN=3Dsegments_= 2,generation=3D2,filenames=3D[segments_2] [junit4:junit4] 2> 24519 T3273 C334 P50064 oasc.SolrDeletionPolicy.update= Commits newest commit =3D 2[segments_2] [junit4:junit4] 2> 24520 T3273 C334 P50064 oasu.DefaultSolrCoreState.newI= ndexWriter New IndexWriter is ready to be used. [junit4:junit4] 2> 24520 T3273 C334 P50064 oass.SolrIndexSearcher. = Opening Searcher@691536ec main [junit4:junit4] 2> 24522 T3272 oasc.SolrCore.registerSearcher [collection= 1] Registered new searcher Searcher@691536ec main{StandardDirectoryReader(s= egments_2:1:nrt)} [junit4:junit4] 2> 24523 T3273 C334 P50064 oash.SnapPuller.fetchLatestInd= ex removing temporary index download directory files org.apache.lucene.stor= e.NIOFSDirectory@/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-M= acOSX/solr/build/solr-core/test/J0/org.apache.solr.cloud.ChaosMonkeySafeLea= derTest-1362618633034/jetty4/index.20130306201057528 lockFactory=3Dorg.apac= he.lucene.store.NativeFSLockFactory@305e0ade [junit4:junit4] 2> 24524 T3273 C334 P50064 oasc.RecoveryStrategy.replay N= o replay needed. core=3Dcollection1 [junit4:junit4] 2> 24524 T3273 C334 P50064 oasc.RecoveryStrategy.doRecove= ry Replication Recovery was successful - registering as Active. core=3Dcoll= ection1 [junit4:junit4] 2> 24525 T3273 C334 P50064 oasc.ZkController.publish publ= ishing core=3Dcollection1 state=3Dactive [junit4:junit4] 2> 24525 T3273 C334 P50064 oasc.ZkController.publish numS= hards not found on descriptor - reading it from system property [junit4:junit4] 2> 24528 T3273 C334 P50064 oasc.RecoveryStrategy.doRecove= ry Finished recovery process. core=3Dcollection1 [junit4:junit4] 2> 25261 T3203 oascc.ZkStateReader.updateClusterState Upd= ating cloud state from ZooKeeper...=20 [junit4:junit4] 2> 25263 T3203 oasc.Overseer$ClusterStateUpdater.updateSt= ate Update state numShards=3D3 message=3D{ [junit4:junit4] 2> =09 "operation":"state", [junit4:junit4] 2> =09 "core_node_name":null, [junit4:junit4] 2> =09 "numShards":"3", [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:50068_", [junit4:junit4] 2> =09 "base_url":"http://127.0.0.1:50068"} [junit4:junit4] 2> 25264 T3203 oasc.Overseer$ClusterStateUpdater.updateSt= ate Collection already exists with numShards=3D3 [junit4:junit4] 2> 25264 T3203 oasc.Overseer$ClusterStateUpdater.updateSt= ate Assigning new node to shard shard=3Dshard2 [junit4:junit4] 2> 25273 T3203 oasc.Overseer$ClusterStateUpdater.updateSt= ate Update state numShards=3D3 message=3D{ [junit4:junit4] 2> =09 "operation":"state", [junit4:junit4] 2> =09 "core_node_name":null, [junit4:junit4] 2> =09 "numShards":"3", [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:50064_", [junit4:junit4] 2> =09 "base_url":"http://127.0.0.1:50064"} [junit4:junit4] 2> 25285 T3202 oascc.ZkStateReader$2.process A cluster st= ate change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clu= sterstate.json, has occurred - updating... (live nodes size: 6) [junit4:junit4] 2> 25285 T3254 oascc.ZkStateReader$2.process A cluster st= ate change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clu= sterstate.json, has occurred - updating... (live nodes size: 6) [junit4:junit4] 2> 25286 T3270 oascc.ZkStateReader$2.process A cluster st= ate change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clu= sterstate.json, has occurred - updating... (live nodes size: 6) [junit4:junit4] 2> 25287 T3287 oascc.ZkStateReader$2.process A cluster st= ate change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clu= sterstate.json, has occurred - updating... (live nodes size: 6) [junit4:junit4] 2> 25287 T3222 oascc.ZkStateReader$2.process A cluster st= ate change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clu= sterstate.json, has occurred - updating... (live nodes size: 6) [junit4:junit4] 2> 25286 T3238 oascc.ZkStateReader$2.process A cluster st= ate change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clu= sterstate.json, has occurred - updating... (live nodes size: 6) [junit4:junit4] 2> 25286 T3209 oascc.ZkStateReader$2.process A cluster st= ate change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clu= sterstate.json, has occurred - updating... (live nodes size: 6) [junit4:junit4] 2> 26247 T3288 oasc.CoreContainer.registerCore registerin= g core: collection1 [junit4:junit4] 2> 26247 T3288 oasc.ZkController.register Register replic= a - core:collection1 address:http://127.0.0.1:50068 collection:collection1 = shard:shard2 [junit4:junit4] 2> 26254 T3288 oasc.ZkController.register We are http://1= 27.0.0.1:50068/collection1/ and leader is http://127.0.0.1:50058/collection= 1/ [junit4:junit4] 2> 26254 T3288 oasc.ZkController.register No LogReplay ne= eded for core=3Dcollection1 baseURL=3Dhttp://127.0.0.1:50068 [junit4:junit4] 2> 26254 T3288 oasc.ZkController.checkRecovery Core needs= to recover:collection1 [junit4:junit4] 2> 26255 T3288 oasu.DefaultSolrCoreState.doRecovery Runni= ng recovery - first canceling any ongoing recovery [junit4:junit4] 2> ASYNC NEW_CORE C336 name=3Dcollection1 org.apache.sol= r.core.SolrCore@1825181c url=3Dhttp://127.0.0.1:50068/collection1 node=3D12= 7.0.0.1:50068_ C336_STATE=3Dcoll:collection1 core:collection1 props:{state= =3Ddown, core=3Dcollection1, collection=3Dcollection1, node_name=3D127.0.0.= 1:50068_, base_url=3Dhttp://127.0.0.1:50068} [junit4:junit4] 2> 26256 T3292 C336 P50068 oasc.RecoveryStrategy.run Star= ting recovery process. core=3Dcollection1 recoveringAfterStartup=3Dtrue [junit4:junit4] 2> 26259 T3292 C336 P50068 oasc.RecoveryStrategy.doRecove= ry ###### startupVersions=3D[] [junit4:junit4] 2> 26259 T3292 C336 P50068 oasc.ZkController.publish publ= ishing core=3Dcollection1 state=3Drecovering [junit4:junit4] 2> 26260 T3292 C336 P50068 oasc.ZkController.publish numS= hards not found on descriptor - reading it from system property [junit4:junit4] 2> 26260 T3288 oascc.ZkStateReader.updateClusterState Upd= ating cloud state from ZooKeeper...=20 [junit4:junit4] 2> 26262 T3292 C336 P50068 oascsi.HttpClientUtil.createCl= ient Creating new http client, config:maxConnections=3D128&maxConnectionsPe= rHost=3D32&followRedirects=3Dfalse [junit4:junit4] 2> 26273 T3180 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> 26274 T3180 oass.SolrDispatchFilter.init SolrDispatchF= ilter.init() done [junit4:junit4] 2> 26274 T3180 oascsi.HttpClientUtil.createClient Creatin= g new http client, config:maxConnections=3D128&maxConnectionsPerHost=3D32&f= ollowRedirects=3Dfalse [junit4:junit4] 2> 26597 T3180 oejs.Server.doStart jetty-8.1.8.v20121106 [junit4:junit4] 2> 26601 T3180 oejs.AbstractConnector.doStart Started Sel= ectChannelConnector@127.0.0.1:50075 [junit4:junit4] 2> 26602 T3180 oass.SolrDispatchFilter.init SolrDispatchF= ilter.init() [junit4:junit4] 2> 26602 T3180 oasc.SolrResourceLoader.locateSolrHome JND= I not configured for solr (NoInitialContextEx) [junit4:junit4] 2> 26603 T3180 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.ChaosMonkeySafeLeaderTest-jetty6-1362618659322 [junit4:junit4] 2> 26603 T3180 oasc.CoreContainer$Initializer.initialize = looking for solr config file: /Users/jenkins/jenkins-slave/workspace/Lucene= -Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.Cha= osMonkeySafeLeaderTest-jetty6-1362618659322/solr.xml [junit4:junit4] 2> 26604 T3180 oasc.CoreContainer. New CoreContaine= r 1310856647 [junit4:junit4] 2> 26605 T3180 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.ChaosMonkey= SafeLeaderTest-jetty6-1362618659322/' [junit4:junit4] 2> 26605 T3180 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.Chaos= MonkeySafeLeaderTest-jetty6-1362618659322/' [junit4:junit4] 2> 26675 T3180 oashc.HttpShardHandlerFactory.getParameter= Setting socketTimeout to: 120000 [junit4:junit4] 2> 26676 T3180 oashc.HttpShardHandlerFactory.getParameter= Setting urlScheme to: http:// [junit4:junit4] 2> 26676 T3180 oashc.HttpShardHandlerFactory.getParameter= Setting connTimeout to: 15000 [junit4:junit4] 2> 26677 T3180 oashc.HttpShardHandlerFactory.getParameter= Setting maxConnectionsPerHost to: 20 [junit4:junit4] 2> 26677 T3180 oashc.HttpShardHandlerFactory.getParameter= Setting corePoolSize to: 0 [junit4:junit4] 2> 26678 T3180 oashc.HttpShardHandlerFactory.getParameter= Setting maximumPoolSize to: 2147483647 [junit4:junit4] 2> 26678 T3180 oashc.HttpShardHandlerFactory.getParameter= Setting maxThreadIdleTime to: 5 [junit4:junit4] 2> 26679 T3180 oashc.HttpShardHandlerFactory.getParameter= Setting sizeOfQueue to: -1 [junit4:junit4] 2> 26679 T3180 oashc.HttpShardHandlerFactory.getParameter= Setting fairnessPolicy to: false [junit4:junit4] 2> 26680 T3180 oascsi.HttpClientUtil.createClient Creatin= g new http client, config:maxConnectionsPerHost=3D20&maxConnections=3D10000= &socketTimeout=3D120000&connTimeout=3D15000&retry=3Dfalse [junit4:junit4] 2> 26714 T3180 oasc.CoreContainer.load Registering Log Li= stener [junit4:junit4] 2> 26742 T3180 oasc.CoreContainer.initZooKeeper Zookeeper= client=3D127.0.0.1:50048/solr [junit4:junit4] 2> 26743 T3180 oasc.ZkController.checkChrootPath zkHost i= ncludes chroot [junit4:junit4] 2> 26743 T3180 oaz.ZooKeeper. Initiating client con= nection, connectString=3D127.0.0.1:50048 sessionTimeout=3D60000 watcher=3Do= rg.apache.solr.common.cloud.ConnectionManager@dd0d842 [junit4:junit4] 2> 26744 T3180 oascc.ConnectionManager.waitForConnected W= aiting for client to connect to ZooKeeper [junit4:junit4] 2> 26745 T3303 oaz.ClientCnxn$SendThread.logStartConnect = Opening socket connection to server 127.0.0.1/127.0.0.1:50048. Will not att= empt to authenticate using SASL (access denied (javax.security.auth.AuthPer= mission getLoginConfiguration)) [junit4:junit4] 2> 26747 T3303 oaz.ClientCnxn$SendThread.primeConnection = Socket connection established to 127.0.0.1/127.0.0.1:50048, initiating sess= ion [junit4:junit4] 2> 26748 T3182 oazs.NIOServerCnxnFactory.run Accepted soc= ket connection from /127.0.0.1:50076 [junit4:junit4] 2> 26749 T3182 oazs.ZooKeeperServer.processConnectRequest= Client attempting to establish new session at /127.0.0.1:50076 [junit4:junit4] 2> 26751 T3184 oazs.ZooKeeperServer.finishSessionInit Est= ablished session 0x13d42664b52000f with negotiated timeout 20000 for client= /127.0.0.1:50076 [junit4:junit4] 2> 26751 T3303 oaz.ClientCnxn$SendThread.onConnected Sess= ion establishment complete on server 127.0.0.1/127.0.0.1:50048, sessionid = =3D 0x13d42664b52000f, negotiated timeout =3D 20000 [junit4:junit4] 2> 26752 T3304 oascc.ConnectionManager.process Watcher or= g.apache.solr.common.cloud.ConnectionManager@dd0d842 name:ZooKeeperConnecti= on Watcher:127.0.0.1:50048 got event WatchedEvent state:SyncConnected type:= None path:null path:null type:None [junit4:junit4] 2> 26752 T3180 oascc.ConnectionManager.waitForConnected C= lient is connected to ZooKeeper [junit4:junit4] 2> 26758 T3185 oazs.PrepRequestProcessor.pRequest2Txn Pro= cessed session termination for sessionid: 0x13d42664b52000f [junit4:junit4] 2> 26759 T3182 oazs.NIOServerCnxn.closeSock Closed socket= connection for client /127.0.0.1:50076 which had sessionid 0x13d42664b5200= 0f [junit4:junit4] 2> 26760 T3180 oaz.ZooKeeper.close Session: 0x13d42664b52= 000f closed [junit4:junit4] 2> 26761 T3180 oascsi.HttpClientUtil.createClient Creatin= g new http client, config:maxConnections=3D500&maxConnectionsPerHost=3D16&s= ocketTimeout=3D120000&connTimeout=3D15000 [junit4:junit4] 2> 26763 T3304 oaz.ClientCnxn$EventThread.run EventThread= shut down [junit4:junit4] 2> 26782 T3180 oaz.ZooKeeper. Initiating client con= nection, connectString=3D127.0.0.1:50048/solr sessionTimeout=3D30000 watche= r=3Dorg.apache.solr.common.cloud.ConnectionManager@1fb1a6f8 [junit4:junit4] 2> 26784 T3180 oascc.ConnectionManager.waitForConnected W= aiting for client to connect to ZooKeeper [junit4:junit4] 2> 26785 T3305 oaz.ClientCnxn$SendThread.logStartConnect = Opening socket connection to server 127.0.0.1/127.0.0.1:50048. Will not att= empt to authenticate using SASL (access denied (javax.security.auth.AuthPer= mission getLoginConfiguration)) [junit4:junit4] 2> 26786 T3305 oaz.ClientCnxn$SendThread.primeConnection = Socket connection established to 127.0.0.1/127.0.0.1:50048, initiating sess= ion [junit4:junit4] 2> 26787 T3182 oazs.NIOServerCnxnFactory.run Accepted soc= ket connection from /127.0.0.1:50077 [junit4:junit4] 2> 26787 T3182 oazs.ZooKeeperServer.processConnectRequest= Client attempting to establish new session at /127.0.0.1:50077 [junit4:junit4] 2> 26789 T3184 oazs.ZooKeeperServer.finishSessionInit Est= ablished session 0x13d42664b520010 with negotiated timeout 20000 for client= /127.0.0.1:50077 [junit4:junit4] 2> 26789 T3305 oaz.ClientCnxn$SendThread.onConnected Sess= ion establishment complete on server 127.0.0.1/127.0.0.1:50048, sessionid = =3D 0x13d42664b520010, negotiated timeout =3D 20000 [junit4:junit4] 2> 26789 T3306 oascc.ConnectionManager.process Watcher or= g.apache.solr.common.cloud.ConnectionManager@1fb1a6f8 name:ZooKeeperConnect= ion Watcher:127.0.0.1:50048/solr got event WatchedEvent state:SyncConnected= type:None path:null path:null type:None [junit4:junit4] 2> 26790 T3180 oascc.ConnectionManager.waitForConnected C= lient is connected to ZooKeeper [junit4:junit4] 2> 26792 T3185 oazs.PrepRequestProcessor.pRequest Got use= r-level KeeperException when processing sessionid:0x13d42664b520010 type:cr= eate cxid:0x1 zxid:0xdb txntype:-1 reqpath:n/a Error Path:/solr/overseer Er= ror:KeeperErrorCode =3D NodeExists for /solr/overseer [junit4:junit4] 2> 26794 T3185 oazs.PrepRequestProcessor.pRequest Got use= r-level KeeperException when processing sessionid:0x13d42664b520010 type:cr= eate cxid:0x2 zxid:0xdc txntype:-1 reqpath:n/a Error Path:/solr/overseer Er= ror:KeeperErrorCode =3D NodeExists for /solr/overseer [junit4:junit4] 2> 26797 T3180 oascc.ZkStateReader.createClusterStateWatc= hersAndUpdate Updating cluster state from ZooKeeper...=20 [junit4:junit4] 2> 26810 T3203 oascc.ZkStateReader.updateClusterState Upd= ating cloud state from ZooKeeper...=20 [junit4:junit4] 2> 26812 T3203 oasc.Overseer$ClusterStateUpdater.updateSt= ate Update state numShards=3D3 message=3D{ [junit4:junit4] 2> =09 "operation":"state", [junit4:junit4] 2> =09 "core_node_name":null, [junit4:junit4] 2> =09 "numShards":"3", [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:50068_", [junit4:junit4] 2> =09 "base_url":"http://127.0.0.1:50068"} [junit4:junit4] 2> 26821 T3202 oascc.ZkStateReader$2.process A cluster st= ate change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clu= sterstate.json, has occurred - updating... (live nodes size: 6) [junit4:junit4] 2> 26821 T3306 oascc.ZkStateReader$2.process A cluster st= ate change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clu= sterstate.json, has occurred - updating... (live nodes size: 6) [junit4:junit4] 2> 26824 T3238 oascc.ZkStateReader$2.process A cluster st= ate change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clu= sterstate.json, has occurred - updating... (live nodes size: 6) [junit4:junit4] 2> 26824 T3287 oascc.ZkStateReader$2.process A cluster st= ate change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clu= sterstate.json, has occurred - updating... (live nodes size: 6) [junit4:junit4] 2> 26826 T3270 oascc.ZkStateReader$2.process A cluster st= ate change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clu= sterstate.json, has occurred - updating... (live nodes size: 6) [junit4:junit4] 2> 26827 T3222 oascc.ZkStateReader$2.process A cluster st= ate change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clu= sterstate.json, has occurred - updating... (live nodes size: 6) [junit4:junit4] 2> 26827 T3209 oascc.ZkStateReader$2.process A cluster st= ate change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clu= sterstate.json, has occurred - updating... (live nodes size: 6) [junit4:junit4] 2> 26824 T3254 oascc.ZkStateReader$2.process A cluster st= ate change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clu= sterstate.json, has occurred - updating... (live nodes size: 6) [junit4:junit4] 2> 27285 T3229 oass.SolrDispatchFilter.handleAdminRequest= /admin/cores {coreNodeName=3D127.0.0.1:50068__collection1&state=3Drecoveri= ng&nodeName=3D127.0.0.1:50068_&action=3DPREPRECOVERY&checkLive=3Dtrue&core= =3Dcollection1&wt=3Djavabin&onlyIfLeader=3Dtrue&version=3D2} status=3D0 QTi= me=3D1001=20 [junit4:junit4] 2> 27804 T3180 oasc.ZkController.createEphemeralLiveNode = Register node as live in ZooKeeper:/live_nodes/127.0.0.1:50075_ [junit4:junit4] 2> 27805 T3185 oazs.PrepRequestProcessor.pRequest Got use= r-level KeeperException when processing sessionid:0x13d42664b520010 type:de= lete cxid:0xb zxid:0xe1 txntype:-1 reqpath:n/a Error Path:/solr/live_nodes/= 127.0.0.1:50075_ Error:KeeperErrorCode =3D NoNode for /solr/live_nodes/127.= 0.0.1:50075_ [junit4:junit4] 2> 27806 T3180 oascc.SolrZkClient.makePath makePath: /liv= e_nodes/127.0.0.1:50075_ [junit4:junit4] 2> 27811 T3306 oascc.ZkStateReader$2.process A cluster st= ate change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:= /live_nodes, has occurred - updating... (live nodes size: 6) [junit4:junit4] 2> 27812 T3287 oascc.ZkStateReader$2.process A cluster st= ate change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:= /live_nodes, has occurred - updating... (live nodes size: 6) [junit4:junit4] 2> 27812 T3238 oascc.ZkStateReader$2.process A cluster st= ate change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:= /live_nodes, has occurred - updating... (live nodes size: 6) [junit4:junit4] 2> 27813 T3222 oascc.ZkStateReader$2.process A cluster st= ate change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:= /live_nodes, has occurred - updating... (live nodes size: 6) [junit4:junit4] 2> 27814 T3202 oascc.ZkStateReader$3.process Updating liv= e nodes... (7) [junit4:junit4] 2> 27814 T3202 oascc.ZkStateReader$2.process A cluster st= ate change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:= /live_nodes, has occurred - updating... (live nodes size: 7) [junit4:junit4] 2> 27816 T3254 oascc.ZkStateReader$3.process Updating liv= e nodes... (7) [junit4:junit4] 2> 27816 T3254 oascc.ZkStateReader$2.process A cluster st= ate change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:= /live_nodes, has occurred - updating... (live nodes size: 7) [junit4:junit4] 2> 27817 T3270 oascc.ZkStateReader$3.process Updating liv= e nodes... (7) [junit4:junit4] 2> 27817 T3270 oascc.ZkStateReader$2.process A cluster st= ate change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:= /live_nodes, has occurred - updating... (live nodes size: 7) [junit4:junit4] 2> 27817 T3209 oascc.ZkStateReader$3.process Updating liv= e nodes... (7) [junit4:junit4] 2> 27818 T3209 oascc.ZkStateReader$2.process A cluster st= ate change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:= /live_nodes, has occurred - updating... (live nodes size: 7) [junit4:junit4] 2> 27822 T3306 oascc.ZkStateReader$3.process Updating liv= e nodes... (7) [junit4:junit4] 2> 27824 T3287 oascc.ZkStateReader$3.process Updating liv= e nodes... (7) [junit4:junit4] 2> 27824 T3222 oascc.ZkStateReader$3.process Updating liv= e nodes... (7) [junit4:junit4] 2> 27825 T3238 oascc.ZkStateReader$3.process Updating liv= e nodes... (7) [junit4:junit4] 2> 27834 T3307 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.ChaosMonkeySafeLeaderTest-jetty6-1362618659322/collection1 [junit4:junit4] 2> 27835 T3307 oasc.ZkController.createCollectionZkNode C= heck for collection zkNode:collection1 [junit4:junit4] 2> 27837 T3307 oasc.ZkController.createCollectionZkNode C= ollection zkNode exists [junit4:junit4] 2> 27837 T3307 oasc.ZkController.readConfigName Load coll= ection config from:/collections/collection1 [junit4:junit4] 2> 27840 T3307 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.Chaos= MonkeySafeLeaderTest-jetty6-1362618659322/collection1/' [junit4:junit4] 2> 27841 T3307 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.ChaosMonkeySafeLeader= Test-jetty6-1362618659322/collection1/lib/classes/' to classloader [junit4:junit4] 2> 27842 T3307 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.ChaosMonkeySafeLeader= Test-jetty6-1362618659322/collection1/lib/README' to classloader [junit4:junit4] 2> 27904 T3307 oasc.SolrConfig. Using Lucene MatchV= ersion: LUCENE_50 [junit4:junit4] 2> 27989 T3307 oasc.SolrConfig. Loaded SolrConfig: = solrconfig.xml [junit4:junit4] 2> 27990 T3307 oass.IndexSchema.readSchema Reading Solr S= chema [junit4:junit4] 2> 27996 T3307 oass.IndexSchema.readSchema Schema name=3D= test [junit4:junit4] 2> 29218 T3307 oass.OpenExchangeRatesOrgProvider.init Ini= tialized with rates=3Dopen-exchange-rates.json, refreshInterval=3D1440. [junit4:junit4] 2> 29232 T3307 oass.IndexSchema.readSchema default search= field in schema is text [junit4:junit4] 2> 29237 T3307 oass.IndexSchema.readSchema unique key fie= ld: id [junit4:junit4] 2> 29266 T3307 oass.FileExchangeRateProvider.reload Reloa= ding exchange rates from file currency.xml [junit4:junit4] 2> 29274 T3307 oass.FileExchangeRateProvider.reload Reloa= ding exchange rates from file currency.xml [junit4:junit4] 2> 29282 T3307 oass.OpenExchangeRatesOrgProvider.reload R= eloading exchange rates from open-exchange-rates.json [junit4:junit4] 2> 29284 T3307 oass.OpenExchangeRatesOrgProvider$OpenExch= angeRates. WARNING Unknown key IMPORTANT NOTE [junit4:junit4] 2> 29284 T3307 oass.OpenExchangeRatesOrgProvider$OpenExch= angeRates. WARNING Expected key, got STRING [junit4:junit4] 2> 29285 T3307 oass.OpenExchangeRatesOrgProvider.reload R= eloading exchange rates from open-exchange-rates.json [junit4:junit4] 2> C336_STATE=3Dcoll:collection1 core:collection1 props:= {shard=3Dshard2, state=3Drecovering, core=3Dcollection1, collection=3Dcolle= ction1, node_name=3D127.0.0.1:50068_, base_url=3Dhttp://127.0.0.1:50068} [junit4:junit4] 2> 29287 T3292 C336 P50068 oasc.RecoveryStrategy.doRecove= ry Attempting to PeerSync from http://127.0.0.1:50058/collection1/ core=3Dc= ollection1 - recoveringAfterStartup=3Dtrue [junit4:junit4] 2> 29288 T3292 C336 P50068 oasu.PeerSync.sync PeerSync: c= ore=3Dcollection1 url=3Dhttp://127.0.0.1:50068 START replicas=3D[http://127= .0.0.1:50058/collection1/] nUpdates=3D100 [junit4:junit4] 2> 29288 T3307 oass.OpenExchangeRatesOrgProvider$OpenExch= angeRates. WARNING Unknown key IMPORTANT NOTE [junit4:junit4] 2> 29289 T3307 oass.OpenExchangeRatesOrgProvider$OpenExch= angeRates. WARNING Expected key, got STRING [junit4:junit4] 2> 29289 T3307 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.ChaosMonkeySafeL= eaderTest-jetty6-1362618659322/collection1/, dataDir=3D./org.apache.solr.cl= oud.ChaosMonkeySafeLeaderTest-1362618633034/jetty6/ [junit4:junit4] 2> 29289 T3292 C336 P50068 oasu.PeerSync.sync WARNING no = frame of reference=20 [...truncated too long message...] ateDeduplication, TestDFRSimilarityFactory, ChaosMonkeyNothingIsSafeTest, T= estSearchPerf, EchoParamsTest, TestPHPSerializedResponseWriter, DateMathPar= serTest, QueryElevationComponentTest, PathHierarchyTokenizerFactoryTest, UU= IDFieldTest, TermsComponentTest, TestBM25SimilarityFactory, UniqFieldsUpdat= eProcessorFactoryTest, ReturnFieldsTest, TestIndexingPerformance, BadCompon= entTest, TestStressRecovery, TestUtils, MultiTermTest, TestFieldTypeResourc= e, BinaryUpdateRequestHandlerTest, TestJmxMonitoredMap, DirectSolrConnectio= nTest, SOLR749Test, DebugComponentTest, DistributedSpellCheckComponentTest,= TestSolrQueryParser, OverseerCollectionProcessorTest, FileBasedSpellChecke= rTest, TestQuerySenderListener, TestBinaryResponseWriter, TestIndexSearcher= , TestDocumentBuilder, TestCodecSupport, TestFastOutputStream, CurrencyFiel= dOpenExchangeTest, TestExtendedDismaxParser, TestRangeQuery, DocValuesTest,= TestAtomicUpdateErrorCases, SynonymTokenizerTest, FieldAnalysisRequestHand= lerTest, HardAutoCommitTest, BasicDistributedZk2Test, MinimalSchemaTest, Te= stCSVResponseWriter, TestMultiCoreConfBootstrap, ShardRoutingTest, TestDefa= ultSimilarityFactory, StatelessScriptUpdateProcessorFactoryTest, CacheHeade= rTest, BadIndexSchemaTest, SampleTest, LeaderElectionTest, TimeZoneUtilsTes= t, SpellingQueryConverterTest, SolrCoreTest, TestFieldTypeCollectionResourc= e, SimplePostToolTest, TestReload, TestFastWriter, TestSystemIdResolver, Te= stCSVLoader, CSVRequestHandlerTest, TestFoldingMultitermQuery, BasicZkTest,= SortByFunctionTest, XsltUpdateRequestHandlerTest, TestJmxIntegration, Luke= RequestHandlerTest, TestPropInject, DateFieldTest, ZkSolrClientTest, TestSu= rroundQueryParser, TestZkChroot, TestPhraseSuggestions, StandardRequestHand= lerTest, ShowFileRequestHandlerTest, ExternalFileFieldSortTest, TestCharFil= ters, DOMUtilTest, TestQuerySenderNoQuery, TestFieldResource, DirectSolrSpe= llCheckerTest, BasicDistributedZkTest, ChaosMonkeySafeLeaderTest] [junit4:junit4] 2> NOTE: reproduce with: ant test -Dtestcase=3DChaosMonk= eySafeLeaderTest -Dtests.seed=3D3BB7A992A26D0C84 -Dtests.slow=3Dtrue -Dtest= s.locale=3Den_PH -Dtests.timezone=3DAmerica/Indiana/Winamac -Dtests.file.en= coding=3DMacRoman [junit4:junit4] ERROR 0.00s | ChaosMonkeySafeLeaderTest (suite) <<< [junit4:junit4] > Throwable #1: java.lang.AssertionError: ERROR: SolrInd= exSearcher opens=3D40 closes=3D39 [junit4:junit4] > =09at __randomizedtesting.SeedInfo.seed([3BB7A992A26D0= C84]: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.GeneratedMethodAccessor21.invoke(Unk= nown Source) [junit4:junit4] > =09at sun.reflect.DelegatingMethodAccessorImpl.invoke(= DelegatingMethodAccessorImpl.java:25) [junit4:junit4] > =09at java.lang.reflect.Method.invoke(Method.java:597) [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:680) [junit4:junit4] > Throwable #2: com.carrotsearch.randomizedtesting.Threa= dLeakError: 2 threads leaked from SUITE scope at org.apache.solr.cloud.Chao= sMonkeySafeLeaderTest:=20 [junit4:junit4] > 1) Thread[id=3D3309, name=3DsearcherExecutor-2230-t= hread-1, state=3DWAITING, group=3DTGRP-ChaosMonkeySafeLeaderTest] [junit4:junit4] > at sun.misc.Unsafe.park(Native Method) [junit4:junit4] > at java.util.concurrent.locks.LockSupport.park= (LockSupport.java:156) [junit4:junit4] > at java.util.concurrent.locks.AbstractQueuedSy= nchronizer$ConditionObject.await(AbstractQueuedSynchronizer.java:1987) [junit4:junit4] > at java.util.concurrent.LinkedBlockingQueue.ta= ke(LinkedBlockingQueue.java:399) [junit4:junit4] > at java.util.concurrent.ThreadPoolExecutor.get= Task(ThreadPoolExecutor.java:957) [junit4:junit4] > at java.util.concurrent.ThreadPoolExecutor$Wor= ker.run(ThreadPoolExecutor.java:917) [junit4:junit4] > at java.lang.Thread.run(Thread.java:680) [junit4:junit4] > 2) Thread[id=3D3503, name=3DRecoveryThread, state= =3DTIMED_WAITING, group=3DTGRP-ChaosMonkeySafeLeaderTest] [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([3BB7A992A26D0= C84]: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=3D3309, name=3DsearcherExecutor-2230-t= hread-1, state=3DWAITING, group=3DTGRP-ChaosMonkeySafeLeaderTest] [junit4:junit4] > at sun.misc.Unsafe.park(Native Method) [junit4:junit4] > at java.util.concurrent.locks.LockSupport.park= (LockSupport.java:156) [junit4:junit4] > at java.util.concurrent.locks.AbstractQueuedSy= nchronizer$ConditionObject.await(AbstractQueuedSynchronizer.java:1987) [junit4:junit4] > at java.util.concurrent.LinkedBlockingQueue.ta= ke(LinkedBlockingQueue.java:399) [junit4:junit4] > at java.util.concurrent.ThreadPoolExecutor.get= Task(ThreadPoolExecutor.java:957) [junit4:junit4] > at java.util.concurrent.ThreadPoolExecutor$Wor= ker.run(ThreadPoolExecutor.java:917) [junit4:junit4] > at java.lang.Thread.run(Thread.java:680) [junit4:junit4] > 2) Thread[id=3D3503, name=3DRecoveryThread, state= =3DWAITING, group=3DTGRP-ChaosMonkeySafeLeaderTest] [junit4:junit4] > at java.lang.Object.wait(Native Method) [junit4:junit4] > at java.lang.Thread.join(Thread.java:1210) [junit4:junit4] > at java.lang.Thread.join(Thread.java:1263) [junit4:junit4] > at org.apache.solr.update.DefaultSolrCoreState= .cancelRecovery(DefaultSolrCoreState.java:250) [junit4:junit4] > at org.apache.solr.update.DefaultSolrCoreState= .close(DefaultSolrCoreState.java:277) [junit4:junit4] > at org.apache.solr.update.SolrCoreState.decref= SolrCoreState(SolrCoreState.java:73) [junit4:junit4] > at org.apache.solr.core.SolrCore.close(SolrCor= e.java:975) [junit4:junit4] > at org.apache.solr.cloud.RecoveryStrategy.run(= RecoveryStrategy.java:235) [junit4:junit4] > =09at __randomizedtesting.SeedInfo.seed([3BB7A992A26D0= C84]:0) [junit4:junit4] Completed in 374.97s, 1 test, 1 failure, 2 errors <<< FAILU= RES! [...truncated 405 lines...] BUILD FAILED /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/build.xml:3= 81: The following error occurred while executing this line: /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/build.xml:3= 61: 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:183: The following error occurred while executing this line: /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/common= -build.xml:449: The following error occurred while executing this line: /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/lucene/comm= on-build.xml:1213: The following error occurred while executing this line: /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/lucene/comm= on-build.xml:877: There were test failures: 268 suites, 1134 tests, 3 suite= -level errors, 578 ignored (5 assumptions) Total time: 74 minutes 14 seconds Build step 'Invoke Ant' marked build as failure Archiving artifacts Recording test results Description set: Java: 64bit/jdk1.6.0 -XX:+UseParallelGC Email was triggered for: Failure Sending email for trigger: Failure ------=_Part_70_526881153.1362619095371 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_70_526881153.1362619095371--