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

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

Build: http://jenkins.thetaphi.de/job/Lucene-Solr-4.x-MacOSX/874/
Java: 64bit/jdk1.7.0 -XX:+UseCompressedOops -XX:+UseG1GC

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

Error Message:


Stack Trace:
java.lang.AssertionError
	at __randomizedtesting.SeedInfo.seed([915C111CF3ADF84E:10BA9F0484F29872]:0)
	at org.junit.Assert.fail(Assert.java:92)
	at org.junit.Assert.assertTrue(Assert.java:43)
	at org.junit.Assert.assertFalse(Assert.java:68)
	at org.junit.Assert.assertFalse(Assert.java:79)
	at org.apache.solr.cloud.CollectionsAPIDistributedZkTest.deleteCollectionRemovesStaleZkCollectionsNode(CollectionsAPIDistributedZkTest.java:223)
	at org.apache.solr.cloud.CollectionsAPIDistributedZkTest.doTest(CollectionsAPIDistributedZkTest.java:185)
	at org.apache.solr.BaseDistributedSearchTestCase.testDistribSearch(BaseDistributedSearchTestCase.java:835)
	at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
	at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:57)
	at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
	at java.lang.reflect.Method.invoke(Method.java:606)
	at com.carrotsearch.randomizedtesting.RandomizedRunner.invoke(RandomizedRunner.java:1559)
	at com.carrotsearch.randomizedtesting.RandomizedRunner.access$600(RandomizedRunner.java:79)
	at com.carrotsearch.randomizedtesting.RandomizedRunner$6.evaluate(RandomizedRunner.java:737)
	at com.carrotsearch.randomizedtesting.RandomizedRunner$7.evaluate(RandomizedRunner.java:773)
	at com.carrotsearch.randomizedtesting.RandomizedRunner$8.evaluate(RandomizedRunner.java:787)
	at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:53)
	at org.apache.lucene.util.TestRuleSetupTeardownChained$1.evaluate(TestRuleSetupTeardownChained.java:50)
	at org.apache.lucene.util.TestRuleFieldCacheSanity$1.evaluate(TestRuleFieldCacheSanity.java:51)
	at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:46)
	at com.carrotsearch.randomizedtesting.rules.SystemPropertiesInvariantRule$1.evaluate(SystemPropertiesInvariantRule.java:55)
	at org.apache.lucene.util.TestRuleThreadAndTestName$1.evaluate(TestRuleThreadAndTestName.java:49)
	at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:70)
	at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:48)
	at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
	at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:358)
	at com.carrotsearch.randomizedtesting.ThreadLeakControl.forkTimeoutingTask(ThreadLeakControl.java:782)
	at com.carrotsearch.randomizedtesting.ThreadLeakControl$3.evaluate(ThreadLeakControl.java:442)
	at com.carrotsearch.randomizedtesting.RandomizedRunner.runSingleTest(RandomizedRunner.java:746)
	at com.carrotsearch.randomizedtesting.RandomizedRunner$3.evaluate(RandomizedRunner.java:648)
	at com.carrotsearch.randomizedtesting.RandomizedRunner$4.evaluate(RandomizedRunner.java:682)
	at com.carrotsearch.randomizedtesting.RandomizedRunner$5.evaluate(RandomizedRunner.java:693)
	at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
	at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:53)
	at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:46)
	at org.apache.lucene.util.TestRuleStoreClassName$1.evaluate(TestRuleStoreClassName.java:42)
	at com.carrotsearch.randomizedtesting.rules.SystemPropertiesInvariantRule$1.evaluate(SystemPropertiesInvariantRule.java:55)
	at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:39)
	at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:39)
	at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
	at org.apache.lucene.util.TestRuleAssertionsRequired$1.evaluate(TestRuleAssertionsRequired.java:43)
	at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:48)
	at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:70)
	at org.apache.lucene.util.TestRuleIgnoreTestSuites$1.evaluate(TestRuleIgnoreTestSuites.java:55)
	at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
	at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:358)
	at java.lang.Thread.run(Thread.java:724)




Build Log:
[...truncated 10191 lines...]
   [junit4] Suite: org.apache.solr.cloud.CollectionsAPIDistributedZkTest
   [junit4]   2> 1661259 T4025 oas.BaseDistributedSearchTestCase.initHostContext Setting hostContext system property: /
   [junit4]   2> 1661280 T4025 oas.SolrTestCaseJ4.setUp ###Starting testDistribSearch
   [junit4]   2> Creating dataDir: /Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./solrtest-CollectionsAPIDistributedZkTest-1381355758510
   [junit4]   2> 1661288 T4025 oasc.ZkTestServer.run STARTING ZK TEST SERVER
   [junit4]   2> 1661290 T4026 oasc.ZkTestServer$ZKServerMain.runFromConfig Starting server
   [junit4]   2> 1661391 T4025 oasc.ZkTestServer.run start zk server on port:51792
   [junit4]   2> 1661393 T4025 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 1661402 T4032 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@63c882b5 name:ZooKeeperConnection Watcher:127.0.0.1:51792 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 1661403 T4025 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 1661403 T4025 oascc.SolrZkClient.makePath makePath: /solr
   [junit4]   2> 1661415 T4025 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 1661421 T4034 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@5ac9ef4a name:ZooKeeperConnection Watcher:127.0.0.1:51792/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 1661421 T4025 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 1661422 T4025 oascc.SolrZkClient.makePath makePath: /collections/collection1
   [junit4]   2> 1661432 T4025 oascc.SolrZkClient.makePath makePath: /collections/collection1/shards
   [junit4]   2> 1661440 T4025 oascc.SolrZkClient.makePath makePath: /collections/control_collection
   [junit4]   2> 1661448 T4025 oascc.SolrZkClient.makePath makePath: /collections/control_collection/shards
   [junit4]   2> 1661457 T4025 oasc.AbstractZkTestCase.putConfig put /Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test-files/solr/collection1/conf/solrconfig-tlog.xml to /configs/conf1/solrconfig.xml
   [junit4]   2> 1661458 T4025 oascc.SolrZkClient.makePath makePath: /configs/conf1/solrconfig.xml
   [junit4]   2> 1661471 T4025 oasc.AbstractZkTestCase.putConfig put /Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test-files/solr/collection1/conf/schema.xml to /configs/conf1/schema.xml
   [junit4]   2> 1661472 T4025 oascc.SolrZkClient.makePath makePath: /configs/conf1/schema.xml
   [junit4]   2> 1661482 T4025 oasc.AbstractZkTestCase.putConfig put /Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test-files/solr/collection1/conf/solrconfig.snippet.randomindexconfig.xml to /configs/conf1/solrconfig.snippet.randomindexconfig.xml
   [junit4]   2> 1661484 T4025 oascc.SolrZkClient.makePath makePath: /configs/conf1/solrconfig.snippet.randomindexconfig.xml
   [junit4]   2> 1661492 T4025 oasc.AbstractZkTestCase.putConfig put /Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test-files/solr/collection1/conf/stopwords.txt to /configs/conf1/stopwords.txt
   [junit4]   2> 1661493 T4025 oascc.SolrZkClient.makePath makePath: /configs/conf1/stopwords.txt
   [junit4]   2> 1661502 T4025 oasc.AbstractZkTestCase.putConfig put /Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test-files/solr/collection1/conf/protwords.txt to /configs/conf1/protwords.txt
   [junit4]   2> 1661504 T4025 oascc.SolrZkClient.makePath makePath: /configs/conf1/protwords.txt
   [junit4]   2> 1661513 T4025 oasc.AbstractZkTestCase.putConfig put /Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test-files/solr/collection1/conf/currency.xml to /configs/conf1/currency.xml
   [junit4]   2> 1661514 T4025 oascc.SolrZkClient.makePath makePath: /configs/conf1/currency.xml
   [junit4]   2> 1661523 T4025 oasc.AbstractZkTestCase.putConfig put /Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test-files/solr/collection1/conf/open-exchange-rates.json to /configs/conf1/open-exchange-rates.json
   [junit4]   2> 1661524 T4025 oascc.SolrZkClient.makePath makePath: /configs/conf1/open-exchange-rates.json
   [junit4]   2> 1661538 T4025 oasc.AbstractZkTestCase.putConfig put /Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test-files/solr/collection1/conf/mapping-ISOLatin1Accent.txt to /configs/conf1/mapping-ISOLatin1Accent.txt
   [junit4]   2> 1661540 T4025 oascc.SolrZkClient.makePath makePath: /configs/conf1/mapping-ISOLatin1Accent.txt
   [junit4]   2> 1661551 T4025 oasc.AbstractZkTestCase.putConfig put /Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test-files/solr/collection1/conf/old_synonyms.txt to /configs/conf1/old_synonyms.txt
   [junit4]   2> 1661553 T4025 oascc.SolrZkClient.makePath makePath: /configs/conf1/old_synonyms.txt
   [junit4]   2> 1661563 T4025 oasc.AbstractZkTestCase.putConfig put /Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test-files/solr/collection1/conf/synonyms.txt to /configs/conf1/synonyms.txt
   [junit4]   2> 1661565 T4025 oascc.SolrZkClient.makePath makePath: /configs/conf1/synonyms.txt
   [junit4]   2> 1661581 T4025 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 1661587 T4036 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@2b27587b name:ZooKeeperConnection Watcher:127.0.0.1:51792 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 1661588 T4025 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 1661588 T4025 oascc.SolrZkClient.makePath makePath: /solr
   [junit4]   2> 1661599 T4025 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 1661604 T4038 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@1c59691e name:ZooKeeperConnection Watcher:127.0.0.1:51792/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 1661605 T4025 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 1661607 T4025 oasc.AbstractZkTestCase.putConfig put /Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test-files/solr/collection1/conf/solrconfig.xml to /configs/conf2/solrconfig.xml
   [junit4]   2> 1661607 T4025 oascc.SolrZkClient.makePath makePath: /configs/conf2/solrconfig.xml
   [junit4]   2> 1661617 T4025 oasc.AbstractZkTestCase.putConfig put /Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test-files/solr/collection1/conf/schema.xml to /configs/conf2/schema.xml
   [junit4]   2> 1661619 T4025 oascc.SolrZkClient.makePath makePath: /configs/conf2/schema.xml
   [junit4]   2> 1661627 T4025 oasc.AbstractZkTestCase.putConfig put /Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test-files/solr/collection1/conf/solrconfig.snippet.randomindexconfig.xml to /configs/conf2/solrconfig.snippet.randomindexconfig.xml
   [junit4]   2> 1661629 T4025 oascc.SolrZkClient.makePath makePath: /configs/conf2/solrconfig.snippet.randomindexconfig.xml
   [junit4]   2> 1661636 T4025 oasc.AbstractZkTestCase.putConfig put /Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test-files/solr/collection1/conf/stopwords.txt to /configs/conf2/stopwords.txt
   [junit4]   2> 1661637 T4025 oascc.SolrZkClient.makePath makePath: /configs/conf2/stopwords.txt
   [junit4]   2> 1661644 T4025 oasc.AbstractZkTestCase.putConfig put /Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test-files/solr/collection1/conf/protwords.txt to /configs/conf2/protwords.txt
   [junit4]   2> 1661644 T4025 oascc.SolrZkClient.makePath makePath: /configs/conf2/protwords.txt
   [junit4]   2> 1661651 T4025 oasc.AbstractZkTestCase.putConfig put /Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test-files/solr/collection1/conf/currency.xml to /configs/conf2/currency.xml
   [junit4]   2> 1661652 T4025 oascc.SolrZkClient.makePath makePath: /configs/conf2/currency.xml
   [junit4]   2> 1661659 T4025 oasc.AbstractZkTestCase.putConfig put /Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test-files/solr/collection1/conf/open-exchange-rates.json to /configs/conf2/open-exchange-rates.json
   [junit4]   2> 1661660 T4025 oascc.SolrZkClient.makePath makePath: /configs/conf2/open-exchange-rates.json
   [junit4]   2> 1661666 T4025 oasc.AbstractZkTestCase.putConfig put /Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test-files/solr/collection1/conf/mapping-ISOLatin1Accent.txt to /configs/conf2/mapping-ISOLatin1Accent.txt
   [junit4]   2> 1661667 T4025 oascc.SolrZkClient.makePath makePath: /configs/conf2/mapping-ISOLatin1Accent.txt
   [junit4]   2> 1661674 T4025 oasc.AbstractZkTestCase.putConfig put /Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test-files/solr/collection1/conf/old_synonyms.txt to /configs/conf2/old_synonyms.txt
   [junit4]   2> 1661675 T4025 oascc.SolrZkClient.makePath makePath: /configs/conf2/old_synonyms.txt
   [junit4]   2> 1661683 T4025 oasc.AbstractZkTestCase.putConfig put /Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test-files/solr/collection1/conf/synonyms.txt to /configs/conf2/synonyms.txt
   [junit4]   2> 1661683 T4025 oascc.SolrZkClient.makePath makePath: /configs/conf2/synonyms.txt
   [junit4]   2> 1661690 T4025 oasc.AbstractZkTestCase.putConfig put /Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test-files/solr/collection1/conf/elevate.xml to /configs/conf2/elevate.xml
   [junit4]   2> 1661691 T4025 oascc.SolrZkClient.makePath makePath: /configs/conf2/elevate.xml
   [junit4]   2> 1662163 T4025 oejs.Server.doStart jetty-8.1.10.v20130312
   [junit4]   2> 1662174 T4025 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:51797
   [junit4]   2> 1662175 T4025 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
   [junit4]   2> 1662176 T4025 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
   [junit4]   2> 1662176 T4025 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: ./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-controljetty-1381355758922
   [junit4]   2> 1662177 T4025 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: './org.apache.solr.cloud.CollectionsAPIDistributedZkTest-controljetty-1381355758922/'
   [junit4]   2> 1662234 T4025 oasc.ConfigSolr.fromFile Loading container configuration from /Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-controljetty-1381355758922/solr.xml
   [junit4]   2> 1662346 T4025 oasc.ConfigSolrXml.<init> Config-defined core root directory: 
   [junit4]   2> 1662347 T4025 oasc.CoreContainer.<init> New CoreContainer 1479749142
   [junit4]   2> 1662347 T4025 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-controljetty-1381355758922/]
   [junit4]   2> 1662350 T4025 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 120000
   [junit4]   2> 1662350 T4025 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
   [junit4]   2> 1662351 T4025 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
   [junit4]   2> 1662351 T4025 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
   [junit4]   2> 1662352 T4025 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
   [junit4]   2> 1662352 T4025 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
   [junit4]   2> 1662352 T4025 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
   [junit4]   2> 1662353 T4025 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
   [junit4]   2> 1662353 T4025 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
   [junit4]   2> 1662354 T4025 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=120000&connTimeout=15000&retry=false
   [junit4]   2> 1662360 T4025 oasl.LogWatcher.createWatcher SLF4J impl is org.slf4j.impl.Log4jLoggerFactory
   [junit4]   2> 1662361 T4025 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
   [junit4]   2> 1662361 T4025 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:51792/solr
   [junit4]   2> 1662362 T4025 oasc.ZkController.checkChrootPath zkHost includes chroot
   [junit4]   2> 1662364 T4025 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 1662369 T4049 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@1ab7cb7d name:ZooKeeperConnection Watcher:127.0.0.1:51792 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 1662369 T4025 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 1662374 T4025 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=500&maxConnectionsPerHost=16&socketTimeout=120000&connTimeout=15000
   [junit4]   2> 1662379 T4025 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 1662384 T4051 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@4d6eb448 name:ZooKeeperConnection Watcher:127.0.0.1:51792/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 1662384 T4025 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 1662388 T4025 oascc.SolrZkClient.makePath makePath: /overseer/queue
   [junit4]   2> 1662398 T4025 oascc.SolrZkClient.makePath makePath: /overseer/collection-queue-work
   [junit4]   2> 1662408 T4025 oascc.SolrZkClient.makePath makePath: /live_nodes
   [junit4]   2> 1662413 T4025 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:51797_
   [junit4]   2> 1662415 T4025 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:51797_
   [junit4]   2> 1662425 T4025 oascc.SolrZkClient.makePath makePath: /overseer_elect/election
   [junit4]   2> 1662439 T4025 oascc.SolrZkClient.makePath makePath: /overseer_elect/leader
   [junit4]   2> 1662446 T4025 oasc.Overseer.start Overseer (id=90528530990432261-127.0.0.1:51797_-n_0000000000) starting
   [junit4]   2> 1662456 T4025 oascc.SolrZkClient.makePath makePath: /overseer/queue-work
   [junit4]   2> 1662467 T4053 oasc.OverseerCollectionProcessor.run Process current queue of collection creations
   [junit4]   2> 1662470 T4025 oascc.SolrZkClient.makePath makePath: /clusterstate.json
   [junit4]   2> 1662477 T4025 oascc.SolrZkClient.makePath makePath: /aliases.json
   [junit4]   2> 1662482 T4025 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
   [junit4]   2> 1662491 T4052 oasc.Overseer$ClusterStateUpdater.run Starting to work on the main queue
   [junit4]   2> 1662498 T4025 oasc.CorePropertiesLocator.discover Looking for core definitions underneath /Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-controljetty-1381355758922
   [junit4]   2> 1662638 T4025 oasc.CorePropertiesLocator.discoverUnder Found core conf in /Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-controljetty-1381355758922/conf/
   [junit4]   2> 1662645 T4025 oasc.CorePropertiesLocator.discover Found 1 core definitions
   [junit4]   2> 1662647 T4025 oass.SolrDispatchFilter.init user.dir=/Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0
   [junit4]   2> 1662647 T4025 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
   [junit4]   2> 1662648 T4025 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
   [junit4]   2> 1662655 T4025 oascsi.HttpClientUtil.createClient Creating new http client, config:
   [junit4]   2> 1662658 T4025 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 1662663 T4056 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@778afcc2 name:ZooKeeperConnection Watcher:127.0.0.1:51792/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 1662664 T4025 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 1662668 T4025 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
   [junit4]   2> 1662675 T4025 oasc.ChaosMonkey.monkeyLog monkey: init - expire sessions:true cause connection loss:true
   [junit4]   2> 1663084 T4025 oejs.Server.doStart jetty-8.1.10.v20130312
   [junit4]   2> 1663089 T4025 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:51801
   [junit4]   2> 1663092 T4025 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
   [junit4]   2> 1663093 T4025 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
   [junit4]   2> 1663093 T4025 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: ./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty1-1381355759898
   [junit4]   2> 1663093 T4025 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: './org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty1-1381355759898/'
   [junit4]   2> 1663163 T4025 oasc.ConfigSolr.fromFile Loading container configuration from /Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty1-1381355759898/solr.xml
   [junit4]   2> 1663274 T4025 oasc.ConfigSolrXml.<init> Config-defined core root directory: 
   [junit4]   2> 1663275 T4025 oasc.CoreContainer.<init> New CoreContainer 791848239
   [junit4]   2> 1663275 T4025 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty1-1381355759898/]
   [junit4]   2> 1663277 T4025 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 120000
   [junit4]   2> 1663277 T4025 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
   [junit4]   2> 1663278 T4025 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
   [junit4]   2> 1663278 T4025 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
   [junit4]   2> 1663278 T4025 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
   [junit4]   2> 1663279 T4025 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
   [junit4]   2> 1663279 T4025 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
   [junit4]   2> 1663279 T4025 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
   [junit4]   2> 1663280 T4025 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
   [junit4]   2> 1663280 T4025 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=120000&connTimeout=15000&retry=false
   [junit4]   2> 1663285 T4025 oasl.LogWatcher.createWatcher SLF4J impl is org.slf4j.impl.Log4jLoggerFactory
   [junit4]   2> 1663285 T4025 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
   [junit4]   2> 1663286 T4025 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:51792/solr
   [junit4]   2> 1663287 T4025 oasc.ZkController.checkChrootPath zkHost includes chroot
   [junit4]   2> 1663289 T4025 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 1663293 T4067 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@612c4ede name:ZooKeeperConnection Watcher:127.0.0.1:51792 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 1663294 T4025 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 1663297 T4025 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=500&maxConnectionsPerHost=16&socketTimeout=120000&connTimeout=15000
   [junit4]   2> 1663301 T4025 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 1663305 T4069 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@252c16fe name:ZooKeeperConnection Watcher:127.0.0.1:51792/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 1663306 T4025 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 1663316 T4025 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
   [junit4]   2> 1664326 T4025 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:51801_
   [junit4]   2> 1664329 T4025 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:51801_
   [junit4]   2> 1664342 T4051 oascc.ZkStateReader$3.process Updating live nodes... (2)
   [junit4]   2> 1664342 T4069 oascc.ZkStateReader$3.process Updating live nodes... (2)
   [junit4]   2> 1664343 T4056 oascc.ZkStateReader$3.process Updating live nodes... (2)
   [junit4]   2> 1664355 T4025 oasc.CorePropertiesLocator.discover Looking for core definitions underneath /Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty1-1381355759898
   [junit4]   2> 1664494 T4025 oasc.CorePropertiesLocator.discoverUnder Found core conf in /Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty1-1381355759898/conf/
   [junit4]   2> 1664501 T4025 oasc.CorePropertiesLocator.discover Found 1 core definitions
   [junit4]   2> 1664503 T4025 oass.SolrDispatchFilter.init user.dir=/Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0
   [junit4]   2> 1664503 T4025 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
   [junit4]   2> 1664504 T4025 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
   [junit4]   2> 1664911 T4025 oejs.Server.doStart jetty-8.1.10.v20130312
   [junit4]   2> 1664918 T4025 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:51804
   [junit4]   2> 1664919 T4025 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
   [junit4]   2> 1664920 T4025 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
   [junit4]   2> 1664920 T4025 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: ../../../../../../../../../Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty2-1381355761731
   [junit4]   2> 1664921 T4025 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '../../../../../../../../../Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty2-1381355761731/'
   [junit4]   2> 1664972 T4025 oasc.ConfigSolr.fromFile Loading container configuration from /Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/../../../../../../../../../Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty2-1381355761731/solr.xml
   [junit4]   2> 1665080 T4025 oasc.ConfigSolrXml.<init> Config-defined core root directory: 
   [junit4]   2> 1665081 T4025 oasc.CoreContainer.<init> New CoreContainer 719013462
   [junit4]   2> 1665082 T4025 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=../../../../../../../../../Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty2-1381355761731/]
   [junit4]   2> 1665084 T4025 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 120000
   [junit4]   2> 1665084 T4025 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
   [junit4]   2> 1665085 T4025 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
   [junit4]   2> 1665085 T4025 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
   [junit4]   2> 1665086 T4025 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
   [junit4]   2> 1665086 T4025 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
   [junit4]   2> 1665087 T4025 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
   [junit4]   2> 1665087 T4025 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
   [junit4]   2> 1665088 T4025 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
   [junit4]   2> 1665088 T4025 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=120000&connTimeout=15000&retry=false
   [junit4]   2> 1665094 T4025 oasl.LogWatcher.createWatcher SLF4J impl is org.slf4j.impl.Log4jLoggerFactory
   [junit4]   2> 1665094 T4025 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
   [junit4]   2> 1665095 T4025 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:51792/solr
   [junit4]   2> 1665095 T4025 oasc.ZkController.checkChrootPath zkHost includes chroot
   [junit4]   2> 1665098 T4025 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 1665103 T4081 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@4efc5b04 name:ZooKeeperConnection Watcher:127.0.0.1:51792 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 1665103 T4025 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 1665107 T4025 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=500&maxConnectionsPerHost=16&socketTimeout=120000&connTimeout=15000
   [junit4]   2> 1665111 T4025 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 1665115 T4083 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@6a7e785b name:ZooKeeperConnection Watcher:127.0.0.1:51792/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 1665116 T4025 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 1665127 T4025 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
   [junit4]   2> 1666136 T4025 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:51804_
   [junit4]   2> 1666139 T4025 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:51804_
   [junit4]   2> 1666147 T4051 oascc.ZkStateReader$3.process Updating live nodes... (3)
   [junit4]   2> 1666148 T4069 oascc.ZkStateReader$3.process Updating live nodes... (3)
   [junit4]   2> 1666148 T4056 oascc.ZkStateReader$3.process Updating live nodes... (3)
   [junit4]   2> 1666149 T4083 oascc.ZkStateReader$3.process Updating live nodes... (3)
   [junit4]   2> 1666161 T4025 oasc.CorePropertiesLocator.discover Looking for core definitions underneath /Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/../../../../../../../../../Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty2-1381355761731
   [junit4]   2> 1666360 T4025 oasc.CorePropertiesLocator.discoverUnder Found core conf in /Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/../../../../../../../../../Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty2-1381355761731/conf/
   [junit4]   2> 1666371 T4025 oasc.CorePropertiesLocator.discover Found 1 core definitions
   [junit4]   2> 1666372 T4025 oass.SolrDispatchFilter.init user.dir=/Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0
   [junit4]   2> 1666373 T4025 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
   [junit4]   2> 1666373 T4025 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
   [junit4]   2> 1666776 T4025 oejs.Server.doStart jetty-8.1.10.v20130312
   [junit4]   2> 1666782 T4025 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:51807
   [junit4]   2> 1666785 T4025 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
   [junit4]   2> 1666786 T4025 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
   [junit4]   2> 1666786 T4025 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: ./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty3-1381355763601
   [junit4]   2> 1666786 T4025 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: './org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty3-1381355763601/'
   [junit4]   2> 1666867 T3 oasc.CoreContainer.finalize ERROR CoreContainer was not shutdown prior to finalize(), indicates a bug -- POSSIBLE RESOURCE LEAK!!!  instance=825437015
   [junit4]   2> 1666907 T4025 oasc.ConfigSolr.fromFile Loading container configuration from /Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty3-1381355763601/solr.xml
   [junit4]   2> 1666992 T4025 oasc.ConfigSolrXml.<init> Config-defined core root directory: 
   [junit4]   2> 1666993 T4025 oasc.CoreContainer.<init> New CoreContainer 1035805402
   [junit4]   2> 1666994 T4025 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty3-1381355763601/]
   [junit4]   2> 1666996 T4025 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 120000
   [junit4]   2> 1666996 T4025 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
   [junit4]   2> 1666997 T4025 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
   [junit4]   2> 1666997 T4025 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
   [junit4]   2> 1666998 T4025 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
   [junit4]   2> 1666998 T4025 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
   [junit4]   2> 1666998 T4025 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
   [junit4]   2> 1666999 T4025 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
   [junit4]   2> 1666999 T4025 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
   [junit4]   2> 1667000 T4025 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=120000&connTimeout=15000&retry=false
   [junit4]   2> 1667007 T4025 oasl.LogWatcher.createWatcher SLF4J impl is org.slf4j.impl.Log4jLoggerFactory
   [junit4]   2> 1667007 T4025 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
   [junit4]   2> 1667008 T4025 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:51792/solr
   [junit4]   2> 1667008 T4025 oasc.ZkController.checkChrootPath zkHost includes chroot
   [junit4]   2> 1667011 T4025 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 1667016 T4095 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@413974b4 name:ZooKeeperConnection Watcher:127.0.0.1:51792 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 1667016 T4025 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 1667020 T4025 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=500&maxConnectionsPerHost=16&socketTimeout=120000&connTimeout=15000
   [junit4]   2> 1667024 T4025 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 1667028 T4097 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@59377c47 name:ZooKeeperConnection Watcher:127.0.0.1:51792/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 1667028 T4025 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 1667039 T4025 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
   [junit4]   2> 1668048 T4025 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:51807_
   [junit4]   2> 1668051 T4025 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:51807_
   [junit4]   2> 1668061 T4083 oascc.ZkStateReader$3.process Updating live nodes... (4)
   [junit4]   2> 1668061 T4051 oascc.ZkStateReader$3.process Updating live nodes... (4)
   [junit4]   2> 1668062 T4069 oascc.ZkStateReader$3.process Updating live nodes... (4)
   [junit4]   2> 1668062 T4097 oascc.ZkStateReader$3.process Updating live nodes... (4)
   [junit4]   2> 1668063 T4056 oascc.ZkStateReader$3.process Updating live nodes... (4)
   [junit4]   2> 1668077 T4025 oasc.CorePropertiesLocator.discover Looking for core definitions underneath /Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty3-1381355763601
   [junit4]   2> 1668217 T4025 oasc.CorePropertiesLocator.discoverUnder Found core conf in /Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty3-1381355763601/conf/
   [junit4]   2> 1668224 T4025 oasc.CorePropertiesLocator.discover Found 1 core definitions
   [junit4]   2> 1668225 T4025 oass.SolrDispatchFilter.init user.dir=/Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0
   [junit4]   2> 1668226 T4025 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
   [junit4]   2> 1668226 T4025 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
   [junit4]   2> 1668655 T4025 oejs.Server.doStart jetty-8.1.10.v20130312
   [junit4]   2> 1668660 T4025 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:51810
   [junit4]   2> 1668662 T4025 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
   [junit4]   2> 1668663 T4025 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
   [junit4]   2> 1668663 T4025 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: ./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1381355765454
   [junit4]   2> 1668664 T4025 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: './org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1381355765454/'
   [junit4]   2> 1668717 T4025 oasc.ConfigSolr.fromFile Loading container configuration from /Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1381355765454/solr.xml
   [junit4]   2> 1668835 T4025 oasc.ConfigSolrXml.<init> Config-defined core root directory: 
   [junit4]   2> 1668836 T4025 oasc.CoreContainer.<init> New CoreContainer 1068388636
   [junit4]   2> 1668836 T4025 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1381355765454/]
   [junit4]   2> 1668840 T4025 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 120000
   [junit4]   2> 1668840 T4025 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
   [junit4]   2> 1668841 T4025 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
   [junit4]   2> 1668842 T4025 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
   [junit4]   2> 1668842 T4025 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
   [junit4]   2> 1668843 T4025 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
   [junit4]   2> 1668843 T4025 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
   [junit4]   2> 1668844 T4025 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
   [junit4]   2> 1668845 T4025 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
   [junit4]   2> 1668845 T4025 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=120000&connTimeout=15000&retry=false
   [junit4]   2> 1668853 T4025 oasl.LogWatcher.createWatcher SLF4J impl is org.slf4j.impl.Log4jLoggerFactory
   [junit4]   2> 1668853 T4025 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
   [junit4]   2> 1668854 T4025 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:51792/solr
   [junit4]   2> 1668854 T4025 oasc.ZkController.checkChrootPath zkHost includes chroot
   [junit4]   2> 1668856 T4025 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 1668860 T4109 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@4463aec7 name:ZooKeeperConnection Watcher:127.0.0.1:51792 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 1668860 T4025 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 1668865 T4025 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=500&maxConnectionsPerHost=16&socketTimeout=120000&connTimeout=15000
   [junit4]   2> 1668867 T4025 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 1668871 T4111 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@5ecd9e7 name:ZooKeeperConnection Watcher:127.0.0.1:51792/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 1668872 T4025 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 1668882 T4025 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
   [junit4]   2> 1669895 T4025 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:51810_
   [junit4]   2> 1669897 T4025 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:51810_
   [junit4]   2> 1669906 T4097 oascc.ZkStateReader$3.process Updating live nodes... (5)
   [junit4]   2> 1669907 T4083 oascc.ZkStateReader$3.process Updating live nodes... (5)
   [junit4]   2> 1669907 T4056 oascc.ZkStateReader$3.process Updating live nodes... (5)
   [junit4]   2> 1669908 T4069 oascc.ZkStateReader$3.process Updating live nodes... (5)
   [junit4]   2> 1669909 T4051 oascc.ZkStateReader$3.process Updating live nodes... (5)
   [junit4]   2> 1669909 T4111 oascc.ZkStateReader$3.process Updating live nodes... (5)
   [junit4]   2> 1669921 T4025 oasc.CorePropertiesLocator.discover Looking for core definitions underneath /Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1381355765454
   [junit4]   2> 1670069 T4025 oasc.CorePropertiesLocator.discoverUnder Found core conf in /Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1381355765454/conf/
   [junit4]   2> 1670076 T4025 oasc.CorePropertiesLocator.discover Found 1 core definitions
   [junit4]   2> 1670077 T4025 oass.SolrDispatchFilter.init user.dir=/Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0
   [junit4]   2> 1670077 T4025 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
   [junit4]   2> 1670078 T4025 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
   [junit4]   2> 1670084 T4025 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
   [junit4]   2> 1670088 T4065 oasha.CollectionsHandler.handleCreateAction Creating Collection : numShards=2&collection.configName=conf1&name=nodes_used_collection&replicationFactor=2&action=CREATE&wt=javabin&version=2
   [junit4]   2> 1670091 T4051 oasc.DistributedQueue$LatchChildWatcher.process Watcher fired on path: /overseer/collection-queue-work state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 1670095 T4053 oasc.OverseerCollectionProcessor.run Overseer Collection Processor: Get the message id:/overseer/collection-queue-work/qn-0000000000 message:{
   [junit4]   2> 	  "operation":"createcollection",
   [junit4]   2> 	  "numShards":"2",
   [junit4]   2> 	  "collection.configName":"conf1",
   [junit4]   2> 	  "name":"nodes_used_collection",
   [junit4]   2> 	  "replicationFactor":"2"}
   [junit4]   2> 1670095 T4053 oasc.OverseerCollectionProcessor.processMessage WARN OverseerCollectionProcessor.processMessage : createcollection , {
   [junit4]   2> 	  "operation":"createcollection",
   [junit4]   2> 	  "numShards":"2",
   [junit4]   2> 	  "collection.configName":"conf1",
   [junit4]   2> 	  "name":"nodes_used_collection",
   [junit4]   2> 	  "replicationFactor":"2"}
   [junit4]   2> 1671529 T4052 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 1671530 T4052 oasc.Overseer$ClusterStateUpdater.buildCollection building a new collection: nodes_used_collection
   [junit4]   2> 1671531 T4052 oasc.Overseer$ClusterStateUpdater.createCollection Create collection nodes_used_collection with shards [shard1, shard2]
   [junit4]   2> 1671540 T4097 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> 1671541 T4069 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> 1671541 T4083 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> 1671542 T4111 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> 1671541 T4051 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> 1671541 T4056 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> 1671621 T4053 oasc.OverseerCollectionProcessor.createCollection going to create cores replicas shardNames [shard1, shard2] , repFactor : 2
   [junit4]   2> 1671622 T4053 oasc.OverseerCollectionProcessor.createCollection Creating shard nodes_used_collection_shard1_replica1 as part of slice shard1 of collection nodes_used_collection on 127.0.0.1:51801_
   [junit4]   2> 1671622 T4053 oasc.OverseerCollectionProcessor.createCollection Creating shard nodes_used_collection_shard1_replica2 as part of slice shard1 of collection nodes_used_collection on 127.0.0.1:51804_
   [junit4]   2> 1671623 T4053 oasc.OverseerCollectionProcessor.createCollection Creating shard nodes_used_collection_shard2_replica1 as part of slice shard2 of collection nodes_used_collection on 127.0.0.1:51810_
   [junit4]   2> 1671626 T4053 oasc.OverseerCollectionProcessor.createCollection Creating shard nodes_used_collection_shard2_replica2 as part of slice shard2 of collection nodes_used_collection on 127.0.0.1:51797_
   [junit4]   2> 1671636 T4103 oasc.ZkController.publish publishing core=nodes_used_collection_shard2_replica1 state=down
   [junit4]   2> 1671638 T4063 oasc.ZkController.publish publishing core=nodes_used_collection_shard1_replica1 state=down
   [junit4]   2> 1671636 T4046 oasc.ZkController.publish publishing core=nodes_used_collection_shard2_replica2 state=down
   [junit4]   2> 1671638 T4077 oasc.ZkController.publish publishing core=nodes_used_collection_shard1_replica2 state=down
   [junit4]   2> 1671640 T4103 oasc.ZkController.waitForCoreNodeName look for our core node name
   [junit4]   2> 1671642 T4063 oasc.ZkController.waitForCoreNodeName look for our core node name
   [junit4]   2> 1671643 T4046 oasc.ZkController.waitForCoreNodeName look for our core node name
   [junit4]   2> 1671643 T4077 oasc.ZkController.waitForCoreNodeName look for our core node name
   [junit4]   2> 1673056 T4052 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 1673058 T4052 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:51810",
   [junit4]   2> 	  "core":"nodes_used_collection_shard2_replica1",
   [junit4]   2> 	  "roles":null,
   [junit4]   2> 	  "node_name":"127.0.0.1:51810_",
   [junit4]   2> 	  "shard":"shard2",
   [junit4]   2> 	  "shard_range":null,
   [junit4]   2> 	  "shard_state":"active",
   [junit4]   2> 	  "collection":"nodes_used_collection",
   [junit4]   2> 	  "numShards":"2",
   [junit4]   2> 	  "core_node_name":"core_node1"}
   [junit4]   2> 1673069 T4052 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:51801",
   [junit4]   2> 	  "core":"nodes_used_collection_shard1_replica1",
   [junit4]   2> 	  "roles":null,
   [junit4]   2> 	  "node_name":"127.0.0.1:51801_",
   [junit4]   2> 	  "shard":"shard1",
   [junit4]   2> 	  "shard_range":null,
   [junit4]   2> 	  "shard_state":"active",
   [junit4]   2> 	  "collection":"nodes_used_collection",
   [junit4]   2> 	  "numShards":"2",
   [junit4]   2> 	  "core_node_name":"core_node2"}
   [junit4]   2> 1673080 T4052 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:51797",
   [junit4]   2> 	  "core":"nodes_used_collection_shard2_replica2",
   [junit4]   2> 	  "roles":null,
   [junit4]   2> 	  "node_name":"127.0.0.1:51797_",
   [junit4]   2> 	  "shard":"shard2",
   [junit4]   2> 	  "shard_range":null,
   [junit4]   2> 	  "shard_state":"active",
   [junit4]   2> 	  "collection":"nodes_used_collection",
   [junit4]   2> 	  "numShards":"2",
   [junit4]   2> 	  "core_node_name":"core_node3"}
   [junit4]   2> 1673091 T4052 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:51804",
   [junit4]   2> 	  "core":"nodes_used_collection_shard1_replica2",
   [junit4]   2> 	  "roles":null,
   [junit4]   2> 	  "node_name":"127.0.0.1:51804_",
   [junit4]   2> 	  "shard":"shard1",
   [junit4]   2> 	  "shard_range":null,
   [junit4]   2> 	  "shard_state":"active",
   [junit4]   2> 	  "collection":"nodes_used_collection",
   [junit4]   2> 	  "numShards":"2",
   [junit4]   2> 	  "core_node_name":"core_node4"}
   [junit4]   2> 1673102 T4097 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> 1673103 T4083 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> 1673103 T4056 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> 1673104 T4051 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> 1673104 T4111 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> 1673103 T4069 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> 1673643 T4103 oasc.ZkController.waitForShardId waiting to find shard id in clusterstate for nodes_used_collection_shard2_replica1
   [junit4]   2> 1673645 T4046 oasc.ZkController.waitForShardId waiting to find shard id in clusterstate for nodes_used_collection_shard2_replica2
   [junit4]   2> 1673647 T4063 oasc.ZkController.waitForShardId waiting to find shard id in clusterstate for nodes_used_collection_shard1_replica1
   [junit4]   2> 1673648 T4046 oasc.CoreContainer.create Creating SolrCore 'nodes_used_collection_shard2_replica2' using instanceDir: ./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-controljetty-1381355758922/nodes_used_collection_shard2_replica2
   [junit4]   2> 1673649 T4046 oasc.ZkController.createCollectionZkNode Check for collection zkNode:nodes_used_collection
   [junit4]   2> 1673650 T4077 oasc.ZkController.waitForShardId waiting to find shard id in clusterstate for nodes_used_collection_shard1_replica2
   [junit4]   2> 1673652 T4103 oasc.CoreContainer.create Creating SolrCore 'nodes_used_collection_shard2_replica1' using instanceDir: ./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1381355765454/nodes_used_collection_shard2_replica1
   [junit4]   2> 1673652 T4103 oasc.ZkController.createCollectionZkNode Check for collection zkNode:nodes_used_collection
   [junit4]   2> 1673653 T4077 oasc.CoreContainer.create Creating SolrCore 'nodes_used_collection_shard1_replica2' using instanceDir: ../../../../../../../../../Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty2-1381355761731/nodes_used_collection_shard1_replica2
   [junit4]   2> 1673654 T4077 oasc.ZkController.createCollectionZkNode Check for collection zkNode:nodes_used_collection
   [junit4]   2> 1673654 T4063 oasc.CoreContainer.create Creating SolrCore 'nodes_used_collection_shard1_replica1' using instanceDir: ./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty1-1381355759898/nodes_used_collection_shard1_replica1
   [junit4]   2> 1673656 T4063 oasc.ZkController.createCollectionZkNode Check for collection zkNode:nodes_used_collection
   [junit4]   2> 1673662 T4063 oasc.ZkController.createCollectionZkNode Creating collection in ZooKeeper:nodes_used_collection
   [junit4]   2> 1673663 T4063 oascc.SolrZkClient.makePath makePath: /collections/nodes_used_collection
   [junit4]   2> 1673663 T4077 oasc.ZkController.createCollectionZkNode Creating collection in ZooKeeper:nodes_used_collection
   [junit4]   2> 1673664 T4077 oascc.SolrZkClient.makePath makePath: /collections/nodes_used_collection
   [junit4]   2> 1673665 T4103 oasc.ZkController.createCollectionZkNode Creating collection in ZooKeeper:nodes_used_collection
   [junit4]   2> 1673666 T4046 oasc.ZkController.createCollectionZkNode Creating collection in ZooKeeper:nodes_used_collection
   [junit4]   2> 1673666 T4046 oascc.SolrZkClient.makePath makePath: /collections/nodes_used_collection
   [junit4]   2> 1673666 T4103 oascc.SolrZkClient.makePath makePath: /collections/nodes_used_collection
   [junit4]   2> 1673677 T4063 oasc.ZkController.readConfigName Load collection config from:/collections/nodes_used_collection
   [junit4]   2> 1673684 T4077 oasc.ZkController.readConfigName Load collection config from:/collections/nodes_used_collection
   [junit4]   2> 1673691 T4063 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: './org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty1-1381355759898/nodes_used_collection_shard1_replica1/'
   [junit4]   2> 1673699 T4103 oasc.ZkController.readConfigName Load collection config from:/collections/nodes_used_collection
   [junit4]   2> 1673703 T4077 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '../../../../../../../../../Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty2-1381355761731/nodes_used_collection_shard1_replica2/'
   [junit4]   2> 1673720 T4046 oasc.ZkController.readConfigName Load collection config from:/collections/nodes_used_collection
   [junit4]   2> 1673721 T4103 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: './org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1381355765454/nodes_used_collection_shard2_replica1/'
   [junit4]   2> 1673727 T4046 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: './org.apache.solr.cloud.CollectionsAPIDistributedZkTest-controljetty-1381355758922/nodes_used_collection_shard2_replica2/'
   [junit4]   2> 1674002 T4077 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_46
   [junit4]   2> 1674028 T4063 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_46
   [junit4]   2> 1674060 T4046 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_46
   [junit4]   2> 1674063 T4103 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_46
   [junit4]   2> 1674195 T4077 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
   [junit4]   2> 1674215 T4077 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
   [junit4]   2> 1674239 T4077 oass.IndexSchema.readSchema [nodes_used_collection_shard1_replica2] Schema name=test
   [junit4]   2> 1674243 T4103 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
   [junit4]   2> 1674263 T4046 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
   [junit4]   2> 1674265 T4103 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
   [junit4]   2> 1674278 T4063 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
   [junit4]   2> 1674279 T4046 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
   [junit4]   2> 1674292 T4063 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
   [junit4]   2> 1674295 T4046 oass.IndexSchema.readSchema [nodes_used_collection_shard2_replica2] Schema name=test
   [junit4]   2> 1674313 T4103 oass.IndexSchema.readSchema [nodes_used_collection_shard2_replica1] Schema name=test
   [junit4]   2> 1674325 T4063 oass.IndexSchema.readSchema [nodes_used_collection_shard1_replica1] Schema name=test
   [junit4]   2> 1676414 T4077 oass.ByteField.init WARN ByteField is deprecated and will be removed in 5.0. You should use TrieIntField instead.
   [junit4]   2> 1676423 T4077 oass.ShortField.init WARN ShortField is deprecated and will be removed in 5.0. You should use TrieIntField instead.
   [junit4]   2> 1676425 T4077 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
   [junit4]   2> 1676442 T4077 oass.IndexSchema.readSchema default search field in schema is text
   [junit4]   2> 1676460 T4077 oass.IndexSchema.readSchema unique key field: id
   [junit4]   2> 1676473 T4063 oass.ByteField.init WARN ByteField is deprecated and will be removed in 5.0. You should use TrieIntField instead.
   [junit4]   2> 1676473 T4063 oass.ShortField.init WARN ShortField is deprecated and will be removed in 5.0. You should use TrieIntField instead.
   [junit4]   2> 1676474 T4046 oass.ByteField.init WARN ByteField is deprecated and will be removed in 5.0. You should use TrieIntField instead.
   [junit4]   2> 1676474 T4046 oass.ShortField.init WARN ShortField is deprecated and will be removed in 5.0. You should use TrieIntField instead.
   [junit4]   2> 1676475 T4063 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
   [junit4]   2> 1676476 T4046 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
   [junit4]   2> 1676484 T4103 oass.ByteField.init WARN ByteField is deprecated and will be removed in 5.0. You should use TrieIntField instead.
   [junit4]   2> 1676485 T4103 oass.ShortField.init WARN ShortField is deprecated and will be removed in 5.0. You should use TrieIntField instead.
   [junit4]   2> 1676486 T4103 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
   [junit4]   2> 1676489 T4063 oass.IndexSchema.readSchema default search field in schema is text
   [junit4]   2> 1676495 T4063 oass.IndexSchema.readSchema unique key field: id
   [junit4]   2> 1676501 T4046 oass.IndexSchema.readSchema default search field in schema is text
   [junit4]   2> 1676506 T4046 oass.IndexSchema.readSchema unique key field: id
   [junit4]   2> 1676510 T4103 oass.IndexSchema.readSchema default search field in schema is text
   [junit4]   2> 1676516 T4103 oass.IndexSchema.readSchema unique key field: id
   [junit4]   2> 1676557 T4077 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
   [junit4]   2> 1676559 T4063 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
   [junit4]   2> 1676569 T4077 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
   [junit4]   2> 1676573 T4063 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
   [junit4]   2> 1676578 T4103 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
   [junit4]   2> 1676582 T4077 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
   [junit4]   2> 1676589 T4063 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
   [junit4]   2> 1676590 T4103 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
   [junit4]   2> 1676592 T4077 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
   [junit4]   2> 1676593 T4077 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
   [junit4]   2> 1676594 T4077 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
   [junit4]   2> 1676599 T4077 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
   [junit4]   2> 1676600 T4077 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
   [junit4]   2> 1676600 T4077 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
   [junit4]   2> 1676601 T4077 oasc.SolrCore.<init> [nodes_used_collection_shard1_replica2] Opening new SolrCore at ../../../../../../../../../Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty2-1381355761731/nodes_used_collection_shard1_replica2/, dataDir=../../../../../../../../../Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty2-1381355761731/nodes_used_collection_shard1_replica2/data/
   [junit4]   2> 1676602 T4077 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@2813e554
   [junit4]   2> 1676603 T4063 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
   [junit4]   2> 1676604 T4063 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
   [junit4]   2> 1676604 T4103 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
   [junit4]   2> 1676604 T4077 oasc.CachingDirectoryFactory.get return new directory for ../../../../../../../../../Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty2-1381355761731/nodes_used_collection_shard1_replica2/data
   [junit4]   2> 1676604 T4063 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
   [junit4]   2> 1676606 T4077 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=../../../../../../../../../Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty2-1381355761731/nodes_used_collection_shard1_replica2/data/index/
   [junit4]   2> 1676607 T4077 oasc.SolrCore.initIndex WARN [nodes_used_collection_shard1_replica2] Solr index directory '../../../../../../../../../Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty2-1381355761731/nodes_used_collection_shard1_replica2/data/index' doesn't exist. Creating new index...
   [junit4]   2> 1676608 T4103 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
   [junit4]   2> 1676608 T4103 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
   [junit4]   2> 1676609 T4103 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
   [junit4]   2> 1676609 T4077 oasc.CachingDirectoryFactory.get return new directory for ../../../../../../../../../Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty2-1381355761731/nodes_used_collection_shard1_replica2/data/index
   [junit4]   2> 1676613 T4077 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.LogByteSizeMergePolicy: [LogByteSizeMergePolicy: minMergeSize=1677721, mergeFactor=33, maxMergeSize=2147483648, maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=false, maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.3517948966363601]
   [junit4]   2> 1676614 T4103 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
   [junit4]   2> 1676615 T4103 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
   [junit4]   2> 1676615 T4103 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
   [junit4]   2> 1676613 T4063 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
   [junit4]   2> 1676617 T4063 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
   [junit4]   2> 1676616 T4103 oasc.SolrCore.<init> [nodes_used_collection_shard2_replica1] Opening new SolrCore at ./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1381355765454/nodes_used_collection_shard2_replica1/, dataDir=./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1381355765454/nodes_used_collection_shard2_replica1/data/
   [junit4]   2> 1676616 T4077 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
   [junit4]   2> 		commit{dir=MockDirectoryWrapper(org.apache.lucene.store.RAMDirectory@1e77145c lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@796718a3),segFN=segments_1,generation=1}
   [junit4]   2> 1676618 T4077 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
   [junit4]   2> 1676615 T4046 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
   [junit4]   2> 1676618 T4103 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@2813e554
   [junit4]   2> 1676617 T4063 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
   [junit4]   2> 1676621 T4063 oasc.SolrCore.<init> [nodes_used_collection_shard1_replica1] Opening new SolrCore at ./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty1-1381355759898/nodes_used_collection_shard1_replica1/, dataDir=./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty1-1381355759898/nodes_used_collection_shard1_replica1/data/
   [junit4]   2> 1676621 T4063 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@2813e554
   [junit4]   2> 1676623 T4103 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1381355765454/nodes_used_collection_shard2_replica1/data
   [junit4]   2> 1676623 T4063 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty1-1381355759898/nodes_used_collection_shard1_replica1/data
   [junit4]   2> 1676623 T4103 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1381355765454/nodes_used_collection_shard2_replica1/data/index/
   [junit4]   2> 1676624 T4103 oasc.SolrCore.initIndex WARN [nodes_used_collection_shard2_replica1] Solr index directory './org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1381355765454/nodes_used_collection_shard2_replica1/data/index' doesn't exist. Creating new index...
   [junit4]   2> 1676625 T4063 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty1-1381355759898/nodes_used_collection_shard1_replica1/data/index/
   [junit4]   2> 1676625 T4063 oasc.SolrCore.initIndex WARN [nodes_used_collection_shard1_replica1] Solr index directory './org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty1-1381355759898/nodes_used_collection_shard1_replica1/data/index' doesn't exist. Creating new index...
   [junit4]   2> 1676625 T4077 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "nodistrib"
   [junit4]   2> 1676627 T4063 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty1-1381355759898/nodes_used_collection_shard1_replica1/data/index
   [junit4]   2> 1676627 T4077 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "dedupe"
   [junit4]   2> 1676628 T4077 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
   [junit4]   2> 1676628 T4077 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "stored_sig"
   [junit4]   2> 1676629 T4077 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
   [junit4]   2> 1676629 T4077 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-explicit"
   [junit4]   2> 1676630 T4077 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-implicit"
   [junit4]   2> 1676631 T4077 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
   [junit4]   2> 1676631 T4077 oasc.SolrCore.loadUpdateProcessorChains no updateRequestProcessorChain defined as default, creating implicit default
   [junit4]   2> 1676632 T4077 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
   [junit4]   2> 1676634 T4046 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
   [junit4]   2> 1676626 T4103 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1381355765454/nodes_used_collection_shard2_replica1/data/index
   [junit4]   2> 1676633 T4077 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
   [junit4]   2> 1676635 T4077 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
   [junit4]   2> 1676627 T4063 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.LogByteSizeMergePolicy: [LogByteSizeMergePolicy: minMergeSize=1677721, mergeFactor=33, maxMergeSize=2147483648, maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=false, maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.3517948966363601]
   [junit4]   2> 1676636 T4077 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
   [junit4]   2> 1676635 T4103 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.LogByteSizeMergePolicy: [LogByteSizeMergePolicy: minMergeSize=1677721, mergeFactor=33, maxMergeSize=2147483648, maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=false, maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.3517948966363601]
   [junit4]   2> 1676638 T4077 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
   [junit4]   2> 1676639 T4063 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
   [junit4]   2> 		commit{dir=MockDirectoryWrapper(org.apache.lucene.store.RAMDirectory@959e624 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@5ea11c46),segFN=segments_1,generation=1}
   [junit4]   2> 1676639 T4063 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
   [junit4]   2> 1676644 T4046 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
   [junit4]   2> 1676639 T4077 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
   [junit4]   2> 1676647 T4103 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
   [junit4]   2> 		commit{dir=MockDirectoryWrapper(org.apache.lucene.store.RAMDirectory@75b874a5 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@52a00007),segFN=segments_1,generation=1}
   [junit4]   2> 1676648 T4103 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
   [junit4]   2> 1676655 T4103 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "nodistrib"
   [junit4]   2> 1676656 T4103 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "dedupe"
   [junit4]   2> 1676657 T4103 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
   [junit4]   2> 1676658 T4103 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "stored_sig"
   [junit4]   2> 1676659 T4103 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
   [junit4]   2> 1676659 T4103 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-explicit"
   [junit4]   2> 1676661 T4103 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-implicit"
   [junit4]   2> 1676661 T4103 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
   [junit4]   2> 1676662 T4103 oasc.SolrCore.loadUpdateProcessorChains no updateRequestProcessorChain defined as default, creating implicit default
   [junit4]   2> 1676663 T4103 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
   [junit4]   2> 1676664 T4103 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
   [junit4]   2> 1676664 T4103 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
   [junit4]   2> 1676665 T4077 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
   [junit4]   2> 1676657 T4063 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "nodistrib"
   [junit4]   2> 1676667 T4063 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "dedupe"
   [junit4]   2> 1676668 T4063 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
   [junit4]   2> 1676668 T4063 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "stored_sig"
   [junit4]   2> 1676669 T4063 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
   [junit4]   2> 1676669 T4063 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-explicit"
   [junit4]   2> 1676671 T4063 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-implicit"
   [junit4]   2> 1676671 T4063 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
   [junit4]   2> 1676672 T4063 oasc.SolrCore.loadUpdateProcessorChains no updateRequestProcessorChain defined as default, creating implicit default
   [junit4]   2> 1676673 T4063 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
   [junit4]   2> 1676666 T4103 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
   [junit4]   2> 1676676 T4103 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
   [junit4]   2> 1676677 T4103 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
   [junit4]   2> 1676660 T4046 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
   [junit4]   2> 1676679 T4046 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
   [junit4]   2> 1676680 T4046 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
   [junit4]   2> 1676681 T4103 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
   [junit4]   2> 1676675 T4063 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
   [junit4]   2> 1676682 T4063 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
   [junit4]   2> 1676683 T4063 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
   [junit4]   2> 1676684 T4046 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
   [junit4]   2> 1676685 T4063 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
   [junit4]   2> 1676686 T4063 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
   [junit4]   2> 1676689 T4063 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
   [junit4]   2> 1676673 T4077 oasu.CommitTracker.<init> Hard AutoCommit: disabled
   [junit4]   2> 1676692 T4077 oasu.CommitTracker.<init> Soft AutoCommit: disabled
   [junit4]   2> 1676693 T4103 oasu.CommitTracker.<init> Hard AutoCommit: disabled
   [junit4]   2> 1676693 T4103 oasu.CommitTracker.<init> Soft AutoCommit: disabled
   [junit4]   2> 1676685 T4046 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
   [junit4]   2> 1676695 T4046 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
   [junit4]   2> 1676696 T4046 oasc.SolrCore.<init> [nodes_used_collection_shard2_replica2] Opening new SolrCore at ./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-controljetty-1381355758922/nodes_used_collection_shard2_replica2/, dataDir=./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-controljetty-1381355758922/nodes_used_collection_shard2_replica2/data/
   [junit4]   2> 1676696 T4046 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@2813e554
   [junit4]   2> 1676697 T4063 oasu.CommitTracker.<init> Hard AutoCommit: disabled
   [junit4]   2> 1676698 T4063 oasu.CommitTracker.<init> Soft AutoCommit: disabled
   [junit4]   2> 1676695 T4103 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: maxMergeAtOnce=22, maxMergeAtOnceExplicit=18, maxMergedSegmentMB=25.2275390625, floorSegmentMB=1.3359375, forceMergeDeletesPctAllowed=24.772808460492715, segmentsPerTier=11.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.0
   [junit4]   2> 1676699 T4063 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: maxMergeAtOnce=22, maxMergeAtOnceExplicit=18, maxMergedSegmentMB=25.2275390625, floorSegmentMB=1.3359375, forceMergeDeletesPctAllowed=24.772808460492715, segmentsPerTier=11.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.0
   [junit4]   2> 1676699 T4103 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=1
   [junit4]   2> 		commit{dir=MockDirectoryWrapper(org.apache.lucene.store.RAMDirectory@75b874a5 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@52a00007),segFN=segments_1,generation=1}
   [junit4]   2> 1676700 T4063 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=1
   [junit4]   2> 		commit{dir=MockDirectoryWrapper(org.apache.lucene.store.RAMDirectory@959e624 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@5ea11c46),segFN=segments_1,generation=1}
   [junit4]   2> 1676700 T4063 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
   [junit4]   2> 1676698 T4046 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-controljetty-1381355758922/nodes_used_collection_shard2_replica2/data
   [junit4]   2> 1676701 T4046 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-controljetty-1381355758922/nodes_used_collection_shard2_replica2/data/index/
   [junit4]   2> 1676702 T4046 oasc.SolrCore.initIndex WARN [nodes_used_collection_shard2_replica2] Solr index directory './org.apache.solr.cloud.CollectionsAPIDistributedZkTest-controljetty-1381355758922/nodes_used_collection_shard2_replica2/data/index' doesn't exist. Creating new index...
   [junit4]   2> 1676698 T4077 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: maxMergeAtOnce=22, maxMergeAtOnceExplicit=18, maxMergedSegmentMB=25.2275390625, floorSegmentMB=1.3359375, forceMergeDeletesPctAllowed=24.772808460492715, segmentsPerTier=11.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.0
   [junit4]   2> 1676703 T4046 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-controljetty-1381355758922/nodes_used_collection_shard2_replica2/data/index
   [junit4]   2> 1676701 T4063 oass.SolrIndexSearcher.<init> Opening Searcher@1007dc63 main
   [junit4]   2> 1676700 T4103 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
   [junit4]   2> 1676705 T4103 oass.SolrIndexSearcher.<init> Opening Searcher@544125a4 main
   [junit4]   2> 1676704 T4046 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.LogByteSizeMergePolicy: [LogByteSizeMergePolicy: minMergeSize=1677721, mergeFactor=33, maxMergeSize=2147483648, maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=false, maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.3517948966363601]
   [junit4]   2> 1676703 T4077 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=1
   [junit4]   2> 		commit{dir=MockDirectoryWrapper(org.apache.lucene.store.RAMDirectory@1e77145c lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@796718a3),segFN=segments_1,generation=1}
   [junit4]   2> 1676708 T4077 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
   [junit4]   2> 1676709 T4077 oass.SolrIndexSearcher.<init> Opening Searcher@756f896c main
   [junit4]   2> 1676707 T4046 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
   [junit4]   2> 		commit{dir=MockDirectoryWrapper(org.apache.lucene.store.RAMDirectory@7415efcd lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@46f808be),segFN=segments_1,generation=1}
   [junit4]   2> 1676716 T4046 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
   [junit4]   2> 1676722 T4119 oasc.SolrCore.registerSearcher [nodes_used_collection_shard1_replica1] Registered new searcher Searcher@1007dc63 main{StandardDirectoryReader(segments_1:1:nrt)}
   [junit4]   2> 1676725 T4118 oasc.SolrCore.registerSearcher [nodes_used_collection_shard2_replica1] Registered new searcher Searcher@544125a4 main{StandardDirectoryReader(segments_1:1:nrt)}
   [junit4]   2> 1676726 T4117 oasc.SolrCore.registerSearcher [nodes_used_collection_shard1_replica2] Registered new searcher Searcher@756f896c main{StandardDirectoryReader(segments_1:1:nrt)}
   [junit4]   2> 1676732 T4063 oasc.CoreContainer.registerCore registering core: nodes_used_collection_shard1_replica1
   [junit4]   2> 1676733 T4063 oasc.ZkController.register Register replica - core:nodes_used_collection_shard1_replica1 address:http://127.0.0.1:51801 collection:nodes_used_collection shard:shard1
   [junit4]   2> 1676733 T4063 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=10000&maxConnectionsPerHost=20&connTimeout=15000&socketTimeout=30000&retry=false
   [junit4]   2> 1676737 T4063 oascc.SolrZkClient.makePath makePath: /collections/nodes_used_collection/leader_elect/shard1/election
   [junit4]   2> 1676742 T4046 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "nodistrib"
   [junit4]   2> 1676743 T4046 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "dedupe"
   [junit4]   2> 1676744 T4046 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
   [junit4]   2> 1676744 T4046 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "stored_sig"
   [junit4]   2> 1676745 T4103 oasc.CoreContainer.registerCore registering core: nodes_used_collection_shard2_replica1
   [junit4]   2> 1676746 T4103 oasc.ZkController.register Register replica - core:nodes_used_collection_shard2_replica1 address:http://127.0.0.1:51810 collection:nodes_used_collection shard:shard2
   [junit4]   2> 1676744 T4077 oasc.CoreContainer.registerCore registering core: nodes_used_collection_shard1_replica2
   [junit4]   2> 1676747 T4077 oasc.ZkController.register Register replica - core:nodes_used_co

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

ked
   [junit4]   2> 1847414 T4025 oasc.CachingDirectoryFactory.closeCacheValue looking to close ./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1381355765454/nodes_used_collection_shard2_replica1/data [CachedDir<<refCount=0;path=./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1381355765454/nodes_used_collection_shard2_replica1/data;done=false>>]
   [junit4]   2> 1847415 T4025 oasc.CachingDirectoryFactory.close Closing directory: ./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1381355765454/nodes_used_collection_shard2_replica1/data
   [junit4]   2> 1847415 T4025 oasc.CachingDirectoryFactory.closeCacheValue looking to close ./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1381355765454/nodes_used_collection_shard2_replica1/data/index [CachedDir<<refCount=0;path=./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1381355765454/nodes_used_collection_shard2_replica1/data/index;done=false>>]
   [junit4]   2> 1847415 T4025 oasc.CachingDirectoryFactory.close Closing directory: ./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1381355765454/nodes_used_collection_shard2_replica1/data/index
   [junit4]   2> 1847416 T4025 oasc.SolrCore.close [awholynewcollection_0_shard1_replica2]  CLOSING SolrCore org.apache.solr.core.SolrCore@34b539b2
   [junit4]   2> 1847432 T4025 oasu.DirectUpdateHandler2.close closing DirectUpdateHandler2{commits=0,autocommits=0,soft autocommits=0,optimizes=0,rollbacks=0,expungeDeletes=0,docsPending=0,adds=0,deletesById=0,deletesByQuery=0,errors=0,cumulative_adds=0,cumulative_deletesById=0,cumulative_deletesByQuery=0,cumulative_errors=0}
   [junit4]   2> 1847432 T4025 oasu.SolrCoreState.decrefSolrCoreState Closing SolrCoreState
   [junit4]   2> 1847433 T4025 oasu.DefaultSolrCoreState.closeIndexWriter SolrCoreState ref count has reached 0 - closing IndexWriter
   [junit4]   2> 1847433 T4025 oasu.DefaultSolrCoreState.closeIndexWriter closing IndexWriter with IndexWriterCloser
   [junit4]   2> 1847434 T4025 oasc.SolrCore.closeSearcher [awholynewcollection_0_shard1_replica2] Closing main searcher on request.
   [junit4]   2> 1847435 T4025 oasc.CachingDirectoryFactory.close Closing MockDirectoryFactory - 2 directories currently being tracked
   [junit4]   2> 1847435 T4025 oasc.CachingDirectoryFactory.closeCacheValue looking to close ./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1381355765454/awholynewcollection_0_shard1_replica2/data [CachedDir<<refCount=0;path=./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1381355765454/awholynewcollection_0_shard1_replica2/data;done=false>>]
   [junit4]   2> 1847435 T4025 oasc.CachingDirectoryFactory.close Closing directory: ./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1381355765454/awholynewcollection_0_shard1_replica2/data
   [junit4]   2> 1847436 T4025 oasc.CachingDirectoryFactory.closeCacheValue looking to close ./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1381355765454/awholynewcollection_0_shard1_replica2/data/index [CachedDir<<refCount=0;path=./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1381355765454/awholynewcollection_0_shard1_replica2/data/index;done=false>>]
   [junit4]   2> 1847436 T4025 oasc.CachingDirectoryFactory.close Closing directory: ./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1381355765454/awholynewcollection_0_shard1_replica2/data/index
   [junit4]   2> 1847437 T4258 oasc.Overseer$ClusterStateUpdater.amILeader According to ZK I (id=90528530990432270-127.0.0.1:51810_-n_0000000004) am no longer a leader.
   [junit4]   2> 1847441 T4111 oascc.ZkStateReader$3.process WARN ZooKeeper watch triggered, but Solr cannot talk to ZK
   [junit4]   2> 1847457 T4025 oejsh.ContextHandler.doStop stopped o.e.j.s.ServletContextHandler{/,null}
   [junit4]   2> 1847519 T4025 oas.SolrTestCaseJ4.tearDown ###Ending testDistribSearch
   [junit4]   2> 1847522 T4025 oasc.ZkTestServer.send4LetterWord connecting to 127.0.0.1:51792 51792
   [junit4]   1> client port:0.0.0.0/0.0.0.0:0
   [junit4]   2> NOTE: reproduce with: ant test  -Dtestcase=CollectionsAPIDistributedZkTest -Dtests.method=testDistribSearch -Dtests.seed=915C111CF3ADF84E -Dtests.slow=true -Dtests.locale=sr_BA -Dtests.timezone=Brazil/West -Dtests.file.encoding=UTF-8
   [junit4] FAILURE  186s | CollectionsAPIDistributedZkTest.testDistribSearch <<<
   [junit4]    > Throwable #1: java.lang.AssertionError
   [junit4]    > 	at __randomizedtesting.SeedInfo.seed([915C111CF3ADF84E:10BA9F0484F29872]:0)
   [junit4]    > 	at org.apache.solr.cloud.CollectionsAPIDistributedZkTest.deleteCollectionRemovesStaleZkCollectionsNode(CollectionsAPIDistributedZkTest.java:223)
   [junit4]    > 	at org.apache.solr.cloud.CollectionsAPIDistributedZkTest.doTest(CollectionsAPIDistributedZkTest.java:185)
   [junit4]    > 	at org.apache.solr.BaseDistributedSearchTestCase.testDistribSearch(BaseDistributedSearchTestCase.java:835)
   [junit4]    > 	at java.lang.Thread.run(Thread.java:724)
   [junit4]   2> 1847635 T4025 oas.SolrTestCaseJ4.deleteCore ###deleteCore
   [junit4]   2> 186385 T4024 ccr.ThreadLeakControl.checkThreadLeaks WARNING Will linger awaiting termination of 1 leaked thread(s).
   [junit4]   2> NOTE: test params are: codec=DummyCompressingStoredFields(storedFieldsFormat=CompressingStoredFieldsFormat(compressionMode=DUMMY, chunkSize=361), termVectorsFormat=CompressingTermVectorsFormat(compressionMode=DUMMY, chunkSize=361)), sim=RandomSimilarityProvider(queryNorm=false,coord=no): {}, locale=sr_BA, timezone=Brazil/West
   [junit4]   2> NOTE: Mac OS X 10.8.4 x86_64/Oracle Corporation 1.7.0_40 (64-bit)/cpus=2,threads=1,free=115575752,total=519045120
   [junit4]   2> NOTE: All tests run in this JVM: [ShardRoutingTest, TestQuerySenderListener, TestRecoveryHdfs, TestAnalyzeInfixSuggestions, JSONWriterTest, OutputWriterTest, PreAnalyzedUpdateProcessorTest, BadIndexSchemaTest, TestDefaultSimilarityFactory, TestSchemaSimilarityResource, TestRandomMergePolicy, DirectSolrConnectionTest, PingRequestHandlerTest, SliceStateUpdateTest, StatsComponentTest, MBeansHandlerTest, TestSolrDeletionPolicy1, SortByFunctionTest, TestCloudManagedSchema, TestFoldingMultitermQuery, MinimalSchemaTest, TestFunctionQuery, SuggesterTSTTest, DeleteShardTest, TestRangeQuery, SpellingQueryConverterTest, RecoveryZkTest, UpdateRequestProcessorFactoryTest, QueryEqualityTest, JsonLoaderTest, AliasIntegrationTest, HighlighterConfigTest, TestIndexingPerformance, TestReplicationHandler, DocValuesTest, HdfsBasicDistributedZk2Test, IndexSchemaTest, TestQueryTypes, TestArbitraryIndexDir, LeaderElectionTest, TestNRTOpen, DocumentAnalysisRequestHandlerTest, TestConfig, SampleTest, TestValueSourceCache, TestDynamicFieldCollectionResource, DocumentBuilderTest, SolrRequestParserTest, DistributedTermsComponentTest, TestStressReorder, URLClassifyProcessorTest, HighlighterTest, BasicFunctionalityTest, FieldAnalysisRequestHandlerTest, InfoHandlerTest, StatelessScriptUpdateProcessorFactoryTest, PolyFieldTest, LeaderElectionIntegrationTest, TestJoin, TestNonNRTOpen, DistributedQueryElevationComponentTest, AutoCommitTest, TestAddFieldRealTimeGet, SuggesterFSTTest, BlockCacheTest, TestBinaryField, TestIBSimilarityFactory, TestReload, QueryParsingTest, ResourceLoaderTest, TestExtendedDismaxParser, TestRealTimeGet, SynonymTokenizerTest, LukeRequestHandlerTest, TestLRUCache, SchemaVersionSpecificBehaviorTest, TestReloadAndDeleteDocs, TestIndexSearcher, TestSolrQueryParserResource, RAMDirectoryFactoryTest, ChaosMonkeySafeLeaderTest, SyncSliceTest, DistributedSpellCheckComponentTest, FieldMutatingUpdateProcessorTest, TestReversedWildcardFilterFactory, TestPHPSerializedResponseWriter, BadCopyFieldTest, TestNumberUtils, TestPerFieldSimilarity, TestMultiCoreConfBootstrap, DefaultValueUpdateProcessorTest, BasicDistributedZkTest, TestPostingsSolrHighlighter, OverseerCollectionProcessorTest, AddBlockUpdateTest, HdfsDirectoryTest, SolrTestCaseJ4Test, BJQParserTest, TestShardHandlerFactory, SolrInfoMBeanTest, TestQuerySenderNoQuery, TestSort, CSVRequestHandlerTest, TestBinaryResponseWriter, SolrCoreTest, ReturnFieldsTest, SolrCoreCheckLockOnStartupTest, UUIDFieldTest, TestSolr4Spatial, MoreLikeThisHandlerTest, TestSolrXmlPersistor, SolrIndexConfigTest, TestQueryUtils, TestCollationKeyRangeQueries, OpenCloseCoreStressTest, DebugComponentTest, SolrIndexSplitterTest, FullSolrCloudDistribCmdsTest, TestAtomicUpdateErrorCases, FileBasedSpellCheckerTest, SpellCheckCollatorTest, OpenExchangeRatesOrgProviderTest, TestRecovery, ZkNodePropsTest, TestFieldCollectionResource, TestZkChroot, TestSuggestSpellingConverter, ScriptEngineTest, CollectionsAPIDistributedZkTest]
   [junit4] Completed in 186.71s, 1 test, 1 failure <<< FAILURES!

[...truncated 598 lines...]
BUILD FAILED
/Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/build.xml:428: The following error occurred while executing this line:
/Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/build.xml:408: The following error occurred while executing this line:
/Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/build.xml:39: The following error occurred while executing this line:
/Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build.xml:189: The following error occurred while executing this line:
/Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/common-build.xml:451: The following error occurred while executing this line:
/Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/lucene/common-build.xml:1233: The following error occurred while executing this line:
/Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/lucene/common-build.xml:876: There were test failures: 327 suites, 1453 tests, 1 failure, 39 ignored (5 assumptions)

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