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/01/12 17:32:09 UTC

[JENKINS] Lucene-Solr-trunk-MacOSX (64bit/jdk1.7.0) - Build # 1217 - Failure!

Build: http://jenkins.thetaphi.de/job/Lucene-Solr-trunk-MacOSX/1217/
Java: 64bit/jdk1.7.0 -XX:+UseCompressedOops -XX:+UseSerialGC

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

Error Message:
deletecollection the collection time out:60s

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




Build Log:
[...truncated 10455 lines...]
   [junit4] Suite: org.apache.solr.cloud.CollectionsAPIDistributedZkTest
   [junit4]   2> 1761619 T6109 oas.BaseDistributedSearchTestCase.initHostContext Setting hostContext system property: /
   [junit4]   2> 1761628 T6109 oas.SolrTestCaseJ4.setUp ###Starting testDistribSearch
   [junit4]   2> Creating dataDir: /Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./solrtest-CollectionsAPIDistributedZkTest-1389542783107
   [junit4]   2> 1761630 T6109 oasc.ZkTestServer.run STARTING ZK TEST SERVER
   [junit4]   2> 1761632 T6110 oasc.ZkTestServer$ZKServerMain.runFromConfig Starting server
   [junit4]   2> 1761732 T6109 oasc.ZkTestServer.run start zk server on port:51141
   [junit4]   2> 1761735 T6109 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 1761743 T6116 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@2fdad495 name:ZooKeeperConnection Watcher:127.0.0.1:51141 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 1761743 T6109 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 1761744 T6109 oascc.SolrZkClient.makePath makePath: /solr
   [junit4]   2> 1761755 T6109 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 1761760 T6118 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@2882c9a2 name:ZooKeeperConnection Watcher:127.0.0.1:51141/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 1761760 T6109 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 1761760 T6109 oascc.SolrZkClient.makePath makePath: /collections/collection1
   [junit4]   2> 1761770 T6109 oascc.SolrZkClient.makePath makePath: /collections/collection1/shards
   [junit4]   2> 1761777 T6109 oascc.SolrZkClient.makePath makePath: /collections/control_collection
   [junit4]   2> 1761783 T6109 oascc.SolrZkClient.makePath makePath: /collections/control_collection/shards
   [junit4]   2> 1761790 T6109 oasc.AbstractZkTestCase.putConfig put /Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test-files/solr/collection1/conf/solrconfig-tlog.xml to /configs/conf1/solrconfig.xml
   [junit4]   2> 1761791 T6109 oascc.SolrZkClient.makePath makePath: /configs/conf1/solrconfig.xml
   [junit4]   2> 1761802 T6109 oasc.AbstractZkTestCase.putConfig put /Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test-files/solr/collection1/conf/schema.xml to /configs/conf1/schema.xml
   [junit4]   2> 1761802 T6109 oascc.SolrZkClient.makePath makePath: /configs/conf1/schema.xml
   [junit4]   2> 1761809 T6109 oasc.AbstractZkTestCase.putConfig put /Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test-files/solr/collection1/conf/solrconfig.snippet.randomindexconfig.xml to /configs/conf1/solrconfig.snippet.randomindexconfig.xml
   [junit4]   2> 1761810 T6109 oascc.SolrZkClient.makePath makePath: /configs/conf1/solrconfig.snippet.randomindexconfig.xml
   [junit4]   2> 1761819 T6109 oasc.AbstractZkTestCase.putConfig put /Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test-files/solr/collection1/conf/stopwords.txt to /configs/conf1/stopwords.txt
   [junit4]   2> 1761820 T6109 oascc.SolrZkClient.makePath makePath: /configs/conf1/stopwords.txt
   [junit4]   2> 1761828 T6109 oasc.AbstractZkTestCase.putConfig put /Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test-files/solr/collection1/conf/protwords.txt to /configs/conf1/protwords.txt
   [junit4]   2> 1761829 T6109 oascc.SolrZkClient.makePath makePath: /configs/conf1/protwords.txt
   [junit4]   2> 1761837 T6109 oasc.AbstractZkTestCase.putConfig put /Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test-files/solr/collection1/conf/currency.xml to /configs/conf1/currency.xml
   [junit4]   2> 1761838 T6109 oascc.SolrZkClient.makePath makePath: /configs/conf1/currency.xml
   [junit4]   2> 1761845 T6109 oasc.AbstractZkTestCase.putConfig put /Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test-files/solr/collection1/conf/enumsConfig.xml to /configs/conf1/enumsConfig.xml
   [junit4]   2> 1761845 T6109 oascc.SolrZkClient.makePath makePath: /configs/conf1/enumsConfig.xml
   [junit4]   2> 1761852 T6109 oasc.AbstractZkTestCase.putConfig put /Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test-files/solr/collection1/conf/open-exchange-rates.json to /configs/conf1/open-exchange-rates.json
   [junit4]   2> 1761852 T6109 oascc.SolrZkClient.makePath makePath: /configs/conf1/open-exchange-rates.json
   [junit4]   2> 1761859 T6109 oasc.AbstractZkTestCase.putConfig put /Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test-files/solr/collection1/conf/mapping-ISOLatin1Accent.txt to /configs/conf1/mapping-ISOLatin1Accent.txt
   [junit4]   2> 1761860 T6109 oascc.SolrZkClient.makePath makePath: /configs/conf1/mapping-ISOLatin1Accent.txt
   [junit4]   2> 1761867 T6109 oasc.AbstractZkTestCase.putConfig put /Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test-files/solr/collection1/conf/old_synonyms.txt to /configs/conf1/old_synonyms.txt
   [junit4]   2> 1761867 T6109 oascc.SolrZkClient.makePath makePath: /configs/conf1/old_synonyms.txt
   [junit4]   2> 1761875 T6109 oasc.AbstractZkTestCase.putConfig put /Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test-files/solr/collection1/conf/synonyms.txt to /configs/conf1/synonyms.txt
   [junit4]   2> 1761875 T6109 oascc.SolrZkClient.makePath makePath: /configs/conf1/synonyms.txt
   [junit4]   2> Using old style solr.xml
   [junit4]   2> 1761886 T6109 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 1761890 T6120 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@1e31ac8d name:ZooKeeperConnection Watcher:127.0.0.1:51141 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 1761890 T6109 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 1761890 T6109 oascc.SolrZkClient.makePath makePath: /solr
   [junit4]   2> 1761898 T6109 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 1761901 T6122 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@fa900f name:ZooKeeperConnection Watcher:127.0.0.1:51141/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 1761902 T6109 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 1761904 T6109 oasc.AbstractZkTestCase.putConfig put /Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test-files/solr/collection1/conf/solrconfig.xml to /configs/conf2/solrconfig.xml
   [junit4]   2> 1761904 T6109 oascc.SolrZkClient.makePath makePath: /configs/conf2/solrconfig.xml
   [junit4]   2> 1761915 T6109 oasc.AbstractZkTestCase.putConfig put /Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test-files/solr/collection1/conf/schema.xml to /configs/conf2/schema.xml
   [junit4]   2> 1761916 T6109 oascc.SolrZkClient.makePath makePath: /configs/conf2/schema.xml
   [junit4]   2> 1761924 T6109 oasc.AbstractZkTestCase.putConfig put /Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test-files/solr/collection1/conf/solrconfig.snippet.randomindexconfig.xml to /configs/conf2/solrconfig.snippet.randomindexconfig.xml
   [junit4]   2> 1761925 T6109 oascc.SolrZkClient.makePath makePath: /configs/conf2/solrconfig.snippet.randomindexconfig.xml
   [junit4]   2> 1761934 T6109 oasc.AbstractZkTestCase.putConfig put /Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test-files/solr/collection1/conf/stopwords.txt to /configs/conf2/stopwords.txt
   [junit4]   2> 1761935 T6109 oascc.SolrZkClient.makePath makePath: /configs/conf2/stopwords.txt
   [junit4]   2> 1761944 T6109 oasc.AbstractZkTestCase.putConfig put /Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test-files/solr/collection1/conf/protwords.txt to /configs/conf2/protwords.txt
   [junit4]   2> 1761945 T6109 oascc.SolrZkClient.makePath makePath: /configs/conf2/protwords.txt
   [junit4]   2> 1761953 T6109 oasc.AbstractZkTestCase.putConfig put /Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test-files/solr/collection1/conf/currency.xml to /configs/conf2/currency.xml
   [junit4]   2> 1761955 T6109 oascc.SolrZkClient.makePath makePath: /configs/conf2/currency.xml
   [junit4]   2> 1761963 T6109 oasc.AbstractZkTestCase.putConfig put /Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test-files/solr/collection1/conf/open-exchange-rates.json to /configs/conf2/open-exchange-rates.json
   [junit4]   2> 1761964 T6109 oascc.SolrZkClient.makePath makePath: /configs/conf2/open-exchange-rates.json
   [junit4]   2> 1761974 T6109 oasc.AbstractZkTestCase.putConfig put /Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test-files/solr/collection1/conf/mapping-ISOLatin1Accent.txt to /configs/conf2/mapping-ISOLatin1Accent.txt
   [junit4]   2> 1761975 T6109 oascc.SolrZkClient.makePath makePath: /configs/conf2/mapping-ISOLatin1Accent.txt
   [junit4]   2> 1761983 T6109 oasc.AbstractZkTestCase.putConfig put /Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test-files/solr/collection1/conf/old_synonyms.txt to /configs/conf2/old_synonyms.txt
   [junit4]   2> 1761984 T6109 oascc.SolrZkClient.makePath makePath: /configs/conf2/old_synonyms.txt
   [junit4]   2> 1761991 T6109 oasc.AbstractZkTestCase.putConfig put /Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test-files/solr/collection1/conf/synonyms.txt to /configs/conf2/synonyms.txt
   [junit4]   2> 1761992 T6109 oascc.SolrZkClient.makePath makePath: /configs/conf2/synonyms.txt
   [junit4]   2> 1761999 T6109 oasc.AbstractZkTestCase.putConfig put /Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test-files/solr/collection1/conf/elevate.xml to /configs/conf2/elevate.xml
   [junit4]   2> 1762000 T6109 oascc.SolrZkClient.makePath makePath: /configs/conf2/elevate.xml
   [junit4]   2> 1762331 T6109 oejs.Server.doStart jetty-8.1.10.v20130312
   [junit4]   2> 1762335 T6109 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:51146
   [junit4]   2> 1762336 T6109 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
   [junit4]   2> 1762337 T6109 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
   [junit4]   2> 1762337 T6109 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: ./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-controljetty-1389542783490
   [junit4]   2> 1762337 T6109 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: './org.apache.solr.cloud.CollectionsAPIDistributedZkTest-controljetty-1389542783490/'
   [junit4]   2> 1762364 T6109 oasc.ConfigSolr.fromFile Loading container configuration from /Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-controljetty-1389542783490/solr.xml
   [junit4]   2> 1762449 T6109 oasc.CoreContainer.<init> New CoreContainer 21936389
   [junit4]   2> 1762450 T6109 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-controljetty-1389542783490/]
   [junit4]   2> 1762451 T6109 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 120000
   [junit4]   2> 1762451 T6109 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
   [junit4]   2> 1762451 T6109 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
   [junit4]   2> 1762452 T6109 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
   [junit4]   2> 1762452 T6109 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
   [junit4]   2> 1762452 T6109 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
   [junit4]   2> 1762453 T6109 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
   [junit4]   2> 1762453 T6109 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
   [junit4]   2> 1762453 T6109 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
   [junit4]   2> 1762463 T6109 oasl.LogWatcher.createWatcher SLF4J impl is org.slf4j.impl.Log4jLoggerFactory
   [junit4]   2> 1762464 T6109 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
   [junit4]   2> 1762464 T6109 oasc.CoreContainer.load Host Name: 127.0.0.1
   [junit4]   2> 1762464 T6109 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:51141/solr
   [junit4]   2> 1762465 T6109 oasc.ZkController.checkChrootPath zkHost includes chroot
   [junit4]   2> 1762466 T6109 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 1762470 T6133 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@5754f7ee name:ZooKeeperConnection Watcher:127.0.0.1:51141 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 1762471 T6109 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 1762476 T6109 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 1762480 T6135 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@7afe976b name:ZooKeeperConnection Watcher:127.0.0.1:51141/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 1762480 T6109 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 1762484 T6109 oascc.SolrZkClient.makePath makePath: /overseer/queue
   [junit4]   2> 1762493 T6109 oascc.SolrZkClient.makePath makePath: /overseer/collection-queue-work
   [junit4]   2> 1762502 T6109 oascc.SolrZkClient.makePath makePath: /live_nodes
   [junit4]   2> 1762506 T6109 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:51146_
   [junit4]   2> 1762508 T6109 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:51146_
   [junit4]   2> 1762517 T6109 oascc.SolrZkClient.makePath makePath: /overseer_elect
   [junit4]   2> 1762524 T6109 oascc.SolrZkClient.makePath makePath: /overseer_elect/election
   [junit4]   2> 1762535 T6109 oascc.SolrZkClient.makePath makePath: /overseer_elect/leader
   [junit4]   2> 1762541 T6109 oasc.Overseer.start Overseer (id=91065075834224645-127.0.0.1:51146_-n_0000000000) starting
   [junit4]   2> 1762549 T6109 oascc.SolrZkClient.makePath makePath: /overseer/queue-work
   [junit4]   2> 1762559 T6137 oasc.OverseerCollectionProcessor.run Process current queue of collection creations
   [junit4]   2> 1762560 T6109 oascc.SolrZkClient.makePath makePath: /clusterstate.json
   [junit4]   2> 1762565 T6109 oascc.SolrZkClient.makePath makePath: /aliases.json
   [junit4]   2> 1762570 T6109 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
   [junit4]   2> 1762578 T6136 oasc.Overseer$ClusterStateUpdater.run Starting to work on the main queue
   [junit4]   2> 1762584 T6109 oass.SolrDispatchFilter.init user.dir=/Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0
   [junit4]   2> 1762584 T6109 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
   [junit4]   2> 1762586 T6109 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 1762589 T6140 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@51f96fcb name:ZooKeeperConnection Watcher:127.0.0.1:51141/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 1762590 T6109 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 1762592 T6109 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
   [junit4]   2> 1762598 T6109 oasc.ChaosMonkey.monkeyLog monkey: init - expire sessions:false cause connection loss:false
   [junit4]   2> 1762906 T6109 oejs.Server.doStart jetty-8.1.10.v20130312
   [junit4]   2> 1762910 T6109 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:51150
   [junit4]   2> 1762912 T6109 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
   [junit4]   2> 1762913 T6109 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
   [junit4]   2> 1762913 T6109 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: ../../../../../../../../../Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty1-1389542784077
   [junit4]   2> 1762913 T6109 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '../../../../../../../../../Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty1-1389542784077/'
   [junit4]   2> 1762947 T6109 oasc.ConfigSolr.fromFile Loading container configuration from /Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/../../../../../../../../../Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty1-1389542784077/solr.xml
   [junit4]   2> 1763020 T6109 oasc.CoreContainer.<init> New CoreContainer 1267657532
   [junit4]   2> 1763020 T6109 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=../../../../../../../../../Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty1-1389542784077/]
   [junit4]   2> 1763022 T6109 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 120000
   [junit4]   2> 1763023 T6109 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
   [junit4]   2> 1763024 T6109 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
   [junit4]   2> 1763024 T6109 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
   [junit4]   2> 1763024 T6109 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
   [junit4]   2> 1763024 T6109 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
   [junit4]   2> 1763025 T6109 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
   [junit4]   2> 1763025 T6109 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
   [junit4]   2> 1763025 T6109 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
   [junit4]   2> 1763035 T6109 oasl.LogWatcher.createWatcher SLF4J impl is org.slf4j.impl.Log4jLoggerFactory
   [junit4]   2> 1763035 T6109 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
   [junit4]   2> 1763035 T6109 oasc.CoreContainer.load Host Name: 127.0.0.1
   [junit4]   2> 1763036 T6109 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:51141/solr
   [junit4]   2> 1763036 T6109 oasc.ZkController.checkChrootPath zkHost includes chroot
   [junit4]   2> 1763037 T6109 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 1763042 T6151 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@13f5d6e5 name:ZooKeeperConnection Watcher:127.0.0.1:51141 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 1763043 T6109 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 1763049 T6109 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 1763053 T6153 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@52b96165 name:ZooKeeperConnection Watcher:127.0.0.1:51141/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 1763053 T6109 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 1763063 T6109 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
   [junit4]   2> 1764072 T6109 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:51150_
   [junit4]   2> 1764074 T6109 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:51150_
   [junit4]   2> 1764083 T6140 oascc.ZkStateReader$3.process Updating live nodes... (2)
   [junit4]   2> 1764084 T6135 oascc.ZkStateReader$3.process Updating live nodes... (2)
   [junit4]   2> 1764084 T6153 oascc.ZkStateReader$3.process Updating live nodes... (2)
   [junit4]   2> 1764097 T6109 oass.SolrDispatchFilter.init user.dir=/Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0
   [junit4]   2> 1764097 T6109 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
   [junit4]   2> 1764417 T6109 oejs.Server.doStart jetty-8.1.10.v20130312
   [junit4]   2> 1764424 T6109 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:51153
   [junit4]   2> 1764427 T6109 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
   [junit4]   2> 1764428 T6109 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
   [junit4]   2> 1764428 T6109 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: ../../../../../../../../../Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty2-1389542785576
   [junit4]   2> 1764429 T6109 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '../../../../../../../../../Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty2-1389542785576/'
   [junit4]   2> 1764461 T6109 oasc.ConfigSolr.fromFile Loading container configuration from /Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/../../../../../../../../../Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty2-1389542785576/solr.xml
   [junit4]   2> 1764567 T6109 oasc.CoreContainer.<init> New CoreContainer 438515754
   [junit4]   2> 1764568 T6109 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=../../../../../../../../../Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty2-1389542785576/]
   [junit4]   2> 1764570 T6109 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 120000
   [junit4]   2> 1764571 T6109 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
   [junit4]   2> 1764571 T6109 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
   [junit4]   2> 1764572 T6109 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
   [junit4]   2> 1764572 T6109 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
   [junit4]   2> 1764573 T6109 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
   [junit4]   2> 1764573 T6109 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
   [junit4]   2> 1764574 T6109 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
   [junit4]   2> 1764574 T6109 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
   [junit4]   2> 1764586 T6109 oasl.LogWatcher.createWatcher SLF4J impl is org.slf4j.impl.Log4jLoggerFactory
   [junit4]   2> 1764587 T6109 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
   [junit4]   2> 1764587 T6109 oasc.CoreContainer.load Host Name: 127.0.0.1
   [junit4]   2> 1764587 T6109 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:51141/solr
   [junit4]   2> 1764588 T6109 oasc.ZkController.checkChrootPath zkHost includes chroot
   [junit4]   2> 1764589 T6109 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 1764594 T6165 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@7e3c5acd name:ZooKeeperConnection Watcher:127.0.0.1:51141 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 1764595 T6109 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 1764601 T6109 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 1764605 T6167 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@2cec8da name:ZooKeeperConnection Watcher:127.0.0.1:51141/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 1764606 T6109 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 1764617 T6109 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
   [junit4]   2> 1765629 T6109 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:51153_
   [junit4]   2> 1765632 T6109 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:51153_
   [junit4]   2> 1765639 T6167 oascc.ZkStateReader$3.process Updating live nodes... (3)
   [junit4]   2> 1765644 T6140 oascc.ZkStateReader$3.process Updating live nodes... (3)
   [junit4]   2> 1765645 T6153 oascc.ZkStateReader$3.process Updating live nodes... (3)
   [junit4]   2> 1765645 T6135 oascc.ZkStateReader$3.process Updating live nodes... (3)
   [junit4]   2> 1765659 T6109 oass.SolrDispatchFilter.init user.dir=/Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0
   [junit4]   2> 1765659 T6109 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
   [junit4]   2> 1765987 T6109 oejs.Server.doStart jetty-8.1.10.v20130312
   [junit4]   2> 1765991 T6109 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:51156
   [junit4]   2> 1765992 T6109 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
   [junit4]   2> 1765993 T6109 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
   [junit4]   2> 1765993 T6109 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: ../../../../../../../../../Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty3-1389542787138
   [junit4]   2> 1765993 T6109 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '../../../../../../../../../Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty3-1389542787138/'
   [junit4]   2> 1766020 T6109 oasc.ConfigSolr.fromFile Loading container configuration from /Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/../../../../../../../../../Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty3-1389542787138/solr.xml
   [junit4]   2> 1766088 T6109 oasc.CoreContainer.<init> New CoreContainer 710321103
   [junit4]   2> 1766089 T6109 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=../../../../../../../../../Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty3-1389542787138/]
   [junit4]   2> 1766091 T6109 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 120000
   [junit4]   2> 1766092 T6109 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
   [junit4]   2> 1766092 T6109 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
   [junit4]   2> 1766093 T6109 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
   [junit4]   2> 1766093 T6109 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
   [junit4]   2> 1766093 T6109 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
   [junit4]   2> 1766094 T6109 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
   [junit4]   2> 1766094 T6109 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
   [junit4]   2> 1766095 T6109 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
   [junit4]   2> 1766108 T6109 oasl.LogWatcher.createWatcher SLF4J impl is org.slf4j.impl.Log4jLoggerFactory
   [junit4]   2> 1766108 T6109 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
   [junit4]   2> 1766109 T6109 oasc.CoreContainer.load Host Name: 127.0.0.1
   [junit4]   2> 1766109 T6109 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:51141/solr
   [junit4]   2> 1766110 T6109 oasc.ZkController.checkChrootPath zkHost includes chroot
   [junit4]   2> 1766112 T6109 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 1766115 T6179 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@1e1c80c0 name:ZooKeeperConnection Watcher:127.0.0.1:51141 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 1766116 T6109 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 1766121 T6109 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 1766124 T6181 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@67cd4dfb name:ZooKeeperConnection Watcher:127.0.0.1:51141/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 1766125 T6109 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 1766135 T6109 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
   [junit4]   2> 1767145 T6109 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:51156_
   [junit4]   2> 1767148 T6109 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:51156_
   [junit4]   2> 1767157 T6181 oascc.ZkStateReader$3.process Updating live nodes... (4)
   [junit4]   2> 1767157 T6153 oascc.ZkStateReader$3.process Updating live nodes... (4)
   [junit4]   2> 1767157 T6167 oascc.ZkStateReader$3.process Updating live nodes... (4)
   [junit4]   2> 1767157 T6140 oascc.ZkStateReader$3.process Updating live nodes... (4)
   [junit4]   2> 1767158 T6135 oascc.ZkStateReader$3.process Updating live nodes... (4)
   [junit4]   2> 1767171 T6109 oass.SolrDispatchFilter.init user.dir=/Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0
   [junit4]   2> 1767171 T6109 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
   [junit4]   2> 1767548 T6109 oejs.Server.doStart jetty-8.1.10.v20130312
   [junit4]   2> 1767553 T6109 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:51159
   [junit4]   2> 1767556 T6109 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
   [junit4]   2> 1767556 T6109 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
   [junit4]   2> 1767557 T6109 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: ./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1389542788650
   [junit4]   2> 1767557 T6109 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: './org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1389542788650/'
   [junit4]   2> 1767587 T6109 oasc.ConfigSolr.fromFile Loading container configuration from /Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1389542788650/solr.xml
   [junit4]   2> 1767671 T6109 oasc.CoreContainer.<init> New CoreContainer 1323212043
   [junit4]   2> 1767671 T6109 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1389542788650/]
   [junit4]   2> 1767673 T6109 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 120000
   [junit4]   2> 1767673 T6109 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
   [junit4]   2> 1767673 T6109 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
   [junit4]   2> 1767674 T6109 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
   [junit4]   2> 1767674 T6109 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
   [junit4]   2> 1767674 T6109 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
   [junit4]   2> 1767674 T6109 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
   [junit4]   2> 1767674 T6109 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
   [junit4]   2> 1767675 T6109 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
   [junit4]   2> 1767684 T6109 oasl.LogWatcher.createWatcher SLF4J impl is org.slf4j.impl.Log4jLoggerFactory
   [junit4]   2> 1767685 T6109 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
   [junit4]   2> 1767686 T6109 oasc.CoreContainer.load Host Name: 127.0.0.1
   [junit4]   2> 1767686 T6109 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:51141/solr
   [junit4]   2> 1767686 T6109 oasc.ZkController.checkChrootPath zkHost includes chroot
   [junit4]   2> 1767688 T6109 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 1767692 T6193 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@791865a0 name:ZooKeeperConnection Watcher:127.0.0.1:51141 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 1767694 T6109 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 1767700 T6109 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 1767704 T6195 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@352d6e2f name:ZooKeeperConnection Watcher:127.0.0.1:51141/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 1767705 T6109 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 1767716 T6109 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
   [junit4]   2> 1768725 T6109 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:51159_
   [junit4]   2> 1768728 T6109 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:51159_
   [junit4]   2> 1768735 T6195 oascc.ZkStateReader$3.process Updating live nodes... (5)
   [junit4]   2> 1768736 T6135 oascc.ZkStateReader$3.process Updating live nodes... (5)
   [junit4]   2> 1768736 T6153 oascc.ZkStateReader$3.process Updating live nodes... (5)
   [junit4]   2> 1768736 T6140 oascc.ZkStateReader$3.process Updating live nodes... (5)
   [junit4]   2> 1768737 T6181 oascc.ZkStateReader$3.process Updating live nodes... (5)
   [junit4]   2> 1768737 T6167 oascc.ZkStateReader$3.process Updating live nodes... (5)
   [junit4]   2> 1768750 T6109 oass.SolrDispatchFilter.init user.dir=/Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0
   [junit4]   2> 1768751 T6109 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
   [junit4]   2> 1768760 T6145 oasha.CollectionsHandler.handleCreateAction Creating Collection : numShards=2&router.field=myOwnField&router.name=compositeId&action=CREATE&replicationFactor=2&version=2&name=solrj_collection&collection.configName=conf1&wt=javabin
   [junit4]   2> 1768762 T6135 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/collection-queue-work state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 1768765 T6137 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> 1768765 T6137 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> 1768766 T6137 oasc.OverseerCollectionProcessor.createConfNode creating collections conf node /collections/solrj_collection 
   [junit4]   2> 1768766 T6137 oascc.SolrZkClient.makePath makePath: /collections/solrj_collection
   [junit4]   2> 1768776 T6135 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 1768781 T6136 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 1768782 T6136 oasc.Overseer$ClusterStateUpdater.buildCollection building a new collection: solrj_collection
   [junit4]   2> 1768783 T6136 oasc.Overseer$ClusterStateUpdater.createCollection Create collection solrj_collection with shards [shard1, shard2]
   [junit4]   2> 1768789 T6135 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 1768791 T6167 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> 1768791 T6135 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> 1768791 T6140 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> 1768791 T6153 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> 1768792 T6195 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> 1768792 T6181 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> 1768878 T6137 oasc.OverseerCollectionProcessor.createCollection going to create cores replicas shardNames [shard1, shard2] , repFactor : 2
   [junit4]   2> 1768878 T6137 oasc.OverseerCollectionProcessor.createCollection Creating shard solrj_collection_shard1_replica1 as part of slice shard1 of collection solrj_collection on 127.0.0.1:51146_
   [junit4]   2> 1768879 T6137 oasc.OverseerCollectionProcessor.createCollection Creating shard solrj_collection_shard1_replica2 as part of slice shard1 of collection solrj_collection on 127.0.0.1:51159_
   [junit4]   2> 1768879 T6137 oasc.OverseerCollectionProcessor.createCollection Creating shard solrj_collection_shard2_replica1 as part of slice shard2 of collection solrj_collection on 127.0.0.1:51153_
   [junit4]   2> 1768881 T6137 oasc.OverseerCollectionProcessor.createCollection Creating shard solrj_collection_shard2_replica2 as part of slice shard2 of collection solrj_collection on 127.0.0.1:51150_
   [junit4]   2> 1768887 T6130 oasc.ZkController.publish publishing core=solrj_collection_shard1_replica1 state=down
   [junit4]   2> 1768888 T6146 oasc.ZkController.publish publishing core=solrj_collection_shard2_replica2 state=down
   [junit4]   2> 1768889 T6189 oasc.ZkController.publish publishing core=solrj_collection_shard1_replica2 state=down
   [junit4]   2> 1768890 T6163 oasc.ZkController.publish publishing core=solrj_collection_shard2_replica1 state=down
   [junit4]   2> 1768892 T6135 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 1768892 T6130 oasc.ZkController.waitForCoreNodeName look for our core node name
   [junit4]   2> 1768892 T6189 oasc.ZkController.waitForCoreNodeName look for our core node name
   [junit4]   2> 1768893 T6146 oasc.ZkController.waitForCoreNodeName look for our core node name
   [junit4]   2> 1768893 T6163 oasc.ZkController.waitForCoreNodeName look for our core node name
   [junit4]   2> 1768896 T6136 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 1768897 T6136 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:51159",
   [junit4]   2> 	  "core":"solrj_collection_shard1_replica2",
   [junit4]   2> 	  "roles":null,
   [junit4]   2> 	  "node_name":"127.0.0.1:51159_",
   [junit4]   2> 	  "shard":"shard1",
   [junit4]   2> 	  "shard_range":null,
   [junit4]   2> 	  "shard_state":"active",
   [junit4]   2> 	  "shard_parent":null,
   [junit4]   2> 	  "collection":"solrj_collection",
   [junit4]   2> 	  "numShards":"2",
   [junit4]   2> 	  "core_node_name":null}
   [junit4]   2> 1768903 T6135 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 1768905 T6136 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:51146",
   [junit4]   2> 	  "core":"solrj_collection_shard1_replica1",
   [junit4]   2> 	  "roles":null,
   [junit4]   2> 	  "node_name":"127.0.0.1:51146_",
   [junit4]   2> 	  "shard":"shard1",
   [junit4]   2> 	  "shard_range":null,
   [junit4]   2> 	  "shard_state":"active",
   [junit4]   2> 	  "shard_parent":null,
   [junit4]   2> 	  "collection":"solrj_collection",
   [junit4]   2> 	  "numShards":"2",
   [junit4]   2> 	  "core_node_name":null}
   [junit4]   2> 1768912 T6135 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 1768915 T6136 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:51150",
   [junit4]   2> 	  "core":"solrj_collection_shard2_replica2",
   [junit4]   2> 	  "roles":null,
   [junit4]   2> 	  "node_name":"127.0.0.1:51150_",
   [junit4]   2> 	  "shard":"shard2",
   [junit4]   2> 	  "shard_range":null,
   [junit4]   2> 	  "shard_state":"active",
   [junit4]   2> 	  "shard_parent":null,
   [junit4]   2> 	  "collection":"solrj_collection",
   [junit4]   2> 	  "numShards":"2",
   [junit4]   2> 	  "core_node_name":null}
   [junit4]   2> 1768920 T6135 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 1768923 T6136 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:51153",
   [junit4]   2> 	  "core":"solrj_collection_shard2_replica1",
   [junit4]   2> 	  "roles":null,
   [junit4]   2> 	  "node_name":"127.0.0.1:51153_",
   [junit4]   2> 	  "shard":"shard2",
   [junit4]   2> 	  "shard_range":null,
   [junit4]   2> 	  "shard_state":"active",
   [junit4]   2> 	  "shard_parent":null,
   [junit4]   2> 	  "collection":"solrj_collection",
   [junit4]   2> 	  "numShards":"2",
   [junit4]   2> 	  "core_node_name":null}
   [junit4]   2> 1768930 T6135 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 1769035 T6181 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> 1769036 T6135 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> 1769036 T6153 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> 1769036 T6167 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> 1769037 T6140 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> 1769037 T6195 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> 1769894 T6130 oasc.ZkController.waitForShardId waiting to find shard id in clusterstate for solrj_collection_shard1_replica1
   [junit4]   2> 1769894 T6146 oasc.ZkController.waitForShardId waiting to find shard id in clusterstate for solrj_collection_shard2_replica2
   [junit4]   2> 1769895 T6130 oasc.SolrXMLCoresLocator.doPersist Persisted core descriptions to /Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-controljetty-1389542783490/solr.xml
   [junit4]   2> 1769895 T6130 oasc.CoreContainer.create Creating SolrCore 'solrj_collection_shard1_replica1' using instanceDir: ./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-controljetty-1389542783490/solrj_collection_shard1_replica1
   [junit4]   2> 1769896 T6130 oasc.ZkController.createCollectionZkNode Check for collection zkNode:solrj_collection
   [junit4]   2> 1769894 T6189 oasc.ZkController.waitForShardId waiting to find shard id in clusterstate for solrj_collection_shard1_replica2
   [junit4]   2> 1769896 T6163 oasc.ZkController.waitForShardId waiting to find shard id in clusterstate for solrj_collection_shard2_replica1
   [junit4]   2> 1769897 T6189 oasc.SolrXMLCoresLocator.doPersist Persisted core descriptions to /Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1389542788650/solr.xml
   [junit4]   2> 1769898 T6189 oasc.CoreContainer.create Creating SolrCore 'solrj_collection_shard1_replica2' using instanceDir: ./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1389542788650/solrj_collection_shard1_replica2
   [junit4]   2> 1769898 T6189 oasc.ZkController.createCollectionZkNode Check for collection zkNode:solrj_collection
   [junit4]   2> 1769896 T6146 oasc.SolrXMLCoresLocator.doPersist Persisted core descriptions to /Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/../../../../../../../../../Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty1-1389542784077/solr.xml
   [junit4]   2> 1769898 T6146 oasc.CoreContainer.create Creating SolrCore 'solrj_collection_shard2_replica2' using instanceDir: ../../../../../../../../../Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty1-1389542784077/solrj_collection_shard2_replica2
   [junit4]   2> 1769899 T6146 oasc.ZkController.createCollectionZkNode Check for collection zkNode:solrj_collection
   [junit4]   2> 1769899 T6189 oasc.ZkController.createCollectionZkNode Collection zkNode exists
   [junit4]   2> 1769899 T6189 oascc.ZkStateReader.readConfigName Load collection config from:/collections/solrj_collection
   [junit4]   2> 1769898 T6130 oasc.ZkController.createCollectionZkNode Collection zkNode exists
   [junit4]   2> 1769900 T6130 oascc.ZkStateReader.readConfigName Load collection config from:/collections/solrj_collection
   [junit4]   2> 1769900 T6146 oasc.ZkController.createCollectionZkNode Collection zkNode exists
   [junit4]   2> 1769901 T6146 oascc.ZkStateReader.readConfigName Load collection config from:/collections/solrj_collection
   [junit4]   2> 1769898 T6163 oasc.SolrXMLCoresLocator.doPersist Persisted core descriptions to /Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/../../../../../../../../../Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty2-1389542785576/solr.xml
   [junit4]   2> 1769901 T6163 oasc.CoreContainer.create Creating SolrCore 'solrj_collection_shard2_replica1' using instanceDir: ../../../../../../../../../Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty2-1389542785576/solrj_collection_shard2_replica1
   [junit4]   2> 1769902 T6163 oasc.ZkController.createCollectionZkNode Check for collection zkNode:solrj_collection
   [junit4]   2> 1769902 T6189 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: './org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1389542788650/solrj_collection_shard1_replica2/'
   [junit4]   2> 1769904 T6146 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '../../../../../../../../../Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty1-1389542784077/solrj_collection_shard2_replica2/'
   [junit4]   2> 1769908 T6163 oasc.ZkController.createCollectionZkNode Collection zkNode exists
   [junit4]   2> 1769909 T6163 oascc.ZkStateReader.readConfigName Load collection config from:/collections/solrj_collection
   [junit4]   2> 1769916 T6130 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: './org.apache.solr.cloud.CollectionsAPIDistributedZkTest-controljetty-1389542783490/solrj_collection_shard1_replica1/'
   [junit4]   2> 1769919 T6163 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '../../../../../../../../../Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty2-1389542785576/solrj_collection_shard2_replica1/'
   [junit4]   2> 1770040 T6146 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_50
   [junit4]   2> 1770043 T6130 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_50
   [junit4]   2> 1770059 T6163 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_50
   [junit4]   2> 1770085 T6189 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_50
   [junit4]   2> 1770185 T6130 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
   [junit4]   2> 1770189 T6130 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
   [junit4]   2> 1770192 T6146 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
   [junit4]   2> 1770195 T6146 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
   [junit4]   2> 1770206 T6146 oass.IndexSchema.readSchema [solrj_collection_shard2_replica2] Schema name=test
   [junit4]   2> 1770208 T6130 oass.IndexSchema.readSchema [solrj_collection_shard1_replica1] Schema name=test
   [junit4]   2> 1770212 T6189 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
   [junit4]   2> 1770220 T6163 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
   [junit4]   2> 1770222 T6189 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
   [junit4]   2> 1770233 T6189 oass.IndexSchema.readSchema [solrj_collection_shard1_replica2] Schema name=test
   [junit4]   2> 1770245 T6163 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
   [junit4]   2> 1770254 T6163 oass.IndexSchema.readSchema [solrj_collection_shard2_replica1] Schema name=test
   [junit4]   2> 1771564 T6146 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
   [junit4]   2> 1771584 T6146 oass.IndexSchema.readSchema default search field in schema is text
   [junit4]   2> 1771595 T6146 oass.IndexSchema.readSchema unique key field: id
   [junit4]   2> 1771660 T6189 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
   [junit4]   2> 1771669 T6163 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
   [junit4]   2> 1771671 T6189 oass.IndexSchema.readSchema default search field in schema is text
   [junit4]   2> 1771682 T6163 oass.IndexSchema.readSchema default search field in schema is text
   [junit4]   2> 1771687 T6189 oass.IndexSchema.readSchema unique key field: id
   [junit4]   2> 1771690 T6163 oass.IndexSchema.readSchema unique key field: id
   [junit4]   2> 1771712 T6146 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
   [junit4]   2> 1771726 T6146 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
   [junit4]   2> 1771739 T6146 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
   [junit4]   2> 1771744 T6146 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
   [junit4]   2> 1771752 T6146 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
   [junit4]   2> 1771753 T6146 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
   [junit4]   2> 1771746 T6130 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
   [junit4]   2> 1771757 T6146 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
   [junit4]   2> 1771758 T6146 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
   [junit4]   2> 1771758 T6146 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
   [junit4]   2> 1771758 T6146 oasc.SolrCore.<init> [solrj_collection_shard2_replica2] Opening new SolrCore at ../../../../../../../../../Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty1-1389542784077/solrj_collection_shard2_replica2/, dataDir=../../../../../../../../../Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty1-1389542784077/solrj_collection_shard2_replica2/data/
   [junit4]   2> 1771759 T6146 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@2134a226
   [junit4]   2> 1771760 T6146 oasc.CachingDirectoryFactory.get return new directory for ../../../../../../../../../Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty1-1389542784077/solrj_collection_shard2_replica2/data
   [junit4]   2> 1771760 T6146 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=../../../../../../../../../Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty1-1389542784077/solrj_collection_shard2_replica2/data/index/
   [junit4]   2> 1771760 T6146 oasc.SolrCore.initIndex WARN [solrj_collection_shard2_replica2] Solr index directory '../../../../../../../../../Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty1-1389542784077/solrj_collection_shard2_replica2/data/index' doesn't exist. Creating new index...
   [junit4]   2> 1771761 T6146 oasc.CachingDirectoryFactory.get return new directory for ../../../../../../../../../Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty1-1389542784077/solrj_collection_shard2_replica2/data/index
   [junit4]   2> 1771761 T6146 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.LogDocMergePolicy: [LogDocMergePolicy: minMergeSize=1000, mergeFactor=46, maxMergeSize=9223372036854775807, maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=true, maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=1.0]
   [junit4]   2> 1771762 T6146 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
   [junit4]   2> 		commit{dir=MockDirectoryWrapper(org.apache.lucene.store.RAMDirectory@1cede282 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@1a9e453e),segFN=segments_1,generation=1}
   [junit4]   2> 1771762 T6146 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
   [junit4]   2> 1771763 T6130 oass.IndexSchema.readSchema default search field in schema is text
   [junit4]   2> 1771772 T6146 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "nodistrib"
   [junit4]   2> 1771773 T6146 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "dedupe"
   [junit4]   2> 1771773 T6146 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
   [junit4]   2> 1771773 T6146 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "stored_sig"
   [junit4]   2> 1771774 T6146 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
   [junit4]   2> 1771774 T6146 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-explicit"
   [junit4]   2> 1771775 T6146 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-implicit"
   [junit4]   2> 1771775 T6146 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
   [junit4]   2> 1771775 T6146 oasc.SolrCore.loadUpdateProcessorChains no updateRequestProcessorChain defined as default, creating implicit default
   [junit4]   2> 1771777 T6146 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
   [junit4]   2> 1771778 T6163 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
   [junit4]   2> 1771779 T6146 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
   [junit4]   2> 1771780 T6146 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
   [junit4]   2> 1771780 T6189 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
   [junit4]   2> 1771779 T6130 oass.IndexSchema.readSchema unique key field: id
   [junit4]   2> 1771781 T6146 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
   [junit4]   2> 1771785 T6163 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
   [junit4]   2> 1771786 T6146 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
   [junit4]   2> 1771786 T6146 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
   [junit4]   2> 1771788 T6146 oasc.RequestHandlers.initHandlersFromConfig created /admin/file: solr.admin.ShowFileRequestHandler
   [junit4]   2> 1771788 T6146 oasc.RequestHandlers.initHandlersFromConfig created /admin/fileedit: solr.admin.EditFileRequestHandler
   [junit4]   2> 1771791 T6189 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
   [junit4]   2> 1771797 T6163 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
   [junit4]   2> 1771798 T6189 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
   [junit4]   2> 1771803 T6163 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
   [junit4]   2> 1771805 T6163 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
   [junit4]   2> 1771805 T6163 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
   [junit4]   2> 1771804 T6189 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
   [junit4]   2> 1771806 T6189 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
   [junit4]   2> 1771806 T6189 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
   [junit4]   2> 1771809 T6163 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
   [junit4]   2> 1771810 T6163 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
   [junit4]   2> 1771810 T6163 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
   [junit4]   2> 1771810 T6189 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
   [junit4]   2> 1771811 T6189 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
   [junit4]   2> 1771812 T6189 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
   [junit4]   2> 1771812 T6189 oasc.SolrCore.<init> [solrj_collection_shard1_replica2] Opening new SolrCore at ./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1389542788650/solrj_collection_shard1_replica2/, dataDir=./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1389542788650/solrj_collection_shard1_replica2/data/
   [junit4]   2> 1771813 T6189 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@2134a226
   [junit4]   2> 1771810 T6146 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
   [junit4]   2> 1771813 T6189 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1389542788650/solrj_collection_shard1_replica2/data
   [junit4]   2> 1771811 T6163 oasc.SolrCore.<init> [solrj_collection_shard2_replica1] Opening new SolrCore at ../../../../../../../../../Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty2-1389542785576/solrj_collection_shard2_replica1/, dataDir=../../../../../../../../../Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty2-1389542785576/solrj_collection_shard2_replica1/data/
   [junit4]   2> 1771814 T6163 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@2134a226
   [junit4]   2> 1771815 T6189 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1389542788650/solrj_collection_shard1_replica2/data/index/
   [junit4]   2> 1771815 T6189 oasc.SolrCore.initIndex WARN [solrj_collection_shard1_replica2] Solr index directory './org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1389542788650/solrj_collection_shard1_replica2/data/index' doesn't exist. Creating new index...
   [junit4]   2> 1771816 T6189 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1389542788650/solrj_collection_shard1_replica2/data/index
   [junit4]   2> 1771817 T6163 oasc.CachingDirectoryFactory.get return new directory for ../../../../../../../../../Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty2-1389542785576/solrj_collection_shard2_replica1/data
   [junit4]   2> 1771817 T6189 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.LogDocMergePolicy: [LogDocMergePolicy: minMergeSize=1000, mergeFactor=46, maxMergeSize=9223372036854775807, maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=true, maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=1.0]
   [junit4]   2> 1771818 T6163 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=../../../../../../../../../Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty2-1389542785576/solrj_collection_shard2_replica1/data/index/
   [junit4]   2> 1771818 T6163 oasc.SolrCore.initIndex WARN [solrj_collection_shard2_replica1] Solr index directory '../../../../../../../../../Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty2-1389542785576/solrj_collection_shard2_replica1/data/index' doesn't exist. Creating new index...
   [junit4]   2> 1771820 T6163 oasc.CachingDirectoryFactory.get return new directory for ../../../../../../../../../Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty2-1389542785576/solrj_collection_shard2_replica1/data/index
   [junit4]   2> 1771820 T6146 oasu.CommitTracker.<init> Hard AutoCommit: disabled
   [junit4]   2> 1771821 T6146 oasu.CommitTracker.<init> Soft AutoCommit: disabled
   [junit4]   2> 1771822 T6146 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.LogByteSizeMergePolicy: [LogByteSizeMergePolicy: minMergeSize=1677721, mergeFactor=18, maxMergeSize=2147483648, maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=false, maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.0]
   [junit4]   2> 1771820 T6163 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.LogDocMergePolicy: [LogDocMergePolicy: minMergeSize=1000, mergeFactor=46, maxMergeSize=9223372036854775807, maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=true, maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=1.0]
   [junit4]   2> 1771823 T6146 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=1
   [junit4]   2> 		commit{dir=MockDirectoryWrapper(org.apache.lucene.store.RAMDirectory@1cede282 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@1a9e453e),segFN=segments_1,generation=1}
   [junit4]   2> 1771823 T6146 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
   [junit4]   2> 1771821 T6189 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
   [junit4]   2> 		commit{dir=MockDirectoryWrapper(org.apache.lucene.store.RAMDirectory@2c95ebe3 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@59f504e6),segFN=segments_1,generation=1}
   [junit4]   2> 1771824 T6163 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
   [junit4]   2> 		commit{dir=MockDirectoryWrapper(org.apache.lucene.store.RAMDirectory@7a4dd8f9 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@411688df),segFN=segments_1,generation=1}
   [junit4]   2> 1771824 T6163 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
   [junit4]   2> 1771824 T6146 oass.SolrIndexSearcher.<init> Opening Searcher@2dea9023 main
   [junit4]   2> 1771824 T6189 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
   [junit4]   2> 1771828 T6201 oasc.SolrCore.registerSearcher [solrj_collection_shard2_replica2] Registered new searcher Searcher@2dea9023 main{StandardDirectoryReader(segments_1:1:nrt)}
   [junit4]   2> 1771830 T6146 oasc.CoreContainer.registerCore registering core: solrj_collection_shard2_replica2
   [junit4]   2> 1771831 T6163 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "nodistrib"
   [junit4]   2> 1771831 T6146 oasc.ZkController.register Register replica - core:solrj_collection_shard2_replica2 address:http://127.0.0.1:51150 collection:solrj_collection shard:shard2
   [junit4]   2> 1771832 T6163 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "dedupe"
   [junit4]   2> 1771833 T6163 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
   [junit4]   2> 1771833 T6163 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "stored_sig"
   [junit4]   2> 1771834 T6163 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
   [junit4]   2> 1771834 T6163 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-explicit"
   [junit4]   2> 1771835 T6163 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-implicit"
   [junit4]   2> 1771835 T6163 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
   [junit4]   2> 1771835 T6163 oasc.SolrCore.loadUpdateProcessorChains no updateRequestProcessorChain defined as default, creating implicit default
   [junit4]   2> 1771836 T6163 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
   [junit4]   2> 1771836 T6189 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "nodistrib"
   [junit4]   2> 1771837 T6189 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "dedupe"
   [junit4]   2> 1771837 T6163 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
   [junit4]   2> 1771838 T6163 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
   [junit4]   2> 1771838 T6163 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
   [junit4]   2> 1771839 T6146 oascc.SolrZkClient.makePath makePath: /collections/solrj_collection/leader_elect/shard2/election
   [junit4]   2> 1771837 T6189 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
   [junit4]   2> 1771840 T6189 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "stored_sig"
   [junit4]   2> 1771841 T6189 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
   [junit4]   2> 1771842 T6189 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-explicit"
   [junit4]   2> 1771839 T6163 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
   [junit4]   2> 1771844 T6189 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-implicit"
   [junit4]   2> 1771844 T6189 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
   [junit4]   2> 1771845 T6189 oasc.SolrCore.loadUpdateProcessorChains no updateRequestProcessorChain defined as default, creating implicit default
   [junit4]   2> 1771846 T6189 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
   [junit4]   2> 1771846 T6189 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
   [junit4]   2> 1771847 T6189 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
   [junit4]   2> 1771844 T6130 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
   [junit4]   2> 1771848 T6189 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
   [junit4]   2> 1771845 T6163 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
   [junit4]   2> 1771849 T6189 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
   [junit4]   2> 1771849 T6163 oasc.RequestHandlers.initHandlersFromConfig created /admin/file: solr.admin.ShowFileRequestHandler
   [junit4]   2> 1771850 T6163 oasc.RequestHandlers.initHandlersFromConfig created /admin/fileedit: solr.admin.EditFileRequestHandler
   [junit4]   2> 1771849 T6189 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
   [junit4]   2> 1771852 T6189 oasc.RequestHandlers.initHandlersFromConfig created /admin/file: solr.admin.ShowFileRequestHandler
   [junit4]   2> 1771853 T6163 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
   [junit4]   2> 1771853 T6189 oasc.RequestHandlers.initHandlersFromConfig created /admin/fileedit: solr.admin.EditFileRequestHandler
   [junit4]   2> 1771868 T6189 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
   [junit4]   2> 1771871 T6130 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
   [junit4]   2> 1771876 T6189 oasu.CommitTracker.<init> Hard AutoCommit: disabled
   [junit4]   2> 1771876 T6189 oasu.CommitTracker.<init> Soft AutoCommit: disabled
   [junit4]   2> 1771877 T6163 oasu.CommitTracker.<init> Hard AutoCommit: disabled
   [junit4]   2> 1771878 T6163 oasu.CommitTracker.<init> Soft AutoCommit: disabled
   [junit4]   2> 1771878 T6189 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.LogByteSizeMergePolicy: [LogByteSizeMergePolicy: minMergeSize=1677721, mergeFactor=18, maxMergeSize=2147483648, maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=false, maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.0]
   [junit4]   2> 1771881 T6189 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=1
   [junit4]   2> 		commit{dir=MockDirectoryWrapper(org.apache.lucene.store.RAMDirectory@2c95ebe3 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@59f504e6),segFN=segments_1,generation=1}
   [junit4]   2> 1771881 T6189 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
   [junit4]   2> 1771882 T6189 oass.SolrIndexSearcher.<init> Opening Searcher@396bdae8 main
   [junit4]   2> 1771883 T6130 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
   [junit4]   2> 1771880 T6163 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.LogByteSizeMergePolicy: [LogByteSizeMergePolicy: minMergeSize=1677721, mergeFactor=18, maxMergeSize=2147483648, maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=false, maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.0]
   [junit4]   2> 1771887 T6203 oasc.SolrCore.registerSearcher [solrj_collection_shard1_replica2] Registered new searcher Searcher@396bdae8 main{StandardDirectoryReader(segments_1:1:nrt)}
   [junit4]   2> 1771887 T6163 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=1
   [junit4]   2> 		commit{dir=MockDirectoryWrapper(org.apache.lucene.store.RAMDirectory@7a4dd8f9 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@411688df),segFN=segments_1,generation=1}
   [junit4]   2> 1771887 T6163 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
   [junit4]   2> 1771888 T6163 oass.SolrIndexSearcher.<init> Opening Searcher@425f18d7 main
   [junit4]   2> 1771891 T6130 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
   [junit4]   2> 1771891 T6130 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
   [junit4]   2> 1771892 T6130 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
   [junit4]   2> 1771893 T6189 oasc.CoreContainer.registerCore registering core: solrj_collection_shard1_replica2
   [junit4]   2> 1771893 T6189 oasc.ZkController.register Register replica - core:solrj_collection_shard1_replica2 address:http://127.0.0.1:51159 collection:solrj_collection shard:shard1
   [junit4]   2> 1771895 T6146 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process for shard shard2
   [junit4]   2> 1771898 T6130 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
   [junit4]   2> 1771900 T6130 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
   [junit4]   2> 1771901 T6130 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
   [junit4]   2> 1771902 T6130 oasc.SolrCore.<init> [solrj_collection_shard1_replica1] Opening new SolrCore at ./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-controljetty-1389542783490/solrj_collection_shard1_replica1/, dataDir=./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-controljetty-1389542783490/solrj_collection_shard1_replica1/data/
   [junit4]   2> 1771903 T6130 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@2134a226
   [junit4]   2> 1771900 T6204 oasc.SolrCore.registerSearcher [solrj_collection_shard2_replica1] Registered new searcher Searcher@425f18d7 main{StandardDirectoryReader(segments_1:1:nrt)}
   [junit4]   2> 1771908 T6189 oascc.SolrZkClient.makePath makePath: /collections/solrj_collection/leader_elect/shard1/election
   [junit4]   2> 1771903 T6163 oasc.CoreContainer.registerCore registering core: solrj_collection_shard2_replica1
   [junit4]   2> 1771909 T6163 oasc.ZkController.register Register replica - core:solrj_collection_shard2_replica1 address:http://127.0.0.1:51153 collection:solrj_collection shard:shard2
   [junit4]   2> 1771910 T6130 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-controljetty-1389542783490/solrj_collection_shard1_replica1/data
   [junit4]   2> 1771913 T6135 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 1771913 T6135 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 1771913 T6135 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 1771915 T6130 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-controljetty-1389542783490/solrj_collection_shard1_replica1/data/index/
   [junit4]   2> 1771915 T6130 oasc.SolrCore.initIndex WARN [solrj_collection_shard1_replica1] Solr index directory './org.apache.solr.cloud.CollectionsAPIDistributedZkTest-controljetty-1389542783490/solrj_collection_shard1_replica1/data/index' doesn't exist. Creating new index...
   [junit4]   2> 1771917 T6130 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-controljetty-1389542783490/solrj_collection_shard1_replica1/data/index
   [junit4]   2> 1771917 T6146 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up for shard shard2: total=2 found=1 timeoutin=-2
   [junit4]   2> 1771918 T6146 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Was waiting for replicas to come up, but they are taking too long - assuming they won't come back till later
   [junit4]   2> 1771918 T6146 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new leader - try and sync
   [junit4]   2> ASYNC  NEW_CORE C4907 name=solrj_collection_shard2_replica2 org.apache.solr.core.SolrCore@53032773 url=http://127.0.0.1:51150/solrj_collection_shard2_replica2 node=127.0.0.1:51150_ C4907_STATE=coll:solrj_collection core:solrj_collection_shard2_replica2 props:{state=down, base_url=http://127.0.0.1:51150, core=solrj_collection_shard2_replica2, node_name=127.0.0.1:51150_}
   [junit4]   2> 1771918 T6146 C4907 P51150 oasc.SyncStrategy.sync Sync replicas to http://127.0.0.1:51150/solrj_collection_shard2_replica2/
   [junit4]   2> 1771919 T6146 C4907 P51150 oasu.PeerSync.sync PeerSync: core=solrj_collection_shard2_replica2 url=http://127.0.0.1:51150 START replicas=[http://127.0.0.1:51153/solrj_collection_shard2_replica1/] nUpdates=100
   [junit4]   2> 1771921 T6146 C4907 P51150 oasu.PeerSync.sync PeerSync: core=solrj_collection_shard2_replica2 url=http://127.0.0.1:51150 DONE.  We have no versions.  sync failed.
   [junit4]   2> 1771921 T6146 C4907 P51150 oasc.SyncStrategy.syncReplicas Leader's attempt to sync with shard failed, moving to the next candidate
   [junit4]   2> 1771923 T6146 oasc.ShardLeaderElectionContext.runLeaderProcess We failed sync, but we have no versions - we can't sync in that case - we were active before, so become leader anyway
   [junit4]   2> 1771924 T6130 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.LogDocMergePolicy: [LogDocMergePolicy: minMergeSize=1000, mergeFactor=46, maxMergeSize=9223372036854775807, maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=true, maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=1.0]
   [junit4]   2> 1771923 T6136 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 1771928 T6130 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
   [junit4]   2> 		commit{dir=MockDirectoryWrapper(org.apache.lucene.store.RAMDirectory@132dc985 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@70ca2bb3),segFN=segments_1,generation=1}
   [junit4]   2> 1771929 T6130 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
   [junit4]   2> 1771933 T6130 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "nodistrib"
   [junit4]   2> 1771933 T6130 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "dedupe"
   [junit4]   2> 1771935 T6130 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
   [junit4]   2> 1771935 T6130 oasup.UpdateRequestProcessorChain.init creating updateRequestProcesso

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

LeaderElector.java:107)
   [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:136)
   [junit4]   2> 		at org.apache.zookeeper.ClientCnxn$EventThread.processEvent(ClientCnxn.java:519)
   [junit4]   2> 		at org.apache.zookeeper.ClientCnxn$EventThread.run(ClientCnxn.java:495)
   [junit4]   2> 	
   [junit4]   2> 1951784 T6167 oasc.LeaderElector$1.process WARN  org.apache.zookeeper.KeeperException$SessionExpiredException: KeeperErrorCode = Session expired for /collections/nodes_used_collection/leader_elect/shard2/election/91065075834224650-core_node4-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:173)
   [junit4]   2> 	at org.apache.solr.common.cloud.SolrZkClient$2.execute(SolrZkClient.java:170)
   [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:170)
   [junit4]   2> 	at org.apache.solr.cloud.ElectionContext.cancelElection(ElectionContext.java:67)
   [junit4]   2> 	at org.apache.solr.cloud.ShardLeaderElectionContext.runLeaderProcess(ElectionContext.java:276)
   [junit4]   2> 	at org.apache.solr.cloud.LeaderElector.runIamLeaderProcess(LeaderElector.java:163)
   [junit4]   2> 	at org.apache.solr.cloud.LeaderElector.checkIfIamLeader(LeaderElector.java:107)
   [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:136)
   [junit4]   2> 	at org.apache.zookeeper.ClientCnxn$EventThread.processEvent(ClientCnxn.java:519)
   [junit4]   2> 	at org.apache.zookeeper.ClientCnxn$EventThread.run(ClientCnxn.java:495)
   [junit4]   2> 
   [junit4]   2> 1951785 T6167 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:1468)
   [junit4]   2> 	at org.apache.solr.common.cloud.SolrZkClient$6.execute(SolrZkClient.java:256)
   [junit4]   2> 	at org.apache.solr.common.cloud.SolrZkClient$6.execute(SolrZkClient.java:253)
   [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:253)
   [junit4]   2> 	at org.apache.solr.cloud.LeaderElector.checkIfIamLeader(LeaderElector.java:91)
   [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:136)
   [junit4]   2> 	at org.apache.zookeeper.ClientCnxn$EventThread.processEvent(ClientCnxn.java:519)
   [junit4]   2> 	at org.apache.zookeeper.ClientCnxn$EventThread.run(ClientCnxn.java:495)
   [junit4]   2> 
   [junit4]   2> 1951785 T6167 oascc.ZkStateReader$3.process WARN ZooKeeper watch triggered, but Solr cannot talk to ZK
   [junit4]   2> NOTE: test params are: codec=Lucene46: {other_tl1=PostingsFormat(name=Direct), a_si=PostingsFormat(name=SimpleText), a_t=PostingsFormat(name=Direct), _version_=PostingsFormat(name=Direct), timestamp=PostingsFormat(name=Direct), range_facet_l=PostingsFormat(name=Direct), range_facet_si=PostingsFormat(name=SimpleText), multiDefault=PostingsFormat(name=SimpleText), range_facet_sl=PostingsFormat(name=MockRandom), text=PostingsFormat(name=MockRandom), intDefault=PostingsFormat(name=Direct), id=PostingsFormat(name=FSTOrdPulsing41)}, docValues:{timestamp=DocValuesFormat(name=Lucene45)}, sim=DefaultSimilarity, locale=sr_RS_#Latn, timezone=Europe/Moscow
   [junit4]   2> NOTE: Mac OS X 10.8.5 x86_64/Oracle Corporation 1.7.0_45 (64-bit)/cpus=2,threads=1,free=29037408,total=221683712
   [junit4]   2> NOTE: All tests run in this JVM: [AbstractAnalyticsFacetTest, SolrTestCaseJ4Test, StatsComponentTest, HardAutoCommitTest, TestWriterPerf, TestCollationField, OpenCloseCoreStressTest, TestStressRecovery, QueryParsingTest, HighlighterTest, SuggesterTest, TimeZoneUtilsTest, DebugComponentTest, DistributedSuggestComponentTest, OverseerTest, DirectUpdateHandlerOptimizeTest, SystemInfoHandlerTest, CurrencyFieldOpenExchangeTest, TestModifyConfFiles, StatelessScriptUpdateProcessorFactoryTest, TestQuerySenderListener, JSONWriterTest, SynonymTokenizerTest, TestDynamicFieldResource, ShowFileRequestHandlerTest, UniqFieldsUpdateProcessorFactoryTest, TestSolr4Spatial, TestStressUserVersions, ChangedSchemaMergeTest, TestQueryUtils, TestSort, DefaultValueUpdateProcessorTest, DistributedTermsComponentTest, HdfsSyncSliceTest, SchemaVersionSpecificBehaviorTest, SolrCoreTest, LegacyHTMLStripCharFilterTest, TestSystemIdResolver, AliasIntegrationTest, HdfsDirectoryTest, PeerSyncTest, DocumentBuilderTest, TestAtomicUpdateErrorCases, TestFileDictionaryLookup, TestPerFieldSimilarity, TestFieldTypeCollectionResource, TestMaxScoreQueryParser, TestDistributedMissingSort, DistributedQueryComponentCustomSortTest, TestFieldTypeResource, TestOmitPositions, TestConfig, CacheHeaderTest, TestDynamicFieldCollectionResource, UUIDFieldTest, TestCloudManagedSchemaAddField, HdfsChaosMonkeySafeLeaderTest, DocValuesMissingTest, TestLuceneMatchVersion, ReturnFieldsTest, ChaosMonkeyNothingIsSafeTest, TestNumberUtils, FieldFacetTest, TestPartialUpdateDeduplication, PolyFieldTest, AddSchemaFieldsUpdateProcessorFactoryTest, TestCharFilters, StressHdfsTest, TestSearchPerf, TestLMJelinekMercerSimilarityFactory, TestSerializedLuceneMatchVersion, TestFoldingMultitermQuery, ParsingFieldUpdateProcessorsTest, TestAnalyzedSuggestions, ShardSplitTest, SliceStateUpdateTest, MBeansHandlerTest, TestRecovery, SuggesterFSTTest, HdfsBasicDistributedZkTest, MinimalSchemaTest, TestSolrDeletionPolicy2, TestSolrXmlPersistence, QueryResultKeyTest, TestFieldResource, TestHighFrequencyDictionaryFactory, PrimitiveFieldTypeTest, LeaderElectionIntegrationTest, SoftAutoCommitTest, TestDefaultSimilarityFactory, TestQueryTypes, BasicDistributedZk2Test, DistributedDebugComponentTest, TestReloadAndDeleteDocs, SuggesterTSTTest, TestDocSet, RAMDirectoryFactoryTest, SolrXmlInZkTest, TestCollationFieldDocValues, TestCustomSort, NumericFieldsTest, TestSchemaResource, DirectUpdateHandlerTest, TestAnalyzeInfixSuggestions, TestSolrQueryParserResource, TestArbitraryIndexDir, TestLMDirichletSimilarityFactory, SpellCheckComponentTest, ZkCLITest, ZkSolrClientTest, DOMUtilTest, InfoHandlerTest, SolrRequestParserTest, TestSolrCoreProperties, HdfsBasicDistributedZk2Test, QueryEqualityTest, HdfsCollectionsAPIDistributedZkTest, TestJmxIntegration, TestDistributedGrouping, PreAnalyzedFieldTest, TriLevelCompositeIdRoutingTest, TestRandomFaceting, TestDFRSimilarityFactory, CursorMarkTest, BasicZkTest, SignatureUpdateProcessorFactoryTest, TestCSVLoader, TestElisionMultitermQuery, TermVectorComponentTest, IndexSchemaTest, BlockCacheTest, TestDocumentBuilder, JsonLoaderTest, TestJmxMonitoredMap, SolrCoreCheckLockOnStartupTest, SimpleFacetsTest, TestClassNameShortening, PrimUtilsTest, AbstractAnalyticsStatsTest, AutoCommitTest, NoFacetTest, SolrIndexSplitterTest, BJQParserTest, OutputWriterTest, LeaderElectionTest, TestCursorMarkWithoutUniqueKey, FullSolrCloudDistribCmdsTest, DateMathParserTest, TestPseudoReturnFields, ZkNodePropsTest, FileBasedSpellCheckerTest, TestFiltering, SpellCheckCollatorTest, TestStressLucene, TestZkChroot, DeleteReplicaTest, CircularListTest, TestMergePolicyConfig, XmlUpdateRequestHandlerTest, TestRemoteStreaming, BadCopyFieldTest, TestValueSourceCache, TestSolrQueryParserDefaultOperatorResource, HdfsLockFactoryTest, OverseerCollectionProcessorTest, DeleteShardTest, CoreMergeIndexesAdminHandlerTest, TestNRTOpen, TestAddFieldRealTimeGet, TestFunctionQuery, TestBinaryResponseWriter, CoreAdminHandlerTest, TestPHPSerializedResponseWriter, TestRealTimeGet, BasicDistributedZkTest, ChaosMonkeySafeLeaderTest, UnloadDistributedZkTest, CollectionsAPIDistributedZkTest]
   [junit4] Completed in 191.04s, 1 test, 1 error <<< FAILURES!

[...truncated 545 lines...]
BUILD FAILED
/Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/build.xml:453: The following error occurred while executing this line:
/Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/build.xml:433: The following error occurred while executing this line:
/Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/build.xml:39: The following error occurred while executing this line:
/Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/extra-targets.xml:37: The following error occurred while executing this line:
/Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build.xml:189: The following error occurred while executing this line:
/Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/common-build.xml:491: The following error occurred while executing this line:
/Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/lucene/common-build.xml:1304: The following error occurred while executing this line:
/Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/lucene/common-build.xml:937: There were test failures: 362 suites, 1592 tests, 1 error, 39 ignored (5 assumptions)

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