You are viewing a plain text version of this content. The canonical link for it is here.
Posted to dev@lucene.apache.org by Policeman Jenkins Server <je...@thetaphi.de> on 2013/11/03 16:50:47 UTC

[JENKINS] Lucene-Solr-4.x-MacOSX (64bit/jdk1.6.0) - Build # 952 - Failure!

Build: http://jenkins.thetaphi.de/job/Lucene-Solr-4.x-MacOSX/952/
Java: 64bit/jdk1.6.0 -XX:+UseCompressedOops -XX:+UseConcMarkSweepGC

4 tests failed.
REGRESSION:  org.apache.solr.cloud.DeleteReplicaTest.testDistribSearch

Error Message:
No live SolrServers available to handle this request:[http://127.0.0.1:50309, http://127.0.0.1:50302, http://127.0.0.1:50299, http://127.0.0.1:50295, http://127.0.0.1:50306]

Stack Trace:
org.apache.solr.client.solrj.SolrServerException: No live SolrServers available to handle this request:[http://127.0.0.1:50309, http://127.0.0.1:50302, http://127.0.0.1:50299, http://127.0.0.1:50295, http://127.0.0.1:50306]
	at __randomizedtesting.SeedInfo.seed([85DB331831D2512B:43DBD00468D3117]:0)
	at org.apache.solr.client.solrj.impl.LBHttpSolrServer.request(LBHttpSolrServer.java:337)
	at org.apache.solr.client.solrj.impl.CloudSolrServer.request(CloudSolrServer.java:640)
	at org.apache.solr.cloud.DeleteReplicaTest.removeAndWaitForReplicaGone(DeleteReplicaTest.java:149)
	at org.apache.solr.cloud.DeleteReplicaTest.deleteLiveReplicaTest(DeleteReplicaTest.java:135)
	at org.apache.solr.cloud.DeleteReplicaTest.doTest(DeleteReplicaTest.java:115)
	at org.apache.solr.BaseDistributedSearchTestCase.testDistribSearch(BaseDistributedSearchTestCase.java:835)
	at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
	at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:39)
	at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
	at java.lang.reflect.Method.invoke(Method.java:597)
	at com.carrotsearch.randomizedtesting.RandomizedRunner.invoke(RandomizedRunner.java:1559)
	at com.carrotsearch.randomizedtesting.RandomizedRunner.access$600(RandomizedRunner.java:79)
	at com.carrotsearch.randomizedtesting.RandomizedRunner$6.evaluate(RandomizedRunner.java:737)
	at com.carrotsearch.randomizedtesting.RandomizedRunner$7.evaluate(RandomizedRunner.java:773)
	at com.carrotsearch.randomizedtesting.RandomizedRunner$8.evaluate(RandomizedRunner.java:787)
	at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:53)
	at org.apache.lucene.util.TestRuleSetupTeardownChained$1.evaluate(TestRuleSetupTeardownChained.java:50)
	at org.apache.lucene.util.TestRuleFieldCacheSanity$1.evaluate(TestRuleFieldCacheSanity.java:51)
	at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:46)
	at com.carrotsearch.randomizedtesting.rules.SystemPropertiesInvariantRule$1.evaluate(SystemPropertiesInvariantRule.java:55)
	at org.apache.lucene.util.TestRuleThreadAndTestName$1.evaluate(TestRuleThreadAndTestName.java:49)
	at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:70)
	at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:48)
	at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
	at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:358)
	at com.carrotsearch.randomizedtesting.ThreadLeakControl.forkTimeoutingTask(ThreadLeakControl.java:782)
	at com.carrotsearch.randomizedtesting.ThreadLeakControl$3.evaluate(ThreadLeakControl.java:442)
	at com.carrotsearch.randomizedtesting.RandomizedRunner.runSingleTest(RandomizedRunner.java:746)
	at com.carrotsearch.randomizedtesting.RandomizedRunner$3.evaluate(RandomizedRunner.java:648)
	at com.carrotsearch.randomizedtesting.RandomizedRunner$4.evaluate(RandomizedRunner.java:682)
	at com.carrotsearch.randomizedtesting.RandomizedRunner$5.evaluate(RandomizedRunner.java:693)
	at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
	at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:53)
	at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:46)
	at org.apache.lucene.util.TestRuleStoreClassName$1.evaluate(TestRuleStoreClassName.java:42)
	at com.carrotsearch.randomizedtesting.rules.SystemPropertiesInvariantRule$1.evaluate(SystemPropertiesInvariantRule.java:55)
	at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:39)
	at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:39)
	at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
	at org.apache.lucene.util.TestRuleAssertionsRequired$1.evaluate(TestRuleAssertionsRequired.java:43)
	at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:48)
	at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:70)
	at org.apache.lucene.util.TestRuleIgnoreTestSuites$1.evaluate(TestRuleIgnoreTestSuites.java:55)
	at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
	at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:358)
	at java.lang.Thread.run(Thread.java:695)
Caused by: org.apache.solr.client.solrj.SolrServerException: Timeout occured while waiting response from server at: http://127.0.0.1:50299
	at org.apache.solr.client.solrj.impl.HttpSolrServer.request(HttpSolrServer.java:472)
	at org.apache.solr.client.solrj.impl.HttpSolrServer.request(HttpSolrServer.java:181)
	at org.apache.solr.client.solrj.impl.LBHttpSolrServer.request(LBHttpSolrServer.java:268)
	... 45 more
Caused by: java.net.SocketTimeoutException: Read timed out
	at java.net.SocketInputStream.socketRead0(Native Method)
	at java.net.SocketInputStream.read(SocketInputStream.java:129)
	at org.apache.http.impl.io.AbstractSessionInputBuffer.fillBuffer(AbstractSessionInputBuffer.java:166)
	at org.apache.http.impl.io.SocketInputBuffer.fillBuffer(SocketInputBuffer.java:90)
	at org.apache.http.impl.io.AbstractSessionInputBuffer.readLine(AbstractSessionInputBuffer.java:281)
	at org.apache.http.impl.conn.DefaultHttpResponseParser.parseHead(DefaultHttpResponseParser.java:92)
	at org.apache.http.impl.conn.DefaultHttpResponseParser.parseHead(DefaultHttpResponseParser.java:61)
	at org.apache.http.impl.io.AbstractMessageParser.parse(AbstractMessageParser.java:254)
	at org.apache.http.impl.AbstractHttpClientConnection.receiveResponseHeader(AbstractHttpClientConnection.java:289)
	at org.apache.http.impl.conn.DefaultClientConnection.receiveResponseHeader(DefaultClientConnection.java:252)
	at org.apache.http.impl.conn.ManagedClientConnectionImpl.receiveResponseHeader(ManagedClientConnectionImpl.java:191)
	at org.apache.http.protocol.HttpRequestExecutor.doReceiveResponse(HttpRequestExecutor.java:300)
	at org.apache.http.protocol.HttpRequestExecutor.execute(HttpRequestExecutor.java:127)
	at org.apache.http.impl.client.DefaultRequestDirector.tryExecute(DefaultRequestDirector.java:715)
	at org.apache.http.impl.client.DefaultRequestDirector.execute(DefaultRequestDirector.java:520)
	at org.apache.http.impl.client.AbstractHttpClient.execute(AbstractHttpClient.java:906)
	at org.apache.http.impl.client.AbstractHttpClient.execute(AbstractHttpClient.java:805)
	at org.apache.http.impl.client.AbstractHttpClient.execute(AbstractHttpClient.java:784)
	at org.apache.solr.client.solrj.impl.HttpSolrServer.request(HttpSolrServer.java:366)
	... 47 more


FAILED:  junit.framework.TestSuite.org.apache.solr.cloud.DeleteReplicaTest

Error Message:
ERROR: SolrZkClient opens=15 closes=14

Stack Trace:
java.lang.AssertionError: ERROR: SolrZkClient opens=15 closes=14
	at __randomizedtesting.SeedInfo.seed([85DB331831D2512B]:0)
	at org.junit.Assert.fail(Assert.java:93)
	at org.apache.solr.SolrTestCaseJ4.endTrackingZkClients(SolrTestCaseJ4.java:343)
	at org.apache.solr.SolrTestCaseJ4.afterClass(SolrTestCaseJ4.java:135)
	at sun.reflect.GeneratedMethodAccessor25.invoke(Unknown Source)
	at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
	at java.lang.reflect.Method.invoke(Method.java:597)
	at com.carrotsearch.randomizedtesting.RandomizedRunner.invoke(RandomizedRunner.java:1559)
	at com.carrotsearch.randomizedtesting.RandomizedRunner.access$600(RandomizedRunner.java:79)
	at com.carrotsearch.randomizedtesting.RandomizedRunner$5.evaluate(RandomizedRunner.java:700)
	at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
	at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:53)
	at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:46)
	at org.apache.lucene.util.TestRuleStoreClassName$1.evaluate(TestRuleStoreClassName.java:42)
	at com.carrotsearch.randomizedtesting.rules.SystemPropertiesInvariantRule$1.evaluate(SystemPropertiesInvariantRule.java:55)
	at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:39)
	at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:39)
	at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
	at org.apache.lucene.util.TestRuleAssertionsRequired$1.evaluate(TestRuleAssertionsRequired.java:43)
	at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:48)
	at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:70)
	at org.apache.lucene.util.TestRuleIgnoreTestSuites$1.evaluate(TestRuleIgnoreTestSuites.java:55)
	at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
	at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:358)
	at java.lang.Thread.run(Thread.java:695)


FAILED:  junit.framework.TestSuite.org.apache.solr.cloud.DeleteReplicaTest

Error Message:
2 threads leaked from SUITE scope at org.apache.solr.cloud.DeleteReplicaTest:     1) Thread[id=4022, name=TEST-DeleteReplicaTest.testDistribSearch-seed#[85DB331831D2512B]-SendThread(localhost:50292), state=TIMED_WAITING, group=TGRP-DeleteReplicaTest]         at java.lang.Thread.sleep(Native Method)         at org.apache.zookeeper.client.StaticHostProvider.next(StaticHostProvider.java:86)         at org.apache.zookeeper.ClientCnxn$SendThread.startConnect(ClientCnxn.java:937)         at org.apache.zookeeper.ClientCnxn$SendThread.run(ClientCnxn.java:993)    2) Thread[id=4023, name=TEST-DeleteReplicaTest.testDistribSearch-seed#[85DB331831D2512B]-EventThread, state=WAITING, group=TGRP-DeleteReplicaTest]         at sun.misc.Unsafe.park(Native Method)         at java.util.concurrent.locks.LockSupport.park(LockSupport.java:156)         at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.await(AbstractQueuedSynchronizer.java:1987)         at java.util.concurrent.LinkedBlockingQueue.take(LinkedBlockingQueue.java:399)         at org.apache.zookeeper.ClientCnxn$EventThread.run(ClientCnxn.java:491)

Stack Trace:
com.carrotsearch.randomizedtesting.ThreadLeakError: 2 threads leaked from SUITE scope at org.apache.solr.cloud.DeleteReplicaTest: 
   1) Thread[id=4022, name=TEST-DeleteReplicaTest.testDistribSearch-seed#[85DB331831D2512B]-SendThread(localhost:50292), state=TIMED_WAITING, group=TGRP-DeleteReplicaTest]
        at java.lang.Thread.sleep(Native Method)
        at org.apache.zookeeper.client.StaticHostProvider.next(StaticHostProvider.java:86)
        at org.apache.zookeeper.ClientCnxn$SendThread.startConnect(ClientCnxn.java:937)
        at org.apache.zookeeper.ClientCnxn$SendThread.run(ClientCnxn.java:993)
   2) Thread[id=4023, name=TEST-DeleteReplicaTest.testDistribSearch-seed#[85DB331831D2512B]-EventThread, state=WAITING, group=TGRP-DeleteReplicaTest]
        at sun.misc.Unsafe.park(Native Method)
        at java.util.concurrent.locks.LockSupport.park(LockSupport.java:156)
        at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.await(AbstractQueuedSynchronizer.java:1987)
        at java.util.concurrent.LinkedBlockingQueue.take(LinkedBlockingQueue.java:399)
        at org.apache.zookeeper.ClientCnxn$EventThread.run(ClientCnxn.java:491)
	at __randomizedtesting.SeedInfo.seed([85DB331831D2512B]:0)


FAILED:  junit.framework.TestSuite.org.apache.solr.cloud.DeleteReplicaTest

Error Message:
There are still zombie threads that couldn't be terminated:    1) Thread[id=4022, name=TEST-DeleteReplicaTest.testDistribSearch-seed#[85DB331831D2512B]-SendThread(localhost:50292), state=TIMED_WAITING, group=TGRP-DeleteReplicaTest]         at java.lang.Thread.sleep(Native Method)         at org.apache.zookeeper.client.StaticHostProvider.next(StaticHostProvider.java:86)         at org.apache.zookeeper.ClientCnxn$SendThread.startConnect(ClientCnxn.java:937)         at org.apache.zookeeper.ClientCnxn$SendThread.run(ClientCnxn.java:993)

Stack Trace:
com.carrotsearch.randomizedtesting.ThreadLeakError: There are still zombie threads that couldn't be terminated:
   1) Thread[id=4022, name=TEST-DeleteReplicaTest.testDistribSearch-seed#[85DB331831D2512B]-SendThread(localhost:50292), state=TIMED_WAITING, group=TGRP-DeleteReplicaTest]
        at java.lang.Thread.sleep(Native Method)
        at org.apache.zookeeper.client.StaticHostProvider.next(StaticHostProvider.java:86)
        at org.apache.zookeeper.ClientCnxn$SendThread.startConnect(ClientCnxn.java:937)
        at org.apache.zookeeper.ClientCnxn$SendThread.run(ClientCnxn.java:993)
	at __randomizedtesting.SeedInfo.seed([85DB331831D2512B]:0)




Build Log:
[...truncated 9517 lines...]
   [junit4] Suite: org.apache.solr.cloud.DeleteReplicaTest
   [junit4]   2> 1356145 T3935 oas.BaseDistributedSearchTestCase.initHostContext Setting hostContext system property: /
   [junit4]   2> 1356154 T3935 oas.SolrTestCaseJ4.setUp ###Starting testDistribSearch
   [junit4]   2> Creating dataDir: /Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./solrtest-DeleteReplicaTest-1383493544100
   [junit4]   2> 1356155 T3935 oasc.ZkTestServer.run STARTING ZK TEST SERVER
   [junit4]   2> 1356157 T3936 oasc.ZkTestServer$ZKServerMain.runFromConfig Starting server
   [junit4]   2> 1356261 T3935 oasc.ZkTestServer.run start zk server on port:50292
   [junit4]   2> 1356263 T3935 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 1356278 T3942 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@13116a7b name:ZooKeeperConnection Watcher:127.0.0.1:50292 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 1356279 T3935 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 1356280 T3935 oascc.SolrZkClient.makePath makePath: /solr
   [junit4]   2> 1356305 T3935 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 1356314 T3944 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@1403fc5d name:ZooKeeperConnection Watcher:127.0.0.1:50292/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 1356314 T3935 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 1356315 T3935 oascc.SolrZkClient.makePath makePath: /collections/collection1
   [junit4]   2> 1356335 T3935 oascc.SolrZkClient.makePath makePath: /collections/collection1/shards
   [junit4]   2> 1356358 T3935 oascc.SolrZkClient.makePath makePath: /collections/control_collection
   [junit4]   2> 1356376 T3935 oascc.SolrZkClient.makePath makePath: /collections/control_collection/shards
   [junit4]   2> 1356396 T3935 oasc.AbstractZkTestCase.putConfig put /Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test-files/solr/collection1/conf/solrconfig-tlog.xml to /configs/conf1/solrconfig.xml
   [junit4]   2> 1356397 T3935 oascc.SolrZkClient.makePath makePath: /configs/conf1/solrconfig.xml
   [junit4]   2> 1356426 T3935 oasc.AbstractZkTestCase.putConfig put /Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test-files/solr/collection1/conf/schema.xml to /configs/conf1/schema.xml
   [junit4]   2> 1356428 T3935 oascc.SolrZkClient.makePath makePath: /configs/conf1/schema.xml
   [junit4]   2> 1356440 T3935 oasc.AbstractZkTestCase.putConfig put /Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test-files/solr/collection1/conf/solrconfig.snippet.randomindexconfig.xml to /configs/conf1/solrconfig.snippet.randomindexconfig.xml
   [junit4]   2> 1356441 T3935 oascc.SolrZkClient.makePath makePath: /configs/conf1/solrconfig.snippet.randomindexconfig.xml
   [junit4]   2> 1356451 T3935 oasc.AbstractZkTestCase.putConfig put /Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test-files/solr/collection1/conf/stopwords.txt to /configs/conf1/stopwords.txt
   [junit4]   2> 1356452 T3935 oascc.SolrZkClient.makePath makePath: /configs/conf1/stopwords.txt
   [junit4]   2> 1356460 T3935 oasc.AbstractZkTestCase.putConfig put /Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test-files/solr/collection1/conf/protwords.txt to /configs/conf1/protwords.txt
   [junit4]   2> 1356461 T3935 oascc.SolrZkClient.makePath makePath: /configs/conf1/protwords.txt
   [junit4]   2> 1356468 T3935 oasc.AbstractZkTestCase.putConfig put /Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test-files/solr/collection1/conf/currency.xml to /configs/conf1/currency.xml
   [junit4]   2> 1356469 T3935 oascc.SolrZkClient.makePath makePath: /configs/conf1/currency.xml
   [junit4]   2> 1356477 T3935 oasc.AbstractZkTestCase.putConfig put /Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test-files/solr/collection1/conf/open-exchange-rates.json to /configs/conf1/open-exchange-rates.json
   [junit4]   2> 1356478 T3935 oascc.SolrZkClient.makePath makePath: /configs/conf1/open-exchange-rates.json
   [junit4]   2> 1356487 T3935 oasc.AbstractZkTestCase.putConfig put /Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test-files/solr/collection1/conf/mapping-ISOLatin1Accent.txt to /configs/conf1/mapping-ISOLatin1Accent.txt
   [junit4]   2> 1356488 T3935 oascc.SolrZkClient.makePath makePath: /configs/conf1/mapping-ISOLatin1Accent.txt
   [junit4]   2> 1356498 T3935 oasc.AbstractZkTestCase.putConfig put /Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test-files/solr/collection1/conf/old_synonyms.txt to /configs/conf1/old_synonyms.txt
   [junit4]   2> 1356499 T3935 oascc.SolrZkClient.makePath makePath: /configs/conf1/old_synonyms.txt
   [junit4]   2> 1356509 T3935 oasc.AbstractZkTestCase.putConfig put /Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test-files/solr/collection1/conf/synonyms.txt to /configs/conf1/synonyms.txt
   [junit4]   2> 1356510 T3935 oascc.SolrZkClient.makePath makePath: /configs/conf1/synonyms.txt
   [junit4]   2> 1356859 T3935 oejs.Server.doStart jetty-8.1.10.v20130312
   [junit4]   2> 1356877 T3935 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:50295
   [junit4]   2> 1356879 T3935 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
   [junit4]   2> 1356879 T3935 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
   [junit4]   2> 1356880 T3935 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: ../../../../../../../../../Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.DeleteReplicaTest-controljetty-1383493544471
   [junit4]   2> 1356880 T3935 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '../../../../../../../../../Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.DeleteReplicaTest-controljetty-1383493544471/'
   [junit4]   2> 1356926 T3935 oasc.ConfigSolr.fromFile Loading container configuration from /Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/../../../../../../../../../Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.DeleteReplicaTest-controljetty-1383493544471/solr.xml
   [junit4]   2> 1356979 T3935 oasc.ConfigSolrXml.<init> Config-defined core root directory: 
   [junit4]   2> 1356980 T3935 oasc.CoreContainer.<init> New CoreContainer 339579374
   [junit4]   2> 1356981 T3935 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=../../../../../../../../../Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.DeleteReplicaTest-controljetty-1383493544471/]
   [junit4]   2> 1356982 T3935 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 240000
   [junit4]   2> 1356982 T3935 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
   [junit4]   2> 1356982 T3935 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
   [junit4]   2> 1356983 T3935 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
   [junit4]   2> 1356983 T3935 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
   [junit4]   2> 1356984 T3935 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
   [junit4]   2> 1356984 T3935 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
   [junit4]   2> 1356985 T3935 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
   [junit4]   2> 1356985 T3935 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
   [junit4]   2> 1356989 T3935 oasl.LogWatcher.createWatcher SLF4J impl is org.slf4j.impl.Log4jLoggerFactory
   [junit4]   2> 1356990 T3935 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
   [junit4]   2> 1356990 T3935 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:50292/solr
   [junit4]   2> 1356991 T3935 oasc.ZkController.checkChrootPath zkHost includes chroot
   [junit4]   2> 1356992 T3935 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 1356997 T3955 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@5637aaa3 name:ZooKeeperConnection Watcher:127.0.0.1:50292 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 1356998 T3935 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 1357005 T3935 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 1357009 T3957 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@3e2fc9d2 name:ZooKeeperConnection Watcher:127.0.0.1:50292/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 1357010 T3935 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 1357015 T3935 oascc.SolrZkClient.makePath makePath: /overseer/queue
   [junit4]   2> 1357027 T3935 oascc.SolrZkClient.makePath makePath: /overseer/collection-queue-work
   [junit4]   2> 1357040 T3935 oascc.SolrZkClient.makePath makePath: /live_nodes
   [junit4]   2> 1357048 T3935 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:50295_
   [junit4]   2> 1357051 T3935 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:50295_
   [junit4]   2> 1357069 T3935 oascc.SolrZkClient.makePath makePath: /overseer_elect/election
   [junit4]   2> 1357090 T3935 oascc.SolrZkClient.makePath makePath: /overseer_elect/leader
   [junit4]   2> 1357100 T3935 oasc.Overseer.start Overseer (id=90668632906924035-127.0.0.1:50295_-n_0000000000) starting
   [junit4]   2> 1357112 T3935 oascc.SolrZkClient.makePath makePath: /overseer/queue-work
   [junit4]   2> 1357130 T3959 oasc.OverseerCollectionProcessor.run Process current queue of collection creations
   [junit4]   2> 1357132 T3935 oascc.SolrZkClient.makePath makePath: /clusterstate.json
   [junit4]   2> 1357146 T3935 oascc.SolrZkClient.makePath makePath: /aliases.json
   [junit4]   2> 1357156 T3935 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
   [junit4]   2> 1357175 T3958 oasc.Overseer$ClusterStateUpdater.run Starting to work on the main queue
   [junit4]   2> 1357180 T3935 oasc.CorePropertiesLocator.discover Looking for core definitions underneath /Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/../../../../../../../../../Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.DeleteReplicaTest-controljetty-1383493544471
   [junit4]   2> 1357328 T3935 oasc.CorePropertiesLocator.discoverUnder Found core conf in /Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/../../../../../../../../../Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.DeleteReplicaTest-controljetty-1383493544471/conf/
   [junit4]   2> 1357336 T3935 oasc.CorePropertiesLocator.discover Found 1 core definitions
   [junit4]   2> 1357337 T3935 oass.SolrDispatchFilter.init user.dir=/Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0
   [junit4]   2> 1357337 T3935 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
   [junit4]   2> 1357343 T3935 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 1357347 T3962 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@7d3d1ee6 name:ZooKeeperConnection Watcher:127.0.0.1:50292/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 1357348 T3935 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 1357352 T3935 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
   [junit4]   2> 1357361 T3935 oasc.ChaosMonkey.monkeyLog monkey: init - expire sessions:true cause connection loss:true
   [junit4]   2> 1357680 T3935 oejs.Server.doStart jetty-8.1.10.v20130312
   [junit4]   2> 1357685 T3935 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:50299
   [junit4]   2> 1357686 T3935 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
   [junit4]   2> 1357686 T3935 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
   [junit4]   2> 1357687 T3935 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: ../../../../../../../../../Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.DeleteReplicaTest-jetty1-1383493545307
   [junit4]   2> 1357688 T3935 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '../../../../../../../../../Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.DeleteReplicaTest-jetty1-1383493545307/'
   [junit4]   2> 1357749 T3935 oasc.ConfigSolr.fromFile Loading container configuration from /Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/../../../../../../../../../Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.DeleteReplicaTest-jetty1-1383493545307/solr.xml
   [junit4]   2> 1357802 T3935 oasc.ConfigSolrXml.<init> Config-defined core root directory: 
   [junit4]   2> 1357803 T3935 oasc.CoreContainer.<init> New CoreContainer 1503678331
   [junit4]   2> 1357803 T3935 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=../../../../../../../../../Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.DeleteReplicaTest-jetty1-1383493545307/]
   [junit4]   2> 1357804 T3935 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 240000
   [junit4]   2> 1357805 T3935 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
   [junit4]   2> 1357806 T3935 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
   [junit4]   2> 1357806 T3935 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
   [junit4]   2> 1357806 T3935 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
   [junit4]   2> 1357808 T3935 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
   [junit4]   2> 1357808 T3935 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
   [junit4]   2> 1357808 T3935 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
   [junit4]   2> 1357809 T3935 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
   [junit4]   2> 1357812 T3935 oasl.LogWatcher.createWatcher SLF4J impl is org.slf4j.impl.Log4jLoggerFactory
   [junit4]   2> 1357812 T3935 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
   [junit4]   2> 1357813 T3935 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:50292/solr
   [junit4]   2> 1357813 T3935 oasc.ZkController.checkChrootPath zkHost includes chroot
   [junit4]   2> 1357815 T3935 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 1357821 T3973 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@2bc24235 name:ZooKeeperConnection Watcher:127.0.0.1:50292 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 1357823 T3935 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 1357829 T3935 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 1357833 T3975 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@6207b64c name:ZooKeeperConnection Watcher:127.0.0.1:50292/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 1357834 T3935 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 1357849 T3935 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
   [junit4]   2> 1358868 T3935 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:50299_
   [junit4]   2> 1358875 T3935 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:50299_
   [junit4]   2> 1358897 T3957 oascc.ZkStateReader$3.process Updating live nodes... (2)
   [junit4]   2> 1358900 T3975 oascc.ZkStateReader$3.process Updating live nodes... (2)
   [junit4]   2> 1358903 T3962 oascc.ZkStateReader$3.process Updating live nodes... (2)
   [junit4]   2> 1358930 T3935 oasc.CorePropertiesLocator.discover Looking for core definitions underneath /Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/../../../../../../../../../Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.DeleteReplicaTest-jetty1-1383493545307
   [junit4]   2> 1359070 T3935 oasc.CorePropertiesLocator.discoverUnder Found core conf in /Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/../../../../../../../../../Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.DeleteReplicaTest-jetty1-1383493545307/conf/
   [junit4]   2> 1359078 T3935 oasc.CorePropertiesLocator.discover Found 1 core definitions
   [junit4]   2> 1359079 T3935 oass.SolrDispatchFilter.init user.dir=/Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0
   [junit4]   2> 1359080 T3935 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
   [junit4]   2> 1359453 T3935 oejs.Server.doStart jetty-8.1.10.v20130312
   [junit4]   2> 1359457 T3935 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:50302
   [junit4]   2> 1359458 T3935 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
   [junit4]   2> 1359458 T3935 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
   [junit4]   2> 1359459 T3935 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: ../../../../../../../../../Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.DeleteReplicaTest-jetty2-1383493547028
   [junit4]   2> 1359459 T3935 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '../../../../../../../../../Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.DeleteReplicaTest-jetty2-1383493547028/'
   [junit4]   2> 1359508 T3935 oasc.ConfigSolr.fromFile Loading container configuration from /Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/../../../../../../../../../Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.DeleteReplicaTest-jetty2-1383493547028/solr.xml
   [junit4]   2> 1359571 T3935 oasc.ConfigSolrXml.<init> Config-defined core root directory: 
   [junit4]   2> 1359572 T3935 oasc.CoreContainer.<init> New CoreContainer 1800534322
   [junit4]   2> 1359572 T3935 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=../../../../../../../../../Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.DeleteReplicaTest-jetty2-1383493547028/]
   [junit4]   2> 1359573 T3935 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 240000
   [junit4]   2> 1359574 T3935 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
   [junit4]   2> 1359574 T3935 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
   [junit4]   2> 1359575 T3935 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
   [junit4]   2> 1359575 T3935 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
   [junit4]   2> 1359576 T3935 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
   [junit4]   2> 1359576 T3935 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
   [junit4]   2> 1359576 T3935 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
   [junit4]   2> 1359577 T3935 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
   [junit4]   2> 1359580 T3935 oasl.LogWatcher.createWatcher SLF4J impl is org.slf4j.impl.Log4jLoggerFactory
   [junit4]   2> 1359580 T3935 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
   [junit4]   2> 1359581 T3935 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:50292/solr
   [junit4]   2> 1359581 T3935 oasc.ZkController.checkChrootPath zkHost includes chroot
   [junit4]   2> 1359583 T3935 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 1359590 T3987 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@52bf78a9 name:ZooKeeperConnection Watcher:127.0.0.1:50292 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 1359591 T3935 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 1359597 T3935 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 1359601 T3989 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@55e47659 name:ZooKeeperConnection Watcher:127.0.0.1:50292/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 1359601 T3935 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 1359616 T3935 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
   [junit4]   2> 1360631 T3935 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:50302_
   [junit4]   2> 1360637 T3935 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:50302_
   [junit4]   2> 1360657 T3962 oascc.ZkStateReader$3.process Updating live nodes... (3)
   [junit4]   2> 1360661 T3975 oascc.ZkStateReader$3.process Updating live nodes... (3)
   [junit4]   2> 1360665 T3957 oascc.ZkStateReader$3.process Updating live nodes... (3)
   [junit4]   2> 1360668 T3989 oascc.ZkStateReader$3.process Updating live nodes... (3)
   [junit4]   2> 1360683 T3935 oasc.CorePropertiesLocator.discover Looking for core definitions underneath /Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/../../../../../../../../../Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.DeleteReplicaTest-jetty2-1383493547028
   [junit4]   2> 1360809 T3935 oasc.CorePropertiesLocator.discoverUnder Found core conf in /Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/../../../../../../../../../Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.DeleteReplicaTest-jetty2-1383493547028/conf/
   [junit4]   2> 1360816 T3935 oasc.CorePropertiesLocator.discover Found 1 core definitions
   [junit4]   2> 1360817 T3935 oass.SolrDispatchFilter.init user.dir=/Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0
   [junit4]   2> 1360818 T3935 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
   [junit4]   2> 1361122 T3935 oejs.Server.doStart jetty-8.1.10.v20130312
   [junit4]   2> 1361127 T3935 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:50306
   [junit4]   2> 1361127 T3935 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
   [junit4]   2> 1361128 T3935 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
   [junit4]   2> 1361128 T3935 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: ../../../../../../../../../Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.DeleteReplicaTest-jetty3-1383493548766
   [junit4]   2> 1361129 T3935 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '../../../../../../../../../Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.DeleteReplicaTest-jetty3-1383493548766/'
   [junit4]   2> 1361183 T3935 oasc.ConfigSolr.fromFile Loading container configuration from /Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/../../../../../../../../../Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.DeleteReplicaTest-jetty3-1383493548766/solr.xml
   [junit4]   2> 1361236 T3935 oasc.ConfigSolrXml.<init> Config-defined core root directory: 
   [junit4]   2> 1361237 T3935 oasc.CoreContainer.<init> New CoreContainer 237068683
   [junit4]   2> 1361237 T3935 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=../../../../../../../../../Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.DeleteReplicaTest-jetty3-1383493548766/]
   [junit4]   2> 1361239 T3935 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 240000
   [junit4]   2> 1361239 T3935 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
   [junit4]   2> 1361241 T3935 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
   [junit4]   2> 1361241 T3935 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
   [junit4]   2> 1361241 T3935 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
   [junit4]   2> 1361242 T3935 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
   [junit4]   2> 1361242 T3935 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
   [junit4]   2> 1361243 T3935 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
   [junit4]   2> 1361243 T3935 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
   [junit4]   2> 1361247 T3935 oasl.LogWatcher.createWatcher SLF4J impl is org.slf4j.impl.Log4jLoggerFactory
   [junit4]   2> 1361247 T3935 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
   [junit4]   2> 1361248 T3935 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:50292/solr
   [junit4]   2> 1361248 T3935 oasc.ZkController.checkChrootPath zkHost includes chroot
   [junit4]   2> 1361249 T3935 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 1361256 T4002 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@318af3ec name:ZooKeeperConnection Watcher:127.0.0.1:50292 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 1361257 T3935 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 1361264 T3935 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 1361268 T4004 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@6cd1a6bc name:ZooKeeperConnection Watcher:127.0.0.1:50292/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 1361269 T3935 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 1361283 T3935 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
   [junit4]   2> 1362296 T3935 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:50306_
   [junit4]   2> 1362302 T3935 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:50306_
   [junit4]   2> 1362324 T3975 oascc.ZkStateReader$3.process Updating live nodes... (4)
   [junit4]   2> 1362328 T4004 oascc.ZkStateReader$3.process Updating live nodes... (4)
   [junit4]   2> 1362331 T3957 oascc.ZkStateReader$3.process Updating live nodes... (4)
   [junit4]   2> 1362333 T3962 oascc.ZkStateReader$3.process Updating live nodes... (4)
   [junit4]   2> 1362339 T3989 oascc.ZkStateReader$3.process Updating live nodes... (4)
   [junit4]   2> 1362367 T3935 oasc.CorePropertiesLocator.discover Looking for core definitions underneath /Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/../../../../../../../../../Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.DeleteReplicaTest-jetty3-1383493548766
   [junit4]   2> 1362520 T3935 oasc.CorePropertiesLocator.discoverUnder Found core conf in /Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/../../../../../../../../../Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.DeleteReplicaTest-jetty3-1383493548766/conf/
   [junit4]   2> 1362527 T3935 oasc.CorePropertiesLocator.discover Found 1 core definitions
   [junit4]   2> 1362528 T3935 oass.SolrDispatchFilter.init user.dir=/Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0
   [junit4]   2> 1362529 T3935 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
   [junit4]   2> 1362874 T3935 oejs.Server.doStart jetty-8.1.10.v20130312
   [junit4]   2> 1362878 T3935 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:50309
   [junit4]   2> 1362879 T3935 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
   [junit4]   2> 1362879 T3935 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
   [junit4]   2> 1362880 T3935 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: ./org.apache.solr.cloud.DeleteReplicaTest-jetty4-1383493550478
   [junit4]   2> 1362880 T3935 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: './org.apache.solr.cloud.DeleteReplicaTest-jetty4-1383493550478/'
   [junit4]   2> 1362942 T3935 oasc.ConfigSolr.fromFile Loading container configuration from /Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.DeleteReplicaTest-jetty4-1383493550478/solr.xml
   [junit4]   2> 1363005 T3935 oasc.ConfigSolrXml.<init> Config-defined core root directory: 
   [junit4]   2> 1363006 T3935 oasc.CoreContainer.<init> New CoreContainer 1112170764
   [junit4]   2> 1363006 T3935 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=./org.apache.solr.cloud.DeleteReplicaTest-jetty4-1383493550478/]
   [junit4]   2> 1363008 T3935 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 240000
   [junit4]   2> 1363009 T3935 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
   [junit4]   2> 1363009 T3935 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
   [junit4]   2> 1363010 T3935 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
   [junit4]   2> 1363010 T3935 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
   [junit4]   2> 1363011 T3935 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
   [junit4]   2> 1363011 T3935 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
   [junit4]   2> 1363012 T3935 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
   [junit4]   2> 1363012 T3935 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
   [junit4]   2> 1363016 T3935 oasl.LogWatcher.createWatcher SLF4J impl is org.slf4j.impl.Log4jLoggerFactory
   [junit4]   2> 1363017 T3935 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
   [junit4]   2> 1363018 T3935 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:50292/solr
   [junit4]   2> 1363018 T3935 oasc.ZkController.checkChrootPath zkHost includes chroot
   [junit4]   2> 1363021 T3935 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 1363027 T4016 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@21297cd4 name:ZooKeeperConnection Watcher:127.0.0.1:50292 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 1363029 T3935 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 1363036 T3935 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 1363041 T4018 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@1789785c name:ZooKeeperConnection Watcher:127.0.0.1:50292/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 1363042 T3935 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 1363058 T3935 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
   [junit4]   2> 1364075 T3935 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:50309_
   [junit4]   2> 1364078 T3935 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:50309_
   [junit4]   2> 1364097 T4004 oascc.ZkStateReader$3.process Updating live nodes... (5)
   [junit4]   2> 1364100 T4018 oascc.ZkStateReader$3.process Updating live nodes... (5)
   [junit4]   2> 1364102 T3962 oascc.ZkStateReader$3.process Updating live nodes... (5)
   [junit4]   2> 1364103 T3989 oascc.ZkStateReader$3.process Updating live nodes... (5)
   [junit4]   2> 1364103 T3957 oascc.ZkStateReader$3.process Updating live nodes... (5)
   [junit4]   2> 1364104 T3975 oascc.ZkStateReader$3.process Updating live nodes... (5)
   [junit4]   2> 1364124 T3935 oasc.CorePropertiesLocator.discover Looking for core definitions underneath /Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.DeleteReplicaTest-jetty4-1383493550478
   [junit4]   2> 1364238 T3935 oasc.CorePropertiesLocator.discoverUnder Found core conf in /Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.DeleteReplicaTest-jetty4-1383493550478/conf/
   [junit4]   2> 1364243 T3935 oasc.CorePropertiesLocator.discover Found 1 core definitions
   [junit4]   2> 1364244 T3935 oass.SolrDispatchFilter.init user.dir=/Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0
   [junit4]   2> 1364244 T3935 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
   [junit4]   2> 1364250 T3935 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 1364255 T4021 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@6e9f3f46 name:ZooKeeperConnection Watcher:127.0.0.1:50292/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 1364256 T3935 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 1364260 T3935 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
   [junit4]   2> 1364270 T3935 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 1364275 T4023 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@3c8f9f08 name:ZooKeeperConnection Watcher:127.0.0.1:50292/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 1364275 T3935 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 1364279 T3935 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
   [junit4]   2> 1364290 T3948 oasha.CollectionsHandler.handleCreateAction Creating Collection : numShards=2&maxShardsPerNode=2&name=delLiveColl&replicationFactor=2&action=CREATE&wt=javabin&version=2
   [junit4]   2> 1364293 T3957 oasc.DistributedQueue$LatchChildWatcher.process Watcher fired on path: /overseer/collection-queue-work state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 1364298 T3959 oasc.OverseerCollectionProcessor.run Overseer Collection Processor: Get the message id:/overseer/collection-queue-work/qn-0000000000 message:{
   [junit4]   2> 	  "operation":"createcollection",
   [junit4]   2> 	  "fromApi":"true",
   [junit4]   2> 	  "name":"delLiveColl",
   [junit4]   2> 	  "replicationFactor":"2",
   [junit4]   2> 	  "numShards":"2",
   [junit4]   2> 	  "maxShardsPerNode":"2"}
   [junit4]   2> 1364299 T3959 oasc.OverseerCollectionProcessor.processMessage WARN OverseerCollectionProcessor.processMessage : createcollection , {
   [junit4]   2> 	  "operation":"createcollection",
   [junit4]   2> 	  "fromApi":"true",
   [junit4]   2> 	  "name":"delLiveColl",
   [junit4]   2> 	  "replicationFactor":"2",
   [junit4]   2> 	  "numShards":"2",
   [junit4]   2> 	  "maxShardsPerNode":"2"}
   [junit4]   2> 1364729 T3958 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 1364732 T3958 oasc.Overseer$ClusterStateUpdater.buildCollection building a new collection: delLiveColl
   [junit4]   2> 1364733 T3958 oasc.Overseer$ClusterStateUpdater.createCollection Create collection delLiveColl with shards [shard1, shard2]
   [junit4]   2> 1364745 T3957 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
   [junit4]   2> 1364746 T4018 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
   [junit4]   2> 1364746 T4021 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
   [junit4]   2> 1364746 T3962 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
   [junit4]   2> 1364747 T3975 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
   [junit4]   2> 1364746 T4004 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
   [junit4]   2> 1364749 T3989 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
   [junit4]   2> 1364750 T4023 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
   [junit4]   2> 1364813 T3959 oasc.OverseerCollectionProcessor.createCollection going to create cores replicas shardNames [shard1, shard2] , repFactor : 2
   [junit4]   2> 1364813 T3959 oasc.OverseerCollectionProcessor.createCollection Creating shard delLiveColl_shard1_replica1 as part of slice shard1 of collection delLiveColl on 127.0.0.1:50295_
   [junit4]   2> 1364814 T3959 oasc.OverseerCollectionProcessor.createCollection Creating shard delLiveColl_shard1_replica2 as part of slice shard1 of collection delLiveColl on 127.0.0.1:50302_
   [junit4]   2> 1364815 T3959 oasc.OverseerCollectionProcessor.createCollection Creating shard delLiveColl_shard2_replica1 as part of slice shard2 of collection delLiveColl on 127.0.0.1:50299_
   [junit4]   2> 1364825 T3959 oasc.OverseerCollectionProcessor.createCollection Creating shard delLiveColl_shard2_replica2 as part of slice shard2 of collection delLiveColl on 127.0.0.1:50309_
   [junit4]   2> 1364829 T3950 oasc.ZkController.publish publishing core=delLiveColl_shard1_replica1 state=down
   [junit4]   2> 1364831 T3980 oasc.ZkController.publish publishing core=delLiveColl_shard1_replica2 state=down
   [junit4]   2> 1364833 T3971 oasc.ZkController.publish publishing core=delLiveColl_shard2_replica1 state=down
   [junit4]   2> 1364834 T4013 oasc.ZkController.publish publishing core=delLiveColl_shard2_replica2 state=down
   [junit4]   2> 1364835 T3950 oasc.ZkController.waitForCoreNodeName look for our core node name
   [junit4]   2> 1364837 T3980 oasc.ZkController.waitForCoreNodeName look for our core node name
   [junit4]   2> 1364838 T3971 oasc.ZkController.waitForCoreNodeName look for our core node name
   [junit4]   2> 1364838 T4013 oasc.ZkController.waitForCoreNodeName look for our core node name
   [junit4]   2> 1366275 T3958 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 1366277 T3958 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
   [junit4]   2> 	  "operation":"state",
   [junit4]   2> 	  "state":"down",
   [junit4]   2> 	  "base_url":"http://127.0.0.1:50295",
   [junit4]   2> 	  "core":"delLiveColl_shard1_replica1",
   [junit4]   2> 	  "roles":null,
   [junit4]   2> 	  "node_name":"127.0.0.1:50295_",
   [junit4]   2> 	  "shard":"shard1",
   [junit4]   2> 	  "shard_range":null,
   [junit4]   2> 	  "shard_state":"active",
   [junit4]   2> 	  "shard_parent":null,
   [junit4]   2> 	  "collection":"delLiveColl",
   [junit4]   2> 	  "numShards":"2",
   [junit4]   2> 	  "core_node_name":null}
   [junit4]   2> 1366290 T3958 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
   [junit4]   2> 	  "operation":"state",
   [junit4]   2> 	  "state":"down",
   [junit4]   2> 	  "base_url":"http://127.0.0.1:50302",
   [junit4]   2> 	  "core":"delLiveColl_shard1_replica2",
   [junit4]   2> 	  "roles":null,
   [junit4]   2> 	  "node_name":"127.0.0.1:50302_",
   [junit4]   2> 	  "shard":"shard1",
   [junit4]   2> 	  "shard_range":null,
   [junit4]   2> 	  "shard_state":"active",
   [junit4]   2> 	  "shard_parent":null,
   [junit4]   2> 	  "collection":"delLiveColl",
   [junit4]   2> 	  "numShards":"2",
   [junit4]   2> 	  "core_node_name":null}
   [junit4]   2> 1366302 T3958 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
   [junit4]   2> 	  "operation":"state",
   [junit4]   2> 	  "state":"down",
   [junit4]   2> 	  "base_url":"http://127.0.0.1:50299",
   [junit4]   2> 	  "core":"delLiveColl_shard2_replica1",
   [junit4]   2> 	  "roles":null,
   [junit4]   2> 	  "node_name":"127.0.0.1:50299_",
   [junit4]   2> 	  "shard":"shard2",
   [junit4]   2> 	  "shard_range":null,
   [junit4]   2> 	  "shard_state":"active",
   [junit4]   2> 	  "shard_parent":null,
   [junit4]   2> 	  "collection":"delLiveColl",
   [junit4]   2> 	  "numShards":"2",
   [junit4]   2> 	  "core_node_name":null}
   [junit4]   2> 1366315 T3958 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
   [junit4]   2> 	  "operation":"state",
   [junit4]   2> 	  "state":"down",
   [junit4]   2> 	  "base_url":"http://127.0.0.1:50309",
   [junit4]   2> 	  "core":"delLiveColl_shard2_replica2",
   [junit4]   2> 	  "roles":null,
   [junit4]   2> 	  "node_name":"127.0.0.1:50309_",
   [junit4]   2> 	  "shard":"shard2",
   [junit4]   2> 	  "shard_range":null,
   [junit4]   2> 	  "shard_state":"active",
   [junit4]   2> 	  "shard_parent":null,
   [junit4]   2> 	  "collection":"delLiveColl",
   [junit4]   2> 	  "numShards":"2",
   [junit4]   2> 	  "core_node_name":null}
   [junit4]   2> 1366333 T3975 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
   [junit4]   2> 1366334 T3957 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
   [junit4]   2> 1366334 T4004 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
   [junit4]   2> 1366336 T4023 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
   [junit4]   2> 1366334 T3989 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
   [junit4]   2> 1366337 T3962 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
   [junit4]   2> 1366338 T4021 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
   [junit4]   2> 1366336 T4018 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
   [junit4]   2> 1366838 T3950 oasc.ZkController.waitForShardId waiting to find shard id in clusterstate for delLiveColl_shard1_replica1
   [junit4]   2> 1366841 T3980 oasc.ZkController.waitForShardId waiting to find shard id in clusterstate for delLiveColl_shard1_replica2
   [junit4]   2> 1366841 T4013 oasc.ZkController.waitForShardId waiting to find shard id in clusterstate for delLiveColl_shard2_replica2
   [junit4]   2> 1366841 T3971 oasc.ZkController.waitForShardId waiting to find shard id in clusterstate for delLiveColl_shard2_replica1
   [junit4]   2> 1366844 T4013 oasc.CoreContainer.create Creating SolrCore 'delLiveColl_shard2_replica2' using instanceDir: ./org.apache.solr.cloud.DeleteReplicaTest-jetty4-1383493550478/delLiveColl_shard2_replica2
   [junit4]   2> 1366844 T4013 oasc.ZkController.createCollectionZkNode Check for collection zkNode:delLiveColl
   [junit4]   2> 1366841 T3950 oasc.CoreContainer.create Creating SolrCore 'delLiveColl_shard1_replica1' using instanceDir: ../../../../../../../../../Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.DeleteReplicaTest-controljetty-1383493544471/delLiveColl_shard1_replica1
   [junit4]   2> 1366845 T3950 oasc.ZkController.createCollectionZkNode Check for collection zkNode:delLiveColl
   [junit4]   2> 1366845 T3971 oasc.CoreContainer.create Creating SolrCore 'delLiveColl_shard2_replica1' using instanceDir: ../../../../../../../../../Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.DeleteReplicaTest-jetty1-1383493545307/delLiveColl_shard2_replica1
   [junit4]   2> 1366846 T3971 oasc.ZkController.createCollectionZkNode Check for collection zkNode:delLiveColl
   [junit4]   2> 1366843 T3980 oasc.CoreContainer.create Creating SolrCore 'delLiveColl_shard1_replica2' using instanceDir: ../../../../../../../../../Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.DeleteReplicaTest-jetty2-1383493547028/delLiveColl_shard1_replica2
   [junit4]   2> 1366847 T3980 oasc.ZkController.createCollectionZkNode Check for collection zkNode:delLiveColl
   [junit4]   2> 1366848 T4013 oasc.ZkController.createCollectionZkNode Creating collection in ZooKeeper:delLiveColl
   [junit4]   2> 1366849 T4013 oasc.ZkController.getConfName Looking for collection configName
   [junit4]   2> 1366849 T3971 oasc.ZkController.createCollectionZkNode Creating collection in ZooKeeper:delLiveColl
   [junit4]   2> 1366850 T3971 oasc.ZkController.getConfName Looking for collection configName
   [junit4]   2> 1366850 T3980 oasc.ZkController.createCollectionZkNode Creating collection in ZooKeeper:delLiveColl
   [junit4]   2> 1366851 T3980 oasc.ZkController.getConfName Looking for collection configName
   [junit4]   2> 1366851 T3950 oasc.ZkController.createCollectionZkNode Creating collection in ZooKeeper:delLiveColl
   [junit4]   2> 1366852 T3950 oasc.ZkController.getConfName Looking for collection configName
   [junit4]   2> 1366872 T4013 oasc.ZkController.getConfName Only one config set found in zk - using it:conf1
   [junit4]   2> 1366873 T4013 oascc.SolrZkClient.makePath makePath: /collections/delLiveColl
   [junit4]   2> 1366876 T3980 oasc.ZkController.getConfName Only one config set found in zk - using it:conf1
   [junit4]   2> 1366877 T3980 oascc.SolrZkClient.makePath makePath: /collections/delLiveColl
   [junit4]   2> 1366877 T3950 oasc.ZkController.getConfName Only one config set found in zk - using it:conf1
   [junit4]   2> 1366878 T3950 oascc.SolrZkClient.makePath makePath: /collections/delLiveColl
   [junit4]   2> 1366877 T3971 oasc.ZkController.getConfName Only one config set found in zk - using it:conf1
   [junit4]   2> 1366879 T3971 oascc.SolrZkClient.makePath makePath: /collections/delLiveColl
   [junit4]   2> 1366890 T4013 oasc.ZkController.readConfigName Load collection config from:/collections/delLiveColl
   [junit4]   2> 1366893 T3971 oasc.ZkController.readConfigName Load collection config from:/collections/delLiveColl
   [junit4]   2> 1366895 T3950 oasc.ZkController.readConfigName Load collection config from:/collections/delLiveColl
   [junit4]   2> 1366896 T3980 oasc.ZkController.readConfigName Load collection config from:/collections/delLiveColl
   [junit4]   2> 1366903 T3950 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '../../../../../../../../../Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.DeleteReplicaTest-controljetty-1383493544471/delLiveColl_shard1_replica1/'
   [junit4]   2> 1366904 T3971 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '../../../../../../../../../Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.DeleteReplicaTest-jetty1-1383493545307/delLiveColl_shard2_replica1/'
   [junit4]   2> 1366905 T4013 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: './org.apache.solr.cloud.DeleteReplicaTest-jetty4-1383493550478/delLiveColl_shard2_replica2/'
   [junit4]   2> 1366907 T3980 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '../../../../../../../../../Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.DeleteReplicaTest-jetty2-1383493547028/delLiveColl_shard1_replica2/'
   [junit4]   2> 1367022 T3971 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_46
   [junit4]   2> 1367083 T3950 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_46
   [junit4]   2> 1367116 T3980 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_46
   [junit4]   2> 1367142 T4013 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_46
   [junit4]   2> 1367145 T3971 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
   [junit4]   2> 1367153 T3971 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
   [junit4]   2> 1367180 T3971 oass.IndexSchema.readSchema [delLiveColl_shard2_replica1] Schema name=test
   [junit4]   2> 1367209 T3980 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
   [junit4]   2> 1367219 T3980 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
   [junit4]   2> 1367253 T3980 oass.IndexSchema.readSchema [delLiveColl_shard1_replica2] Schema name=test
   [junit4]   2> 1367265 T3950 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
   [junit4]   2> 1367268 T4013 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
   [junit4]   2> 1367291 T4013 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
   [junit4]   2> 1367298 T3950 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
   [junit4]   2> 1367304 T4013 oass.IndexSchema.readSchema [delLiveColl_shard2_replica2] Schema name=test
   [junit4]   2> 1367340 T3950 oass.IndexSchema.readSchema [delLiveColl_shard1_replica1] Schema name=test
   [junit4]   2> 1368684 T3980 oass.ByteField.init WARN ByteField is deprecated and will be removed in 5.0. You should use TrieIntField instead.
   [junit4]   2> 1368685 T3980 oass.ShortField.init WARN ShortField is deprecated and will be removed in 5.0. You should use TrieIntField instead.
   [junit4]   2> 1368686 T3980 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
   [junit4]   2> 1368697 T3980 oass.IndexSchema.readSchema default search field in schema is text
   [junit4]   2> 1368701 T3980 oass.IndexSchema.readSchema unique key field: id
   [junit4]   2> 1368717 T4013 oass.ByteField.init WARN ByteField is deprecated and will be removed in 5.0. You should use TrieIntField instead.
   [junit4]   2> 1368721 T4013 oass.ShortField.init WARN ShortField is deprecated and will be removed in 5.0. You should use TrieIntField instead.
   [junit4]   2> 1368723 T4013 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
   [junit4]   2> 1368733 T4013 oass.IndexSchema.readSchema default search field in schema is text
   [junit4]   2> 1368742 T4013 oass.IndexSchema.readSchema unique key field: id
   [junit4]   2> 1368783 T3950 oass.ByteField.init WARN ByteField is deprecated and will be removed in 5.0. You should use TrieIntField instead.
   [junit4]   2> 1368784 T3950 oass.ShortField.init WARN ShortField is deprecated and will be removed in 5.0. You should use TrieIntField instead.
   [junit4]   2> 1368785 T3950 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
   [junit4]   2> 1368796 T3950 oass.IndexSchema.readSchema default search field in schema is text
   [junit4]   2> 1368818 T3950 oass.IndexSchema.readSchema unique key field: id
   [junit4]   2> 1368833 T3980 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
   [junit4]   2> 1368841 T3971 oass.ByteField.init WARN ByteField is deprecated and will be removed in 5.0. You should use TrieIntField instead.
   [junit4]   2> 1368843 T3971 oass.ShortField.init WARN ShortField is deprecated and will be removed in 5.0. You should use TrieIntField instead.
   [junit4]   2> 1368844 T3971 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
   [junit4]   2> 1368853 T3980 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
   [junit4]   2> 1368855 T3971 oass.IndexSchema.readSchema default search field in schema is text
   [junit4]   2> 1368863 T3971 oass.IndexSchema.readSchema unique key field: id
   [junit4]   2> 1368871 T3980 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
   [junit4]   2> 1368888 T3980 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
   [junit4]   2> 1368889 T3980 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
   [junit4]   2> 1368890 T3980 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
   [junit4]   2> 1368898 T3980 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
   [junit4]   2> 1368899 T3980 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
   [junit4]   2> 1368899 T3980 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
   [junit4]   2> 1368900 T3980 oasc.SolrCore.<init> [delLiveColl_shard1_replica2] Opening new SolrCore at ../../../../../../../../../Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.DeleteReplicaTest-jetty2-1383493547028/delLiveColl_shard1_replica2/, dataDir=../../../../../../../../../Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.DeleteReplicaTest-jetty2-1383493547028/delLiveColl_shard1_replica2/data/
   [junit4]   2> 1368900 T3980 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@34845b35
   [junit4]   2> 1368902 T3980 oasc.CachingDirectoryFactory.get return new directory for ../../../../../../../../../Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.DeleteReplicaTest-jetty2-1383493547028/delLiveColl_shard1_replica2/data
   [junit4]   2> 1368904 T3980 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=../../../../../../../../../Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.DeleteReplicaTest-jetty2-1383493547028/delLiveColl_shard1_replica2/data/index/
   [junit4]   2> 1368904 T3980 oasc.SolrCore.initIndex WARN [delLiveColl_shard1_replica2] Solr index directory '../../../../../../../../../Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.DeleteReplicaTest-jetty2-1383493547028/delLiveColl_shard1_replica2/data/index' doesn't exist. Creating new index...
   [junit4]   2> 1368905 T3980 oasc.CachingDirectoryFactory.get return new directory for ../../../../../../../../../Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.DeleteReplicaTest-jetty2-1383493547028/delLiveColl_shard1_replica2/data/index
   [junit4]   2> 1368909 T3980 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: maxMergeAtOnce=42, maxMergeAtOnceExplicit=38, maxMergedSegmentMB=68.0361328125, floorSegmentMB=0.2734375, forceMergeDeletesPctAllowed=25.96084357475879, segmentsPerTier=11.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.7484421910509794
   [junit4]   2> 1368914 T3980 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
   [junit4]   2> 		commit{dir=MockDirectoryWrapper(org.apache.lucene.store.RAMDirectory@4c289909 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@5436804a),segFN=segments_1,generation=1}
   [junit4]   2> 1368914 T3980 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
   [junit4]   2> 1368915 T3950 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
   [junit4]   2> 1368919 T3980 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "nodistrib"
   [junit4]   2> 1368920 T3980 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "dedupe"
   [junit4]   2> 1368914 T4013 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
   [junit4]   2> 1368941 T3980 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
   [junit4]   2> 1368944 T3980 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "stored_sig"
   [junit4]   2> 1368945 T3980 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
   [junit4]   2> 1368945 T3980 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-explicit"
   [junit4]   2> 1368946 T3950 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
   [junit4]   2> 1368946 T3980 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-implicit"
   [junit4]   2> 1368948 T3980 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
   [junit4]   2> 1368949 T3980 oasc.SolrCore.loadUpdateProcessorChains no updateRequestProcessorChain defined as default, creating implicit default
   [junit4]   2> 1368951 T3980 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
   [junit4]   2> 1368952 T3980 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
   [junit4]   2> 1368952 T3980 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
   [junit4]   2> 1368952 T3980 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
   [junit4]   2> 1368953 T3980 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
   [junit4]   2> 1368954 T3980 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
   [junit4]   2> 1368954 T3950 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
   [junit4]   2> 1368952 T4013 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
   [junit4]   2> 1368960 T3950 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
   [junit4]   2> 1368961 T3950 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
   [junit4]   2> 1368961 T3950 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
   [junit4]   2> 1368964 T3980 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
   [junit4]   2> 1368972 T3950 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
   [junit4]   2> 1368973 T3950 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
   [junit4]   2> 1368973 T4013 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
   [junit4]   2> 1368974 T3980 oasu.CommitTracker.<init> Hard AutoCommit: disabled
   [junit4]   2> 1368976 T3980 oasu.CommitTracker.<init> Soft AutoCommit: disabled
   [junit4]   2> 1368974 T3950 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
   [junit4]   2> 1368979 T3950 oasc.SolrCore.<init> [delLiveColl_shard1_replica1] Opening new SolrCore at ../../../../../../../../../Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.DeleteReplicaTest-controljetty-1383493544471/delLiveColl_shard1_replica1/, dataDir=../../../../../../../../../Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.DeleteReplicaTest-controljetty-1383493544471/delLiveColl_shard1_replica1/data/
   [junit4]   2> 1368980 T3950 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@34845b35
   [junit4]   2> 1368978 T3980 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.LogByteSizeMergePolicy: [LogByteSizeMergePolicy: minMergeSize=1677721, mergeFactor=12, maxMergeSize=2147483648, maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=true, maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.0]
   [junit4]   2> 1368979 T4013 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
   [junit4]   2> 1368981 T4013 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
   [junit4]   2> 1368982 T4013 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
   [junit4]   2> 1368981 T3980 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=1
   [junit4]   2> 		commit{dir=MockDirectoryWrapper(org.apache.lucene.store.RAMDirectory@4c289909 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@5436804a),segFN=segments_1,generation=1}
   [junit4]   2> 1368984 T3980 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
   [junit4]   2> 1368984 T3980 oass.SolrIndexSearcher.<init> Opening Searcher@38f75d22 main
   [junit4]   2> 1368981 T3950 oasc.CachingDirectoryFactory.get return new directory for ../../../../../../../../../Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.DeleteReplicaTest-controljetty-1383493544471/delLiveColl_shard1_replica1/data
   [junit4]   2> 1368984 T3971 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
   [junit4]   2> 1368985 T3950 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=../../../../../../../../../Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.DeleteReplicaTest-controljetty-1383493544471/delLiveColl_shard1_replica1/data/index/
   [junit4]   2> 1368989 T3950 oasc.SolrCore.initIndex WARN [delLiveColl_shard1_replica1] Solr index directory '../../../../../../../../../Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.DeleteReplicaTest-controljetty-1383493544471/delLiveColl_shard1_replica1/data/index' doesn't exist. Creating new index...
   [junit4]   2> 1368993 T4028 oasc.SolrCore.registerSearcher [delLiveColl_shard1_replica2] Registered new searcher Searcher@38f75d22 main{StandardDirectoryReader(segments_1:1:nrt)}
   [junit4]   2> 1368994 T4013 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
   [junit4]   2> 1368994 T4013 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
   [junit4]   2> 1368995 T3950 oasc.CachingDirectoryFactory.get return new directory for ../../../../../../../../../Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.DeleteReplicaTest-controljetty-1383493544471/delLiveColl_shard1_replica1/data/index
   [junit4]   2> 1368996 T3950 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: maxMergeAtOnce=42, maxMergeAtOnceExplicit=38, maxMergedSegmentMB=68.0361328125, floorSegmentMB=0.2734375, forceMergeDeletesPctAllowed=25.96084357475879, segmentsPerTier=11.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.7484421910509794
   [junit4]   2> 1368995 T4013 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
   [junit4]   2> 1368997 T4013 oasc.SolrCore.<init> [delLiveColl_shard2_replica2] Opening new SolrCore at ./org.apache.solr.cloud.DeleteReplicaTest-jetty4-1383493550478/delLiveColl_shard2_replica2/, dataDir=./org.apache.solr.cloud.DeleteReplicaTest-jetty4-1383493550478/delLiveColl_shard2_replica2/data/
   [junit4]   2> 1368997 T4013 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@34845b35
   [junit4]   2> 1368998 T3980 oasc.CoreContainer.registerCore registering core: delLiveColl_shard1_replica2
   [junit4]   2> 1368998 T3980 oasc.ZkController.register Register replica - core:delLiveColl_shard1_replica2 address:http://127.0.0.1:50302 collection:delLiveColl shard:shard1
   [junit4]   2> 1368998 T4013 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.DeleteReplicaTest-jetty4-1383493550478/delLiveColl_shard2_replica2/data
   [junit4]   2> 1368999 T4013 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=./org.apache.solr.cloud.DeleteReplicaTest-jetty4-1383493550478/delLiveColl_shard2_replica2/data/index/
   [junit4]   2> 1369000 T4013 oasc.SolrCore.initIndex WARN [delLiveColl_shard2_replica2] Solr index directory './org.apache.solr.cloud.DeleteReplicaTest-jetty4-1383493550478/delLiveColl_shard2_replica2/data/index' doesn't exist. Creating new index...
   [junit4]   2> 1369001 T3950 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
   [junit4]   2> 		commit{dir=MockDirectoryWrapper(org.apache.lucene.store.RAMDirectory@19cabb4e lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@4af03c44),segFN=segments_1,generation=1}
   [junit4]   2> 1369004 T3950 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
   [junit4]   2> 1369004 T4013 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.DeleteReplicaTest-jetty4-1383493550478/delLiveColl_shard2_replica2/data/index
   [junit4]   2> 1369006 T3971 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
   [junit4]   2> 1369006 T4013 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: maxMergeAtOnce=42, maxMergeAtOnceExplicit=38, maxMergedSegmentMB=68.0361328125, floorSegmentMB=0.2734375, forceMergeDeletesPctAllowed=25.96084357475879, segmentsPerTier=11.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.7484421910509794
   [junit4]   2> 1369007 T3980 oascc.SolrZkClient.makePath makePath: /collections/delLiveColl/leader_elect/shard1/election
   [junit4]   2> 1369010 T3950 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "nodistrib"
   [junit4]   2> 1369011 T3950 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "dedupe"
   [junit4]   2> 1369010 T4013 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
   [junit4]   2> 		commit{dir=MockDirectoryWrapper(org.apache.lucene.store.RAMDirectory@48ce8ecd lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@2a972c80),segFN=segments_1,generation=1}
   [junit4]   2> 1369013 T4013 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
   [junit4]   2> 1369013 T3950 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
   [junit4]   2> 1369015 T3950 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "stored_sig"
   [junit4]   2> 1369015 T3950 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
   [junit4]   2> 1369016 T3950 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-explicit"
   [junit4]   2> 1369016 T3950 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-implicit"
   [junit4]   2> 1369017 T3950 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
   [junit4]   2> 1369018 T3950 oasc.SolrCore.loadUpdateProcessorChains no updateRequestProcessorChain defined as default, creating implicit default
   [junit4]   2> 1369019 T3950 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
   [junit4]   2> 1369017 T3971 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
   [junit4]   2> 1369024 T4013 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "nodistrib"
   [junit4]   2> 1369020 T3950 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
   [junit4]   2> 1369025 T3950 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
   [junit4]   2> 1369025 T4013 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "dedupe"
   [junit4]   2> 1369027 T4013 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
   [junit4]   2> 1369027 T4013 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "stored_sig"
   [junit4]   2> 1369029 T4013 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
   [junit4]   2> 1369029 T4013 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-explicit"
   [junit4]   2> 1369025 T3971 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
   [junit4]   2> 1369031 T3971 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
   [junit4]   2> 1369031 T3971 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
   [junit4]   2> 1369030 T4013 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-implicit"
   [junit4]   2> 1369033 T4013 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
   [junit4]   2> 1369034 T4013 oasc.SolrCore.loadUpdateProcessorChains no updateRequestProcessorChain defined as default, creating implicit default
   [junit4]   2> 1369036 T4013 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
   [junit4]   2> 1369037 T4013 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
   [junit4]   2> 1369038 T4013 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
   [junit4]   2> 1369039 T4013 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
   [junit4]   2> 1369027 T3950 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
   [junit4]   2> 1369040 T4013 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
   [junit4]   2> 1369042 T4013 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
   [junit4]   2> 1369038 T3971 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
   [junit4]   2> 1369043 T3971 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
   [junit4]   2> 1369044 T3971 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
   [junit4]   2> 1369044 T3971 oasc.SolrCore.<init> [delLiveColl_shard2_replica1] Opening new SolrCore at ../../../../../../../../../Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.DeleteReplicaTest-jetty1-1383493545307/delLiveColl_shard2_replica1/, dataDir=../../../../../../../../../Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.DeleteReplicaTest-jetty1-1383493545307/delLiveColl_shard2_replica1/data/
   [junit4]   2> 1369042 T3980 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process for shard shard1
   [junit4]   2> 1369042 T3950 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
   [junit4]   2> 1369045 T3971 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@34845b35
   [junit4]   2> 1369047 T3950 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
   [junit4]   2> 1369045 T4013 oash

[...truncated too long message...]

junit4]   2> 
   [junit4]   2> 1584484 T4022 oaz.ClientCnxn$SendThread.run WARN Session 0x1421ea428b0000e for server null, unexpected error, closing socket connection and attempting reconnect java.net.ConnectException: Connection refused
   [junit4]   2> 	at sun.nio.ch.SocketChannelImpl.checkConnect(Native Method)
   [junit4]   2> 	at sun.nio.ch.SocketChannelImpl.finishConnect(SocketChannelImpl.java:599)
   [junit4]   2> 	at org.apache.zookeeper.ClientCnxnSocketNIO.doTransport(ClientCnxnSocketNIO.java:350)
   [junit4]   2> 	at org.apache.zookeeper.ClientCnxn$SendThread.run(ClientCnxn.java:1068)
   [junit4]   2> 
   [junit4]   2> 1584982 T4022 oaz.ClientCnxn$SendThread.run WARN Unexpected exception java.lang.InterruptedException: sleep interrupted
   [junit4]   2> 	at java.lang.Thread.sleep(Native Method)
   [junit4]   2> 	at org.apache.zookeeper.ClientCnxn$SendThread.run(ClientCnxn.java:984)
   [junit4]   2> 
   [junit4]   2> 1585483 T4022 oazc.StaticHostProvider.next WARN Unexpected exception java.lang.InterruptedException: sleep interrupted
   [junit4]   2> 	at java.lang.Thread.sleep(Native Method)
   [junit4]   2> 	at org.apache.zookeeper.client.StaticHostProvider.next(StaticHostProvider.java:86)
   [junit4]   2> 	at org.apache.zookeeper.ClientCnxn$SendThread.startConnect(ClientCnxn.java:937)
   [junit4]   2> 	at org.apache.zookeeper.ClientCnxn$SendThread.run(ClientCnxn.java:993)
   [junit4]   2> 
   [junit4]   2> 1585485 T4022 oaz.ClientCnxn$SendThread.run WARN Session 0x1421ea428b0000e for server null, unexpected error, closing socket connection and attempting reconnect java.net.ConnectException: Connection refused
   [junit4]   2> 	at sun.nio.ch.SocketChannelImpl.checkConnect(Native Method)
   [junit4]   2> 	at sun.nio.ch.SocketChannelImpl.finishConnect(SocketChannelImpl.java:599)
   [junit4]   2> 	at org.apache.zookeeper.ClientCnxnSocketNIO.doTransport(ClientCnxnSocketNIO.java:350)
   [junit4]   2> 	at org.apache.zookeeper.ClientCnxn$SendThread.run(ClientCnxn.java:1068)
   [junit4]   2> 
   [junit4]   2> 1585985 T4022 oaz.ClientCnxn$SendThread.run WARN Unexpected exception java.lang.InterruptedException: sleep interrupted
   [junit4]   2> 	at java.lang.Thread.sleep(Native Method)
   [junit4]   2> 	at org.apache.zookeeper.ClientCnxn$SendThread.run(ClientCnxn.java:984)
   [junit4]   2> 
   [junit4]   2> 230344 T3934 ccr.ThreadLeakControl.tryToInterruptAll SEVERE There are still zombie threads that couldn't be terminated:
   [junit4]   2> 	   1) Thread[id=4022, name=TEST-DeleteReplicaTest.testDistribSearch-seed#[85DB331831D2512B]-SendThread(localhost:50292), state=TIMED_WAITING, group=TGRP-DeleteReplicaTest]
   [junit4]   2> 	        at java.lang.Thread.sleep(Native Method)
   [junit4]   2> 	        at org.apache.zookeeper.client.StaticHostProvider.next(StaticHostProvider.java:86)
   [junit4]   2> 	        at org.apache.zookeeper.ClientCnxn$SendThread.startConnect(ClientCnxn.java:937)
   [junit4]   2> 	        at org.apache.zookeeper.ClientCnxn$SendThread.run(ClientCnxn.java:993)
   [junit4]   2> NOTE: test params are: codec=Asserting, sim=RandomSimilarityProvider(queryNorm=false,coord=yes): {}, locale=es_ES, timezone=Africa/Lome
   [junit4]   2> NOTE: Mac OS X 10.8.5 x86_64/Apple Inc. 1.6.0_65 (64-bit)/cpus=2,threads=3,free=176838128,total=324063232
   [junit4]   2> NOTE: All tests run in this JVM: [TestNoOpRegenerator, TestLazyCores, SystemInfoHandlerTest, TestSchemaResource, SuggesterWFSTTest, RequiredFieldsTest, CurrencyFieldXmlFileTest, TestInfoStreamLogging, TermsComponentTest, TestGroupingSearch, TestWriterPerf, TestDocumentBuilder, TestSolrXml, SolrXmlInZkTest, TestPhraseSuggestions, IndexSchemaTest, TestStressUserVersions, TestBinaryField, CollectionsAPIDistributedZkTest, TestSort, TestCSVLoader, PluginInfoTest, FileBasedSpellCheckerTest, TestBinaryResponseWriter, TestManagedSchemaFieldResource, TermVectorComponentDistributedTest, DirectSolrConnectionTest, TestFiltering, HdfsBasicDistributedZk2Test, TestCloudManagedSchema, NoCacheHeaderTest, TestSerializedLuceneMatchVersion, BJQParserTest, DisMaxRequestHandlerTest, DocValuesMultiTest, IndexBasedSpellCheckerTest, TestReloadAndDeleteDocs, TestSolrQueryParserResource, BadCopyFieldTest, FieldMutatingUpdateProcessorTest, HdfsLockFactoryTest, DirectSolrSpellCheckerTest, BasicDistributedZkTest, DirectUpdateHandlerTest, TestQuerySenderNoQuery, AssignTest, SynonymTokenizerTest, PrimUtilsTest, SearchHandlerTest, TestRandomMergePolicy, TestRecoveryHdfs, TestSolrIndexConfig, SpellingQueryConverterTest, TestRealTimeGet, SuggesterTSTTest, DefaultValueUpdateProcessorTest, TestCloudManagedSchemaAddField, TestCollationKeyRangeQueries, TestLRUCache, UpdateParamsTest, TestSystemIdResolver, SchemaVersionSpecificBehaviorTest, TestClassNameShortening, TestSchemaSimilarityResource, PeerSyncTest, SuggesterFSTTest, TestCodecSupport, DOMUtilTest, BlockDirectoryTest, TestMultiCoreConfBootstrap, TestDocBasedVersionConstraints, TestRTGBase, OverseerTest, SliceStateUpdateTest, TestFaceting, TestPseudoReturnFields, EchoParamsTest, TestReplicationHandler, HdfsChaosMonkeySafeLeaderTest, TestIndexSearcher, TestBM25SimilarityFactory, CachingDirectoryFactoryTest, TestSolrDeletionPolicy2, ChaosMonkeyNothingIsSafeTest, ShardRoutingCustomTest, BlockCacheTest, XmlUpdateRequestHandlerTest, TestNumberUtils, OpenCloseCoreStressTest, QueryResultKeyTest, TestCopyFieldCollectionResource, TestJmxMonitoredMap, TestZkChroot, TestStressVersions, ScriptEngineTest, AutoCommitTest, DeleteInactiveReplicaTest, TestCoreDiscovery, IndexSchemaRuntimeFieldTest, StatsComponentTest, TestValueSourceCache, PreAnalyzedUpdateProcessorTest, ShardSplitTest, TestManagedSchema, TestIBSimilarityFactory, BadIndexSchemaTest, CoreAdminHandlerTest, DeleteReplicaTest]
   [junit4]   2> NOTE: reproduce with: ant test  -Dtestcase=DeleteReplicaTest -Dtests.seed=85DB331831D2512B -Dtests.slow=true -Dtests.locale=es_ES -Dtests.timezone=Africa/Lome -Dtests.file.encoding=ISO-8859-1
   [junit4] ERROR   0.00s | DeleteReplicaTest (suite) <<<
   [junit4]    > Throwable #1: java.lang.AssertionError: ERROR: SolrZkClient opens=15 closes=14
   [junit4]    > 	at __randomizedtesting.SeedInfo.seed([85DB331831D2512B]:0)
   [junit4]    > 	at org.apache.solr.SolrTestCaseJ4.endTrackingZkClients(SolrTestCaseJ4.java:343)
   [junit4]    > 	at org.apache.solr.SolrTestCaseJ4.afterClass(SolrTestCaseJ4.java:135)
   [junit4]    > 	at java.lang.Thread.run(Thread.java:695)Throwable #2: com.carrotsearch.randomizedtesting.ThreadLeakError: 2 threads leaked from SUITE scope at org.apache.solr.cloud.DeleteReplicaTest: 
   [junit4]    >    1) Thread[id=4022, name=TEST-DeleteReplicaTest.testDistribSearch-seed#[85DB331831D2512B]-SendThread(localhost:50292), state=TIMED_WAITING, group=TGRP-DeleteReplicaTest]
   [junit4]    >         at java.lang.Thread.sleep(Native Method)
   [junit4]    >         at org.apache.zookeeper.client.StaticHostProvider.next(StaticHostProvider.java:86)
   [junit4]    >         at org.apache.zookeeper.ClientCnxn$SendThread.startConnect(ClientCnxn.java:937)
   [junit4]    >         at org.apache.zookeeper.ClientCnxn$SendThread.run(ClientCnxn.java:993)
   [junit4]    >    2) Thread[id=4023, name=TEST-DeleteReplicaTest.testDistribSearch-seed#[85DB331831D2512B]-EventThread, state=WAITING, group=TGRP-DeleteReplicaTest]
   [junit4]    >         at sun.misc.Unsafe.park(Native Method)
   [junit4]    >         at java.util.concurrent.locks.LockSupport.park(LockSupport.java:156)
   [junit4]    >         at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.await(AbstractQueuedSynchronizer.java:1987)
   [junit4]    >         at java.util.concurrent.LinkedBlockingQueue.take(LinkedBlockingQueue.java:399)
   [junit4]    >         at org.apache.zookeeper.ClientCnxn$EventThread.run(ClientCnxn.java:491)
   [junit4]    > 	at __randomizedtesting.SeedInfo.seed([85DB331831D2512B]:0)Throwable #3: com.carrotsearch.randomizedtesting.ThreadLeakError: There are still zombie threads that couldn't be terminated:
   [junit4]    >    1) Thread[id=4022, name=TEST-DeleteReplicaTest.testDistribSearch-seed#[85DB331831D2512B]-SendThread(localhost:50292), state=TIMED_WAITING, group=TGRP-DeleteReplicaTest]
   [junit4]    >         at java.lang.Thread.sleep(Native Method)
   [junit4]    >         at org.apache.zookeeper.client.StaticHostProvider.next(StaticHostProvider.java:86)
   [junit4]    >         at org.apache.zookeeper.ClientCnxn$SendThread.startConnect(ClientCnxn.java:937)
   [junit4]    >         at org.apache.zookeeper.ClientCnxn$SendThread.run(ClientCnxn.java:993)
   [junit4]    > 	at __randomizedtesting.SeedInfo.seed([85DB331831D2512B]:0)
   [junit4] Completed in 230.44s, 1 test, 1 failure, 3 errors <<< FAILURES!

[...truncated 673 lines...]
BUILD FAILED
/Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/build.xml:428: The following error occurred while executing this line:
/Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/build.xml:408: The following error occurred while executing this line:
/Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/build.xml:39: The following error occurred while executing this line:
/Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build.xml:189: The following error occurred while executing this line:
/Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/common-build.xml:483: The following error occurred while executing this line:
/Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/lucene/common-build.xml:1263: The following error occurred while executing this line:
/Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/lucene/common-build.xml:906: There were test failures: 333 suites, 1469 tests, 3 suite-level errors, 1 error, 1006 ignored (4 assumptions)

Total time: 67 minutes 32 seconds
Build step 'Invoke Ant' marked build as failure
Description set: Java: 64bit/jdk1.6.0 -XX:+UseCompressedOops -XX:+UseConcMarkSweepGC
Archiving artifacts
Recording test results
Email was triggered for: Failure
Sending email for trigger: Failure



[JENKINS] Lucene-Solr-4.x-MacOSX (64bit/jdk1.7.0) - Build # 953 - Still Failing!

Posted by Policeman Jenkins Server <je...@thetaphi.de>.
Build: http://jenkins.thetaphi.de/job/Lucene-Solr-4.x-MacOSX/953/
Java: 64bit/jdk1.7.0 -XX:-UseCompressedOops -XX:+UseG1GC

1 tests failed.
REGRESSION:  org.apache.solr.cloud.CollectionsAPIDistributedZkTest.testDistribSearch

Error Message:
createcollection the collection time out:60s

Stack Trace:
org.apache.solr.client.solrj.impl.HttpSolrServer$RemoteSolrException: createcollection the collection time out:60s
	at __randomizedtesting.SeedInfo.seed([B22F2E20CA6577D2:33C9A038BD3A17EE]:0)
	at org.apache.solr.client.solrj.impl.HttpSolrServer.request(HttpSolrServer.java:464)
	at org.apache.solr.client.solrj.impl.HttpSolrServer.request(HttpSolrServer.java:181)
	at org.apache.solr.cloud.CollectionsAPIDistributedZkTest.testCollectionsAPI(CollectionsAPIDistributedZkTest.java:818)
	at org.apache.solr.cloud.CollectionsAPIDistributedZkTest.doTest(CollectionsAPIDistributedZkTest.java:197)
	at org.apache.solr.BaseDistributedSearchTestCase.testDistribSearch(BaseDistributedSearchTestCase.java:835)
	at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
	at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:57)
	at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
	at java.lang.reflect.Method.invoke(Method.java:606)
	at com.carrotsearch.randomizedtesting.RandomizedRunner.invoke(RandomizedRunner.java:1559)
	at com.carrotsearch.randomizedtesting.RandomizedRunner.access$600(RandomizedRunner.java:79)
	at com.carrotsearch.randomizedtesting.RandomizedRunner$6.evaluate(RandomizedRunner.java:737)
	at com.carrotsearch.randomizedtesting.RandomizedRunner$7.evaluate(RandomizedRunner.java:773)
	at com.carrotsearch.randomizedtesting.RandomizedRunner$8.evaluate(RandomizedRunner.java:787)
	at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:53)
	at org.apache.lucene.util.TestRuleSetupTeardownChained$1.evaluate(TestRuleSetupTeardownChained.java:50)
	at org.apache.lucene.util.TestRuleFieldCacheSanity$1.evaluate(TestRuleFieldCacheSanity.java:51)
	at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:46)
	at com.carrotsearch.randomizedtesting.rules.SystemPropertiesInvariantRule$1.evaluate(SystemPropertiesInvariantRule.java:55)
	at org.apache.lucene.util.TestRuleThreadAndTestName$1.evaluate(TestRuleThreadAndTestName.java:49)
	at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:70)
	at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:48)
	at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
	at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:358)
	at com.carrotsearch.randomizedtesting.ThreadLeakControl.forkTimeoutingTask(ThreadLeakControl.java:782)
	at com.carrotsearch.randomizedtesting.ThreadLeakControl$3.evaluate(ThreadLeakControl.java:442)
	at com.carrotsearch.randomizedtesting.RandomizedRunner.runSingleTest(RandomizedRunner.java:746)
	at com.carrotsearch.randomizedtesting.RandomizedRunner$3.evaluate(RandomizedRunner.java:648)
	at com.carrotsearch.randomizedtesting.RandomizedRunner$4.evaluate(RandomizedRunner.java:682)
	at com.carrotsearch.randomizedtesting.RandomizedRunner$5.evaluate(RandomizedRunner.java:693)
	at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
	at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:53)
	at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:46)
	at org.apache.lucene.util.TestRuleStoreClassName$1.evaluate(TestRuleStoreClassName.java:42)
	at com.carrotsearch.randomizedtesting.rules.SystemPropertiesInvariantRule$1.evaluate(SystemPropertiesInvariantRule.java:55)
	at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:39)
	at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:39)
	at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
	at org.apache.lucene.util.TestRuleAssertionsRequired$1.evaluate(TestRuleAssertionsRequired.java:43)
	at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:48)
	at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:70)
	at org.apache.lucene.util.TestRuleIgnoreTestSuites$1.evaluate(TestRuleIgnoreTestSuites.java:55)
	at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
	at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:358)
	at java.lang.Thread.run(Thread.java:744)




Build Log:
[...truncated 9869 lines...]
   [junit4] Suite: org.apache.solr.cloud.CollectionsAPIDistributedZkTest
   [junit4]   2> 167843 T290 oas.BaseDistributedSearchTestCase.initHostContext Setting hostContext system property: /ncx/
   [junit4]   2> 167872 T290 oas.SolrTestCaseJ4.setUp ###Starting testDistribSearch
   [junit4]   2> Creating dataDir: /Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./solrtest-CollectionsAPIDistributedZkTest-1383513182648
   [junit4]   2> 167880 T290 oasc.ZkTestServer.run STARTING ZK TEST SERVER
   [junit4]   2> 167886 T291 oasc.ZkTestServer$ZKServerMain.runFromConfig Starting server
   [junit4]   2> 168088 T290 oasc.ZkTestServer.run start zk server on port:49429
   [junit4]   2> 168224 T290 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 168326 T297 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@513676bb name:ZooKeeperConnection Watcher:127.0.0.1:49429 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 168327 T290 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 168330 T290 oascc.SolrZkClient.makePath makePath: /solr
   [junit4]   2> 168399 T290 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 168404 T299 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@6d6255f2 name:ZooKeeperConnection Watcher:127.0.0.1:49429/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 168404 T290 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 168409 T290 oascc.SolrZkClient.makePath makePath: /collections/collection1
   [junit4]   2> 168419 T290 oascc.SolrZkClient.makePath makePath: /collections/collection1/shards
   [junit4]   2> 168428 T290 oascc.SolrZkClient.makePath makePath: /collections/control_collection
   [junit4]   2> 168435 T290 oascc.SolrZkClient.makePath makePath: /collections/control_collection/shards
   [junit4]   2> 168444 T290 oasc.AbstractZkTestCase.putConfig put /Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test-files/solr/collection1/conf/solrconfig-tlog.xml to /configs/conf1/solrconfig.xml
   [junit4]   2> 168467 T290 oascc.SolrZkClient.makePath makePath: /configs/conf1/solrconfig.xml
   [junit4]   2> 168481 T290 oasc.AbstractZkTestCase.putConfig put /Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test-files/solr/collection1/conf/schema.xml to /configs/conf1/schema.xml
   [junit4]   2> 168481 T290 oascc.SolrZkClient.makePath makePath: /configs/conf1/schema.xml
   [junit4]   2> 168490 T290 oasc.AbstractZkTestCase.putConfig put /Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test-files/solr/collection1/conf/solrconfig.snippet.randomindexconfig.xml to /configs/conf1/solrconfig.snippet.randomindexconfig.xml
   [junit4]   2> 168491 T290 oascc.SolrZkClient.makePath makePath: /configs/conf1/solrconfig.snippet.randomindexconfig.xml
   [junit4]   2> 168500 T290 oasc.AbstractZkTestCase.putConfig put /Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test-files/solr/collection1/conf/stopwords.txt to /configs/conf1/stopwords.txt
   [junit4]   2> 168500 T290 oascc.SolrZkClient.makePath makePath: /configs/conf1/stopwords.txt
   [junit4]   2> 168509 T290 oasc.AbstractZkTestCase.putConfig put /Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test-files/solr/collection1/conf/protwords.txt to /configs/conf1/protwords.txt
   [junit4]   2> 168510 T290 oascc.SolrZkClient.makePath makePath: /configs/conf1/protwords.txt
   [junit4]   2> 168518 T290 oasc.AbstractZkTestCase.putConfig put /Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test-files/solr/collection1/conf/currency.xml to /configs/conf1/currency.xml
   [junit4]   2> 168519 T290 oascc.SolrZkClient.makePath makePath: /configs/conf1/currency.xml
   [junit4]   2> 168527 T290 oasc.AbstractZkTestCase.putConfig put /Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test-files/solr/collection1/conf/open-exchange-rates.json to /configs/conf1/open-exchange-rates.json
   [junit4]   2> 168528 T290 oascc.SolrZkClient.makePath makePath: /configs/conf1/open-exchange-rates.json
   [junit4]   2> 168537 T290 oasc.AbstractZkTestCase.putConfig put /Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test-files/solr/collection1/conf/mapping-ISOLatin1Accent.txt to /configs/conf1/mapping-ISOLatin1Accent.txt
   [junit4]   2> 168537 T290 oascc.SolrZkClient.makePath makePath: /configs/conf1/mapping-ISOLatin1Accent.txt
   [junit4]   2> 168547 T290 oasc.AbstractZkTestCase.putConfig put /Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test-files/solr/collection1/conf/old_synonyms.txt to /configs/conf1/old_synonyms.txt
   [junit4]   2> 168547 T290 oascc.SolrZkClient.makePath makePath: /configs/conf1/old_synonyms.txt
   [junit4]   2> 168556 T290 oasc.AbstractZkTestCase.putConfig put /Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test-files/solr/collection1/conf/synonyms.txt to /configs/conf1/synonyms.txt
   [junit4]   2> 168556 T290 oascc.SolrZkClient.makePath makePath: /configs/conf1/synonyms.txt
   [junit4]   2> Using old style solr.xml
   [junit4]   2> 168568 T290 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 168572 T301 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@60ee590c name:ZooKeeperConnection Watcher:127.0.0.1:49429 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 168573 T290 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 168573 T290 oascc.SolrZkClient.makePath makePath: /solr
   [junit4]   2> 168591 T290 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 168595 T303 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@286738b6 name:ZooKeeperConnection Watcher:127.0.0.1:49429/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 168596 T290 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 168597 T290 oasc.AbstractZkTestCase.putConfig put /Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test-files/solr/collection1/conf/solrconfig.xml to /configs/conf2/solrconfig.xml
   [junit4]   2> 168598 T290 oascc.SolrZkClient.makePath makePath: /configs/conf2/solrconfig.xml
   [junit4]   2> 168610 T290 oasc.AbstractZkTestCase.putConfig put /Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test-files/solr/collection1/conf/schema.xml to /configs/conf2/schema.xml
   [junit4]   2> 168610 T290 oascc.SolrZkClient.makePath makePath: /configs/conf2/schema.xml
   [junit4]   2> 168619 T290 oasc.AbstractZkTestCase.putConfig put /Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test-files/solr/collection1/conf/solrconfig.snippet.randomindexconfig.xml to /configs/conf2/solrconfig.snippet.randomindexconfig.xml
   [junit4]   2> 168619 T290 oascc.SolrZkClient.makePath makePath: /configs/conf2/solrconfig.snippet.randomindexconfig.xml
   [junit4]   2> 168628 T290 oasc.AbstractZkTestCase.putConfig put /Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test-files/solr/collection1/conf/stopwords.txt to /configs/conf2/stopwords.txt
   [junit4]   2> 168629 T290 oascc.SolrZkClient.makePath makePath: /configs/conf2/stopwords.txt
   [junit4]   2> 168638 T290 oasc.AbstractZkTestCase.putConfig put /Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test-files/solr/collection1/conf/protwords.txt to /configs/conf2/protwords.txt
   [junit4]   2> 168638 T290 oascc.SolrZkClient.makePath makePath: /configs/conf2/protwords.txt
   [junit4]   2> 168647 T290 oasc.AbstractZkTestCase.putConfig put /Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test-files/solr/collection1/conf/currency.xml to /configs/conf2/currency.xml
   [junit4]   2> 168648 T290 oascc.SolrZkClient.makePath makePath: /configs/conf2/currency.xml
   [junit4]   2> 168657 T290 oasc.AbstractZkTestCase.putConfig put /Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test-files/solr/collection1/conf/open-exchange-rates.json to /configs/conf2/open-exchange-rates.json
   [junit4]   2> 168657 T290 oascc.SolrZkClient.makePath makePath: /configs/conf2/open-exchange-rates.json
   [junit4]   2> 168666 T290 oasc.AbstractZkTestCase.putConfig put /Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test-files/solr/collection1/conf/mapping-ISOLatin1Accent.txt to /configs/conf2/mapping-ISOLatin1Accent.txt
   [junit4]   2> 168666 T290 oascc.SolrZkClient.makePath makePath: /configs/conf2/mapping-ISOLatin1Accent.txt
   [junit4]   2> 168675 T290 oasc.AbstractZkTestCase.putConfig put /Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test-files/solr/collection1/conf/old_synonyms.txt to /configs/conf2/old_synonyms.txt
   [junit4]   2> 168676 T290 oascc.SolrZkClient.makePath makePath: /configs/conf2/old_synonyms.txt
   [junit4]   2> 168684 T290 oasc.AbstractZkTestCase.putConfig put /Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test-files/solr/collection1/conf/synonyms.txt to /configs/conf2/synonyms.txt
   [junit4]   2> 168685 T290 oascc.SolrZkClient.makePath makePath: /configs/conf2/synonyms.txt
   [junit4]   2> 168694 T290 oasc.AbstractZkTestCase.putConfig put /Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test-files/solr/collection1/conf/elevate.xml to /configs/conf2/elevate.xml
   [junit4]   2> 168694 T290 oascc.SolrZkClient.makePath makePath: /configs/conf2/elevate.xml
   [junit4]   2> 169008 T290 oejs.Server.doStart jetty-8.1.10.v20130312
   [junit4]   2> 169014 T290 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:49434
   [junit4]   2> 169014 T290 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
   [junit4]   2> 169015 T290 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
   [junit4]   2> 169015 T290 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: ../../../../../../../../../Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-controljetty-1383513183478
   [junit4]   2> 169015 T290 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '../../../../../../../../../Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-controljetty-1383513183478/'
   [junit4]   2> 169047 T290 oasc.ConfigSolr.fromFile Loading container configuration from /Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/../../../../../../../../../Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-controljetty-1383513183478/solr.xml
   [junit4]   2> 169116 T290 oasc.CoreContainer.<init> New CoreContainer 1423537106
   [junit4]   2> 169116 T290 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=../../../../../../../../../Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-controljetty-1383513183478/]
   [junit4]   2> 169118 T290 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 120000
   [junit4]   2> 169118 T290 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
   [junit4]   2> 169118 T290 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
   [junit4]   2> 169120 T290 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
   [junit4]   2> 169120 T290 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
   [junit4]   2> 169120 T290 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
   [junit4]   2> 169120 T290 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
   [junit4]   2> 169121 T290 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
   [junit4]   2> 169121 T290 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
   [junit4]   2> 169125 T290 oasl.LogWatcher.createWatcher SLF4J impl is org.slf4j.impl.Log4jLoggerFactory
   [junit4]   2> 169126 T290 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
   [junit4]   2> 169126 T290 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:49429/solr
   [junit4]   2> 169144 T290 oasc.ZkController.checkChrootPath zkHost includes chroot
   [junit4]   2> 169146 T290 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 169150 T314 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@3f530409 name:ZooKeeperConnection Watcher:127.0.0.1:49429 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 169151 T290 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 169165 T290 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 169169 T316 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@7c9d7893 name:ZooKeeperConnection Watcher:127.0.0.1:49429/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 169169 T290 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 169181 T290 oascc.SolrZkClient.makePath makePath: /overseer/queue
   [junit4]   2> 169198 T290 oascc.SolrZkClient.makePath makePath: /overseer/collection-queue-work
   [junit4]   2> 169218 T290 oascc.SolrZkClient.makePath makePath: /live_nodes
   [junit4]   2> 169223 T290 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:49434_ncx
   [junit4]   2> 169230 T290 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:49434_ncx
   [junit4]   2> 169240 T290 oascc.SolrZkClient.makePath makePath: /overseer_elect/election
   [junit4]   2> 169267 T290 oascc.SolrZkClient.makePath makePath: /overseer_elect/leader
   [junit4]   2> 169274 T290 oasc.Overseer.start Overseer (id=90669919952502789-127.0.0.1:49434_ncx-n_0000000000) starting
   [junit4]   2> 169304 T290 oascc.SolrZkClient.makePath makePath: /overseer/queue-work
   [junit4]   2> 169326 T318 oasc.OverseerCollectionProcessor.run Process current queue of collection creations
   [junit4]   2> 169328 T290 oascc.SolrZkClient.makePath makePath: /clusterstate.json
   [junit4]   2> 169335 T290 oascc.SolrZkClient.makePath makePath: /aliases.json
   [junit4]   2> 169343 T290 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
   [junit4]   2> 169364 T317 oasc.Overseer$ClusterStateUpdater.run Starting to work on the main queue
   [junit4]   2> 169370 T290 oass.SolrDispatchFilter.init user.dir=/Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0
   [junit4]   2> 169371 T290 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
   [junit4]   2> 169394 T290 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 169399 T321 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@384ef344 name:ZooKeeperConnection Watcher:127.0.0.1:49429/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 169399 T290 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 169403 T290 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
   [junit4]   2> 169412 T290 oasc.ChaosMonkey.monkeyLog monkey: init - expire sessions:false cause connection loss:false
   [junit4]   2> 169714 T290 oejs.Server.doStart jetty-8.1.10.v20130312
   [junit4]   2> 169719 T290 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:49438
   [junit4]   2> 169720 T290 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
   [junit4]   2> 169720 T290 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
   [junit4]   2> 169721 T290 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: ../../../../../../../../../Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty1-1383513184186
   [junit4]   2> 169721 T290 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '../../../../../../../../../Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty1-1383513184186/'
   [junit4]   2> 169751 T290 oasc.ConfigSolr.fromFile Loading container configuration from /Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/../../../../../../../../../Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty1-1383513184186/solr.xml
   [junit4]   2> 169842 T290 oasc.CoreContainer.<init> New CoreContainer 1604026562
   [junit4]   2> 169843 T290 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=../../../../../../../../../Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty1-1383513184186/]
   [junit4]   2> 169844 T290 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 120000
   [junit4]   2> 169845 T290 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
   [junit4]   2> 169845 T290 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
   [junit4]   2> 169845 T290 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
   [junit4]   2> 169845 T290 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
   [junit4]   2> 169846 T290 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
   [junit4]   2> 169846 T290 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
   [junit4]   2> 169846 T290 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
   [junit4]   2> 169847 T290 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
   [junit4]   2> 169850 T290 oasl.LogWatcher.createWatcher SLF4J impl is org.slf4j.impl.Log4jLoggerFactory
   [junit4]   2> 169850 T290 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
   [junit4]   2> 169851 T290 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:49429/solr
   [junit4]   2> 169851 T290 oasc.ZkController.checkChrootPath zkHost includes chroot
   [junit4]   2> 169853 T290 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 169858 T332 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@183e4e71 name:ZooKeeperConnection Watcher:127.0.0.1:49429 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 169859 T290 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 169866 T290 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 169870 T334 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@109e7b6d name:ZooKeeperConnection Watcher:127.0.0.1:49429/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 169870 T290 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 169883 T290 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
   [junit4]   2> 170895 T290 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:49438_ncx
   [junit4]   2> 170898 T290 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:49438_ncx
   [junit4]   2> 170912 T334 oascc.ZkStateReader$3.process Updating live nodes... (2)
   [junit4]   2> 170913 T316 oascc.ZkStateReader$3.process Updating live nodes... (2)
   [junit4]   2> 170914 T321 oascc.ZkStateReader$3.process Updating live nodes... (2)
   [junit4]   2> 170929 T290 oass.SolrDispatchFilter.init user.dir=/Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0
   [junit4]   2> 170929 T290 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
   [junit4]   2> 171225 T290 oejs.Server.doStart jetty-8.1.10.v20130312
   [junit4]   2> 171230 T290 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:49441
   [junit4]   2> 171231 T290 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
   [junit4]   2> 171231 T290 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
   [junit4]   2> 171232 T290 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: ../../../../../../../../../Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty2-1383513185704
   [junit4]   2> 171232 T290 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '../../../../../../../../../Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty2-1383513185704/'
   [junit4]   2> 171264 T290 oasc.ConfigSolr.fromFile Loading container configuration from /Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/../../../../../../../../../Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty2-1383513185704/solr.xml
   [junit4]   2> 171336 T290 oasc.CoreContainer.<init> New CoreContainer 894964204
   [junit4]   2> 171336 T290 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=../../../../../../../../../Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty2-1383513185704/]
   [junit4]   2> 171338 T290 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 120000
   [junit4]   2> 171339 T290 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
   [junit4]   2> 171339 T290 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
   [junit4]   2> 171339 T290 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
   [junit4]   2> 171340 T290 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
   [junit4]   2> 171340 T290 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
   [junit4]   2> 171340 T290 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
   [junit4]   2> 171340 T290 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
   [junit4]   2> 171341 T290 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
   [junit4]   2> 171345 T290 oasl.LogWatcher.createWatcher SLF4J impl is org.slf4j.impl.Log4jLoggerFactory
   [junit4]   2> 171345 T290 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
   [junit4]   2> 171345 T290 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:49429/solr
   [junit4]   2> 171347 T290 oasc.ZkController.checkChrootPath zkHost includes chroot
   [junit4]   2> 171348 T290 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 171353 T346 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@5bb45a6f name:ZooKeeperConnection Watcher:127.0.0.1:49429 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 171353 T290 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 171360 T290 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 171364 T348 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@24946b86 name:ZooKeeperConnection Watcher:127.0.0.1:49429/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 171364 T290 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 171376 T290 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
   [junit4]   2> 172387 T290 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:49441_ncx
   [junit4]   2> 172389 T290 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:49441_ncx
   [junit4]   2> 172399 T334 oascc.ZkStateReader$3.process Updating live nodes... (3)
   [junit4]   2> 172400 T316 oascc.ZkStateReader$3.process Updating live nodes... (3)
   [junit4]   2> 172400 T321 oascc.ZkStateReader$3.process Updating live nodes... (3)
   [junit4]   2> 172401 T348 oascc.ZkStateReader$3.process Updating live nodes... (3)
   [junit4]   2> 172416 T290 oass.SolrDispatchFilter.init user.dir=/Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0
   [junit4]   2> 172416 T290 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
   [junit4]   2> 172710 T290 oejs.Server.doStart jetty-8.1.10.v20130312
   [junit4]   2> 172714 T290 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:49444
   [junit4]   2> 172716 T290 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
   [junit4]   2> 172716 T290 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
   [junit4]   2> 172716 T290 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: ./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty3-1383513187192
   [junit4]   2> 172717 T290 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: './org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty3-1383513187192/'
   [junit4]   2> 172744 T290 oasc.ConfigSolr.fromFile Loading container configuration from /Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty3-1383513187192/solr.xml
   [junit4]   2> 172815 T290 oasc.CoreContainer.<init> New CoreContainer 1130757670
   [junit4]   2> 172815 T290 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty3-1383513187192/]
   [junit4]   2> 172840 T290 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 120000
   [junit4]   2> 172841 T290 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
   [junit4]   2> 172841 T290 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
   [junit4]   2> 172841 T290 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
   [junit4]   2> 172842 T290 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
   [junit4]   2> 172842 T290 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
   [junit4]   2> 172842 T290 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
   [junit4]   2> 172843 T290 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
   [junit4]   2> 172843 T290 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
   [junit4]   2> 172847 T290 oasl.LogWatcher.createWatcher SLF4J impl is org.slf4j.impl.Log4jLoggerFactory
   [junit4]   2> 172847 T290 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
   [junit4]   2> 172848 T290 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:49429/solr
   [junit4]   2> 172848 T290 oasc.ZkController.checkChrootPath zkHost includes chroot
   [junit4]   2> 172852 T290 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 172854 T360 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@4ef1392c name:ZooKeeperConnection Watcher:127.0.0.1:49429 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 172855 T290 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 172861 T290 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 172867 T362 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@6085861c name:ZooKeeperConnection Watcher:127.0.0.1:49429/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 172867 T290 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 172881 T290 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
   [junit4]   2> 173891 T290 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:49444_ncx
   [junit4]   2> 173894 T290 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:49444_ncx
   [junit4]   2> 173905 T334 oascc.ZkStateReader$3.process Updating live nodes... (4)
   [junit4]   2> 173906 T316 oascc.ZkStateReader$3.process Updating live nodes... (4)
   [junit4]   2> 173908 T362 oascc.ZkStateReader$3.process Updating live nodes... (4)
   [junit4]   2> 173908 T348 oascc.ZkStateReader$3.process Updating live nodes... (4)
   [junit4]   2> 173913 T321 oascc.ZkStateReader$3.process Updating live nodes... (4)
   [junit4]   2> 173923 T290 oass.SolrDispatchFilter.init user.dir=/Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0
   [junit4]   2> 173923 T290 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
   [junit4]   2> 174233 T290 oejs.Server.doStart jetty-8.1.10.v20130312
   [junit4]   2> 174238 T290 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:49447
   [junit4]   2> 174241 T290 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
   [junit4]   2> 174241 T290 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
   [junit4]   2> 174242 T290 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: ./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1383513188698
   [junit4]   2> 174242 T290 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: './org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1383513188698/'
   [junit4]   2> 174270 T290 oasc.ConfigSolr.fromFile Loading container configuration from /Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1383513188698/solr.xml
   [junit4]   2> 174340 T290 oasc.CoreContainer.<init> New CoreContainer 1527607624
   [junit4]   2> 174340 T290 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1383513188698/]
   [junit4]   2> 174341 T290 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 120000
   [junit4]   2> 174342 T290 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
   [junit4]   2> 174342 T290 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
   [junit4]   2> 174342 T290 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
   [junit4]   2> 174343 T290 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
   [junit4]   2> 174343 T290 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
   [junit4]   2> 174344 T290 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
   [junit4]   2> 174344 T290 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
   [junit4]   2> 174344 T290 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
   [junit4]   2> 174348 T290 oasl.LogWatcher.createWatcher SLF4J impl is org.slf4j.impl.Log4jLoggerFactory
   [junit4]   2> 174348 T290 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
   [junit4]   2> 174349 T290 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:49429/solr
   [junit4]   2> 174349 T290 oasc.ZkController.checkChrootPath zkHost includes chroot
   [junit4]   2> 174351 T290 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 174355 T374 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@75c6232a name:ZooKeeperConnection Watcher:127.0.0.1:49429 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 174356 T290 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 174363 T290 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 174367 T376 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@7aca53ab name:ZooKeeperConnection Watcher:127.0.0.1:49429/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 174368 T290 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 174381 T290 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
   [junit4]   2> 175391 T290 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:49447_ncx
   [junit4]   2> 175395 T290 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:49447_ncx
   [junit4]   2> 175406 T362 oascc.ZkStateReader$3.process Updating live nodes... (5)
   [junit4]   2> 175407 T348 oascc.ZkStateReader$3.process Updating live nodes... (5)
   [junit4]   2> 175407 T376 oascc.ZkStateReader$3.process Updating live nodes... (5)
   [junit4]   2> 175406 T321 oascc.ZkStateReader$3.process Updating live nodes... (5)
   [junit4]   2> 175408 T316 oascc.ZkStateReader$3.process Updating live nodes... (5)
   [junit4]   2> 175407 T334 oascc.ZkStateReader$3.process Updating live nodes... (5)
   [junit4]   2> 175420 T290 oass.SolrDispatchFilter.init user.dir=/Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0
   [junit4]   2> 175420 T290 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
   [junit4]   2> 175459 T327 oasha.CollectionsHandler.handleCreateAction Creating Collection : numShards=2&collection.configName=conf1&name=solrj_collection&replicationFactor=2&action=CREATE&router.field=myOwnField&wt=javabin&router.name=compositeId&version=2
   [junit4]   2> 175463 T316 oasc.DistributedQueue$LatchChildWatcher.process Watcher fired on path: /overseer/collection-queue-work state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 175470 T318 oasc.OverseerCollectionProcessor.run Overseer Collection Processor: Get the message id:/overseer/collection-queue-work/qn-0000000000 message:{
   [junit4]   2> 	  "operation":"createcollection",
   [junit4]   2> 	  "fromApi":"true",
   [junit4]   2> 	  "name":"solrj_collection",
   [junit4]   2> 	  "replicationFactor":"2",
   [junit4]   2> 	  "collection.configName":"conf1",
   [junit4]   2> 	  "numShards":"2",
   [junit4]   2> 	  "router.field":"myOwnField",
   [junit4]   2> 	  "router.name":"compositeId"}
   [junit4]   2> 175470 T318 oasc.OverseerCollectionProcessor.processMessage WARN OverseerCollectionProcessor.processMessage : createcollection , {
   [junit4]   2> 	  "operation":"createcollection",
   [junit4]   2> 	  "fromApi":"true",
   [junit4]   2> 	  "name":"solrj_collection",
   [junit4]   2> 	  "replicationFactor":"2",
   [junit4]   2> 	  "collection.configName":"conf1",
   [junit4]   2> 	  "numShards":"2",
   [junit4]   2> 	  "router.field":"myOwnField",
   [junit4]   2> 	  "router.name":"compositeId"}
   [junit4]   2> 176903 T317 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 176905 T317 oasc.Overseer$ClusterStateUpdater.buildCollection building a new collection: solrj_collection
   [junit4]   2> 176905 T317 oasc.Overseer$ClusterStateUpdater.createCollection Create collection solrj_collection with shards [shard1, shard2]
   [junit4]   2> 176943 T334 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
   [junit4]   2> 176943 T376 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
   [junit4]   2> 176943 T362 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
   [junit4]   2> 176943 T348 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
   [junit4]   2> 176943 T321 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
   [junit4]   2> 176943 T316 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
   [junit4]   2> 177004 T318 oasc.OverseerCollectionProcessor.createCollection going to create cores replicas shardNames [shard1, shard2] , repFactor : 2
   [junit4]   2> 177004 T318 oasc.OverseerCollectionProcessor.createCollection Creating shard solrj_collection_shard1_replica1 as part of slice shard1 of collection solrj_collection on 127.0.0.1:49447_ncx
   [junit4]   2> 177008 T318 oasc.OverseerCollectionProcessor.createCollection Creating shard solrj_collection_shard1_replica2 as part of slice shard1 of collection solrj_collection on 127.0.0.1:49444_ncx
   [junit4]   2> 177009 T318 oasc.OverseerCollectionProcessor.createCollection Creating shard solrj_collection_shard2_replica1 as part of slice shard2 of collection solrj_collection on 127.0.0.1:49441_ncx
   [junit4]   2> 177010 T318 oasc.OverseerCollectionProcessor.createCollection Creating shard solrj_collection_shard2_replica2 as part of slice shard2 of collection solrj_collection on 127.0.0.1:49438_ncx
   [junit4]   2> 177032 T341 oasc.ZkController.publish publishing core=solrj_collection_shard2_replica1 state=down
   [junit4]   2> 177032 T325 oasc.ZkController.publish publishing core=solrj_collection_shard2_replica2 state=down
   [junit4]   2> 177032 T367 oasc.ZkController.publish publishing core=solrj_collection_shard1_replica1 state=down
   [junit4]   2> 177032 T357 oasc.ZkController.publish publishing core=solrj_collection_shard1_replica2 state=down
   [junit4]   2> 177037 T341 oasc.ZkController.waitForCoreNodeName look for our core node name
   [junit4]   2> 177038 T325 oasc.ZkController.waitForCoreNodeName look for our core node name
   [junit4]   2> 177038 T357 oasc.ZkController.waitForCoreNodeName look for our core node name
   [junit4]   2> 177038 T367 oasc.ZkController.waitForCoreNodeName look for our core node name
   [junit4]   2> 178461 T317 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 178462 T317 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
   [junit4]   2> 	  "operation":"state",
   [junit4]   2> 	  "state":"down",
   [junit4]   2> 	  "base_url":"http://127.0.0.1:49441/ncx",
   [junit4]   2> 	  "core":"solrj_collection_shard2_replica1",
   [junit4]   2> 	  "roles":null,
   [junit4]   2> 	  "node_name":"127.0.0.1:49441_ncx",
   [junit4]   2> 	  "shard":"shard2",
   [junit4]   2> 	  "shard_range":null,
   [junit4]   2> 	  "shard_state":"active",
   [junit4]   2> 	  "shard_parent":null,
   [junit4]   2> 	  "collection":"solrj_collection",
   [junit4]   2> 	  "numShards":"2",
   [junit4]   2> 	  "core_node_name":null}
   [junit4]   2> 178482 T317 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
   [junit4]   2> 	  "operation":"state",
   [junit4]   2> 	  "state":"down",
   [junit4]   2> 	  "base_url":"http://127.0.0.1:49438/ncx",
   [junit4]   2> 	  "core":"solrj_collection_shard2_replica2",
   [junit4]   2> 	  "roles":null,
   [junit4]   2> 	  "node_name":"127.0.0.1:49438_ncx",
   [junit4]   2> 	  "shard":"shard2",
   [junit4]   2> 	  "shard_range":null,
   [junit4]   2> 	  "shard_state":"active",
   [junit4]   2> 	  "shard_parent":null,
   [junit4]   2> 	  "collection":"solrj_collection",
   [junit4]   2> 	  "numShards":"2",
   [junit4]   2> 	  "core_node_name":null}
   [junit4]   2> 178492 T317 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
   [junit4]   2> 	  "operation":"state",
   [junit4]   2> 	  "state":"down",
   [junit4]   2> 	  "base_url":"http://127.0.0.1:49447/ncx",
   [junit4]   2> 	  "core":"solrj_collection_shard1_replica1",
   [junit4]   2> 	  "roles":null,
   [junit4]   2> 	  "node_name":"127.0.0.1:49447_ncx",
   [junit4]   2> 	  "shard":"shard1",
   [junit4]   2> 	  "shard_range":null,
   [junit4]   2> 	  "shard_state":"active",
   [junit4]   2> 	  "shard_parent":null,
   [junit4]   2> 	  "collection":"solrj_collection",
   [junit4]   2> 	  "numShards":"2",
   [junit4]   2> 	  "core_node_name":null}
   [junit4]   2> 178501 T317 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
   [junit4]   2> 	  "operation":"state",
   [junit4]   2> 	  "state":"down",
   [junit4]   2> 	  "base_url":"http://127.0.0.1:49444/ncx",
   [junit4]   2> 	  "core":"solrj_collection_shard1_replica2",
   [junit4]   2> 	  "roles":null,
   [junit4]   2> 	  "node_name":"127.0.0.1:49444_ncx",
   [junit4]   2> 	  "shard":"shard1",
   [junit4]   2> 	  "shard_range":null,
   [junit4]   2> 	  "shard_state":"active",
   [junit4]   2> 	  "shard_parent":null,
   [junit4]   2> 	  "collection":"solrj_collection",
   [junit4]   2> 	  "numShards":"2",
   [junit4]   2> 	  "core_node_name":null}
   [junit4]   2> 178510 T334 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
   [junit4]   2> 178511 T316 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
   [junit4]   2> 178511 T348 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
   [junit4]   2> 178511 T321 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
   [junit4]   2> 178512 T376 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
   [junit4]   2> 178512 T362 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
   [junit4]   2> 179040 T325 oasc.ZkController.waitForShardId waiting to find shard id in clusterstate for solrj_collection_shard2_replica2
   [junit4]   2> 179040 T357 oasc.ZkController.waitForShardId waiting to find shard id in clusterstate for solrj_collection_shard1_replica2
   [junit4]   2> 179040 T341 oasc.ZkController.waitForShardId waiting to find shard id in clusterstate for solrj_collection_shard2_replica1
   [junit4]   2> 179043 T357 oasc.SolrXMLCoresLocator.doPersist Persisted core descriptions to /Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty3-1383513187192/solr.xml
   [junit4]   2> 179044 T357 oasc.CoreContainer.create Creating SolrCore 'solrj_collection_shard1_replica2' using instanceDir: ./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty3-1383513187192/solrj_collection_shard1_replica2
   [junit4]   2> 179043 T341 oasc.SolrXMLCoresLocator.doPersist Persisted core descriptions to /Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/../../../../../../../../../Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty2-1383513185704/solr.xml
   [junit4]   2> 179046 T341 oasc.CoreContainer.create Creating SolrCore 'solrj_collection_shard2_replica1' using instanceDir: ../../../../../../../../../Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty2-1383513185704/solrj_collection_shard2_replica1
   [junit4]   2> 179046 T341 oasc.ZkController.createCollectionZkNode Check for collection zkNode:solrj_collection
   [junit4]   2> 179046 T357 oasc.ZkController.createCollectionZkNode Check for collection zkNode:solrj_collection
   [junit4]   2> 179046 T367 oasc.ZkController.waitForShardId waiting to find shard id in clusterstate for solrj_collection_shard1_replica1
   [junit4]   2> 179049 T367 oasc.SolrXMLCoresLocator.doPersist Persisted core descriptions to /Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1383513188698/solr.xml
   [junit4]   2> 179049 T367 oasc.CoreContainer.create Creating SolrCore 'solrj_collection_shard1_replica1' using instanceDir: ./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1383513188698/solrj_collection_shard1_replica1
   [junit4]   2> 179049 T367 oasc.ZkController.createCollectionZkNode Check for collection zkNode:solrj_collection
   [junit4]   2> 179044 T325 oasc.SolrXMLCoresLocator.doPersist Persisted core descriptions to /Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/../../../../../../../../../Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty1-1383513184186/solr.xml
   [junit4]   2> 179050 T325 oasc.CoreContainer.create Creating SolrCore 'solrj_collection_shard2_replica2' using instanceDir: ../../../../../../../../../Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty1-1383513184186/solrj_collection_shard2_replica2
   [junit4]   2> 179051 T325 oasc.ZkController.createCollectionZkNode Check for collection zkNode:solrj_collection
   [junit4]   2> 179051 T341 oasc.ZkController.createCollectionZkNode Creating collection in ZooKeeper:solrj_collection
   [junit4]   2> 179052 T367 oasc.ZkController.createCollectionZkNode Creating collection in ZooKeeper:solrj_collection
   [junit4]   2> 179052 T357 oasc.ZkController.createCollectionZkNode Creating collection in ZooKeeper:solrj_collection
   [junit4]   2> 179054 T357 oascc.SolrZkClient.makePath makePath: /collections/solrj_collection
   [junit4]   2> 179052 T341 oascc.SolrZkClient.makePath makePath: /collections/solrj_collection
   [junit4]   2> 179054 T325 oasc.ZkController.createCollectionZkNode Creating collection in ZooKeeper:solrj_collection
   [junit4]   2> 179053 T367 oascc.SolrZkClient.makePath makePath: /collections/solrj_collection
   [junit4]   2> 179055 T325 oascc.SolrZkClient.makePath makePath: /collections/solrj_collection
   [junit4]   2> 179063 T341 oasc.ZkController.readConfigName Load collection config from:/collections/solrj_collection
   [junit4]   2> 179064 T325 oasc.ZkController.readConfigName Load collection config from:/collections/solrj_collection
   [junit4]   2> 179064 T367 oasc.ZkController.readConfigName Load collection config from:/collections/solrj_collection
   [junit4]   2> 179065 T357 oasc.ZkController.readConfigName Load collection config from:/collections/solrj_collection
   [junit4]   2> 179070 T325 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '../../../../../../../../../Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty1-1383513184186/solrj_collection_shard2_replica2/'
   [junit4]   2> 179070 T357 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: './org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty3-1383513187192/solrj_collection_shard1_replica2/'
   [junit4]   2> 179070 T341 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '../../../../../../../../../Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty2-1383513185704/solrj_collection_shard2_replica1/'
   [junit4]   2> 179073 T367 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: './org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1383513188698/solrj_collection_shard1_replica1/'
   [junit4]   2> 179222 T357 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_46
   [junit4]   2> 179248 T325 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_46
   [junit4]   2> 179264 T341 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_46
   [junit4]   2> 179273 T367 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_46
   [junit4]   2> 179371 T325 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
   [junit4]   2> 179390 T325 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
   [junit4]   2> 179397 T357 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
   [junit4]   2> 179400 T357 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
   [junit4]   2> 179416 T367 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
   [junit4]   2> 179417 T325 oass.IndexSchema.readSchema [solrj_collection_shard2_replica2] Schema name=test
   [junit4]   2> 179426 T357 oass.IndexSchema.readSchema [solrj_collection_shard1_replica2] Schema name=test
   [junit4]   2> 179451 T367 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
   [junit4]   2> 179464 T341 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
   [junit4]   2> 179468 T367 oass.IndexSchema.readSchema [solrj_collection_shard1_replica1] Schema name=test
   [junit4]   2> 179468 T341 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
   [junit4]   2> 179484 T341 oass.IndexSchema.readSchema [solrj_collection_shard2_replica1] Schema name=test
   [junit4]   2> 181024 T357 oass.ByteField.init WARN ByteField is deprecated and will be removed in 5.0. You should use TrieIntField instead.
   [junit4]   2> 181045 T357 oass.ShortField.init WARN ShortField is deprecated and will be removed in 5.0. You should use TrieIntField instead.
   [junit4]   2> 181046 T357 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
   [junit4]   2> 181051 T367 oass.ByteField.init WARN ByteField is deprecated and will be removed in 5.0. You should use TrieIntField instead.
   [junit4]   2> 181051 T367 oass.ShortField.init WARN ShortField is deprecated and will be removed in 5.0. You should use TrieIntField instead.
   [junit4]   2> 181053 T367 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
   [junit4]   2> 181071 T357 oass.IndexSchema.readSchema default search field in schema is text
   [junit4]   2> 181093 T367 oass.IndexSchema.readSchema default search field in schema is text
   [junit4]   2> 181096 T357 oass.IndexSchema.readSchema unique key field: id
   [junit4]   2> 181098 T367 oass.IndexSchema.readSchema unique key field: id
   [junit4]   2> 181154 T325 oass.ByteField.init WARN ByteField is deprecated and will be removed in 5.0. You should use TrieIntField instead.
   [junit4]   2> 181155 T325 oass.ShortField.init WARN ShortField is deprecated and will be removed in 5.0. You should use TrieIntField instead.
   [junit4]   2> 181156 T325 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
   [junit4]   2> 181164 T341 oass.ByteField.init WARN ByteField is deprecated and will be removed in 5.0. You should use TrieIntField instead.
   [junit4]   2> 181166 T341 oass.ShortField.init WARN ShortField is deprecated and will be removed in 5.0. You should use TrieIntField instead.
   [junit4]   2> 181167 T325 oass.IndexSchema.readSchema default search field in schema is text
   [junit4]   2> 181172 T325 oass.IndexSchema.readSchema unique key field: id
   [junit4]   2> 181178 T341 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
   [junit4]   2> 181195 T341 oass.IndexSchema.readSchema default search field in schema is text
   [junit4]   2> 181199 T341 oass.IndexSchema.readSchema unique key field: id
   [junit4]   2> 181234 T357 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
   [junit4]   2> 181250 T357 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
   [junit4]   2> 181251 T367 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
   [junit4]   2> 181260 T325 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
   [junit4]   2> 181265 T357 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
   [junit4]   2> 181270 T367 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
   [junit4]   2> 181272 T357 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
   [junit4]   2> 181273 T357 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
   [junit4]   2> 181274 T357 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
   [junit4]   2> 181274 T341 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
   [junit4]   2> 181279 T357 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
   [junit4]   2> 181279 T357 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
   [junit4]   2> 181280 T357 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
   [junit4]   2> 181288 T357 oasc.SolrCore.<init> [solrj_collection_shard1_replica2] Opening new SolrCore at ./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty3-1383513187192/solrj_collection_shard1_replica2/, dataDir=./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty3-1383513187192/solrj_collection_shard1_replica2/data/
   [junit4]   2> 181297 T341 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
   [junit4]   2> 181298 T357 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@14d751d4
   [junit4]   2> 181298 T367 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
   [junit4]   2> 181299 T325 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
   [junit4]   2> 181309 T341 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
   [junit4]   2> 181313 T367 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
   [junit4]   2> 181315 T367 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
   [junit4]   2> 181316 T367 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
   [junit4]   2> 181313 T357 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty3-1383513187192/solrj_collection_shard1_replica2/data
   [junit4]   2> 181316 T357 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty3-1383513187192/solrj_collection_shard1_replica2/data/index/
   [junit4]   2> 181317 T357 oasc.SolrCore.initIndex WARN [solrj_collection_shard1_replica2] Solr index directory './org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty3-1383513187192/solrj_collection_shard1_replica2/data/index' doesn't exist. Creating new index...
   [junit4]   2> 181319 T341 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
   [junit4]   2> 181319 T341 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
   [junit4]   2> 181320 T341 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
   [junit4]   2> 181322 T325 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
   [junit4]   2> 181323 T357 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty3-1383513187192/solrj_collection_shard1_replica2/data/index
   [junit4]   2> 181324 T357 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.LogByteSizeMergePolicy: [LogByteSizeMergePolicy: minMergeSize=1677721, mergeFactor=29, maxMergeSize=2147483648, maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=true, maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.6857274377866711]
   [junit4]   2> 181324 T341 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
   [junit4]   2> 181325 T341 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
   [junit4]   2> 181324 T367 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
   [junit4]   2> 181326 T367 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
   [junit4]   2> 181327 T367 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
   [junit4]   2> 181326 T341 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
   [junit4]   2> 181328 T341 oasc.SolrCore.<init> [solrj_collection_shard2_replica1] Opening new SolrCore at ../../../../../../../../../Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty2-1383513185704/solrj_collection_shard2_replica1/, dataDir=../../../../../../../../../Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty2-1383513185704/solrj_collection_shard2_replica1/data/
   [junit4]   2> 181327 T367 oasc.SolrCore.<init> [solrj_collection_shard1_replica1] Opening new SolrCore at ./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1383513188698/solrj_collection_shard1_replica1/, dataDir=./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1383513188698/solrj_collection_shard1_replica1/data/
   [junit4]   2> 181327 T357 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
   [junit4]   2> 		commit{dir=MockDirectoryWrapper(org.apache.lucene.store.RAMDirectory@66df5ef4 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@754a924f),segFN=segments_1,generation=1}
   [junit4]   2> 181329 T357 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
   [junit4]   2> 181329 T367 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@14d751d4
   [junit4]   2> 181328 T341 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@14d751d4
   [junit4]   2> 181328 T325 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
   [junit4]   2> 181338 T325 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
   [junit4]   2> 181339 T325 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
   [junit4]   2> 181334 T341 oasc.CachingDirectoryFactory.get return new directory for ../../../../../../../../../Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty2-1383513185704/solrj_collection_shard2_replica1/data
   [junit4]   2> 181340 T341 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=../../../../../../../../../Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty2-1383513185704/solrj_collection_shard2_replica1/data/index/
   [junit4]   2> 181342 T341 oasc.SolrCore.initIndex WARN [solrj_collection_shard2_replica1] Solr index directory '../../../../../../../../../Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty2-1383513185704/solrj_collection_shard2_replica1/data/index' doesn't exist. Creating new index...
   [junit4]   2> 181343 T357 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "nodistrib"
   [junit4]   2> 181345 T325 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
   [junit4]   2> 181346 T325 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
   [junit4]   2> 181346 T325 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
   [junit4]   2> 181347 T325 oasc.SolrCore.<init> [solrj_collection_shard2_replica2] Opening new SolrCore at ../../../../../../../../../Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty1-1383513184186/solrj_collection_shard2_replica2/, dataDir=../../../../../../../../../Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty1-1383513184186/solrj_collection_shard2_replica2/data/
   [junit4]   2> 181347 T325 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@14d751d4
   [junit4]   2> 181342 T367 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1383513188698/solrj_collection_shard1_replica1/data
   [junit4]   2> 181350 T367 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1383513188698/solrj_collection_shard1_replica1/data/index/
   [junit4]   2> 181350 T367 oasc.SolrCore.initIndex WARN [solrj_collection_shard1_replica1] Solr index directory './org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1383513188698/solrj_collection_shard1_replica1/data/index' doesn't exist. Creating new index...
   [junit4]   2> 181353 T341 oasc.CachingDirectoryFactory.get return new directory for ../../../../../../../../../Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty2-1383513185704/solrj_collection_shard2_replica1/data/index
   [junit4]   2> 181354 T341 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.LogByteSizeMergePolicy: [LogByteSizeMergePolicy: minMergeSize=1677721, mergeFactor=29, maxMergeSize=2147483648, maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=true, maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.6857274377866711]
   [junit4]   2> 181356 T367 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1383513188698/solrj_collection_shard1_replica1/data/index
   [junit4]   2> 181356 T325 oasc.CachingDirectoryFactory.get return new directory for ../../../../../../../../../Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty1-1383513184186/solrj_collection_shard2_replica2/data
   [junit4]   2> 181356 T325 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=../../../../../../../../../Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty1-1383513184186/solrj_collection_shard2_replica2/data/index/
   [junit4]   2> 181357 T325 oasc.SolrCore.initIndex WARN [solrj_collection_shard2_replica2] Solr index directory '../../../../../../../../../Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty1-1383513184186/solrj_collection_shard2_replica2/data/index' doesn't exist. Creating new index...
   [junit4]   2> 181358 T325 oasc.CachingDirectoryFactory.get return new directory for ../../../../../../../../../Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty1-1383513184186/solrj_collection_shard2_replica2/data/index
   [junit4]   2> 181358 T325 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.LogByteSizeMergePolicy: [LogByteSizeMergePolicy: minMergeSize=1677721, mergeFactor=29, maxMergeSize=2147483648, maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=true, maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.6857274377866711]
   [junit4]   2> 181356 T367 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.LogByteSizeMergePolicy: [LogByteSizeMergePolicy: minMergeSize=1677721, mergeFactor=29, maxMergeSize=2147483648, maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=true, maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.6857274377866711]
   [junit4]   2> 181363 T367 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
   [junit4]   2> 		commit{dir=MockDirectoryWrapper(org.apache.lucene.store.RAMDirectory@8a55cf3 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@55ee2eb4),segFN=segments_1,generation=1}
   [junit4]   2> 181364 T367 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
   [junit4]   2> 181373 T367 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "nodistrib"
   [junit4]   2> 181377 T325 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
   [junit4]   2> 		commit{dir=MockDirectoryWrapper(org.apache.lucene.store.RAMDirectory@37f191aa lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@446e2543),segFN=segments_1,generation=1}
   [junit4]   2> 181377 T325 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
   [junit4]   2> 181392 T325 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "nodistrib"
   [junit4]   2> 181394 T357 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "dedupe"
   [junit4]   2> 181395 T357 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
   [junit4]   2> 181395 T357 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "stored_sig"
   [junit4]   2> 181396 T357 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
   [junit4]   2> 181396 T357 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-explicit"
   [junit4]   2> 181397 T357 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-implicit"
   [junit4]   2> 181398 T357 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
   [junit4]   2> 181398 T357 oasc.SolrCore.loadUpdateProcessorChains no updateRequestProcessorChain defined as default, creating implicit default
   [junit4]   2> 181402 T367 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "dedupe"
   [junit4]   2> 181403 T367 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
   [junit4]   2> 181403 T367 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "stored_sig"
   [junit4]   2> 181404 T367 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
   [junit4]   2> 181404 T367 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-explicit"
   [junit4]   2> 181405 T357 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
   [junit4]   2> 181405 T325 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "dedupe"
   [junit4]   2> 181406 T325 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
   [junit4]   2> 181405 T341 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
   [junit4]   2> 		commit{dir=MockDirectoryWrapper(org.apache.lucene.store.RAMDirectory@45970cbb lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@7542cca3),segFN=segments_1,generation=1}
   [junit4]   2> 181407 T341 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
   [junit4]   2> 181405 T367 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-implicit"
   [junit4]   2> 181408 T367 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
   [junit4]   2> 181409 T367 oasc.SolrCore.loadUpdateProcessorChains no updateRequestProcessorChain defined as default, creating implicit default
   [junit4]   2> 181407 T325 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "stored_sig"
   [junit4]   2> 181410 T325 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
   [junit4]   2> 181410 T325 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-explicit"
   [junit4]   2> 181411 T325 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-implicit"
   [junit4]   2> 181412 T325 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
   [junit4]   2> 181412 T325 oasc.SolrCore.loadUpdateProcessorChains no updateRequestProcessorChain defined as default, creating implicit default
   [junit4]   2> 181406 T357 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
   [junit4]   2> 181415 T357 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
   [junit4]   2> 181416 T357 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
   [junit4]   2> 181417 T357 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
   [junit4]   2> 181418 T325 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
   [junit4]   2> 181415 T367 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
   [junit4]   2> 181420 T325 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
   [junit4]   2> 181420 T325 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
   [junit4]   2> 181418 T357 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
   [junit4]   2> 181417 T341 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "nodistrib"
   [junit4]   2> 181422 T341 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "dedupe"
   [junit4]   2> 181422 T341 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
   [junit4]   2> 181423 T341 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "stored_sig"
   [junit4]   2> 181424 T341 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
   [junit4]   2> 181424 T341 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-explicit"
   [junit4]   2> 181426 T341 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-implicit"
   [junit4]   2> 181426 T341 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
   [junit4]   2> 181427 T341 oasc.SolrCore.loadUpdateProcessorChains no updateRequestProcessorChain defined as default, creating implicit default
   [junit4]   2> 181428 T341 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
   [junit4]   2> 181431 T341 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
   [junit4]   2> 181431 T341 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
   [junit4]   2> 181432 T341 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
   [junit4]   2> 181433 T357 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
   [junit4]   2> 181421 T325 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
   [junit4]   2> 181435 T325 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
   [junit4]   2> 181420 T367 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
   [junit4]   2> 181436 T367 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
   [junit4]   2> 181437 T367 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
   [junit4]   2> 181436 T325 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
   [junit4]   2> 181439 T367 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
   [junit4]   2> 181439 T367 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
   [junit4]   2> 181441 T325 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
   [junit4]   2> 181442 T367 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
   [junit4]   2> 181433 T341 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
   [junit4]   2> 181445 T341 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
   [junit4]   2> 181452 T341 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
   [junit4]   2> 181455 T357 oasu.CommitTracker.<init> Hard AutoCommit: disabled
   [junit4]   2> 181455 T357 oasu.CommitTracker.<init> Soft AutoCommit: disabled
   [junit4]   2> 181456 T367 oasu.CommitTracker.<init> Hard AutoCommit: disabled
   [junit4]   2> 181457 T367 oasu.CommitTracker.<init> Soft AutoCommit: disabled
   [junit4]   2> 181457 T357 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.LogByteSizeMergePolicy: [LogByteSizeMergePolicy: minMergeSize=1677721, mergeFactor=40, maxMergeSize=2147483648, maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=true, maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.7361532777937067]
   [junit4]   2> 181459 T367 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.LogByteSizeMergePolicy: [LogByteSizeMergePolicy: minMergeSize=1677721, mergeFactor=40, maxMergeSize=2147483648, maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=true, maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.7361532777937067]
   [junit4]   2> 181462 T325 oasu.CommitTracker.<init> Hard AutoCommit: disabled
   [junit4]   2> 181463 T325 oasu.CommitTracker.<init> Soft AutoCommit: disabled
   [junit4]   2> 181459 T357 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=1
   [junit4]   2> 		commit{dir=MockDirectoryWrapper(org.apache.lucene.store.RAMDirectory@66df5ef4 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@754a924f),segFN=segments_1,generation=1}
   [junit4]   2> 181465 T357 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
   [junit4]   2> 181463 T367 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=1
   [junit4]   2> 		commit{dir=MockDirectoryWrapper(org.apache.lucene.store.RAMDirectory@8a55cf3 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@55ee2eb4),segFN=segments_1,generation=1}
   [junit4]   2> 181466 T367 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
   [junit4]   2> 181467 T367 oass.SolrIndexSearcher.<init> Opening Searcher@3f71d892 main
   [junit4]   2> 181467 T341 oasu.CommitTracker.<init> Hard AutoCommit: disabled
   [junit4]   2> 181467 T341 oasu.CommitTracker.<init> Soft AutoCommit: disabled
   [junit4]   2> 181466 T357 oass.SolrIndexSearcher.<init> Opening Searcher@499198db main
   [junit4]   2> 181470 T341 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.LogByteSizeMergePolicy: [LogByteSizeMergePolicy: minMergeSize=1677721, mergeFactor=40, maxMergeSize=2147483648, maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=true, maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.7361532777937067]
   [junit4]   2> 181466 T325 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.LogByteSizeMergePolicy: [LogByteSizeMergePolicy: minMergeSize=1677721, mergeFactor=40, maxMergeSize=2147483648, maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=true, maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.7361532777937067]
   [junit4]   2> 181481 T325 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=1
   [junit4]   2> 		commit{dir=MockDirectoryWrapper(org.apache.lucene.store.RAMDirectory@37f191aa lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@446e2543),segFN=segments_1,generation=1}
   [junit4]   2> 181484 T325 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
   [junit4]   2> 181484 T382 oasc.SolrCore.registerSearcher [solrj_collection_shard1_replica2] Registered new searcher Searcher@499198db main{StandardDirectoryReader(segments_1:1:nrt)}
   [junit4]   2> 181486 T325 oass.SolrIndexSearcher.<init> Opening Searcher@74888272 main
   [junit4]   2> 181488 T383 oasc.SolrCore.registerSearcher [solrj_collection_shard1_replica1] Registered new searcher Searcher@3f71d892 main{StandardDirectoryReader(segments_1:1:nrt)}
   [junit4]   2> 181523 T384 oasc.SolrCore.registerSearcher [solrj_collection_shard2_replica2] Registered new searcher Searcher@74888272 main{StandardDirectoryReader(segments_1:1:nrt)}
   [junit4]   2> 181526 T341 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=1
   [junit4]   2> 		commit{dir=MockDirectoryWrapper(org.apache.lucene.store.RAMDirectory@45970cbb lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@7542cca3),segFN=segments_1,generation=1}
   [junit4]   2> 181526 T341 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
   [junit4]   2> 181527 T341 oass.SolrIndexSearcher.<init> Opening Searcher@4f4d438f main
   [junit4]   2> 181533 T325 oasc.CoreContainer.registerCore registering core: solrj_collection_shard2_replica2
   [junit4]   2> 181533 T325 oasc.ZkController.register Register replica - core:solrj_collection_shard2_replica2 address:http://127.0.0.1:49438/ncx collection:solrj_collection shard:shard2
   [junit4]   2> 181534 T367 oasc.CoreContainer.registerCore registering core: solrj_collection_shard1_replica1
   [junit4]   2> 181535 T367 oasc.ZkController.register Register replica - core:solrj_collection_shard1_replica1 address:http://127.0.0.1:49447/ncx collection:solrj_collection shard:shard1
   [junit4]   2> 181539 T357 oasc.CoreContainer.registerCore registering core: solrj_collection_shard1_replica2
   [junit4]   2> 181535 T385 oasc.SolrCore.registerSearcher [solrj_collection_shard2_replica1] Registered new searcher Searcher@4f4d438f main{StandardDirectoryReader(segments_1:1:nrt)}
   [junit4]   2> 181545 T341 oasc.CoreContainer.registerCore registering core: solrj_collection_shard2_replica1
   [junit4]   2> 181545 T341 oasc.ZkController.register Register replica - core:solrj_collection_shard2_replica1 address:http://127.0.0.1:49441/ncx collection:solrj_collection shard:shard2
   [junit4]   2> 181546 T357 oasc.ZkController.register Register replica - core:solrj_collection_shard1_replica2 address:http://127.0.0.1:49444/ncx collection:solrj_collection shard:shard1
   [junit4]   2> 181577 T367 oascc.SolrZkClient.makePath makePath: /collections/solrj_collection/leader_elect/shard1/election
   [junit4]   2> 181580 T341 oascc.SolrZkClient.makePath makePath: /collections/solrj_collection/leader_elect/shard2/election
   [junit4]   2> 181591 T325 oascc.SolrZkClient.makePath makePath: /collections/solrj_collection/leader_elect/shard2/election
   [junit4]   2> 181594 T357 oascc.SolrZkClient.makePath makePath: /collections/solrj_collection/leader_elect/shard1/election
   [junit4]   2> 181621 T341 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process for shard shard2
   [junit4]   2> 181627 T367 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process for shard shard1
   [junit4]   2> 181632 T341 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Enough replicas found to continue.
   [junit4]   2> 181633 T341 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new leader - try and sync
   [junit4]   2> 181633 T341 oasc.SyncStrategy.sync Sync replicas to http://127.0.0.1:49441/ncx/solrj_collection_shard2_replica1/
   [junit4]   2> 181636 T367 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Enough replicas found to continue.
   [junit4]   2> 181636 T367 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new leader - try and sync
   [junit4]   2> 181637 T367 oasc.SyncStrategy.sync Sync replicas to http://127.0.0.1:49447/ncx/solrj_collection_shard1_replica1/
   [junit4]   2> 181649 T341 oasu.PeerSync.sync PeerSync: core=solrj_collection_shard2_replica1 url=http://127.0.0.1:49441/ncx START replicas=[http://127.0.0.1:49438/ncx/solrj_collection_shard2_replica2/] nUpdates=100
   [junit4]   2> 181649 T367 oasu.PeerSync.sync PeerSync: core=solrj_collection_shard1_replica1 url=http://127.0.0.1:49447/ncx START replicas=[http://127.0.0.1:49444/ncx/solrj_collection_shard1_replica2/] nUpdates=100
   [junit4]   2> 181652 T367 oasu.PeerSync.sync PeerSync: core=solrj_colle

[...truncated too long message...]

junit4]   2> 333609 T290 oasu.SolrCoreState.decrefSolrCoreState Closing SolrCoreState
   [junit4]   2> 333609 T290 oasu.DefaultSolrCoreState.closeIndexWriter SolrCoreState ref count has reached 0 - closing IndexWriter
   [junit4]   2> 333609 T290 oasu.DefaultSolrCoreState.closeIndexWriter closing IndexWriter with IndexWriterCloser
   [junit4]   2> 333610 T290 oasc.SolrCore.closeSearcher [awholynewcollection_0_shard5_replica1] Closing main searcher on request.
   [junit4]   2> 333611 T290 oasc.CachingDirectoryFactory.close Closing MockDirectoryFactory - 2 directories currently being tracked
   [junit4]   2> 333611 T290 oasc.CachingDirectoryFactory.closeCacheValue looking to close ./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1383513188698/awholynewcollection_0_shard5_replica1/data [CachedDir<<refCount=0;path=./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1383513188698/awholynewcollection_0_shard5_replica1/data;done=false>>]
   [junit4]   2> 333611 T290 oasc.CachingDirectoryFactory.close Closing directory: ./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1383513188698/awholynewcollection_0_shard5_replica1/data
   [junit4]   2> 333611 T290 oasc.CachingDirectoryFactory.closeCacheValue looking to close ./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1383513188698/awholynewcollection_0_shard5_replica1/data/index [CachedDir<<refCount=0;path=./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1383513188698/awholynewcollection_0_shard5_replica1/data/index;done=false>>]
   [junit4]   2> 333612 T290 oasc.CachingDirectoryFactory.close Closing directory: ./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1383513188698/awholynewcollection_0_shard5_replica1/data/index
   [junit4]   2> 333612 T290 oasc.SolrCore.close [awholynewcollection_0_shard1_replica2]  CLOSING SolrCore org.apache.solr.core.SolrCore@58b19082
   [junit4]   2> 333628 T290 oasu.DirectUpdateHandler2.close closing DirectUpdateHandler2{commits=0,autocommits=0,soft autocommits=0,optimizes=0,rollbacks=0,expungeDeletes=0,docsPending=0,adds=0,deletesById=0,deletesByQuery=0,errors=0,cumulative_adds=0,cumulative_deletesById=0,cumulative_deletesByQuery=0,cumulative_errors=0}
   [junit4]   2> 333629 T290 oasu.SolrCoreState.decrefSolrCoreState Closing SolrCoreState
   [junit4]   2> 333629 T290 oasu.DefaultSolrCoreState.closeIndexWriter SolrCoreState ref count has reached 0 - closing IndexWriter
   [junit4]   2> 333629 T290 oasu.DefaultSolrCoreState.closeIndexWriter closing IndexWriter with IndexWriterCloser
   [junit4]   2> 333630 T290 oasc.SolrCore.closeSearcher [awholynewcollection_0_shard1_replica2] Closing main searcher on request.
   [junit4]   2> 333631 T290 oasc.CachingDirectoryFactory.close Closing MockDirectoryFactory - 2 directories currently being tracked
   [junit4]   2> 333631 T290 oasc.CachingDirectoryFactory.closeCacheValue looking to close ./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1383513188698/awholynewcollection_0_shard1_replica2/data [CachedDir<<refCount=0;path=./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1383513188698/awholynewcollection_0_shard1_replica2/data;done=false>>]
   [junit4]   2> 333631 T290 oasc.CachingDirectoryFactory.close Closing directory: ./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1383513188698/awholynewcollection_0_shard1_replica2/data
   [junit4]   2> 333631 T290 oasc.CachingDirectoryFactory.closeCacheValue looking to close ./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1383513188698/awholynewcollection_0_shard1_replica2/data/index [CachedDir<<refCount=0;path=./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1383513188698/awholynewcollection_0_shard1_replica2/data/index;done=false>>]
   [junit4]   2> 333632 T290 oasc.CachingDirectoryFactory.close Closing directory: ./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1383513188698/awholynewcollection_0_shard1_replica2/data/index
   [junit4]   2> 333632 T290 oasc.SolrCore.close [acollectionafterbaddelete_shard1_replica1]  CLOSING SolrCore org.apache.solr.core.SolrCore@3fbbe33f
   [junit4]   2> 333643 T290 oasu.DirectUpdateHandler2.close closing DirectUpdateHandler2{commits=0,autocommits=0,soft autocommits=0,optimizes=0,rollbacks=0,expungeDeletes=0,docsPending=0,adds=0,deletesById=0,deletesByQuery=0,errors=0,cumulative_adds=0,cumulative_deletesById=0,cumulative_deletesByQuery=0,cumulative_errors=0}
   [junit4]   2> 333643 T290 oasu.SolrCoreState.decrefSolrCoreState Closing SolrCoreState
   [junit4]   2> 333643 T290 oasu.DefaultSolrCoreState.closeIndexWriter SolrCoreState ref count has reached 0 - closing IndexWriter
   [junit4]   2> 333643 T290 oasu.DefaultSolrCoreState.closeIndexWriter closing IndexWriter with IndexWriterCloser
   [junit4]   2> 333645 T290 oasc.SolrCore.closeSearcher [acollectionafterbaddelete_shard1_replica1] Closing main searcher on request.
   [junit4]   2> 333646 T290 oasc.CachingDirectoryFactory.close Closing RAMDirectoryFactory - 2 directories currently being tracked
   [junit4]   2> 333646 T290 oasc.CachingDirectoryFactory.closeCacheValue looking to close data [CachedDir<<refCount=0;path=data;done=false>>]
   [junit4]   2> 333646 T290 oasc.CachingDirectoryFactory.close Closing directory: data
   [junit4]   2> 333647 T290 oasc.CachingDirectoryFactory.closeCacheValue looking to close data/index [CachedDir<<refCount=0;path=data/index;done=false>>]
   [junit4]   2> 333647 T290 oasc.CachingDirectoryFactory.close Closing directory: data/index
   [junit4]   2> 333650 T580 oasc.Overseer$ClusterStateUpdater.amILeader According to ZK I (id=90669919952502798-127.0.0.1:49447_ncx-n_0000000004) am no longer a leader.
   [junit4]   2> 333655 T376 oascc.ZkStateReader$3.process WARN ZooKeeper watch triggered, but Solr cannot talk to ZK
   [junit4]   2> 333656 T534 oazs.NIOServerCnxn.doIO WARN caught end of stream exception EndOfStreamException: Unable to read additional data from client sessionid 0x1421fcfd295000e, likely client has closed socket
   [junit4]   2> 	at org.apache.zookeeper.server.NIOServerCnxn.doIO(NIOServerCnxn.java:220)
   [junit4]   2> 	at org.apache.zookeeper.server.NIOServerCnxnFactory.run(NIOServerCnxnFactory.java:208)
   [junit4]   2> 	at java.lang.Thread.run(Thread.java:744)
   [junit4]   2> 
   [junit4]   2> 333668 T290 oejsh.ContextHandler.doStop stopped o.e.j.s.ServletContextHandler{/ncx,null}
   [junit4]   2> 333729 T290 oas.SolrTestCaseJ4.tearDown ###Ending testDistribSearch
   [junit4]   2> 333733 T290 oasc.ZkTestServer.send4LetterWord connecting to 127.0.0.1:49429 49429
   [junit4]   1> client port:0.0.0.0/0.0.0.0:0
   [junit4]   1> client port:0.0.0.0/0.0.0.0:49429
   [junit4]   2> NOTE: reproduce with: ant test  -Dtestcase=CollectionsAPIDistributedZkTest -Dtests.method=testDistribSearch -Dtests.seed=B22F2E20CA6577D2 -Dtests.slow=true -Dtests.locale=mk -Dtests.timezone=Etc/GMT-9 -Dtests.file.encoding=ISO-8859-1
   [junit4] ERROR    166s | CollectionsAPIDistributedZkTest.testDistribSearch <<<
   [junit4]    > Throwable #1: org.apache.solr.client.solrj.impl.HttpSolrServer$RemoteSolrException: createcollection the collection time out:60s
   [junit4]    > 	at __randomizedtesting.SeedInfo.seed([B22F2E20CA6577D2:33C9A038BD3A17EE]:0)
   [junit4]    > 	at org.apache.solr.client.solrj.impl.HttpSolrServer.request(HttpSolrServer.java:464)
   [junit4]    > 	at org.apache.solr.client.solrj.impl.HttpSolrServer.request(HttpSolrServer.java:181)
   [junit4]    > 	at org.apache.solr.cloud.CollectionsAPIDistributedZkTest.testCollectionsAPI(CollectionsAPIDistributedZkTest.java:818)
   [junit4]    > 	at org.apache.solr.cloud.CollectionsAPIDistributedZkTest.doTest(CollectionsAPIDistributedZkTest.java:197)
   [junit4]    > 	at org.apache.solr.BaseDistributedSearchTestCase.testDistribSearch(BaseDistributedSearchTestCase.java:835)
   [junit4]    > 	at java.lang.Thread.run(Thread.java:744)
   [junit4]   2> 333749 T290 oas.SolrTestCaseJ4.deleteCore ###deleteCore
   [junit4]   2> 165911 T289 ccr.ThreadLeakControl.checkThreadLeaks WARNING Will linger awaiting termination of 2 leaked thread(s).
   [junit4]   2> NOTE: test params are: codec=Appending, sim=DefaultSimilarity, locale=mk, timezone=Etc/GMT-9
   [junit4]   2> NOTE: Mac OS X 10.8.5 x86_64/Oracle Corporation 1.7.0_45 (64-bit)/cpus=2,threads=3,free=72907680,total=535822336
   [junit4]   2> NOTE: All tests run in this JVM: [TestNRTOpen, TestDistributedSearch, QueryElevationComponentTest, TestRandomDVFaceting, HdfsSyncSliceTest, TestSolrQueryParserDefaultOperatorResource, HdfsUnloadDistributedZkTest, TestQuerySenderListener, CSVRequestHandlerTest, CollectionsAPIDistributedZkTest]
   [junit4] Completed in 166.46s, 1 test, 1 error <<< FAILURES!

[...truncated 1001 lines...]
BUILD FAILED
/Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/build.xml:428: The following error occurred while executing this line:
/Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/build.xml:408: The following error occurred while executing this line:
/Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/build.xml:39: The following error occurred while executing this line:
/Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build.xml:189: The following error occurred while executing this line:
/Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/common-build.xml:483: The following error occurred while executing this line:
/Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/lucene/common-build.xml:1263: The following error occurred while executing this line:
/Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/lucene/common-build.xml:906: There were test failures: 333 suites, 1469 tests, 1 error, 40 ignored (5 assumptions)

Total time: 92 minutes 58 seconds
Build step 'Invoke Ant' marked build as failure
Description set: Java: 64bit/jdk1.7.0 -XX:-UseCompressedOops -XX:+UseG1GC
Archiving artifacts
Recording test results
Email was triggered for: Failure
Sending email for trigger: Failure