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 2014/03/26 18:30:16 UTC

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

Build: http://jenkins.thetaphi.de/job/Lucene-Solr-4.x-MacOSX/1409/
Java: 64bit/jdk1.8.0 -XX:-UseCompressedOops -XX:+UseSerialGC

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

Error Message:
createcollection the collection time out:180s

Stack Trace:
org.apache.solr.client.solrj.impl.HttpSolrServer$RemoteSolrException: createcollection the collection time out:180s
	at __randomizedtesting.SeedInfo.seed([44B396F795C16861:C55518EFE29E085D]:0)
	at org.apache.solr.client.solrj.impl.HttpSolrServer.executeMethod(HttpSolrServer.java:553)
	at org.apache.solr.client.solrj.impl.HttpSolrServer.request(HttpSolrServer.java:209)
	at org.apache.solr.client.solrj.impl.HttpSolrServer.request(HttpSolrServer.java:205)
	at org.apache.solr.client.solrj.request.CollectionAdminRequest.process(CollectionAdminRequest.java:300)
	at org.apache.solr.client.solrj.request.CollectionAdminRequest.createCollection(CollectionAdminRequest.java:360)
	at org.apache.solr.client.solrj.request.CollectionAdminRequest.createCollection(CollectionAdminRequest.java:346)
	at org.apache.solr.cloud.CollectionsAPIDistributedZkTest.testSolrJAPICalls(CollectionsAPIDistributedZkTest.java:301)
	at org.apache.solr.cloud.CollectionsAPIDistributedZkTest.doTest(CollectionsAPIDistributedZkTest.java:204)
	at org.apache.solr.BaseDistributedSearchTestCase.testDistribSearch(BaseDistributedSearchTestCase.java:870)
	at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
	at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
	at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
	at java.lang.reflect.Method.invoke(Method.java:483)
	at com.carrotsearch.randomizedtesting.RandomizedRunner.invoke(RandomizedRunner.java:1617)
	at com.carrotsearch.randomizedtesting.RandomizedRunner$6.evaluate(RandomizedRunner.java:826)
	at com.carrotsearch.randomizedtesting.RandomizedRunner$7.evaluate(RandomizedRunner.java:862)
	at com.carrotsearch.randomizedtesting.RandomizedRunner$8.evaluate(RandomizedRunner.java:876)
	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:359)
	at com.carrotsearch.randomizedtesting.ThreadLeakControl.forkTimeoutingTask(ThreadLeakControl.java:783)
	at com.carrotsearch.randomizedtesting.ThreadLeakControl$3.evaluate(ThreadLeakControl.java:443)
	at com.carrotsearch.randomizedtesting.RandomizedRunner.runSingleTest(RandomizedRunner.java:835)
	at com.carrotsearch.randomizedtesting.RandomizedRunner$3.evaluate(RandomizedRunner.java:737)
	at com.carrotsearch.randomizedtesting.RandomizedRunner$4.evaluate(RandomizedRunner.java:771)
	at com.carrotsearch.randomizedtesting.RandomizedRunner$5.evaluate(RandomizedRunner.java:782)
	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:359)
	at java.lang.Thread.run(Thread.java:744)




Build Log:
[...truncated 10379 lines...]
   [junit4] Suite: org.apache.solr.cloud.CollectionsAPIDistributedZkTest
   [junit4]   2> 509486 T1988 oas.SolrTestCaseJ4.buildSSLConfig Randomized ssl (false) and clientAuth (false)
   [junit4]   2> 509486 T1988 oas.BaseDistributedSearchTestCase.initHostContext Setting hostContext system property: /
   [junit4]   2> 509490 T1988 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-1395852587942
   [junit4]   2> 509492 T1988 oasc.ZkTestServer.run STARTING ZK TEST SERVER
   [junit4]   2> 509492 T1989 oasc.ZkTestServer$ZKServerMain.runFromConfig Starting server
   [junit4]   2> 509497 T1988 oasc.ZkTestServer.run start zk server on port:53315
   [junit4]   2> 509504 T1988 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 509510 T1995 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@5fa888ba name:ZooKeeperConnection Watcher:127.0.0.1:53315 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 509510 T1988 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 509510 T1988 oascc.SolrZkClient.makePath makePath: /solr
   [junit4]   2> 509521 T1988 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 509524 T1997 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@29813586 name:ZooKeeperConnection Watcher:127.0.0.1:53315/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 509524 T1988 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 509525 T1988 oascc.SolrZkClient.makePath makePath: /collections/collection1
   [junit4]   2> 509533 T1988 oascc.SolrZkClient.makePath makePath: /collections/collection1/shards
   [junit4]   2> 509539 T1988 oascc.SolrZkClient.makePath makePath: /collections/control_collection
   [junit4]   2> 509544 T1988 oascc.SolrZkClient.makePath makePath: /collections/control_collection/shards
   [junit4]   2> 509550 T1988 oasc.AbstractZkTestCase.putConfig put /Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/core/src/test-files/solr/collection1/conf/solrconfig-tlog.xml to /configs/conf1/solrconfig.xml
   [junit4]   2> 509550 T1988 oascc.SolrZkClient.makePath makePath: /configs/conf1/solrconfig.xml
   [junit4]   2> 509559 T1988 oasc.AbstractZkTestCase.putConfig put /Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/core/src/test-files/solr/collection1/conf/schema.xml to /configs/conf1/schema.xml
   [junit4]   2> 509560 T1988 oascc.SolrZkClient.makePath makePath: /configs/conf1/schema.xml
   [junit4]   2> 509569 T1988 oasc.AbstractZkTestCase.putConfig put /Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/core/src/test-files/solr/collection1/conf/solrconfig.snippet.randomindexconfig.xml to /configs/conf1/solrconfig.snippet.randomindexconfig.xml
   [junit4]   2> 509570 T1988 oascc.SolrZkClient.makePath makePath: /configs/conf1/solrconfig.snippet.randomindexconfig.xml
   [junit4]   2> 509582 T1988 oasc.AbstractZkTestCase.putConfig put /Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/core/src/test-files/solr/collection1/conf/stopwords.txt to /configs/conf1/stopwords.txt
   [junit4]   2> 509583 T1988 oascc.SolrZkClient.makePath makePath: /configs/conf1/stopwords.txt
   [junit4]   2> 509588 T1988 oasc.AbstractZkTestCase.putConfig put /Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/core/src/test-files/solr/collection1/conf/protwords.txt to /configs/conf1/protwords.txt
   [junit4]   2> 509588 T1988 oascc.SolrZkClient.makePath makePath: /configs/conf1/protwords.txt
   [junit4]   2> 509594 T1988 oasc.AbstractZkTestCase.putConfig put /Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/core/src/test-files/solr/collection1/conf/currency.xml to /configs/conf1/currency.xml
   [junit4]   2> 509595 T1988 oascc.SolrZkClient.makePath makePath: /configs/conf1/currency.xml
   [junit4]   2> 509602 T1988 oasc.AbstractZkTestCase.putConfig put /Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/core/src/test-files/solr/collection1/conf/enumsConfig.xml to /configs/conf1/enumsConfig.xml
   [junit4]   2> 509603 T1988 oascc.SolrZkClient.makePath makePath: /configs/conf1/enumsConfig.xml
   [junit4]   2> 509610 T1988 oasc.AbstractZkTestCase.putConfig put /Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/core/src/test-files/solr/collection1/conf/open-exchange-rates.json to /configs/conf1/open-exchange-rates.json
   [junit4]   2> 509611 T1988 oascc.SolrZkClient.makePath makePath: /configs/conf1/open-exchange-rates.json
   [junit4]   2> 509617 T1988 oasc.AbstractZkTestCase.putConfig put /Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/core/src/test-files/solr/collection1/conf/mapping-ISOLatin1Accent.txt to /configs/conf1/mapping-ISOLatin1Accent.txt
   [junit4]   2> 509618 T1988 oascc.SolrZkClient.makePath makePath: /configs/conf1/mapping-ISOLatin1Accent.txt
   [junit4]   2> 509625 T1988 oasc.AbstractZkTestCase.putConfig put /Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/core/src/test-files/solr/collection1/conf/old_synonyms.txt to /configs/conf1/old_synonyms.txt
   [junit4]   2> 509626 T1988 oascc.SolrZkClient.makePath makePath: /configs/conf1/old_synonyms.txt
   [junit4]   2> 509632 T1988 oasc.AbstractZkTestCase.putConfig put /Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/core/src/test-files/solr/collection1/conf/synonyms.txt to /configs/conf1/synonyms.txt
   [junit4]   2> 509633 T1988 oascc.SolrZkClient.makePath makePath: /configs/conf1/synonyms.txt
   [junit4]   2> Using new style solr.xml
   [junit4]   2> 509646 T1988 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 509653 T1999 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@e7d4373 name:ZooKeeperConnection Watcher:127.0.0.1:53315 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 509653 T1988 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 509654 T1988 oascc.SolrZkClient.makePath makePath: /solr
   [junit4]   2> 509666 T1988 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 509672 T2001 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@f4f3fe4 name:ZooKeeperConnection Watcher:127.0.0.1:53315/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 509672 T1988 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 509674 T1988 oasc.AbstractZkTestCase.putConfig put /Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/core/src/test-files/solr/collection1/conf/solrconfig.xml to /configs/conf2/solrconfig.xml
   [junit4]   2> 509675 T1988 oascc.SolrZkClient.makePath makePath: /configs/conf2/solrconfig.xml
   [junit4]   2> 509690 T1988 oasc.AbstractZkTestCase.putConfig put /Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/core/src/test-files/solr/collection1/conf/schema.xml to /configs/conf2/schema.xml
   [junit4]   2> 509690 T1988 oascc.SolrZkClient.makePath makePath: /configs/conf2/schema.xml
   [junit4]   2> 509704 T1988 oasc.AbstractZkTestCase.putConfig put /Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/core/src/test-files/solr/collection1/conf/solrconfig.snippet.randomindexconfig.xml to /configs/conf2/solrconfig.snippet.randomindexconfig.xml
   [junit4]   2> 509706 T1988 oascc.SolrZkClient.makePath makePath: /configs/conf2/solrconfig.snippet.randomindexconfig.xml
   [junit4]   2> 509721 T1988 oasc.AbstractZkTestCase.putConfig put /Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/core/src/test-files/solr/collection1/conf/stopwords.txt to /configs/conf2/stopwords.txt
   [junit4]   2> 509722 T1988 oascc.SolrZkClient.makePath makePath: /configs/conf2/stopwords.txt
   [junit4]   2> 509739 T1988 oasc.AbstractZkTestCase.putConfig put /Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/core/src/test-files/solr/collection1/conf/protwords.txt to /configs/conf2/protwords.txt
   [junit4]   2> 509741 T1988 oascc.SolrZkClient.makePath makePath: /configs/conf2/protwords.txt
   [junit4]   2> 509755 T1988 oasc.AbstractZkTestCase.putConfig put /Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/core/src/test-files/solr/collection1/conf/currency.xml to /configs/conf2/currency.xml
   [junit4]   2> 509757 T1988 oascc.SolrZkClient.makePath makePath: /configs/conf2/currency.xml
   [junit4]   2> 509773 T1988 oasc.AbstractZkTestCase.putConfig put /Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/core/src/test-files/solr/collection1/conf/open-exchange-rates.json to /configs/conf2/open-exchange-rates.json
   [junit4]   2> 509774 T1988 oascc.SolrZkClient.makePath makePath: /configs/conf2/open-exchange-rates.json
   [junit4]   2> 509789 T1988 oasc.AbstractZkTestCase.putConfig put /Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/core/src/test-files/solr/collection1/conf/mapping-ISOLatin1Accent.txt to /configs/conf2/mapping-ISOLatin1Accent.txt
   [junit4]   2> 509791 T1988 oascc.SolrZkClient.makePath makePath: /configs/conf2/mapping-ISOLatin1Accent.txt
   [junit4]   2> 509809 T1988 oasc.AbstractZkTestCase.putConfig put /Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/core/src/test-files/solr/collection1/conf/old_synonyms.txt to /configs/conf2/old_synonyms.txt
   [junit4]   2> 509810 T1988 oascc.SolrZkClient.makePath makePath: /configs/conf2/old_synonyms.txt
   [junit4]   2> 509826 T1988 oasc.AbstractZkTestCase.putConfig put /Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/core/src/test-files/solr/collection1/conf/synonyms.txt to /configs/conf2/synonyms.txt
   [junit4]   2> 509829 T1988 oascc.SolrZkClient.makePath makePath: /configs/conf2/synonyms.txt
   [junit4]   2> 509846 T1988 oasc.AbstractZkTestCase.putConfig put /Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/core/src/test-files/solr/collection1/conf/elevate.xml to /configs/conf2/elevate.xml
   [junit4]   2> 509848 T1988 oascc.SolrZkClient.makePath makePath: /configs/conf2/elevate.xml
   [junit4]   2> 511427 T1988 oejs.Server.doStart jetty-8.1.10.v20130312
   [junit4]   2> 511435 T1988 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:53320
   [junit4]   2> 511436 T1988 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
   [junit4]   2> 511436 T1988 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
   [junit4]   2> 511437 T1988 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-1395852588312
   [junit4]   2> 511437 T1988 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-1395852588312/'
   [junit4]   2> 511474 T1988 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-1395852588312/solr.xml
   [junit4]   2> 511499 T1988 oasc.CorePropertiesLocator.<init> Config-defined core root directory: /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-1395852588312
   [junit4]   2> 511500 T1988 oasc.CoreContainer.<init> New CoreContainer 386042457
   [junit4]   2> 511501 T1988 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-1395852588312/]
   [junit4]   2> 511501 T1988 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 90000
   [junit4]   2> 511501 T1988 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: 
   [junit4]   2> 511502 T1988 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
   [junit4]   2> 511502 T1988 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
   [junit4]   2> 511503 T1988 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
   [junit4]   2> 511504 T1988 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
   [junit4]   2> 511504 T1988 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
   [junit4]   2> 511504 T1988 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
   [junit4]   2> 511504 T1988 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
   [junit4]   2> 511504 T1988 oasl.LogWatcher.createWatcher SLF4J impl is org.slf4j.impl.Log4jLoggerFactory
   [junit4]   2> 511505 T1988 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
   [junit4]   2> 511506 T1988 oasc.CoreContainer.load Host Name: 127.0.0.1
   [junit4]   2> 511506 T1988 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:53315/solr
   [junit4]   2> 511506 T1988 oasc.ZkController.checkChrootPath zkHost includes chroot
   [junit4]   2> 511507 T1988 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 511512 T2012 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@592fde83 name:ZooKeeperConnection Watcher:127.0.0.1:53315 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 511512 T1988 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 511518 T1988 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 511522 T2014 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@466672da name:ZooKeeperConnection Watcher:127.0.0.1:53315/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 511522 T1988 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 511525 T1988 oascc.SolrZkClient.makePath makePath: /overseer/queue
   [junit4]   2> 511533 T1988 oascc.SolrZkClient.makePath makePath: /overseer/collection-queue-work
   [junit4]   2> 511542 T1988 oascc.SolrZkClient.makePath makePath: /overseer/collection-map-running
   [junit4]   2> 511550 T1988 oascc.SolrZkClient.makePath makePath: /overseer/collection-map-completed
   [junit4]   2> 511558 T1988 oascc.SolrZkClient.makePath makePath: /overseer/collection-map-failure
   [junit4]   2> 511565 T1988 oascc.SolrZkClient.makePath makePath: /live_nodes
   [junit4]   2> 511568 T1988 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:53320_
   [junit4]   2> 511570 T1988 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:53320_
   [junit4]   2> 511577 T1988 oascc.SolrZkClient.makePath makePath: /overseer_elect
   [junit4]   2> 511583 T1988 oascc.SolrZkClient.makePath makePath: /overseer_elect/election
   [junit4]   2> 511593 T1988 oasc.OverseerElectionContext.runLeaderProcess I am going to be the leader 127.0.0.1:53320_
   [junit4]   2> 511593 T1988 oascc.SolrZkClient.makePath makePath: /overseer_elect/leader
   [junit4]   2> 511599 T1988 oasc.Overseer.start Overseer (id=91478595203825669-127.0.0.1:53320_-n_0000000000) starting
   [junit4]   2> 511607 T1988 oascc.SolrZkClient.makePath makePath: /overseer/queue-work
   [junit4]   2> 511636 T2016 oasc.OverseerCollectionProcessor.run Process current queue of collection creations
   [junit4]   2> 511637 T1988 oascc.SolrZkClient.makePath makePath: /clusterstate.json
   [junit4]   2> 511638 T2016 oasc.OverseerCollectionProcessor.prioritizeOverseerNodes prioritizing overseer nodes
   [junit4]   2> 511645 T1988 oascc.SolrZkClient.makePath makePath: /aliases.json
   [junit4]   2> 511649 T1988 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
   [junit4]   2> 511656 T2015 oasc.Overseer$ClusterStateUpdater.run Starting to work on the main queue
   [junit4]   2> 511659 T1988 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.CollectionsAPIDistributedZkTest-controljetty-1395852588312
   [junit4]   2> 512328 T1988 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.CollectionsAPIDistributedZkTest-controljetty-1395852588312/conf/
   [junit4]   2> 512402 T1988 oasc.CorePropertiesLocator.discover Found 1 core definitions
   [junit4]   2> 512406 T1988 oass.SolrDispatchFilter.init user.dir=/Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0
   [junit4]   2> 512406 T1988 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
   [junit4]   2> 512409 T1988 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 512413 T2019 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@5c541e21 name:ZooKeeperConnection Watcher:127.0.0.1:53315/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 512413 T1988 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 512416 T1988 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
   [junit4]   2> 512422 T1988 oasc.ChaosMonkey.monkeyLog monkey: init - expire sessions:false cause connection loss:false
   [junit4]   2> 514086 T1988 oasc.AbstractFullDistribZkTestBase.createJettys create jetty 1
   [junit4]   2> 514087 T1988 oejs.Server.doStart jetty-8.1.10.v20130312
   [junit4]   2> 514092 T1988 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:53324
   [junit4]   2> 514093 T1988 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
   [junit4]   2> 514095 T1988 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
   [junit4]   2> 514095 T1988 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-1395852590873
   [junit4]   2> 514095 T1988 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-1395852590873/'
   [junit4]   2> 514125 T1988 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-1395852590873/solr.xml
   [junit4]   2> 514153 T1988 oasc.CorePropertiesLocator.<init> Config-defined core root directory: /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-1395852590873
   [junit4]   2> 514153 T1988 oasc.CoreContainer.<init> New CoreContainer 1884076180
   [junit4]   2> 514153 T1988 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-1395852590873/]
   [junit4]   2> 514154 T1988 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 90000
   [junit4]   2> 514155 T1988 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: 
   [junit4]   2> 514155 T1988 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
   [junit4]   2> 514155 T1988 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
   [junit4]   2> 514155 T1988 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
   [junit4]   2> 514156 T1988 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
   [junit4]   2> 514157 T1988 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
   [junit4]   2> 514157 T1988 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
   [junit4]   2> 514157 T1988 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
   [junit4]   2> 514158 T1988 oasl.LogWatcher.createWatcher SLF4J impl is org.slf4j.impl.Log4jLoggerFactory
   [junit4]   2> 514159 T1988 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
   [junit4]   2> 514159 T1988 oasc.CoreContainer.load Host Name: 127.0.0.1
   [junit4]   2> 514159 T1988 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:53315/solr
   [junit4]   2> 514160 T1988 oasc.ZkController.checkChrootPath zkHost includes chroot
   [junit4]   2> 514162 T1988 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 514166 T2030 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@1b70dbf4 name:ZooKeeperConnection Watcher:127.0.0.1:53315 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 514166 T1988 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 514174 T1988 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 514178 T2032 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@68ce21ed name:ZooKeeperConnection Watcher:127.0.0.1:53315/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 514178 T1988 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 514205 T1988 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
   [junit4]   2> 515216 T1988 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:53324_
   [junit4]   2> 515222 T1988 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:53324_
   [junit4]   2> 515235 T2032 oascc.ZkStateReader$3.process Updating live nodes... (2)
   [junit4]   2> 515236 T2014 oascc.ZkStateReader$3.process Updating live nodes... (2)
   [junit4]   2> 515236 T2019 oascc.ZkStateReader$3.process Updating live nodes... (2)
   [junit4]   2> 515255 T1988 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.CollectionsAPIDistributedZkTest-jetty1-1395852590873
   [junit4]   2> 515969 T1988 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.CollectionsAPIDistributedZkTest-jetty1-1395852590873/conf/
   [junit4]   2> 516046 T1988 oasc.CorePropertiesLocator.discover Found 1 core definitions
   [junit4]   2> 516048 T1988 oass.SolrDispatchFilter.init user.dir=/Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0
   [junit4]   2> 516049 T1988 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
   [junit4]   2> 517637 T1988 oasc.AbstractFullDistribZkTestBase.createJettys create jetty 2
   [junit4]   2> 517638 T1988 oejs.Server.doStart jetty-8.1.10.v20130312
   [junit4]   2> 517644 T1988 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:53327
   [junit4]   2> 517645 T1988 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
   [junit4]   2> 517646 T1988 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
   [junit4]   2> 517646 T1988 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: ./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty2-1395852594500
   [junit4]   2> 517646 T1988 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: './org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty2-1395852594500/'
   [junit4]   2> 517680 T1988 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-jetty2-1395852594500/solr.xml
   [junit4]   2> 517695 T1988 oasc.CorePropertiesLocator.<init> Config-defined core root directory: /Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty2-1395852594500
   [junit4]   2> 517695 T1988 oasc.CoreContainer.<init> New CoreContainer 1768427580
   [junit4]   2> 517695 T1988 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty2-1395852594500/]
   [junit4]   2> 517696 T1988 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 90000
   [junit4]   2> 517696 T1988 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: 
   [junit4]   2> 517697 T1988 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
   [junit4]   2> 517697 T1988 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
   [junit4]   2> 517697 T1988 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
   [junit4]   2> 517697 T1988 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
   [junit4]   2> 517698 T1988 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
   [junit4]   2> 517698 T1988 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
   [junit4]   2> 517698 T1988 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
   [junit4]   2> 517699 T1988 oasl.LogWatcher.createWatcher SLF4J impl is org.slf4j.impl.Log4jLoggerFactory
   [junit4]   2> 517699 T1988 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
   [junit4]   2> 517699 T1988 oasc.CoreContainer.load Host Name: 127.0.0.1
   [junit4]   2> 517700 T1988 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:53315/solr
   [junit4]   2> 517700 T1988 oasc.ZkController.checkChrootPath zkHost includes chroot
   [junit4]   2> 517702 T1988 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 517707 T2044 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@103c4347 name:ZooKeeperConnection Watcher:127.0.0.1:53315 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 517707 T1988 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 517712 T1988 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 517717 T2046 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@4225cfb1 name:ZooKeeperConnection Watcher:127.0.0.1:53315/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 517717 T1988 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 517737 T1988 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
   [junit4]   2> 518745 T1988 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:53327_
   [junit4]   2> 518747 T1988 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:53327_
   [junit4]   2> 518754 T2014 oascc.ZkStateReader$3.process Updating live nodes... (3)
   [junit4]   2> 518754 T2046 oascc.ZkStateReader$3.process Updating live nodes... (3)
   [junit4]   2> 518756 T2032 oascc.ZkStateReader$3.process Updating live nodes... (3)
   [junit4]   2> 518759 T2019 oascc.ZkStateReader$3.process Updating live nodes... (3)
   [junit4]   2> 518764 T1988 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.CollectionsAPIDistributedZkTest-jetty2-1395852594500
   [junit4]   2> 519287 T1988 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.CollectionsAPIDistributedZkTest-jetty2-1395852594500/conf/
   [junit4]   2> 519344 T1988 oasc.CorePropertiesLocator.discover Found 1 core definitions
   [junit4]   2> 519347 T1988 oass.SolrDispatchFilter.init user.dir=/Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0
   [junit4]   2> 519347 T1988 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
   [junit4]   2> 521079 T1988 oasc.AbstractFullDistribZkTestBase.createJettys create jetty 3
   [junit4]   2> 521079 T1988 oejs.Server.doStart jetty-8.1.10.v20130312
   [junit4]   2> 521086 T1988 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:53330
   [junit4]   2> 521086 T1988 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
   [junit4]   2> 521086 T1988 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
   [junit4]   2> 521086 T1988 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: ./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty3-1395852597798
   [junit4]   2> 521086 T1988 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: './org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty3-1395852597798/'
   [junit4]   2> 521120 T1988 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-1395852597798/solr.xml
   [junit4]   2> 521130 T1988 oasc.CorePropertiesLocator.<init> Config-defined core root directory: /Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty3-1395852597798
   [junit4]   2> 521133 T1988 oasc.CoreContainer.<init> New CoreContainer 1277053177
   [junit4]   2> 521134 T1988 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty3-1395852597798/]
   [junit4]   2> 521134 T1988 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 90000
   [junit4]   2> 521134 T1988 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: 
   [junit4]   2> 521134 T1988 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
   [junit4]   2> 521135 T1988 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
   [junit4]   2> 521136 T1988 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
   [junit4]   2> 521136 T1988 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
   [junit4]   2> 521136 T1988 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
   [junit4]   2> 521136 T1988 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
   [junit4]   2> 521136 T1988 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
   [junit4]   2> 521137 T1988 oasl.LogWatcher.createWatcher SLF4J impl is org.slf4j.impl.Log4jLoggerFactory
   [junit4]   2> 521138 T1988 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
   [junit4]   2> 521138 T1988 oasc.CoreContainer.load Host Name: 127.0.0.1
   [junit4]   2> 521138 T1988 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:53315/solr
   [junit4]   2> 521138 T1988 oasc.ZkController.checkChrootPath zkHost includes chroot
   [junit4]   2> 521141 T1988 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 521145 T2058 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@6a558d16 name:ZooKeeperConnection Watcher:127.0.0.1:53315 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 521145 T1988 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 521155 T1988 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 521157 T2060 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@3572ad62 name:ZooKeeperConnection Watcher:127.0.0.1:53315/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 521157 T1988 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 521175 T1988 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
   [junit4]   2> 522183 T1988 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:53330_
   [junit4]   2> 522185 T1988 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:53330_
   [junit4]   2> 522192 T2032 oascc.ZkStateReader$3.process Updating live nodes... (4)
   [junit4]   2> 522193 T2014 oascc.ZkStateReader$3.process Updating live nodes... (4)
   [junit4]   2> 522193 T2060 oascc.ZkStateReader$3.process Updating live nodes... (4)
   [junit4]   2> 522193 T2046 oascc.ZkStateReader$3.process Updating live nodes... (4)
   [junit4]   2> 522193 T2019 oascc.ZkStateReader$3.process Updating live nodes... (4)
   [junit4]   2> 522202 T1988 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.CollectionsAPIDistributedZkTest-jetty3-1395852597798
   [junit4]   2> 522776 T1988 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.CollectionsAPIDistributedZkTest-jetty3-1395852597798/conf/
   [junit4]   2> 522843 T1988 oasc.CorePropertiesLocator.discover Found 1 core definitions
   [junit4]   2> 522846 T1988 oass.SolrDispatchFilter.init user.dir=/Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0
   [junit4]   2> 522846 T1988 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
   [junit4]   2> 524519 T1988 oasc.AbstractFullDistribZkTestBase.createJettys create jetty 4
   [junit4]   2> 524521 T1988 oejs.Server.doStart jetty-8.1.10.v20130312
   [junit4]   2> 524542 T1988 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:53333
   [junit4]   2> 524544 T1988 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
   [junit4]   2> 524545 T1988 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
   [junit4]   2> 524545 T1988 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: ./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1395852601298
   [junit4]   2> 524545 T1988 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: './org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1395852601298/'
   [junit4]   2> 524585 T1988 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-1395852601298/solr.xml
   [junit4]   2> 524598 T1988 oasc.CorePropertiesLocator.<init> Config-defined core root directory: /Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1395852601298
   [junit4]   2> 524600 T1988 oasc.CoreContainer.<init> New CoreContainer 1756428193
   [junit4]   2> 524600 T1988 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1395852601298/]
   [junit4]   2> 524601 T1988 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 90000
   [junit4]   2> 524601 T1988 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: 
   [junit4]   2> 524602 T1988 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
   [junit4]   2> 524602 T1988 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
   [junit4]   2> 524602 T1988 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
   [junit4]   2> 524603 T1988 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
   [junit4]   2> 524603 T1988 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
   [junit4]   2> 524603 T1988 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
   [junit4]   2> 524603 T1988 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
   [junit4]   2> 524604 T1988 oasl.LogWatcher.createWatcher SLF4J impl is org.slf4j.impl.Log4jLoggerFactory
   [junit4]   2> 524605 T1988 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
   [junit4]   2> 524605 T1988 oasc.CoreContainer.load Host Name: 127.0.0.1
   [junit4]   2> 524606 T1988 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:53315/solr
   [junit4]   2> 524606 T1988 oasc.ZkController.checkChrootPath zkHost includes chroot
   [junit4]   2> 524607 T1988 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 524611 T2072 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@7798ff63 name:ZooKeeperConnection Watcher:127.0.0.1:53315 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 524612 T1988 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 524616 T1988 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 524619 T2074 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@704112b7 name:ZooKeeperConnection Watcher:127.0.0.1:53315/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 524620 T1988 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 524641 T1988 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
   [junit4]   2> 525653 T1988 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:53333_
   [junit4]   2> 525657 T1988 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:53333_
   [junit4]   2> 525673 T2014 oascc.ZkStateReader$3.process Updating live nodes... (5)
   [junit4]   2> 525675 T2060 oascc.ZkStateReader$3.process Updating live nodes... (5)
   [junit4]   2> 525676 T2074 oascc.ZkStateReader$3.process Updating live nodes... (5)
   [junit4]   2> 525676 T2032 oascc.ZkStateReader$3.process Updating live nodes... (5)
   [junit4]   2> 525676 T2046 oascc.ZkStateReader$3.process Updating live nodes... (5)
   [junit4]   2> 525676 T2019 oascc.ZkStateReader$3.process Updating live nodes... (5)
   [junit4]   2> 525701 T1988 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.CollectionsAPIDistributedZkTest-jetty4-1395852601298
   [junit4]   2> 526232 T1988 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.CollectionsAPIDistributedZkTest-jetty4-1395852601298/conf/
   [junit4]   2> 526284 T1988 oasc.CorePropertiesLocator.discover Found 1 core definitions
   [junit4]   2> 526287 T1988 oass.SolrDispatchFilter.init user.dir=/Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0
   [junit4]   2> 526287 T1988 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
   [junit4]   2> 526291 T2023 oasha.CollectionsHandler.handleCreateAction Creating Collection : replicationFactor=2&collection.configName=conf1&router.field=myOwnField&name=solrj_collection&router.name=compositeId&action=CREATE&numShards=2&wt=javabin&version=2
   [junit4]   2> 526293 T2014 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/collection-queue-work state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 526296 T2016 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> 526296 T2016 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> 526297 T2016 oasc.OverseerCollectionProcessor.createConfNode creating collections conf node /collections/solrj_collection 
   [junit4]   2> 526297 T2016 oascc.SolrZkClient.makePath makePath: /collections/solrj_collection
   [junit4]   2> 526307 T2014 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 526310 T2015 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 526311 T2015 oasc.Overseer$ClusterStateUpdater.buildCollection building a new collection: solrj_collection
   [junit4]   2> 526311 T2015 oasc.Overseer$ClusterStateUpdater.createCollection Create collection solrj_collection with shards [shard1, shard2]
   [junit4]   2> 526317 T2014 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 526319 T2046 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> 526320 T2032 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> 526322 T2014 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> 526326 T2074 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> 526327 T2019 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> 526326 T2060 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> 526408 T2016 oasc.OverseerCollectionProcessor.createCollection Creating SolrCores for new collection, shardNames [shard1, shard2] , replicationFactor : 2
   [junit4]   2> 526409 T2016 oasc.OverseerCollectionProcessor.createCollection Creating shard solrj_collection_shard1_replica1 as part of slice shard1 of collection solrj_collection on 127.0.0.1:53324_
   [junit4]   2> 526412 T2016 oasc.OverseerCollectionProcessor.createCollection Creating shard solrj_collection_shard1_replica2 as part of slice shard1 of collection solrj_collection on 127.0.0.1:53327_
   [junit4]   2> 526416 T2016 oasc.OverseerCollectionProcessor.createCollection Creating shard solrj_collection_shard2_replica1 as part of slice shard2 of collection solrj_collection on 127.0.0.1:53320_
   [junit4]   2> 526421 T2016 oasc.OverseerCollectionProcessor.createCollection Creating shard solrj_collection_shard2_replica2 as part of slice shard2 of collection solrj_collection on 127.0.0.1:53333_
   [junit4]   2> 526421 T2024 oasha.CoreAdminHandler.handleCreateAction core create command qt=/admin/cores&collection.configName=conf1&name=solrj_collection_shard1_replica1&action=CREATE&numShards=2&collection=solrj_collection&shard=shard1&wt=javabin&version=2
   [junit4]   2> 526423 T2040 oasha.CoreAdminHandler.handleCreateAction core create command qt=/admin/cores&collection.configName=conf1&name=solrj_collection_shard1_replica2&action=CREATE&numShards=2&collection=solrj_collection&shard=shard1&wt=javabin&version=2
   [junit4]   2> 526426 T2006 oasha.CoreAdminHandler.handleCreateAction core create command qt=/admin/cores&collection.configName=conf1&name=solrj_collection_shard2_replica1&action=CREATE&numShards=2&collection=solrj_collection&shard=shard2&wt=javabin&version=2
   [junit4]   2> 526428 T2040 oasc.ZkController.publish publishing core=solrj_collection_shard1_replica2 state=down collection=solrj_collection
   [junit4]   2> 526431 T2014 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 526431 T2040 oasc.ZkController.waitForCoreNodeName look for our core node name
   [junit4]   2> 526433 T2024 oasc.ZkController.publish publishing core=solrj_collection_shard1_replica1 state=down collection=solrj_collection
   [junit4]   2> 526434 T2006 oasc.ZkController.publish publishing core=solrj_collection_shard2_replica1 state=down collection=solrj_collection
   [junit4]   2> 526436 T2069 oasha.CoreAdminHandler.handleCreateAction core create command qt=/admin/cores&collection.configName=conf1&name=solrj_collection_shard2_replica2&action=CREATE&numShards=2&collection=solrj_collection&shard=shard2&wt=javabin&version=2
   [junit4]   2> 526437 T2014 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 526437 T2006 oasc.ZkController.waitForCoreNodeName look for our core node name
   [junit4]   2> 526438 T2024 oasc.ZkController.waitForCoreNodeName look for our core node name
   [junit4]   2> 526439 T2015 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 526440 T2069 oasc.ZkController.publish publishing core=solrj_collection_shard2_replica2 state=down collection=solrj_collection
   [junit4]   2> 526440 T2015 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:53327",
   [junit4]   2> 	  "core":"solrj_collection_shard1_replica2",
   [junit4]   2> 	  "roles":null,
   [junit4]   2> 	  "node_name":"127.0.0.1:53327_",
   [junit4]   2> 	  "shard":"shard1",
   [junit4]   2> 	  "collection":"solrj_collection",
   [junit4]   2> 	  "numShards":"2",
   [junit4]   2> 	  "core_node_name":null}
   [junit4]   2> 526443 T2069 oasc.ZkController.waitForCoreNodeName look for our core node name
   [junit4]   2> 526449 T2015 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:53324",
   [junit4]   2> 	  "core":"solrj_collection_shard1_replica1",
   [junit4]   2> 	  "roles":null,
   [junit4]   2> 	  "node_name":"127.0.0.1:53324_",
   [junit4]   2> 	  "shard":"shard1",
   [junit4]   2> 	  "collection":"solrj_collection",
   [junit4]   2> 	  "numShards":"2",
   [junit4]   2> 	  "core_node_name":null}
   [junit4]   2> 526455 T2014 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 526457 T2015 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:53320",
   [junit4]   2> 	  "core":"solrj_collection_shard2_replica1",
   [junit4]   2> 	  "roles":null,
   [junit4]   2> 	  "node_name":"127.0.0.1:53320_",
   [junit4]   2> 	  "shard":"shard2",
   [junit4]   2> 	  "collection":"solrj_collection",
   [junit4]   2> 	  "numShards":"2",
   [junit4]   2> 	  "core_node_name":null}
   [junit4]   2> 526463 T2014 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 526465 T2015 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:53333",
   [junit4]   2> 	  "core":"solrj_collection_shard2_replica2",
   [junit4]   2> 	  "roles":null,
   [junit4]   2> 	  "node_name":"127.0.0.1:53333_",
   [junit4]   2> 	  "shard":"shard2",
   [junit4]   2> 	  "collection":"solrj_collection",
   [junit4]   2> 	  "numShards":"2",
   [junit4]   2> 	  "core_node_name":null}
   [junit4]   2> 526470 T2014 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 526582 T2014 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> 526582 T2060 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> 526583 T2074 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> 526583 T2046 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> 526583 T2032 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> 526585 T2019 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> 527434 T2040 oasc.ZkController.waitForShardId waiting to find shard id in clusterstate for solrj_collection_shard1_replica2
   [junit4]   2> 527440 T2006 oasc.ZkController.waitForShardId waiting to find shard id in clusterstate for solrj_collection_shard2_replica1
   [junit4]   2> 527440 T2024 oasc.ZkController.waitForShardId waiting to find shard id in clusterstate for solrj_collection_shard1_replica1
   [junit4]   2> 527440 T2040 oasc.ZkController.createCollectionZkNode Check for collection zkNode:solrj_collection
   [junit4]   2> 527445 T2069 oasc.ZkController.waitForShardId waiting to find shard id in clusterstate for solrj_collection_shard2_replica2
   [junit4]   2> 527445 T2024 oasc.ZkController.createCollectionZkNode Check for collection zkNode:solrj_collection
   [junit4]   2> 527447 T2069 oasc.ZkController.createCollectionZkNode Check for collection zkNode:solrj_collection
   [junit4]   2> 527449 T2024 oasc.ZkController.createCollectionZkNode Collection zkNode exists
   [junit4]   2> 527449 T2024 oascc.ZkStateReader.readConfigName Load collection config from:/collections/solrj_collection
   [junit4]   2> 527448 T2006 oasc.ZkController.createCollectionZkNode Check for collection zkNode:solrj_collection
   [junit4]   2> 527450 T2040 oasc.ZkController.createCollectionZkNode Collection zkNode exists
   [junit4]   2> 527450 T2040 oascc.ZkStateReader.readConfigName Load collection config from:/collections/solrj_collection
   [junit4]   2> 527450 T2069 oasc.ZkController.createCollectionZkNode Collection zkNode exists
   [junit4]   2> 527451 T2069 oascc.ZkStateReader.readConfigName Load collection config from:/collections/solrj_collection
   [junit4]   2> 527451 T2024 oascc.ZkStateReader.readConfigName path=/collections/solrj_collection configName=conf1 specified config exists in ZooKeeper
   [junit4]   2> 527452 T2024 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-1395852590873/solrj_collection_shard1_replica1/'
   [junit4]   2> 527453 T2069 oascc.ZkStateReader.readConfigName path=/collections/solrj_collection configName=conf1 specified config exists in ZooKeeper
   [junit4]   2> 527453 T2069 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: './org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1395852601298/solrj_collection_shard2_replica2/'
   [junit4]   2> 527454 T2006 oasc.ZkController.createCollectionZkNode Collection zkNode exists
   [junit4]   2> 527455 T2006 oascc.ZkStateReader.readConfigName Load collection config from:/collections/solrj_collection
   [junit4]   2> 527458 T2006 oascc.ZkStateReader.readConfigName path=/collections/solrj_collection configName=conf1 specified config exists in ZooKeeper
   [junit4]   2> 527458 T2006 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-1395852588312/solrj_collection_shard2_replica1/'
   [junit4]   2> 527459 T2040 oascc.ZkStateReader.readConfigName path=/collections/solrj_collection configName=conf1 specified config exists in ZooKeeper
   [junit4]   2> 527460 T2040 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: './org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty2-1395852594500/solrj_collection_shard1_replica2/'
   [junit4]   2> 527550 T2024 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_48
   [junit4]   2> 527554 T2069 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_48
   [junit4]   2> 527564 T2040 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_48
   [junit4]   2> 527560 T2006 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_48
   [junit4]   2> 527590 T2069 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
   [junit4]   2> 527590 T2040 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
   [junit4]   2> 527595 T2069 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
   [junit4]   2> 527601 T2024 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
   [junit4]   2> 527602 T2040 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
   [junit4]   2> 527616 T2069 oass.IndexSchema.readSchema [solrj_collection_shard2_replica2] Schema name=test
   [junit4]   2> 527620 T2040 oass.IndexSchema.readSchema [solrj_collection_shard1_replica2] Schema name=test
   [junit4]   2> 527627 T2006 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
   [junit4]   2> 527629 T2024 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
   [junit4]   2> 527634 T2024 oass.IndexSchema.readSchema [solrj_collection_shard1_replica1] Schema name=test
   [junit4]   2> 527643 T2006 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
   [junit4]   2> 527667 T2006 oass.IndexSchema.readSchema [solrj_collection_shard2_replica1] Schema name=test
   [junit4]   2> 527977 T2069 oass.ByteField.init WARN ByteField is deprecated and will be removed in 5.0. You should use TrieIntField instead.
   [junit4]   2> 527981 T2069 oass.ShortField.init WARN ShortField is deprecated and will be removed in 5.0. You should use TrieIntField instead.
   [junit4]   2> 527982 T2069 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
   [junit4]   2> 528005 T2069 oass.IndexSchema.readSchema default search field in schema is text
   [junit4]   2> 528006 T2069 oass.IndexSchema.readSchema unique key field: id
   [junit4]   2> 528008 T2024 oass.ByteField.init WARN ByteField is deprecated and will be removed in 5.0. You should use TrieIntField instead.
   [junit4]   2> 528014 T2024 oass.ShortField.init WARN ShortField is deprecated and will be removed in 5.0. You should use TrieIntField instead.
   [junit4]   2> 528015 T2024 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
   [junit4]   2> 528018 T2024 oass.IndexSchema.readSchema default search field in schema is text
   [junit4]   2> 528019 T2024 oass.IndexSchema.readSchema unique key field: id
   [junit4]   2> 528092 T2024 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
   [junit4]   2> 528099 T2069 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
   [junit4]   2> 528101 T2040 oass.ByteField.init WARN ByteField is deprecated and will be removed in 5.0. You should use TrieIntField instead.
   [junit4]   2> 528101 T2040 oass.ShortField.init WARN ShortField is deprecated and will be removed in 5.0. You should use TrieIntField instead.
   [junit4]   2> 528102 T2024 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
   [junit4]   2> 528102 T2040 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
   [junit4]   2> 528109 T2040 oass.IndexSchema.readSchema default search field in schema is text
   [junit4]   2> 528105 T2069 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
   [junit4]   2> 528111 T2040 oass.IndexSchema.readSchema unique key field: id
   [junit4]   2> 528116 T2024 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
   [junit4]   2> 528122 T2024 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
   [junit4]   2> 528122 T2024 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
   [junit4]   2> 528122 T2024 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
   [junit4]   2> 528123 T2069 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
   [junit4]   2> 528129 T2024 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
   [junit4]   2> 528130 T2024 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
   [junit4]   2> 528130 T2024 oasc.CoreContainer.create Creating SolrCore 'solrj_collection_shard1_replica1' using configuration from collection solrj_collection
   [junit4]   2> 528129 T2069 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
   [junit4]   2> 528131 T2069 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
   [junit4]   2> 528131 T2069 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
   [junit4]   2> 528132 T2024 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
   [junit4]   2> 528133 T2024 oasc.SolrCore.<init> [solrj_collection_shard1_replica1] Opening new SolrCore at ../../../../../../../../../Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty1-1395852590873/solrj_collection_shard1_replica1/, dataDir=../../../../../../../../../Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty1-1395852590873/solrj_collection_shard1_replica1/data/
   [junit4]   2> 528134 T2024 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@6e634c92
   [junit4]   2> 528135 T2069 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
   [junit4]   2> 528135 T2069 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
   [junit4]   2> 528135 T2069 oasc.CoreContainer.create Creating SolrCore 'solrj_collection_shard2_replica2' using configuration from collection solrj_collection
   [junit4]   2> 528136 T2069 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
   [junit4]   2> 528137 T2069 oasc.SolrCore.<init> [solrj_collection_shard2_replica2] Opening new SolrCore at ./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1395852601298/solrj_collection_shard2_replica2/, dataDir=./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1395852601298/solrj_collection_shard2_replica2/data/
   [junit4]   2> 528137 T2069 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@6e634c92
   [junit4]   2> 528130 T2006 oass.ByteField.init WARN ByteField is deprecated and will be removed in 5.0. You should use TrieIntField instead.
   [junit4]   2> 528138 T2069 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1395852601298/solrj_collection_shard2_replica2/data
   [junit4]   2> 528136 T2024 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-1395852590873/solrj_collection_shard1_replica1/data
   [junit4]   2> 528138 T2006 oass.ShortField.init WARN ShortField is deprecated and will be removed in 5.0. You should use TrieIntField instead.
   [junit4]   2> 528140 T2006 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
   [junit4]   2> 528143 T2006 oass.IndexSchema.readSchema default search field in schema is text
   [junit4]   2> 528146 T2069 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1395852601298/solrj_collection_shard2_replica2/data/index/
   [junit4]   2> 528146 T2069 oasc.SolrCore.initIndex WARN [solrj_collection_shard2_replica2] Solr index directory './org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1395852601298/solrj_collection_shard2_replica2/data/index' doesn't exist. Creating new index...
   [junit4]   2> 528147 T2006 oass.IndexSchema.readSchema unique key field: id
   [junit4]   2> 528150 T2024 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-1395852590873/solrj_collection_shard1_replica1/data/index/
   [junit4]   2> 528150 T2024 oasc.SolrCore.initIndex WARN [solrj_collection_shard1_replica1] Solr index directory '../../../../../../../../../Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty1-1395852590873/solrj_collection_shard1_replica1/data/index' doesn't exist. Creating new index...
   [junit4]   2> 528150 T2024 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-1395852590873/solrj_collection_shard1_replica1/data/index
   [junit4]   2> 528151 T2024 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.LogByteSizeMergePolicy: [LogByteSizeMergePolicy: minMergeSize=1677721, mergeFactor=43, maxMergeSize=2147483648, maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=true, maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.0]
   [junit4]   2> 528147 T2069 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1395852601298/solrj_collection_shard2_replica2/data/index
   [junit4]   2> 528152 T2069 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.LogByteSizeMergePolicy: [LogByteSizeMergePolicy: minMergeSize=1677721, mergeFactor=43, maxMergeSize=2147483648, maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=true, maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.0]
   [junit4]   2> 528155 T2024 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
   [junit4]   2> 		commit{dir=MockDirectoryWrapper(RAMDirectory@3b6afc8a lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@1483fc36),segFN=segments_1,generation=1}
   [junit4]   2> 528155 T2040 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
   [junit4]   2> 528155 T2069 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
   [junit4]   2> 		commit{dir=MockDirectoryWrapper(RAMDirectory@79b02f7f lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@1354ce7d),segFN=segments_1,generation=1}
   [junit4]   2> 528157 T2069 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
   [junit4]   2> 528155 T2024 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
   [junit4]   2> 528161 T2069 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "nodistrib"
   [junit4]   2> 528161 T2024 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "nodistrib"
   [junit4]   2> 528163 T2024 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "dedupe"
   [junit4]   2> 528163 T2024 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
   [junit4]   2> 528164 T2024 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "stored_sig"
   [junit4]   2> 528164 T2040 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
   [junit4]   2> 528162 T2069 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "dedupe"
   [junit4]   2> 528165 T2069 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
   [junit4]   2> 528165 T2069 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "stored_sig"
   [junit4]   2> 528166 T2069 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
   [junit4]   2> 528166 T2069 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-explicit"
   [junit4]   2> 528167 T2069 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-implicit"
   [junit4]   2> 528167 T2069 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
   [junit4]   2> 528167 T2069 oasc.SolrCore.loadUpdateProcessorChains no updateRequestProcessorChain defined as default, creating implicit default
   [junit4]   2> 528168 T2069 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
   [junit4]   2> 528169 T2069 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
   [junit4]   2> 528169 T2069 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
   [junit4]   2> 528169 T2069 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
   [junit4]   2> 528170 T2069 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
   [junit4]   2> 528170 T2069 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
   [junit4]   2> 528171 T2069 oasc.RequestHandlers.initHandlersFromConfig created /admin/file: solr.admin.ShowFileRequestHandler
   [junit4]   2> 528164 T2024 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
   [junit4]   2> 528175 T2024 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-explicit"
   [junit4]   2> 528181 T2024 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-implicit"
   [junit4]   2> 528181 T2024 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
   [junit4]   2> 528182 T2024 oasc.SolrCore.loadUpdateProcessorChains no updateRequestProcessorChain defined as default, creating implicit default
   [junit4]   2> 528182 T2024 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
   [junit4]   2> 528183 T2024 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
   [junit4]   2> 528183 T2024 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
   [junit4]   2> 528183 T2024 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
   [junit4]   2> 528184 T2024 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
   [junit4]   2> 528180 T2069 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
   [junit4]   2> 528185 T2024 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
   [junit4]   2> 528186 T2024 oasc.RequestHandlers.initHandlersFromConfig created /admin/file: solr.admin.ShowFileRequestHandler
   [junit4]   2> 528187 T2024 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
   [junit4]   2> 528183 T2040 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
   [junit4]   2> 528189 T2069 oasu.CommitTracker.<init> Hard AutoCommit: disabled
   [junit4]   2> 528192 T2040 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
   [junit4]   2> 528193 T2040 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
   [junit4]   2> 528193 T2040 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
   [junit4]   2> 528194 T2024 oasu.CommitTracker.<init> Hard AutoCommit: disabled
   [junit4]   2> 528194 T2024 oasu.CommitTracker.<init> Soft AutoCommit: disabled
   [junit4]   2> 528192 T2069 oasu.CommitTracker.<init> Soft AutoCommit: disabled
   [junit4]   2> 528199 T2069 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: maxMergeAtOnce=16, maxMergeAtOnceExplicit=27, maxMergedSegmentMB=81.6572265625, floorSegmentMB=0.365234375, forceMergeDeletesPctAllowed=13.874206765707264, segmentsPerTier=24.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.0
   [junit4]   2> 528198 T2040 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
   [junit4]   2> 528201 T2040 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
   [junit4]   2> 528202 T2040 oasc.CoreContainer.create Creating SolrCore 'solrj_collection_shard1_replica2' using configuration from collection solrj_collection
   [junit4]   2> 528196 T2024 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: maxMergeAtOnce=16, maxMergeAtOnceExplicit=27, maxMergedSegmentMB=81.6572265625, floorSegmentMB=0.365234375, forceMergeDeletesPctAllowed=13.874206765707264, segmentsPerTier=24.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.0
   [junit4]   2> 528202 T2040 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
   [junit4]   2> 528203 T2040 oasc.SolrCore.<init> [solrj_collection_shard1_replica2] Opening new SolrCore at ./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty2-1395852594500/solrj_collection_shard1_replica2/, dataDir=./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty2-1395852594500/solrj_collection_shard1_replica2/data/
   [junit4]   2> 528203 T2040 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@6e634c92
   [junit4]   2> 528200 T2069 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=1
   [junit4]   2> 		commit{dir=MockDirectoryWrapper(RAMDirectory@79b02f7f lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@1354ce7d),segFN=segments_1,generation=1}
   [junit4]   2> 528206 T2069 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
   [junit4]   2> 528207 T2069 oass.SolrIndexSearcher.<init> Opening Searcher@3f50396e[solrj_collection_shard2_replica2] main
   [junit4]   2> 528211 T2080 oasc.SolrCore.registerSearcher [solrj_collection_shard2_replica2] Registered new searcher Searcher@3f50396e[solrj_collection_shard2_replica2] main{StandardDirectoryReader(segments_1:1:nrt)}
   [junit4]   2> 528203 T2024 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=1
   [junit4]   2> 		commit{dir=MockDirectoryWrapper(RAMDirectory@3b6afc8a lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@1483fc36),segFN=segments_1,generation=1}
   [junit4]   2> 528213 T2024 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
   [junit4]   2> 528213 T2024 oass.SolrIndexSearcher.<init> Opening Searcher@2df5c42f[solrj_collection_shard1_replica1] main
   [junit4]   2> 528216 T2081 oasc.SolrCore.registerSearcher [solrj_collection_shard1_replica1] Registered new searcher Searcher@2df5c42f[solrj_collection_shard1_replica1] main{StandardDirectoryReader(segments_1:1:nrt)}
   [junit4]   2> 528218 T2024 oasc.CoreContainer.registerCore registering core: solrj_collection_shard1_replica1
   [junit4]   2> 528219 T2024 oasc.ZkController.register Register replica - core:solrj_collection_shard1_replica1 address:http://127.0.0.1:53324 collection:solrj_collection shard:shard1
   [junit4]   2> 528225 T2069 oasc.CoreContainer.registerCore registering core: solrj_collection_shard2_replica2
   [junit4]   2> 528225 T2069 oasc.ZkController.register Register replica - core:solrj_collection_shard2_replica2 address:http://127.0.0.1:53333 collection:solrj_collection shard:shard2
   [junit4]   2> 528229 T2024 oascc.SolrZkClient.makePath makePath: /collections/solrj_collection/leader_elect/shard1/election
   [junit4]   2> 528230 T2069 oascc.SolrZkClient.makePath makePath: /collections/solrj_collection/leader_elect/shard2/election
   [junit4]   2> 528234 T2040 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty2-1395852594500/solrj_collection_shard1_replica2/data
   [junit4]   2> 528234 T2040 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty2-1395852594500/solrj_collection_shard1_replica2/data/index/
   [junit4]   2> 528235 T2040 oasc.SolrCore.initIndex WARN [solrj_collection_shard1_replica2] Solr index directory './org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty2-1395852594500/solrj_collection_shard1_replica2/data/index' doesn't exist. Creating new index...
   [junit4]   2> 528236 T2040 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty2-1395852594500/solrj_collection_shard1_replica2/data/index
   [junit4]   2> 528237 T2040 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.LogByteSizeMergePolicy: [LogByteSizeMergePolicy: minMergeSize=1677721, mergeFactor=43, maxMergeSize=2147483648, maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=true, maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.0]
   [junit4]   2> 528238 T2006 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
   [junit4]   2> 528240 T2040 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
   [junit4]   2> 		commit{dir=MockDirectoryWrapper(RAMDirectory@75c5d8b3 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@5470a461),segFN=segments_1,generation=1}
   [junit4]   2> 528241 T2040 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
   [junit4]   2> 528244 T2006 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
   [junit4]   2> 528246 T2040 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "nodistrib"
   [junit4]   2> 528247 T2040 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "dedupe"
   [junit4]   2> 528247 T2040 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
   [junit4]   2> 528248 T2040 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "stored_sig"
   [junit4]   2> 528248 T2040 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
   [junit4]   2> 528248 T2040 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-explicit"
   [junit4]   2> 528249 T2006 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
   [junit4]   2> 528249 T2040 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-implicit"
   [junit4]   2> 528250 T2040 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
   [junit4]   2> 528250 T2040 oasc.SolrCore.loadUpdateProcessorChains no updateRequestProcessorChain defined as default, creating implicit default
   [junit4]   2> 528253 T2040 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
   [junit4]   2> 528254 T2006 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
   [junit4]   2> 528255 T2006 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
   [junit4]   2> 528255 T2006 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
   [junit4]   2> 528256 T2040 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
   [junit4]   2> 528258 T2069 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process for shard shard2
   [junit4]   2> 528258 T2006 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
   [junit4]   2> 528259 T2006 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
   [junit4]   2> 528260 T2006 oasc.CoreContainer.create Creating SolrCore 'solrj_collection_shard2_replica1' using configuration from collection solrj_collection
   [junit4]   2> 528260 T2006 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
   [junit4]   2> 528261 T2006 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-controljetty-1395852588312/solrj_collection_shard2_replica1/, dataDir=../../../../../../../../../Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-controljetty-1395852588312/solrj_collection_shard2_replica1/data/
   [junit4]   2> 528261 T2006 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@6e634c92
   [junit4]   2> 528259 T2040 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
   [junit4]   2> 528263 T2006 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-controljetty-1395852588312/solrj_collection_shard2_replica1/data
   [junit4]   2> 528264 T2024 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process for shard shard1
   [junit4]   2> 528264 T2006 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-controljetty-1395852588312/solrj_collection_shard2_replica1/data/index/
   [junit4]   2> 528265 T2006 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-controljetty-1395852588312/solrj_collection_shard2_replica1/data/index' doesn't exist. Creating new index...
   [junit4]   2> 528266 T2006 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-controljetty-1395852588312/solrj_collection_shard2_replica1/data/index
   [junit4]   2> 528263 T2040 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
   [junit4]   2> 528268 T2040 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
   [junit4]   2> 528267 T2006 o

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

tory: ./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty2-1395852594500/solrj_collection_shard1_replica2/data/index
   [junit4]   2> 716971 T2046 oasc.CachingDirectoryFactory.closeCacheValue looking to close ./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty2-1395852594500/solrj_collection_shard1_replica2/data [CachedDir<<refCount=0;path=./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty2-1395852594500/solrj_collection_shard1_replica2/data;done=false>>]
   [junit4]   2> 716972 T2046 oasc.CachingDirectoryFactory.close Closing directory: ./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty2-1395852594500/solrj_collection_shard1_replica2/data
   [junit4]   2> 716972 T2046 oascc.SolrZkClient.makePath makePath: /collections/solrj_collection/leaders/shard1
   [junit4]   2> 716973 T2046 oasc.SolrException.log ERROR There was a problem trying to register as the leader:org.apache.solr.common.SolrException: Could not register as the leader because creating the ephemeral registration node in ZooKeeper failed
   [junit4]   2> 		at org.apache.solr.cloud.ShardLeaderElectionContextBase.runLeaderProcess(ElectionContext.java:135)
   [junit4]   2> 		at org.apache.solr.cloud.ShardLeaderElectionContext.runLeaderProcess(ElectionContext.java:290)
   [junit4]   2> 		at org.apache.solr.cloud.LeaderElector.runIamLeaderProcess(LeaderElector.java:164)
   [junit4]   2> 		at org.apache.solr.cloud.LeaderElector.checkIfIamLeader(LeaderElector.java:108)
   [junit4]   2> 		at org.apache.solr.cloud.LeaderElector.access$000(LeaderElector.java:55)
   [junit4]   2> 		at org.apache.solr.cloud.LeaderElector$1.process(LeaderElector.java:137)
   [junit4]   2> 		at org.apache.zookeeper.ClientCnxn$EventThread.processEvent(ClientCnxn.java:522)
   [junit4]   2> 		at org.apache.zookeeper.ClientCnxn$EventThread.run(ClientCnxn.java:498)
   [junit4]   2> 	Caused by: org.apache.solr.common.SolrException: org.apache.zookeeper.KeeperException$SessionExpiredException: KeeperErrorCode = Session expired for /collections
   [junit4]   2> 		at org.apache.solr.common.util.RetryUtil.retryOnThrowable(RetryUtil.java:40)
   [junit4]   2> 		at org.apache.solr.cloud.ShardLeaderElectionContextBase.runLeaderProcess(ElectionContext.java:122)
   [junit4]   2> 		... 7 more
   [junit4]   2> 	Caused by: org.apache.zookeeper.KeeperException$SessionExpiredException: KeeperErrorCode = Session expired for /collections
   [junit4]   2> 		at org.apache.zookeeper.KeeperException.create(KeeperException.java:127)
   [junit4]   2> 		at org.apache.zookeeper.KeeperException.create(KeeperException.java:51)
   [junit4]   2> 		at org.apache.zookeeper.ZooKeeper.exists(ZooKeeper.java:1045)
   [junit4]   2> 		at org.apache.solr.common.cloud.SolrZkClient$3.execute(SolrZkClient.java:208)
   [junit4]   2> 		at org.apache.solr.common.cloud.SolrZkClient$3.execute(SolrZkClient.java:205)
   [junit4]   2> 		at org.apache.solr.common.cloud.ZkCmdExecutor.retryOperation(ZkCmdExecutor.java:73)
   [junit4]   2> 		at org.apache.solr.common.cloud.SolrZkClient.exists(SolrZkClient.java:205)
   [junit4]   2> 		at org.apache.solr.common.cloud.SolrZkClient.makePath(SolrZkClient.java:416)
   [junit4]   2> 		at org.apache.solr.common.cloud.SolrZkClient.makePath(SolrZkClient.java:385)
   [junit4]   2> 		at org.apache.solr.common.cloud.SolrZkClient.makePath(SolrZkClient.java:372)
   [junit4]   2> 		at org.apache.solr.cloud.ShardLeaderElectionContextBase$1.execute(ElectionContext.java:127)
   [junit4]   2> 		at org.apache.solr.common.util.RetryUtil.retryOnThrowable(RetryUtil.java:34)
   [junit4]   2> 		... 8 more
   [junit4]   2> 	
   [junit4]   2> 716973 T2046 oasc.LeaderElector$1.process WARN  org.apache.zookeeper.KeeperException$SessionExpiredException: KeeperErrorCode = Session expired for /collections/solrj_collection/leader_elect/shard1/election/91478595203825674-core_node1-n_0000000001
   [junit4]   2> 	at org.apache.zookeeper.KeeperException.create(KeeperException.java:127)
   [junit4]   2> 	at org.apache.zookeeper.KeeperException.create(KeeperException.java:51)
   [junit4]   2> 	at org.apache.zookeeper.ZooKeeper.delete(ZooKeeper.java:873)
   [junit4]   2> 	at org.apache.solr.common.cloud.SolrZkClient$2.execute(SolrZkClient.java:176)
   [junit4]   2> 	at org.apache.solr.common.cloud.SolrZkClient$2.execute(SolrZkClient.java:173)
   [junit4]   2> 	at org.apache.solr.common.cloud.ZkCmdExecutor.retryOperation(ZkCmdExecutor.java:73)
   [junit4]   2> 	at org.apache.solr.common.cloud.SolrZkClient.delete(SolrZkClient.java:173)
   [junit4]   2> 	at org.apache.solr.cloud.ElectionContext.cancelElection(ElectionContext.java:71)
   [junit4]   2> 	at org.apache.solr.cloud.ShardLeaderElectionContext.runLeaderProcess(ElectionContext.java:309)
   [junit4]   2> 	at org.apache.solr.cloud.LeaderElector.runIamLeaderProcess(LeaderElector.java:164)
   [junit4]   2> 	at org.apache.solr.cloud.LeaderElector.checkIfIamLeader(LeaderElector.java:108)
   [junit4]   2> 	at org.apache.solr.cloud.LeaderElector.access$000(LeaderElector.java:55)
   [junit4]   2> 	at org.apache.solr.cloud.LeaderElector$1.process(LeaderElector.java:137)
   [junit4]   2> 	at org.apache.zookeeper.ClientCnxn$EventThread.processEvent(ClientCnxn.java:522)
   [junit4]   2> 	at org.apache.zookeeper.ClientCnxn$EventThread.run(ClientCnxn.java:498)
   [junit4]   2> 
   [junit4]   2> 716973 T2046 oasc.LeaderElector$1.process WARN  org.apache.zookeeper.KeeperException$SessionExpiredException: KeeperErrorCode = Session expired for /overseer_elect/election
   [junit4]   2> 	at org.apache.zookeeper.KeeperException.create(KeeperException.java:127)
   [junit4]   2> 	at org.apache.zookeeper.KeeperException.create(KeeperException.java:51)
   [junit4]   2> 	at org.apache.zookeeper.ZooKeeper.getChildren(ZooKeeper.java:1472)
   [junit4]   2> 	at org.apache.solr.common.cloud.SolrZkClient$6.execute(SolrZkClient.java:259)
   [junit4]   2> 	at org.apache.solr.common.cloud.SolrZkClient$6.execute(SolrZkClient.java:256)
   [junit4]   2> 	at org.apache.solr.common.cloud.ZkCmdExecutor.retryOperation(ZkCmdExecutor.java:73)
   [junit4]   2> 	at org.apache.solr.common.cloud.SolrZkClient.getChildren(SolrZkClient.java:256)
   [junit4]   2> 	at org.apache.solr.cloud.LeaderElector.checkIfIamLeader(LeaderElector.java:92)
   [junit4]   2> 	at org.apache.solr.cloud.LeaderElector.access$000(LeaderElector.java:55)
   [junit4]   2> 	at org.apache.solr.cloud.LeaderElector$1.process(LeaderElector.java:137)
   [junit4]   2> 	at org.apache.zookeeper.ClientCnxn$EventThread.processEvent(ClientCnxn.java:522)
   [junit4]   2> 	at org.apache.zookeeper.ClientCnxn$EventThread.run(ClientCnxn.java:498)
   [junit4]   2> 
   [junit4]   2> 716974 T2046 oascc.ZkStateReader$3.process WARN ZooKeeper watch triggered, but Solr cannot talk to ZK
   [junit4]   2> NOTE: test params are: codec=Lucene41, sim=RandomSimilarityProvider(queryNorm=true,coord=no): {}, locale=is, timezone=Africa/Ndjamena
   [junit4]   2> NOTE: Mac OS X 10.8.5 x86_64/Oracle Corporation 1.8.0 (64-bit)/cpus=2,threads=1,free=82704696,total=259313664
   [junit4]   2> NOTE: All tests run in this JVM: [EnumFieldTest, TestSweetSpotSimilarityFactory, TestFaceting, TimeZoneUtilsTest, SuggesterTSTTest, FieldMutatingUpdateProcessorTest, HdfsDirectoryTest, ClusterStateUpdateTest, RAMDirectoryFactoryTest, SolrInfoMBeanTest, TestNonNRTOpen, SoftAutoCommitTest, TestRTGBase, DirectUpdateHandlerTest, OverseerRolesTest, DistributedQueryElevationComponentTest, TestConfig, UpdateParamsTest, DirectSolrSpellCheckerTest, TestNRTOpen, RequestHandlersTest, TestSchemaNameResource, TestZkChroot, TestInfoStreamLogging, TestClassNameShortening, QueryElevationComponentTest, TestBinaryField, DistributedTermsComponentTest, BinaryUpdateRequestHandlerTest, TestXIncludeConfig, TestReversedWildcardFilterFactory, TestPostingsSolrHighlighter, DirectSolrConnectionTest, TestDistributedGrouping, TestJmxIntegration, SliceStateUpdateTest, SyncSliceTest, TestOmitPositions, TestSolrQueryParserDefaultOperatorResource, TermsComponentTest, AssignTest, MinimalSchemaTest, TestSolr4Spatial, TestBinaryResponseWriter, TestQuerySenderNoQuery, XmlUpdateRequestHandlerTest, TestRequestStatusCollectionAPI, TestSort, LeaderElectionIntegrationTest, TestExtendedDismaxParser, TestLazyCores, StandardRequestHandlerTest, DisMaxRequestHandlerTest, TestCollapseQParserPlugin, TestAnalyzedSuggestions, BasicDistributedZk2Test, TestCollationField, QueryEqualityTest, SolrCoreTest, TestDocBasedVersionConstraints, ResourceLoaderTest, CollectionsAPIAsyncDistributedZkTest, CollectionsAPIDistributedZkTest]
   [junit4] Completed in 208.35s, 1 test, 1 error <<< FAILURES!

[...truncated 973 lines...]
BUILD FAILED
/Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/build.xml:467: The following error occurred while executing this line:
/Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/build.xml:447: The following error occurred while executing this line:
/Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/build.xml:45: The following error occurred while executing this line:
/Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/extra-targets.xml:37: 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:490: The following error occurred while executing this line:
/Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/lucene/common-build.xml:1276: The following error occurred while executing this line:
/Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/lucene/common-build.xml:908: There were test failures: 379 suites, 1603 tests, 1 error, 42 ignored (15 assumptions)

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