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

[JENKINS] Lucene-Solr-trunk-Linux (32bit/jdk1.7.0_60-ea-b02) - Build # 9074 - Failure!

Build: http://jenkins.thetaphi.de/job/Lucene-Solr-trunk-Linux/9074/
Java: 32bit/jdk1.7.0_60-ea-b02 -server -XX:+UseSerialGC

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

Error Message:


Stack Trace:
java.lang.AssertionError
	at __randomizedtesting.SeedInfo.seed([6EBE629241AC666D:EF58EC8A36F30651]: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.deleteCollectionWithDownNodes(CollectionsAPIDistributedZkTest.java:390)
	at org.apache.solr.cloud.CollectionsAPIDistributedZkTest.doTest(CollectionsAPIDistributedZkTest.java:203)
	at org.apache.solr.BaseDistributedSearchTestCase.testDistribSearch(BaseDistributedSearchTestCase.java:867)
	at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
	at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:57)
	at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
	at java.lang.reflect.Method.invoke(Method.java:606)
	at com.carrotsearch.randomizedtesting.RandomizedRunner.invoke(RandomizedRunner.java:1559)
	at com.carrotsearch.randomizedtesting.RandomizedRunner.access$600(RandomizedRunner.java:79)
	at com.carrotsearch.randomizedtesting.RandomizedRunner$6.evaluate(RandomizedRunner.java:737)
	at com.carrotsearch.randomizedtesting.RandomizedRunner$7.evaluate(RandomizedRunner.java:773)
	at com.carrotsearch.randomizedtesting.RandomizedRunner$8.evaluate(RandomizedRunner.java:787)
	at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:53)
	at org.apache.lucene.util.TestRuleSetupTeardownChained$1.evaluate(TestRuleSetupTeardownChained.java:50)
	at org.apache.lucene.util.TestRuleFieldCacheSanity$1.evaluate(TestRuleFieldCacheSanity.java:51)
	at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:46)
	at com.carrotsearch.randomizedtesting.rules.SystemPropertiesInvariantRule$1.evaluate(SystemPropertiesInvariantRule.java:55)
	at org.apache.lucene.util.TestRuleThreadAndTestName$1.evaluate(TestRuleThreadAndTestName.java:49)
	at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:70)
	at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:48)
	at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
	at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:358)
	at com.carrotsearch.randomizedtesting.ThreadLeakControl.forkTimeoutingTask(ThreadLeakControl.java:782)
	at com.carrotsearch.randomizedtesting.ThreadLeakControl$3.evaluate(ThreadLeakControl.java:442)
	at com.carrotsearch.randomizedtesting.RandomizedRunner.runSingleTest(RandomizedRunner.java:746)
	at com.carrotsearch.randomizedtesting.RandomizedRunner$3.evaluate(RandomizedRunner.java:648)
	at com.carrotsearch.randomizedtesting.RandomizedRunner$4.evaluate(RandomizedRunner.java:682)
	at com.carrotsearch.randomizedtesting.RandomizedRunner$5.evaluate(RandomizedRunner.java:693)
	at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
	at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:53)
	at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:46)
	at org.apache.lucene.util.TestRuleStoreClassName$1.evaluate(TestRuleStoreClassName.java:42)
	at com.carrotsearch.randomizedtesting.rules.SystemPropertiesInvariantRule$1.evaluate(SystemPropertiesInvariantRule.java:55)
	at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:39)
	at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:39)
	at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
	at org.apache.lucene.util.TestRuleAssertionsRequired$1.evaluate(TestRuleAssertionsRequired.java:43)
	at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:48)
	at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:70)
	at org.apache.lucene.util.TestRuleIgnoreTestSuites$1.evaluate(TestRuleIgnoreTestSuites.java:55)
	at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
	at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:358)
	at java.lang.Thread.run(Thread.java:744)


REGRESSION:  org.apache.solr.cloud.OverseerTest.testDoubleAssignment

Error Message:
Illegal state, was:null expected:recoveringclusterState:live nodes:[node1] collections:{}

Stack Trace:
java.lang.AssertionError: Illegal state, was:null expected:recoveringclusterState:live nodes:[node1] collections:{}
	at __randomizedtesting.SeedInfo.seed([6EBE629241AC666D:2EFB31790AF1733B]:0)
	at org.junit.Assert.fail(Assert.java:93)
	at org.apache.solr.cloud.OverseerTest.verifyStatus(OverseerTest.java:509)
	at org.apache.solr.cloud.OverseerTest.testDoubleAssignment(OverseerTest.java:732)
	at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
	at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:57)
	at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
	at java.lang.reflect.Method.invoke(Method.java:606)
	at com.carrotsearch.randomizedtesting.RandomizedRunner.invoke(RandomizedRunner.java:1559)
	at com.carrotsearch.randomizedtesting.RandomizedRunner.access$600(RandomizedRunner.java:79)
	at com.carrotsearch.randomizedtesting.RandomizedRunner$6.evaluate(RandomizedRunner.java:737)
	at com.carrotsearch.randomizedtesting.RandomizedRunner$7.evaluate(RandomizedRunner.java:773)
	at com.carrotsearch.randomizedtesting.RandomizedRunner$8.evaluate(RandomizedRunner.java:787)
	at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:53)
	at org.apache.lucene.util.TestRuleSetupTeardownChained$1.evaluate(TestRuleSetupTeardownChained.java:50)
	at org.apache.lucene.util.TestRuleFieldCacheSanity$1.evaluate(TestRuleFieldCacheSanity.java:51)
	at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:46)
	at com.carrotsearch.randomizedtesting.rules.SystemPropertiesInvariantRule$1.evaluate(SystemPropertiesInvariantRule.java:55)
	at org.apache.lucene.util.TestRuleThreadAndTestName$1.evaluate(TestRuleThreadAndTestName.java:49)
	at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:70)
	at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:48)
	at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
	at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:358)
	at com.carrotsearch.randomizedtesting.ThreadLeakControl.forkTimeoutingTask(ThreadLeakControl.java:782)
	at com.carrotsearch.randomizedtesting.ThreadLeakControl$3.evaluate(ThreadLeakControl.java:442)
	at com.carrotsearch.randomizedtesting.RandomizedRunner.runSingleTest(RandomizedRunner.java:746)
	at com.carrotsearch.randomizedtesting.RandomizedRunner$3.evaluate(RandomizedRunner.java:648)
	at com.carrotsearch.randomizedtesting.RandomizedRunner$4.evaluate(RandomizedRunner.java:682)
	at com.carrotsearch.randomizedtesting.RandomizedRunner$5.evaluate(RandomizedRunner.java:693)
	at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
	at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:53)
	at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:46)
	at org.apache.lucene.util.TestRuleStoreClassName$1.evaluate(TestRuleStoreClassName.java:42)
	at com.carrotsearch.randomizedtesting.rules.SystemPropertiesInvariantRule$1.evaluate(SystemPropertiesInvariantRule.java:55)
	at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:39)
	at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:39)
	at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
	at org.apache.lucene.util.TestRuleAssertionsRequired$1.evaluate(TestRuleAssertionsRequired.java:43)
	at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:48)
	at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:70)
	at org.apache.lucene.util.TestRuleIgnoreTestSuites$1.evaluate(TestRuleIgnoreTestSuites.java:55)
	at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
	at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:358)
	at java.lang.Thread.run(Thread.java:744)




Build Log:
[...truncated 10485 lines...]
   [junit4] Suite: org.apache.solr.cloud.CollectionsAPIDistributedZkTest
   [junit4]   2> 585257 T2184 oas.BaseDistributedSearchTestCase.initHostContext Setting hostContext system property: /ho/
   [junit4]   2> 585261 T2184 oas.SolrTestCaseJ4.setUp ###Starting testDistribSearch
   [junit4]   2> Creating dataDir: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./solrtest-CollectionsAPIDistributedZkTest-1389595059076
   [junit4]   2> 585262 T2184 oasc.ZkTestServer.run STARTING ZK TEST SERVER
   [junit4]   2> 585263 T2185 oasc.ZkTestServer$ZKServerMain.runFromConfig Starting server
   [junit4]   2> 585363 T2184 oasc.ZkTestServer.run start zk server on port:42790
   [junit4]   2> 585364 T2184 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 585563 T2191 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@4546cf name:ZooKeeperConnection Watcher:127.0.0.1:42790 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 585564 T2184 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 585564 T2184 oascc.SolrZkClient.makePath makePath: /solr
   [junit4]   2> 585568 T2184 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 585569 T2193 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@1cdd665 name:ZooKeeperConnection Watcher:127.0.0.1:42790/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 585569 T2184 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 585570 T2184 oascc.SolrZkClient.makePath makePath: /collections/collection1
   [junit4]   2> 585573 T2184 oascc.SolrZkClient.makePath makePath: /collections/collection1/shards
   [junit4]   2> 585576 T2184 oascc.SolrZkClient.makePath makePath: /collections/control_collection
   [junit4]   2> 585578 T2184 oascc.SolrZkClient.makePath makePath: /collections/control_collection/shards
   [junit4]   2> 585580 T2184 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test-files/solr/collection1/conf/solrconfig-tlog.xml to /configs/conf1/solrconfig.xml
   [junit4]   2> 585580 T2184 oascc.SolrZkClient.makePath makePath: /configs/conf1/solrconfig.xml
   [junit4]   2> 585584 T2184 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test-files/solr/collection1/conf/schema.xml to /configs/conf1/schema.xml
   [junit4]   2> 585584 T2184 oascc.SolrZkClient.makePath makePath: /configs/conf1/schema.xml
   [junit4]   2> 585587 T2184 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test-files/solr/collection1/conf/solrconfig.snippet.randomindexconfig.xml to /configs/conf1/solrconfig.snippet.randomindexconfig.xml
   [junit4]   2> 585588 T2184 oascc.SolrZkClient.makePath makePath: /configs/conf1/solrconfig.snippet.randomindexconfig.xml
   [junit4]   2> 585590 T2184 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test-files/solr/collection1/conf/stopwords.txt to /configs/conf1/stopwords.txt
   [junit4]   2> 585590 T2184 oascc.SolrZkClient.makePath makePath: /configs/conf1/stopwords.txt
   [junit4]   2> 585593 T2184 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test-files/solr/collection1/conf/protwords.txt to /configs/conf1/protwords.txt
   [junit4]   2> 585593 T2184 oascc.SolrZkClient.makePath makePath: /configs/conf1/protwords.txt
   [junit4]   2> 585596 T2184 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test-files/solr/collection1/conf/currency.xml to /configs/conf1/currency.xml
   [junit4]   2> 585596 T2184 oascc.SolrZkClient.makePath makePath: /configs/conf1/currency.xml
   [junit4]   2> 585598 T2184 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test-files/solr/collection1/conf/enumsConfig.xml to /configs/conf1/enumsConfig.xml
   [junit4]   2> 585598 T2184 oascc.SolrZkClient.makePath makePath: /configs/conf1/enumsConfig.xml
   [junit4]   2> 585601 T2184 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test-files/solr/collection1/conf/open-exchange-rates.json to /configs/conf1/open-exchange-rates.json
   [junit4]   2> 585601 T2184 oascc.SolrZkClient.makePath makePath: /configs/conf1/open-exchange-rates.json
   [junit4]   2> 585604 T2184 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test-files/solr/collection1/conf/mapping-ISOLatin1Accent.txt to /configs/conf1/mapping-ISOLatin1Accent.txt
   [junit4]   2> 585604 T2184 oascc.SolrZkClient.makePath makePath: /configs/conf1/mapping-ISOLatin1Accent.txt
   [junit4]   2> 585606 T2184 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test-files/solr/collection1/conf/old_synonyms.txt to /configs/conf1/old_synonyms.txt
   [junit4]   2> 585607 T2184 oascc.SolrZkClient.makePath makePath: /configs/conf1/old_synonyms.txt
   [junit4]   2> 585609 T2184 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test-files/solr/collection1/conf/synonyms.txt to /configs/conf1/synonyms.txt
   [junit4]   2> 585609 T2184 oascc.SolrZkClient.makePath makePath: /configs/conf1/synonyms.txt
   [junit4]   2> Using old style solr.xml
   [junit4]   2> 585612 T2184 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 585613 T2195 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@be45f5 name:ZooKeeperConnection Watcher:127.0.0.1:42790 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 585613 T2184 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 585613 T2184 oascc.SolrZkClient.makePath makePath: /solr
   [junit4]   2> 585616 T2184 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 585617 T2197 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@84bca6 name:ZooKeeperConnection Watcher:127.0.0.1:42790/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 585617 T2184 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 585617 T2184 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test-files/solr/collection1/conf/solrconfig.xml to /configs/conf2/solrconfig.xml
   [junit4]   2> 585618 T2184 oascc.SolrZkClient.makePath makePath: /configs/conf2/solrconfig.xml
   [junit4]   2> 585621 T2184 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test-files/solr/collection1/conf/schema.xml to /configs/conf2/schema.xml
   [junit4]   2> 585622 T2184 oascc.SolrZkClient.makePath makePath: /configs/conf2/schema.xml
   [junit4]   2> 585625 T2184 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test-files/solr/collection1/conf/solrconfig.snippet.randomindexconfig.xml to /configs/conf2/solrconfig.snippet.randomindexconfig.xml
   [junit4]   2> 585626 T2184 oascc.SolrZkClient.makePath makePath: /configs/conf2/solrconfig.snippet.randomindexconfig.xml
   [junit4]   2> 585628 T2184 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test-files/solr/collection1/conf/stopwords.txt to /configs/conf2/stopwords.txt
   [junit4]   2> 585628 T2184 oascc.SolrZkClient.makePath makePath: /configs/conf2/stopwords.txt
   [junit4]   2> 585630 T2184 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test-files/solr/collection1/conf/protwords.txt to /configs/conf2/protwords.txt
   [junit4]   2> 585630 T2184 oascc.SolrZkClient.makePath makePath: /configs/conf2/protwords.txt
   [junit4]   2> 585632 T2184 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test-files/solr/collection1/conf/currency.xml to /configs/conf2/currency.xml
   [junit4]   2> 585633 T2184 oascc.SolrZkClient.makePath makePath: /configs/conf2/currency.xml
   [junit4]   2> 585635 T2184 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test-files/solr/collection1/conf/open-exchange-rates.json to /configs/conf2/open-exchange-rates.json
   [junit4]   2> 585635 T2184 oascc.SolrZkClient.makePath makePath: /configs/conf2/open-exchange-rates.json
   [junit4]   2> 585637 T2184 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test-files/solr/collection1/conf/mapping-ISOLatin1Accent.txt to /configs/conf2/mapping-ISOLatin1Accent.txt
   [junit4]   2> 585637 T2184 oascc.SolrZkClient.makePath makePath: /configs/conf2/mapping-ISOLatin1Accent.txt
   [junit4]   2> 585640 T2184 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test-files/solr/collection1/conf/old_synonyms.txt to /configs/conf2/old_synonyms.txt
   [junit4]   2> 585640 T2184 oascc.SolrZkClient.makePath makePath: /configs/conf2/old_synonyms.txt
   [junit4]   2> 585642 T2184 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test-files/solr/collection1/conf/synonyms.txt to /configs/conf2/synonyms.txt
   [junit4]   2> 585642 T2184 oascc.SolrZkClient.makePath makePath: /configs/conf2/synonyms.txt
   [junit4]   2> 585645 T2184 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test-files/solr/collection1/conf/elevate.xml to /configs/conf2/elevate.xml
   [junit4]   2> 585645 T2184 oascc.SolrZkClient.makePath makePath: /configs/conf2/elevate.xml
   [junit4]   2> 585735 T2184 oejs.Server.doStart jetty-8.1.10.v20130312
   [junit4]   2> 585741 T2184 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:34644
   [junit4]   2> 585742 T2184 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
   [junit4]   2> 585742 T2184 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
   [junit4]   2> 585742 T2184 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: ../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-controljetty-1389595059463
   [junit4]   2> 585742 T2184 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-controljetty-1389595059463/'
   [junit4]   2> 585753 T2184 oasc.ConfigSolr.fromFile Loading container configuration from /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-controljetty-1389595059463/solr.xml
   [junit4]   2> 585777 T2184 oasc.CoreContainer.<init> New CoreContainer 3610783
   [junit4]   2> 585777 T2184 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-controljetty-1389595059463/]
   [junit4]   2> 585778 T2184 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 120000
   [junit4]   2> 585778 T2184 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
   [junit4]   2> 585778 T2184 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
   [junit4]   2> 585779 T2184 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
   [junit4]   2> 585779 T2184 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
   [junit4]   2> 585779 T2184 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
   [junit4]   2> 585779 T2184 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
   [junit4]   2> 585780 T2184 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
   [junit4]   2> 585780 T2184 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
   [junit4]   2> 585782 T2184 oasl.LogWatcher.createWatcher SLF4J impl is org.slf4j.impl.Log4jLoggerFactory
   [junit4]   2> 585782 T2184 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
   [junit4]   2> 585783 T2184 oasc.CoreContainer.load Host Name: 127.0.0.1
   [junit4]   2> 585783 T2184 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:42790/solr
   [junit4]   2> 585783 T2184 oasc.ZkController.checkChrootPath zkHost includes chroot
   [junit4]   2> 585784 T2184 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 585785 T2208 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@1318773 name:ZooKeeperConnection Watcher:127.0.0.1:42790 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 585786 T2184 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 585788 T2184 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 585789 T2210 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@1fa596 name:ZooKeeperConnection Watcher:127.0.0.1:42790/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 585789 T2184 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 585791 T2184 oascc.SolrZkClient.makePath makePath: /overseer/queue
   [junit4]   2> 585794 T2184 oascc.SolrZkClient.makePath makePath: /overseer/collection-queue-work
   [junit4]   2> 585796 T2184 oascc.SolrZkClient.makePath makePath: /live_nodes
   [junit4]   2> 585798 T2184 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:34644_ho
   [junit4]   2> 585799 T2184 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:34644_ho
   [junit4]   2> 585801 T2184 oascc.SolrZkClient.makePath makePath: /overseer_elect
   [junit4]   2> 585804 T2184 oascc.SolrZkClient.makePath makePath: /overseer_elect/election
   [junit4]   2> 585809 T2184 oascc.SolrZkClient.makePath makePath: /overseer_elect/leader
   [junit4]   2> 585811 T2184 oasc.Overseer.start Overseer (id=91068501791735813-127.0.0.1:34644_ho-n_0000000000) starting
   [junit4]   2> 585814 T2184 oascc.SolrZkClient.makePath makePath: /overseer/queue-work
   [junit4]   2> 585817 T2212 oasc.OverseerCollectionProcessor.run Process current queue of collection creations
   [junit4]   2> 585818 T2184 oascc.SolrZkClient.makePath makePath: /clusterstate.json
   [junit4]   2> 585820 T2184 oascc.SolrZkClient.makePath makePath: /aliases.json
   [junit4]   2> 585822 T2184 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
   [junit4]   2> 585824 T2211 oasc.Overseer$ClusterStateUpdater.run Starting to work on the main queue
   [junit4]   2> 585825 T2184 oass.SolrDispatchFilter.init user.dir=/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1
   [junit4]   2> 585825 T2184 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
   [junit4]   2> 585826 T2184 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 585827 T2215 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@1aa0c42 name:ZooKeeperConnection Watcher:127.0.0.1:42790/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 585828 T2184 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 585829 T2184 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
   [junit4]   2> 585831 T2184 oasc.ChaosMonkey.monkeyLog monkey: init - expire sessions:false cause connection loss:false
   [junit4]   2> 585897 T2184 oejs.Server.doStart jetty-8.1.10.v20130312
   [junit4]   2> 585899 T2184 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:52305
   [junit4]   2> 585900 T2184 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
   [junit4]   2> 585901 T2184 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
   [junit4]   2> 585901 T2184 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: ../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty1-1389595059645
   [junit4]   2> 585901 T2184 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty1-1389595059645/'
   [junit4]   2> 585925 T2184 oasc.ConfigSolr.fromFile Loading container configuration from /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty1-1389595059645/solr.xml
   [junit4]   2> 585960 T2184 oasc.CoreContainer.<init> New CoreContainer 13902234
   [junit4]   2> 585961 T2184 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty1-1389595059645/]
   [junit4]   2> 585962 T2184 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 120000
   [junit4]   2> 585963 T2184 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
   [junit4]   2> 585963 T2184 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
   [junit4]   2> 585964 T2184 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
   [junit4]   2> 585964 T2184 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
   [junit4]   2> 585964 T2184 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
   [junit4]   2> 585965 T2184 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
   [junit4]   2> 585965 T2184 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
   [junit4]   2> 585966 T2184 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
   [junit4]   2> 585969 T2184 oasl.LogWatcher.createWatcher SLF4J impl is org.slf4j.impl.Log4jLoggerFactory
   [junit4]   2> 585969 T2184 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
   [junit4]   2> 585970 T2184 oasc.CoreContainer.load Host Name: 127.0.0.1
   [junit4]   2> 585970 T2184 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:42790/solr
   [junit4]   2> 585971 T2184 oasc.ZkController.checkChrootPath zkHost includes chroot
   [junit4]   2> 585972 T2184 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 585973 T2226 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@ea208e name:ZooKeeperConnection Watcher:127.0.0.1:42790 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 585974 T2184 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 585976 T2184 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 585977 T2228 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@57e7dc name:ZooKeeperConnection Watcher:127.0.0.1:42790/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 585977 T2184 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 585980 T2184 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
   [junit4]   2> 586983 T2184 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:52305_ho
   [junit4]   2> 586984 T2184 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:52305_ho
   [junit4]   2> 586989 T2215 oascc.ZkStateReader$3.process Updating live nodes... (2)
   [junit4]   2> 586989 T2210 oascc.ZkStateReader$3.process Updating live nodes... (2)
   [junit4]   2> 586989 T2228 oascc.ZkStateReader$3.process Updating live nodes... (2)
   [junit4]   2> 586997 T2184 oass.SolrDispatchFilter.init user.dir=/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1
   [junit4]   2> 586997 T2184 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
   [junit4]   2> 587061 T2184 oejs.Server.doStart jetty-8.1.10.v20130312
   [junit4]   2> 587063 T2184 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:50282
   [junit4]   2> 587064 T2184 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
   [junit4]   2> 587064 T2184 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
   [junit4]   2> 587064 T2184 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: ./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty2-1389595060812
   [junit4]   2> 587064 T2184 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: './org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty2-1389595060812/'
   [junit4]   2> 587074 T2184 oasc.ConfigSolr.fromFile Loading container configuration from /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty2-1389595060812/solr.xml
   [junit4]   2> 587102 T2184 oasc.CoreContainer.<init> New CoreContainer 20625029
   [junit4]   2> 587103 T2184 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty2-1389595060812/]
   [junit4]   2> 587104 T2184 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 120000
   [junit4]   2> 587104 T2184 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
   [junit4]   2> 587104 T2184 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
   [junit4]   2> 587104 T2184 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
   [junit4]   2> 587105 T2184 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
   [junit4]   2> 587105 T2184 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
   [junit4]   2> 587105 T2184 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
   [junit4]   2> 587105 T2184 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
   [junit4]   2> 587106 T2184 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
   [junit4]   2> 587108 T2184 oasl.LogWatcher.createWatcher SLF4J impl is org.slf4j.impl.Log4jLoggerFactory
   [junit4]   2> 587108 T2184 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
   [junit4]   2> 587108 T2184 oasc.CoreContainer.load Host Name: 127.0.0.1
   [junit4]   2> 587109 T2184 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:42790/solr
   [junit4]   2> 587109 T2184 oasc.ZkController.checkChrootPath zkHost includes chroot
   [junit4]   2> 587110 T2184 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 587111 T2240 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@1a50387 name:ZooKeeperConnection Watcher:127.0.0.1:42790 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 587111 T2184 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 587114 T2184 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 587115 T2242 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@aa735 name:ZooKeeperConnection Watcher:127.0.0.1:42790/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 587115 T2184 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 587118 T2184 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
   [junit4]   2> 588121 T2184 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:50282_ho
   [junit4]   2> 588122 T2184 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:50282_ho
   [junit4]   2> 588125 T2228 oascc.ZkStateReader$3.process Updating live nodes... (3)
   [junit4]   2> 588125 T2242 oascc.ZkStateReader$3.process Updating live nodes... (3)
   [junit4]   2> 588125 T2215 oascc.ZkStateReader$3.process Updating live nodes... (3)
   [junit4]   2> 588126 T2210 oascc.ZkStateReader$3.process Updating live nodes... (3)
   [junit4]   2> 588130 T2184 oass.SolrDispatchFilter.init user.dir=/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1
   [junit4]   2> 588130 T2184 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
   [junit4]   2> 588202 T2184 oejs.Server.doStart jetty-8.1.10.v20130312
   [junit4]   2> 588204 T2184 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:37452
   [junit4]   2> 588204 T2184 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
   [junit4]   2> 588205 T2184 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
   [junit4]   2> 588205 T2184 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: ./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty3-1389595061944
   [junit4]   2> 588205 T2184 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: './org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty3-1389595061944/'
   [junit4]   2> 588215 T2184 oasc.ConfigSolr.fromFile Loading container configuration from /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty3-1389595061944/solr.xml
   [junit4]   2> 588244 T2184 oasc.CoreContainer.<init> New CoreContainer 16228656
   [junit4]   2> 588245 T2184 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty3-1389595061944/]
   [junit4]   2> 588246 T2184 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 120000
   [junit4]   2> 588246 T2184 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
   [junit4]   2> 588246 T2184 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
   [junit4]   2> 588247 T2184 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
   [junit4]   2> 588247 T2184 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
   [junit4]   2> 588247 T2184 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
   [junit4]   2> 588248 T2184 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
   [junit4]   2> 588248 T2184 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
   [junit4]   2> 588248 T2184 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
   [junit4]   2> 588251 T2184 oasl.LogWatcher.createWatcher SLF4J impl is org.slf4j.impl.Log4jLoggerFactory
   [junit4]   2> 588251 T2184 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
   [junit4]   2> 588251 T2184 oasc.CoreContainer.load Host Name: 127.0.0.1
   [junit4]   2> 588252 T2184 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:42790/solr
   [junit4]   2> 588252 T2184 oasc.ZkController.checkChrootPath zkHost includes chroot
   [junit4]   2> 588253 T2184 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 588256 T2254 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@17758dc name:ZooKeeperConnection Watcher:127.0.0.1:42790 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 588256 T2184 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 588259 T2184 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 588260 T2256 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@1d44648 name:ZooKeeperConnection Watcher:127.0.0.1:42790/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 588260 T2184 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 588265 T2184 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
   [junit4]   2> 589268 T2184 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:37452_ho
   [junit4]   2> 589269 T2184 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:37452_ho
   [junit4]   2> 589272 T2256 oascc.ZkStateReader$3.process Updating live nodes... (4)
   [junit4]   2> 589272 T2215 oascc.ZkStateReader$3.process Updating live nodes... (4)
   [junit4]   2> 589272 T2242 oascc.ZkStateReader$3.process Updating live nodes... (4)
   [junit4]   2> 589272 T2210 oascc.ZkStateReader$3.process Updating live nodes... (4)
   [junit4]   2> 589272 T2228 oascc.ZkStateReader$3.process Updating live nodes... (4)
   [junit4]   2> 589278 T2184 oass.SolrDispatchFilter.init user.dir=/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1
   [junit4]   2> 589278 T2184 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
   [junit4]   2> 589341 T2184 oejs.Server.doStart jetty-8.1.10.v20130312
   [junit4]   2> 589343 T2184 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:42153
   [junit4]   2> 589344 T2184 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
   [junit4]   2> 589344 T2184 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
   [junit4]   2> 589344 T2184 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: ../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1389595063092
   [junit4]   2> 589345 T2184 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1389595063092/'
   [junit4]   2> 589357 T2184 oasc.ConfigSolr.fromFile Loading container configuration from /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1389595063092/solr.xml
   [junit4]   2> 589388 T2184 oasc.CoreContainer.<init> New CoreContainer 18811234
   [junit4]   2> 589388 T2184 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1389595063092/]
   [junit4]   2> 589389 T2184 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 120000
   [junit4]   2> 589390 T2184 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
   [junit4]   2> 589390 T2184 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
   [junit4]   2> 589390 T2184 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
   [junit4]   2> 589391 T2184 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
   [junit4]   2> 589391 T2184 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
   [junit4]   2> 589391 T2184 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
   [junit4]   2> 589392 T2184 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
   [junit4]   2> 589392 T2184 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
   [junit4]   2> 589395 T2184 oasl.LogWatcher.createWatcher SLF4J impl is org.slf4j.impl.Log4jLoggerFactory
   [junit4]   2> 589395 T2184 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
   [junit4]   2> 589395 T2184 oasc.CoreContainer.load Host Name: 127.0.0.1
   [junit4]   2> 589396 T2184 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:42790/solr
   [junit4]   2> 589396 T2184 oasc.ZkController.checkChrootPath zkHost includes chroot
   [junit4]   2> 589397 T2184 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 589399 T2268 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@a131b7 name:ZooKeeperConnection Watcher:127.0.0.1:42790 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 589400 T2184 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 589403 T2184 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 589404 T2270 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@616947 name:ZooKeeperConnection Watcher:127.0.0.1:42790/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 589404 T2184 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 589408 T2184 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
   [junit4]   2> 590411 T2184 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:42153_ho
   [junit4]   2> 590412 T2184 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:42153_ho
   [junit4]   2> 590415 T2215 oascc.ZkStateReader$3.process Updating live nodes... (5)
   [junit4]   2> 590415 T2256 oascc.ZkStateReader$3.process Updating live nodes... (5)
   [junit4]   2> 590415 T2228 oascc.ZkStateReader$3.process Updating live nodes... (5)
   [junit4]   2> 590415 T2242 oascc.ZkStateReader$3.process Updating live nodes... (5)
   [junit4]   2> 590415 T2210 oascc.ZkStateReader$3.process Updating live nodes... (5)
   [junit4]   2> 590416 T2270 oascc.ZkStateReader$3.process Updating live nodes... (5)
   [junit4]   2> 590420 T2184 oass.SolrDispatchFilter.init user.dir=/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1
   [junit4]   2> 590420 T2184 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
   [junit4]   2> 590423 T2222 oasha.CollectionsHandler.handleCreateAction Creating Collection : router.name=compositeId&numShards=2&wt=javabin&replicationFactor=2&version=2&router.field=myOwnField&collection.configName=conf1&action=CREATE&name=solrj_collection
   [junit4]   2> 590424 T2210 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/collection-queue-work state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 590426 T2212 oasc.OverseerCollectionProcessor.run Overseer Collection Processor: Get the message id:/overseer/collection-queue-work/qn-0000000000 message:{
   [junit4]   2> 	  "operation":"createcollection",
   [junit4]   2> 	  "fromApi":"true",
   [junit4]   2> 	  "name":"solrj_collection",
   [junit4]   2> 	  "replicationFactor":"2",
   [junit4]   2> 	  "collection.configName":"conf1",
   [junit4]   2> 	  "numShards":"2",
   [junit4]   2> 	  "router.name":"compositeId",
   [junit4]   2> 	  "router.field":"myOwnField"}
   [junit4]   2> 590426 T2212 oasc.OverseerCollectionProcessor.processMessage WARN OverseerCollectionProcessor.processMessage : createcollection , {
   [junit4]   2> 	  "operation":"createcollection",
   [junit4]   2> 	  "fromApi":"true",
   [junit4]   2> 	  "name":"solrj_collection",
   [junit4]   2> 	  "replicationFactor":"2",
   [junit4]   2> 	  "collection.configName":"conf1",
   [junit4]   2> 	  "numShards":"2",
   [junit4]   2> 	  "router.name":"compositeId",
   [junit4]   2> 	  "router.field":"myOwnField"}
   [junit4]   2> 590426 T2212 oasc.OverseerCollectionProcessor.createConfNode creating collections conf node /collections/solrj_collection 
   [junit4]   2> 590426 T2212 oascc.SolrZkClient.makePath makePath: /collections/solrj_collection
   [junit4]   2> 590429 T2210 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 590430 T2211 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 590431 T2211 oasc.Overseer$ClusterStateUpdater.buildCollection building a new collection: solrj_collection
   [junit4]   2> 590431 T2211 oasc.Overseer$ClusterStateUpdater.createCollection Create collection solrj_collection with shards [shard1, shard2]
   [junit4]   2> 590433 T2210 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 590433 T2210 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> 590433 T2242 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> 590434 T2270 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> 590434 T2215 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> 590433 T2256 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> 590433 T2228 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> 590530 T2212 oasc.OverseerCollectionProcessor.createCollection going to create cores replicas shardNames [shard1, shard2] , repFactor : 2
   [junit4]   2> 590530 T2212 oasc.OverseerCollectionProcessor.createCollection Creating shard solrj_collection_shard1_replica1 as part of slice shard1 of collection solrj_collection on 127.0.0.1:52305_ho
   [junit4]   2> 590530 T2212 oasc.OverseerCollectionProcessor.createCollection Creating shard solrj_collection_shard1_replica2 as part of slice shard1 of collection solrj_collection on 127.0.0.1:34644_ho
   [junit4]   2> 590530 T2212 oasc.OverseerCollectionProcessor.createCollection Creating shard solrj_collection_shard2_replica1 as part of slice shard2 of collection solrj_collection on 127.0.0.1:42153_ho
   [junit4]   2> 590531 T2212 oasc.OverseerCollectionProcessor.createCollection Creating shard solrj_collection_shard2_replica2 as part of slice shard2 of collection solrj_collection on 127.0.0.1:50282_ho
   [junit4]   2> 590533 T2224 oasc.ZkController.publish publishing core=solrj_collection_shard1_replica1 state=down
   [junit4]   2> 590533 T2265 oasc.ZkController.publish publishing core=solrj_collection_shard2_replica1 state=down
   [junit4]   2> 590533 T2235 oasc.ZkController.publish publishing core=solrj_collection_shard2_replica2 state=down
   [junit4]   2> 590534 T2204 oasc.ZkController.publish publishing core=solrj_collection_shard1_replica2 state=down
   [junit4]   2> 590535 T2210 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 590535 T2224 oasc.ZkController.waitForCoreNodeName look for our core node name
   [junit4]   2> 590535 T2265 oasc.ZkController.waitForCoreNodeName look for our core node name
   [junit4]   2> 590536 T2235 oasc.ZkController.waitForCoreNodeName look for our core node name
   [junit4]   2> 590536 T2204 oasc.ZkController.waitForCoreNodeName look for our core node name
   [junit4]   2> 590537 T2211 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 590537 T2211 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:52305/ho",
   [junit4]   2> 	  "core":"solrj_collection_shard1_replica1",
   [junit4]   2> 	  "roles":null,
   [junit4]   2> 	  "node_name":"127.0.0.1:52305_ho",
   [junit4]   2> 	  "shard":"shard1",
   [junit4]   2> 	  "shard_range":null,
   [junit4]   2> 	  "shard_state":"active",
   [junit4]   2> 	  "shard_parent":null,
   [junit4]   2> 	  "collection":"solrj_collection",
   [junit4]   2> 	  "numShards":"2",
   [junit4]   2> 	  "core_node_name":null}
   [junit4]   2> 590539 T2210 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 590540 T2211 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:42153/ho",
   [junit4]   2> 	  "core":"solrj_collection_shard2_replica1",
   [junit4]   2> 	  "roles":null,
   [junit4]   2> 	  "node_name":"127.0.0.1:42153_ho",
   [junit4]   2> 	  "shard":"shard2",
   [junit4]   2> 	  "shard_range":null,
   [junit4]   2> 	  "shard_state":"active",
   [junit4]   2> 	  "shard_parent":null,
   [junit4]   2> 	  "collection":"solrj_collection",
   [junit4]   2> 	  "numShards":"2",
   [junit4]   2> 	  "core_node_name":null}
   [junit4]   2> 590541 T2210 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 590542 T2211 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:50282/ho",
   [junit4]   2> 	  "core":"solrj_collection_shard2_replica2",
   [junit4]   2> 	  "roles":null,
   [junit4]   2> 	  "node_name":"127.0.0.1:50282_ho",
   [junit4]   2> 	  "shard":"shard2",
   [junit4]   2> 	  "shard_range":null,
   [junit4]   2> 	  "shard_state":"active",
   [junit4]   2> 	  "shard_parent":null,
   [junit4]   2> 	  "collection":"solrj_collection",
   [junit4]   2> 	  "numShards":"2",
   [junit4]   2> 	  "core_node_name":null}
   [junit4]   2> 590544 T2210 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 590544 T2211 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:34644/ho",
   [junit4]   2> 	  "core":"solrj_collection_shard1_replica2",
   [junit4]   2> 	  "roles":null,
   [junit4]   2> 	  "node_name":"127.0.0.1:34644_ho",
   [junit4]   2> 	  "shard":"shard1",
   [junit4]   2> 	  "shard_range":null,
   [junit4]   2> 	  "shard_state":"active",
   [junit4]   2> 	  "shard_parent":null,
   [junit4]   2> 	  "collection":"solrj_collection",
   [junit4]   2> 	  "numShards":"2",
   [junit4]   2> 	  "core_node_name":null}
   [junit4]   2> 590546 T2210 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 590649 T2210 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> 590649 T2242 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> 590649 T2270 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> 590649 T2215 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> 590649 T2256 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> 590649 T2228 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> 591535 T2224 oasc.ZkController.waitForShardId waiting to find shard id in clusterstate for solrj_collection_shard1_replica1
   [junit4]   2> 591536 T2265 oasc.ZkController.waitForShardId waiting to find shard id in clusterstate for solrj_collection_shard2_replica1
   [junit4]   2> 591536 T2235 oasc.ZkController.waitForShardId waiting to find shard id in clusterstate for solrj_collection_shard2_replica2
   [junit4]   2> 591536 T2265 oasc.SolrXMLCoresLocator.doPersist Persisted core descriptions to /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1389595063092/solr.xml
   [junit4]   2> 591537 T2235 oasc.SolrXMLCoresLocator.doPersist Persisted core descriptions to /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty2-1389595060812/solr.xml
   [junit4]   2> 591536 T2224 oasc.SolrXMLCoresLocator.doPersist Persisted core descriptions to /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty1-1389595059645/solr.xml
   [junit4]   2> 591537 T2235 oasc.CoreContainer.create Creating SolrCore 'solrj_collection_shard2_replica2' using instanceDir: ./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty2-1389595060812/solrj_collection_shard2_replica2
   [junit4]   2> 591537 T2265 oasc.CoreContainer.create Creating SolrCore 'solrj_collection_shard2_replica1' using instanceDir: ../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1389595063092/solrj_collection_shard2_replica1
   [junit4]   2> 591538 T2265 oasc.ZkController.createCollectionZkNode Check for collection zkNode:solrj_collection
   [junit4]   2> 591536 T2204 oasc.ZkController.waitForShardId waiting to find shard id in clusterstate for solrj_collection_shard1_replica2
   [junit4]   2> 591537 T2235 oasc.ZkController.createCollectionZkNode Check for collection zkNode:solrj_collection
   [junit4]   2> 591537 T2224 oasc.CoreContainer.create Creating SolrCore 'solrj_collection_shard1_replica1' using instanceDir: ../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty1-1389595059645/solrj_collection_shard1_replica1
   [junit4]   2> 591539 T2224 oasc.ZkController.createCollectionZkNode Check for collection zkNode:solrj_collection
   [junit4]   2> 591539 T2204 oasc.SolrXMLCoresLocator.doPersist Persisted core descriptions to /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-controljetty-1389595059463/solr.xml
   [junit4]   2> 591538 T2265 oasc.ZkController.createCollectionZkNode Collection zkNode exists
   [junit4]   2> 591539 T2204 oasc.CoreContainer.create Creating SolrCore 'solrj_collection_shard1_replica2' using instanceDir: ../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-controljetty-1389595059463/solrj_collection_shard1_replica2
   [junit4]   2> 591540 T2204 oasc.ZkController.createCollectionZkNode Check for collection zkNode:solrj_collection
   [junit4]   2> 591539 T2224 oasc.ZkController.createCollectionZkNode Collection zkNode exists
   [junit4]   2> 591539 T2235 oasc.ZkController.createCollectionZkNode Collection zkNode exists
   [junit4]   2> 591541 T2204 oasc.ZkController.createCollectionZkNode Collection zkNode exists
   [junit4]   2> 591541 T2204 oascc.ZkStateReader.readConfigName Load collection config from:/collections/solrj_collection
   [junit4]   2> 591540 T2224 oascc.ZkStateReader.readConfigName Load collection config from:/collections/solrj_collection
   [junit4]   2> 591540 T2265 oascc.ZkStateReader.readConfigName Load collection config from:/collections/solrj_collection
   [junit4]   2> 591541 T2235 oascc.ZkStateReader.readConfigName Load collection config from:/collections/solrj_collection
   [junit4]   2> 591542 T2204 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-controljetty-1389595059463/solrj_collection_shard1_replica2/'
   [junit4]   2> 591543 T2224 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty1-1389595059645/solrj_collection_shard1_replica1/'
   [junit4]   2> 591543 T2235 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: './org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty2-1389595060812/solrj_collection_shard2_replica2/'
   [junit4]   2> 591543 T2265 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1389595063092/solrj_collection_shard2_replica1/'
   [junit4]   2> 591585 T2235 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_50
   [junit4]   2> 591590 T2204 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_50
   [junit4]   2> 591791 T2224 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_50
   [junit4]   2> 591792 T2265 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_50
   [junit4]   2> 591810 T2235 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
   [junit4]   2> 591811 T2235 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
   [junit4]   2> 591813 T2204 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
   [junit4]   2> 591814 T2204 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
   [junit4]   2> 591817 T2235 oass.IndexSchema.readSchema [solrj_collection_shard2_replica2] Schema name=test
   [junit4]   2> 591820 T2204 oass.IndexSchema.readSchema [solrj_collection_shard1_replica2] Schema name=test
   [junit4]   2> 591834 T2224 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
   [junit4]   2> 591836 T2265 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
   [junit4]   2> 591836 T2224 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
   [junit4]   2> 591837 T2265 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
   [junit4]   2> 591851 T2224 oass.IndexSchema.readSchema [solrj_collection_shard1_replica1] Schema name=test
   [junit4]   2> 591852 T2265 oass.IndexSchema.readSchema [solrj_collection_shard2_replica1] Schema name=test
   [junit4]   2> 592137 T2204 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
   [junit4]   2> 592145 T2204 oass.IndexSchema.readSchema default search field in schema is text
   [junit4]   2> 592148 T2204 oass.IndexSchema.readSchema unique key field: id
   [junit4]   2> 592173 T2204 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
   [junit4]   2> 592181 T2204 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
   [junit4]   2> 592186 T2204 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
   [junit4]   2> 592188 T2204 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
   [junit4]   2> 592188 T2204 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
   [junit4]   2> 592189 T2204 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
   [junit4]   2> 592190 T2204 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
   [junit4]   2> 592191 T2204 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
   [junit4]   2> 592191 T2204 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
   [junit4]   2> 592191 T2204 oasc.SolrCore.<init> [solrj_collection_shard1_replica2] Opening new SolrCore at ../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-controljetty-1389595059463/solrj_collection_shard1_replica2/, dataDir=../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-controljetty-1389595059463/solrj_collection_shard1_replica2/data/
   [junit4]   2> 592192 T2204 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@1ae64c3
   [junit4]   2> 592193 T2204 oasc.CachingDirectoryFactory.get return new directory for ../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-controljetty-1389595059463/solrj_collection_shard1_replica2/data
   [junit4]   2> 592193 T2204 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-controljetty-1389595059463/solrj_collection_shard1_replica2/data/index/
   [junit4]   2> 592194 T2204 oasc.SolrCore.initIndex WARN [solrj_collection_shard1_replica2] Solr index directory '../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-controljetty-1389595059463/solrj_collection_shard1_replica2/data/index' doesn't exist. Creating new index...
   [junit4]   2> 592194 T2204 oasc.CachingDirectoryFactory.get return new directory for ../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-controljetty-1389595059463/solrj_collection_shard1_replica2/data/index
   [junit4]   2> 592195 T2204 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.LogDocMergePolicy: [LogDocMergePolicy: minMergeSize=1000, mergeFactor=15, maxMergeSize=9223372036854775807, maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=true, maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=1.0]
   [junit4]   2> 592196 T2204 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
   [junit4]   2> 		commit{dir=MockDirectoryWrapper(org.apache.lucene.store.RAMDirectory@152842c lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@12eca51),segFN=segments_1,generation=1}
   [junit4]   2> 592196 T2204 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
   [junit4]   2> 592204 T2235 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
   [junit4]   2> 592205 T2204 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "nodistrib"
   [junit4]   2> 592205 T2204 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "dedupe"
   [junit4]   2> 592206 T2204 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
   [junit4]   2> 592206 T2204 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "stored_sig"
   [junit4]   2> 592207 T2204 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
   [junit4]   2> 592207 T2204 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-explicit"
   [junit4]   2> 592208 T2204 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-implicit"
   [junit4]   2> 592208 T2204 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
   [junit4]   2> 592209 T2204 oasc.SolrCore.loadUpdateProcessorChains no updateRequestProcessorChain defined as default, creating implicit default
   [junit4]   2> 592209 T2235 oass.IndexSchema.readSchema default search field in schema is text
   [junit4]   2> 592209 T2204 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
   [junit4]   2> 592210 T2204 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
   [junit4]   2> 592210 T2204 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
   [junit4]   2> 592211 T2204 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
   [junit4]   2> 592211 T2235 oass.IndexSchema.readSchema unique key field: id
   [junit4]   2> 592211 T2204 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
   [junit4]   2> 592212 T2204 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
   [junit4]   2> 592213 T2204 oasc.RequestHandlers.initHandlersFromConfig created /admin/file: solr.admin.ShowFileRequestHandler
   [junit4]   2> 592213 T2204 oasc.RequestHandlers.initHandlersFromConfig created /admin/fileedit: solr.admin.EditFileRequestHandler
   [junit4]   2> 592216 T2204 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
   [junit4]   2> 592219 T2204 oasu.CommitTracker.<init> Hard AutoCommit: disabled
   [junit4]   2> 592220 T2204 oasu.CommitTracker.<init> Soft AutoCommit: disabled
   [junit4]   2> 592221 T2204 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.LogByteSizeMergePolicy: [LogByteSizeMergePolicy: minMergeSize=1677721, mergeFactor=20, maxMergeSize=2147483648, maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=false, maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=1.0]
   [junit4]   2> 592222 T2204 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=1
   [junit4]   2> 		commit{dir=MockDirectoryWrapper(org.apache.lucene.store.RAMDirectory@152842c lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@12eca51),segFN=segments_1,generation=1}
   [junit4]   2> 592222 T2204 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
   [junit4]   2> 592222 T2204 oass.SolrIndexSearcher.<init> Opening Searcher@1a5adeb main
   [junit4]   2> 592225 T2235 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
   [junit4]   2> 592237 T2276 oasc.SolrCore.registerSearcher [solrj_collection_shard1_replica2] Registered new searcher Searcher@1a5adeb main{StandardDirectoryReader(segments_1:1:nrt)}
   [junit4]   2> 592238 T2204 oasc.CoreContainer.registerCore registering core: solrj_collection_shard1_replica2
   [junit4]   2> 592238 T2204 oasc.ZkController.register Register replica - core:solrj_collection_shard1_replica2 address:http://127.0.0.1:34644/ho collection:solrj_collection shard:shard1
   [junit4]   2> 592239 T2235 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
   [junit4]   2> 592240 T2204 oascc.SolrZkClient.makePath makePath: /collections/solrj_collection/leader_elect/shard1/election
   [junit4]   2> 592243 T2265 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
   [junit4]   2> 592248 T2235 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
   [junit4]   2> 592248 T2265 oass.IndexSchema.readSchema default search field in schema is text
   [junit4]   2> 592249 T2235 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
   [junit4]   2> 592251 T2235 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
   [junit4]   2> 592252 T2235 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
   [junit4]   2> 592249 T2204 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process for shard shard1
   [junit4]   2> 592252 T2265 oass.IndexSchema.readSchema unique key field: id
   [junit4]   2> 592253 T2235 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
   [junit4]   2> 592253 T2235 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
   [junit4]   2> 592254 T2235 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
   [junit4]   2> 592254 T2235 oasc.SolrCore.<init> [solrj_collection_shard2_replica2] Opening new SolrCore at ./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty2-1389595060812/solrj_collection_shard2_replica2/, dataDir=./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty2-1389595060812/solrj_collection_shard2_replica2/data/
   [junit4]   2> 592255 T2235 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@1ae64c3
   [junit4]   2> 592255 T2235 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty2-1389595060812/solrj_collection_shard2_replica2/data
   [junit4]   2> 592256 T2235 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty2-1389595060812/solrj_collection_shard2_replica2/data/index/
   [junit4]   2> 592256 T2235 oasc.SolrCore.initIndex WARN [solrj_collection_shard2_replica2] Solr index directory './org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty2-1389595060812/solrj_collection_shard2_replica2/data/index' doesn't exist. Creating new index...
   [junit4]   2> 592257 T2235 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty2-1389595060812/solrj_collection_shard2_replica2/data/index
   [junit4]   2> 592257 T2210 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 592257 T2235 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.LogDocMergePolicy: [LogDocMergePolicy: minMergeSize=1000, mergeFactor=15, maxMergeSize=9223372036854775807, maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=true, maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=1.0]
   [junit4]   2> 592257 T2210 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 592258 T2210 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 592257 T2204 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up for shard shard1: total=2 found=1 timeoutin=0
   [junit4]   2> 592258 T2235 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
   [junit4]   2> 		commit{dir=MockDirectoryWrapper(org.apache.lucene.store.RAMDirectory@18ecc41 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@18060fd),segFN=segments_1,generation=1}
   [junit4]   2> 592259 T2235 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
   [junit4]   2> 592259 T2204 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Was waiting for replicas to come up, but they are taking too long - assuming they won't come back till later
   [junit4]   2> 592260 T2204 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new leader - try and sync
   [junit4]   2> ASYNC  NEW_CORE C3501 name=solrj_collection_shard1_replica2 org.apache.solr.core.SolrCore@c63d91 url=http://127.0.0.1:34644/ho/solrj_collection_shard1_replica2 node=127.0.0.1:34644_ho C3501_STATE=coll:solrj_collection core:solrj_collection_shard1_replica2 props:{state=down, base_url=http://127.0.0.1:34644/ho, core=solrj_collection_shard1_replica2, node_name=127.0.0.1:34644_ho}
   [junit4]   2> 592260 T2204 C3501 P34644 oasc.SyncStrategy.sync Sync replicas to http://127.0.0.1:34644/ho/solrj_collection_shard1_replica2/
   [junit4]   2> 592261 T2204 C3501 P34644 oasu.PeerSync.sync PeerSync: core=solrj_collection_shard1_replica2 url=http://127.0.0.1:34644/ho START replicas=[http://127.0.0.1:52305/ho/solrj_collection_shard1_replica1/] nUpdates=100
   [junit4]   2> 592261 T2204 C3501 P34644 oasu.PeerSync.sync PeerSync: core=solrj_collection_shard1_replica2 url=http://127.0.0.1:34644/ho DONE.  We have no versions.  sync failed.
   [junit4]   2> 592261 T2211 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 592262 T2235 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "nodistrib"
   [junit4]   2> 592262 T2204 C3501 P34644 oasc.SyncStrategy.syncReplicas Leader's attempt to sync with shard failed, moving to the next candidate
   [junit4]   2> 592263 T2204 oasc.ShardLeaderElectionContext.runLeaderProcess We failed sync, but we have no versions - we can't sync in that case - we were active before, so become leader anyway
   [junit4]   2> 592263 T2235 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "dedupe"
   [junit4]   2> 592264 T2235 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
   [junit4]   2> 592264 T2204 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: http://127.0.0.1:34644/ho/solrj_collection_shard1_replica2/ shard1
   [junit4]   2> 592265 T2235 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "stored_sig"
   [junit4]   2> 592266 T2210 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 592266 T2235 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
   [junit4]   2> 592267 T2235 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-explicit"
   [junit4]   2> 592267 T2242 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> 592267 T2270 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> 592265 T2204 oascc.SolrZkClient.makePath makePath: /collections/solrj_collection/leaders/shard1
   [junit4]   2> 592267 T2256 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> 592267 T2228 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> 592267 T2210 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> 592267 T2235 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-implicit"
   [junit4]   2> 592267 T2215 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> 592269 T2235 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
   [junit4]   2> 592270 T2235 oasc.SolrCore.loadUpdateProcessorChains no updateRequestProcessorChain defined as default, creating implicit default
   [junit4]   2> 592270 T2235 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
   [junit4]   2> 592271 T2235 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
   [junit4]   2> 592272 T2235 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
   [junit4]   2> 592272 T2235 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
   [junit4]   2> 592273 T2235 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
   [junit4]   2> 592274 T2235 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
   [junit4]   2> 592275 T2235 oasc.RequestHandlers.initHandlersFromConfig created /admin/file: solr.admin.ShowFileRequestHandler
   [junit4]   2> 592275 T2265 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
   [junit4]   2> 592275 T2235 oasc.RequestHandlers.initHandlersFromConfig created /admin/fileedit: solr.admin.EditFileRequestHandler
   [junit4]   2> 592277 T2235 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
   [junit4]   2> 592279 T2265 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
   [junit4]   2> 592280 T2235 oasu.CommitTracker.<init> Hard AutoCommit: disabled
   [junit4]   2> 592280 T2210 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 592280 T2235 oasu.CommitTracker.<init> Soft AutoCommit: disabled
   [junit4]   2> 592289 T2235 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.LogByteSizeMergePolicy: [LogByteSizeMergePolicy: minMergeSize=1677721, mergeFactor=20, maxMergeSize=2147483648, maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=false, maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=1.0]
   [junit4]   2> 592290 T2211 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 592290 T2235 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=1
   [junit4]   2> 		commit{dir=MockDirectoryWrapper(org.apache.lucene.store.RAMDirectory@18ecc41 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@18060fd),segFN=segments_1,generation=1}
   [junit4]   2> 592290 T2235 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
   [junit4]   2> 592291 T2235 oass.SolrIndexSearcher.<init> Opening Searcher@1e8e1ae main
   [junit4]   2> 592292 T2265 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
   [junit4]   2> 592294 T2279 oasc.SolrCore.registerSearcher [solrj_collection_shard2_replica2] Registered new searcher Searcher@1e8e1ae main{StandardDirectoryReader(segments_1:1:nrt)}
   [junit4]   2> 592297 T2235 oasc.CoreContainer.registerCore registering core: solrj_collection_shard2_replica2
   [junit4]   2> 592297 T2235 oasc.ZkController.register Register replica - core:solrj_collection_shard2_replica2 address:http://127.0.0.1:50282/ho collection:solrj_collection shard:shard2
   [junit4]   2> 592299 T2224 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
   [junit4]   2> 592304 T2224 oass.IndexSchema.readSchema default search field in schema is text
   [junit4]   2> 592306 T2224 oass.IndexSchema.readSchema unique key field: id
   [junit4]   2> 592333 T2235 oascc.SolrZkClient.makePath makePath: /collections/solrj_collection/leader_elect/shard2/election
   [junit4]   2> 592334 T2265 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
   [junit4]   2> 592334 T2265 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
   [junit4]   2> 592334 T2265 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
   [junit4]   2> 592335 T2210 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 592336 T2265 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
   [junit4]   2> 592337 T2265 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
   [junit4]   2> 592337 T2265 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
   [junit4]   2> 592337 T2265 oasc.SolrCore.<init> [solrj_collection_shard2_replica1] Opening new SolrCore at ../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1389595063092/solrj_collection_shard2_replica1/, dataDir=../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1389595063092/solrj_collection_shard2_replica1/data/
   [junit4]   2> 592338 T2265 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@1ae64c3
   [junit4]   2> 592339 T2265 oasc.CachingDirectoryFactory.get return new directory for ../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1389595063092/solrj_collection_shard2_replica1/data
   [junit4]   2> 592339 T2265 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1389595063092/solrj_collection_shard2_replica1/data/index/
   [junit4]   2> 592340 T2265 oasc.SolrCore.initIndex WARN [solrj_collection_shard2_replica1] Solr index directory '../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1389595063092/solrj_collection_shard2_replica1/data/index' doesn't exist. Creating new index...
   [junit4]   2> 592340 T2265 oasc.CachingDirectoryFactory.get return new directory for ../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1389595063092/solrj_collection_shard2_replica1/data/index
   [junit4]   2> 592341 T2265 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.LogDocMergePolicy: [LogDocMergePolicy: minMergeSize=1000, mergeFactor=15, maxMergeSize=9223372036854775807, maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=true, maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=1.0]
   [junit4]   2> 592341 T2235 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process for shard shard2
   [junit4]   2> 592342 T2265 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
   [junit4]   2> 		commit{dir=MockDirectoryWrapper(org.apache.lucene.store.RAMDirectory@f0cfd5 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@5cf439),segFN=segments_1,generation=1}
   [junit4]   2> 592342 T2265 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
   [junit4]   2> 592345 T2265 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "nodistrib"
   [junit4]   2> 592345 T2265 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "dedupe"
   [junit4]   2> 592345 T2210 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 592345 T2265 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
   [junit4]   2> 592346 T2235 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up for shard shard2: total=2 found=1 timeoutin=-1
   [junit4]   2> 592346 T2235 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Was waiting for replicas to come up, but they are taking too long - assuming they won't come b

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

nit4]   2> 	at org.apache.solr.cloud.LeaderElector.runIamLeaderProcess(LeaderElector.java:163)
   [junit4]   2> 	at org.apache.solr.cloud.LeaderElector.checkIfIamLeader(LeaderElector.java:107)
   [junit4]   2> 	at org.apache.solr.cloud.LeaderElector.access$000(LeaderElector.java:55)
   [junit4]   2> 	at org.apache.solr.cloud.LeaderElector$1.process(LeaderElector.java:136)
   [junit4]   2> 	at org.apache.zookeeper.ClientCnxn$EventThread.processEvent(ClientCnxn.java:519)
   [junit4]   2> 	at org.apache.zookeeper.ClientCnxn$EventThread.run(ClientCnxn.java:495)
   [junit4]   2> 
   [junit4]   2> 794779 T3687 oascc.ZkStateReader$3.process WARN ZooKeeper watch triggered, but Solr cannot talk to ZK
   [junit4]   2> 794813 T3699 oasc.LeaderElector$1.process WARN  org.apache.zookeeper.KeeperException$SessionExpiredException: KeeperErrorCode = Session expired for /overseer/queue/qn-
   [junit4]   2> 	at org.apache.zookeeper.KeeperException.create(KeeperException.java:127)
   [junit4]   2> 	at org.apache.zookeeper.KeeperException.create(KeeperException.java:51)
   [junit4]   2> 	at org.apache.zookeeper.ZooKeeper.create(ZooKeeper.java:783)
   [junit4]   2> 	at org.apache.solr.common.cloud.SolrZkClient$5.execute(SolrZkClient.java:239)
   [junit4]   2> 	at org.apache.solr.common.cloud.SolrZkClient$5.execute(SolrZkClient.java:236)
   [junit4]   2> 	at org.apache.solr.common.cloud.ZkCmdExecutor.retryOperation(ZkCmdExecutor.java:73)
   [junit4]   2> 	at org.apache.solr.common.cloud.SolrZkClient.create(SolrZkClient.java:236)
   [junit4]   2> 	at org.apache.solr.cloud.DistributedQueue.createData(DistributedQueue.java:284)
   [junit4]   2> 	at org.apache.solr.cloud.DistributedQueue.offer(DistributedQueue.java:271)
   [junit4]   2> 	at org.apache.solr.cloud.ShardLeaderElectionContextBase.runLeaderProcess(ElectionContext.java:121)
   [junit4]   2> 	at org.apache.solr.cloud.LeaderElector.runIamLeaderProcess(LeaderElector.java:163)
   [junit4]   2> 	at org.apache.solr.cloud.LeaderElector.checkIfIamLeader(LeaderElector.java:107)
   [junit4]   2> 	at org.apache.solr.cloud.LeaderElector.access$000(LeaderElector.java:55)
   [junit4]   2> 	at org.apache.solr.cloud.LeaderElector$1.process(LeaderElector.java:136)
   [junit4]   2> 	at org.apache.zookeeper.ClientCnxn$EventThread.processEvent(ClientCnxn.java:519)
   [junit4]   2> 	at org.apache.zookeeper.ClientCnxn$EventThread.run(ClientCnxn.java:495)
   [junit4]   2> 
   [junit4]   2> 794813 T3699 oascc.ZkStateReader$3.process WARN ZooKeeper watch triggered, but Solr cannot talk to ZK
   [junit4]   2> 794917 T3737 oascc.ZkStateReader$3.process WARN ZooKeeper watch triggered, but Solr cannot talk to ZK
   [junit4]   2> 794917 T3737 oasc.LeaderElector$1.process WARN  org.apache.zookeeper.KeeperException$SessionExpiredException: KeeperErrorCode = Session expired for /collections/collection1/leader_elect/shard4/election
   [junit4]   2> 	at org.apache.zookeeper.KeeperException.create(KeeperException.java:127)
   [junit4]   2> 	at org.apache.zookeeper.KeeperException.create(KeeperException.java:51)
   [junit4]   2> 	at org.apache.zookeeper.ZooKeeper.getChildren(ZooKeeper.java:1468)
   [junit4]   2> 	at org.apache.solr.common.cloud.SolrZkClient$6.execute(SolrZkClient.java:256)
   [junit4]   2> 	at org.apache.solr.common.cloud.SolrZkClient$6.execute(SolrZkClient.java:253)
   [junit4]   2> 	at org.apache.solr.common.cloud.ZkCmdExecutor.retryOperation(ZkCmdExecutor.java:73)
   [junit4]   2> 	at org.apache.solr.common.cloud.SolrZkClient.getChildren(SolrZkClient.java:253)
   [junit4]   2> 	at org.apache.solr.cloud.LeaderElector.checkIfIamLeader(LeaderElector.java:91)
   [junit4]   2> 	at org.apache.solr.cloud.LeaderElector.access$000(LeaderElector.java:55)
   [junit4]   2> 	at org.apache.solr.cloud.LeaderElector$1.process(LeaderElector.java:136)
   [junit4]   2> 	at org.apache.zookeeper.ClientCnxn$EventThread.processEvent(ClientCnxn.java:519)
   [junit4]   2> 	at org.apache.zookeeper.ClientCnxn$EventThread.run(ClientCnxn.java:495)
   [junit4]   2> 
   [junit4]   2> 794921 T3741 oascc.ZkStateReader$3.process WARN ZooKeeper watch triggered, but Solr cannot talk to ZK
   [junit4]   2> 794925 T3745 oasc.LeaderElector$1.process WARN  org.apache.zookeeper.KeeperException$SessionExpiredException: KeeperErrorCode = Session expired for /collections/collection1/leaders/shard2
   [junit4]   2> 	at org.apache.zookeeper.KeeperException.create(KeeperException.java:127)
   [junit4]   2> 	at org.apache.zookeeper.KeeperException.create(KeeperException.java:51)
   [junit4]   2> 	at org.apache.zookeeper.ZooKeeper.exists(ZooKeeper.java:1041)
   [junit4]   2> 	at org.apache.solr.common.cloud.SolrZkClient$3.execute(SolrZkClient.java:205)
   [junit4]   2> 	at org.apache.solr.common.cloud.SolrZkClient$3.execute(SolrZkClient.java:202)
   [junit4]   2> 	at org.apache.solr.common.cloud.ZkCmdExecutor.retryOperation(ZkCmdExecutor.java:73)
   [junit4]   2> 	at org.apache.solr.common.cloud.SolrZkClient.exists(SolrZkClient.java:202)
   [junit4]   2> 	at org.apache.solr.common.cloud.SolrZkClient.makePath(SolrZkClient.java:452)
   [junit4]   2> 	at org.apache.solr.common.cloud.SolrZkClient.makePath(SolrZkClient.java:382)
   [junit4]   2> 	at org.apache.solr.common.cloud.SolrZkClient.makePath(SolrZkClient.java:369)
   [junit4]   2> 	at org.apache.solr.cloud.ShardLeaderElectionContextBase.runLeaderProcess(ElectionContext.java:112)
   [junit4]   2> 	at org.apache.solr.cloud.LeaderElector.runIamLeaderProcess(LeaderElector.java:163)
   [junit4]   2> 	at org.apache.solr.cloud.LeaderElector.checkIfIamLeader(LeaderElector.java:107)
   [junit4]   2> 	at org.apache.solr.cloud.LeaderElector.access$000(LeaderElector.java:55)
   [junit4]   2> 	at org.apache.solr.cloud.LeaderElector$1.process(LeaderElector.java:136)
   [junit4]   2> 	at org.apache.zookeeper.ClientCnxn$EventThread.processEvent(ClientCnxn.java:519)
   [junit4]   2> 	at org.apache.zookeeper.ClientCnxn$EventThread.run(ClientCnxn.java:495)
   [junit4]   2> 
   [junit4]   2> 794926 T3745 oascc.ZkStateReader$3.process WARN ZooKeeper watch triggered, but Solr cannot talk to ZK
   [junit4]   2> 797142 T3405 oas.SolrTestCaseJ4.deleteCore ###deleteCore
   [junit4]   2> NOTE: test params are: codec=Lucene46: {}, docValues:{}, sim=DefaultSimilarity, locale=vi_VN, timezone=Canada/Central
   [junit4]   2> NOTE: Linux 3.8.0-35-generic i386/Oracle Corporation 1.7.0_60-ea (32-bit)/cpus=8,threads=1,free=84138400,total=223444992
   [junit4]   2> NOTE: All tests run in this JVM: [SyncSliceTest, SolrTestCaseJ4Test, ResourceLoaderTest, SuggestComponentTest, TestNoOpRegenerator, AddSchemaFieldsUpdateProcessorFactoryTest, HdfsLockFactoryTest, TestModifyConfFiles, PrimitiveFieldTypeTest, TestSystemIdResolver, LukeRequestHandlerTest, UpdateRequestProcessorFactoryTest, SOLR749Test, LeaderElectionTest, FieldMutatingUpdateProcessorTest, TestQueryUtils, HdfsCollectionsAPIDistributedZkTest, TestRealTimeGet, MBeansHandlerTest, TestReloadAndDeleteDocs, TestConfig, SpellPossibilityIteratorTest, HdfsUnloadDistributedZkTest, HdfsRecoveryZkTest, HdfsBasicDistributedZkTest, TestValueSourceCache, JsonLoaderTest, QueryElevationComponentTest, URLClassifyProcessorTest, ZkCLITest, ClusterStateTest, BadComponentTest, TestPseudoReturnFields, TestFunctionQuery, BlockCacheTest, DistributedSuggestComponentTest, SimpleFacetsTest, DeleteShardTest, TestSolrDeletionPolicy1, CoreAdminHandlerTest, TestDocumentBuilder, ShowFileRequestHandlerTest, TestGroupingSearch, SliceStateTest, TestPerFieldSimilarity, TestDocBasedVersionConstraints, TestBM25SimilarityFactory, HdfsSyncSliceTest, TestDocSet, TestNonNRTOpen, PolyFieldTest, TestClassNameShortening, CSVRequestHandlerTest, TestSolrXml, TestCollationFieldDocValues, DistributedSpellCheckComponentTest, ClusterStateUpdateTest, TestWriterPerf, TestRecoveryHdfs, TestSolrIndexConfig, BasicDistributedZkTest, SolrIndexSplitterTest, SystemInfoHandlerTest, TestSearchPerf, DistributedTermsComponentTest, DistributedDebugComponentTest, DistributedQueryElevationComponentTest, TriLevelCompositeIdRoutingTest, TestNRTOpen, TestDynamicFieldCollectionResource, TestLRUCache, MoreLikeThisHandlerTest, TestExtendedDismaxParser, TermVectorComponentTest, OverseerCollectionProcessorTest, SynonymTokenizerTest, RecoveryZkTest, TestSurroundQueryParser, TestAnalyzeInfixSuggestions, TestLFUCache, TestRemoteStreaming, DocValuesTest, TestSchemaSimilarityResource, TestSolrQueryParser, TestBadConfig, TestCustomSort, TestJoin, SoftAutoCommitTest, ChaosMonkeySafeLeaderTest, UnloadDistributedZkTest, OverseerTest]
   [junit4] Completed on J0 in 93.16s, 8 tests, 1 failure <<< FAILURES!

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

Total time: 49 minutes 7 seconds
Build step 'Invoke Ant' marked build as failure
Description set: Java: 32bit/jdk1.7.0_60-ea-b02 -server -XX:+UseSerialGC
Archiving artifacts
Recording test results
Email was triggered for: Failure
Sending email for trigger: Failure