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/10 14:53:22 UTC

[JENKINS] Lucene-Solr-4.x-Linux (32bit/jdk1.8.0-ea-b121) - Build # 8939 - Still Failing!

Build: http://jenkins.thetaphi.de/job/Lucene-Solr-4.x-Linux/8939/
Java: 32bit/jdk1.8.0-ea-b121 -server -XX:+UseG1GC

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

Error Message:


Stack Trace:
java.lang.AssertionError
	at __randomizedtesting.SeedInfo.seed([E4CD87AAD233477A:652B09B2A56C2746]: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:849)
	at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
	at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
	at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
	at java.lang.reflect.Method.invoke(Method.java:483)
	at com.carrotsearch.randomizedtesting.RandomizedRunner.invoke(RandomizedRunner.java: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 10329 lines...]
   [junit4] Suite: org.apache.solr.cloud.CollectionsAPIDistributedZkTest
   [junit4]   2> 302744 T839 oas.BaseDistributedSearchTestCase.initHostContext Setting hostContext system property: /
   [junit4]   2> 302749 T839 oas.SolrTestCaseJ4.setUp ###Starting testDistribSearch
   [junit4]   2> Creating dataDir: /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./solrtest-CollectionsAPIDistributedZkTest-1389361239902
   [junit4]   2> 302750 T839 oasc.ZkTestServer.run STARTING ZK TEST SERVER
   [junit4]   2> 302751 T840 oasc.ZkTestServer$ZKServerMain.runFromConfig Starting server
   [junit4]   2> 302851 T839 oasc.ZkTestServer.run start zk server on port:55995
   [junit4]   2> 302852 T839 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 302855 T846 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@1e013a7 name:ZooKeeperConnection Watcher:127.0.0.1:55995 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 302855 T839 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 302855 T839 oascc.SolrZkClient.makePath makePath: /solr
   [junit4]   2> 302859 T841 oazs.NIOServerCnxn.doIO WARN caught end of stream exception EndOfStreamException: Unable to read additional data from client sessionid 0x1437c6217610000, likely client has closed socket
   [junit4]   2> 	at org.apache.zookeeper.server.NIOServerCnxn.doIO(NIOServerCnxn.java:220)
   [junit4]   2> 	at org.apache.zookeeper.server.NIOServerCnxnFactory.run(NIOServerCnxnFactory.java:208)
   [junit4]   2> 	at java.lang.Thread.run(Thread.java:744)
   [junit4]   2> 
   [junit4]   2> 302861 T839 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 302865 T848 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@15638f0 name:ZooKeeperConnection Watcher:127.0.0.1:55995/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 302866 T839 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 302866 T839 oascc.SolrZkClient.makePath makePath: /collections/collection1
   [junit4]   2> 302868 T839 oascc.SolrZkClient.makePath makePath: /collections/collection1/shards
   [junit4]   2> 302870 T839 oascc.SolrZkClient.makePath makePath: /collections/control_collection
   [junit4]   2> 302872 T839 oascc.SolrZkClient.makePath makePath: /collections/control_collection/shards
   [junit4]   2> 302874 T839 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test-files/solr/collection1/conf/solrconfig-tlog.xml to /configs/conf1/solrconfig.xml
   [junit4]   2> 302875 T839 oascc.SolrZkClient.makePath makePath: /configs/conf1/solrconfig.xml
   [junit4]   2> 302878 T839 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test-files/solr/collection1/conf/schema.xml to /configs/conf1/schema.xml
   [junit4]   2> 302879 T839 oascc.SolrZkClient.makePath makePath: /configs/conf1/schema.xml
   [junit4]   2> 302881 T839 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test-files/solr/collection1/conf/solrconfig.snippet.randomindexconfig.xml to /configs/conf1/solrconfig.snippet.randomindexconfig.xml
   [junit4]   2> 302882 T839 oascc.SolrZkClient.makePath makePath: /configs/conf1/solrconfig.snippet.randomindexconfig.xml
   [junit4]   2> 302884 T839 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test-files/solr/collection1/conf/stopwords.txt to /configs/conf1/stopwords.txt
   [junit4]   2> 302885 T839 oascc.SolrZkClient.makePath makePath: /configs/conf1/stopwords.txt
   [junit4]   2> 302887 T839 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test-files/solr/collection1/conf/protwords.txt to /configs/conf1/protwords.txt
   [junit4]   2> 302888 T839 oascc.SolrZkClient.makePath makePath: /configs/conf1/protwords.txt
   [junit4]   2> 302890 T839 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test-files/solr/collection1/conf/currency.xml to /configs/conf1/currency.xml
   [junit4]   2> 302890 T839 oascc.SolrZkClient.makePath makePath: /configs/conf1/currency.xml
   [junit4]   2> 302892 T839 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test-files/solr/collection1/conf/enumsConfig.xml to /configs/conf1/enumsConfig.xml
   [junit4]   2> 302892 T839 oascc.SolrZkClient.makePath makePath: /configs/conf1/enumsConfig.xml
   [junit4]   2> 302894 T839 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test-files/solr/collection1/conf/open-exchange-rates.json to /configs/conf1/open-exchange-rates.json
   [junit4]   2> 302894 T839 oascc.SolrZkClient.makePath makePath: /configs/conf1/open-exchange-rates.json
   [junit4]   2> 302897 T839 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test-files/solr/collection1/conf/mapping-ISOLatin1Accent.txt to /configs/conf1/mapping-ISOLatin1Accent.txt
   [junit4]   2> 302898 T839 oascc.SolrZkClient.makePath makePath: /configs/conf1/mapping-ISOLatin1Accent.txt
   [junit4]   2> 302900 T839 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test-files/solr/collection1/conf/old_synonyms.txt to /configs/conf1/old_synonyms.txt
   [junit4]   2> 302900 T839 oascc.SolrZkClient.makePath makePath: /configs/conf1/old_synonyms.txt
   [junit4]   2> 302902 T839 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test-files/solr/collection1/conf/synonyms.txt to /configs/conf1/synonyms.txt
   [junit4]   2> 302902 T839 oascc.SolrZkClient.makePath makePath: /configs/conf1/synonyms.txt
   [junit4]   2> Using old style solr.xml
   [junit4]   2> 302905 T839 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 302907 T850 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@1755640 name:ZooKeeperConnection Watcher:127.0.0.1:55995 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 302907 T839 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 302907 T839 oascc.SolrZkClient.makePath makePath: /solr
   [junit4]   2> 302910 T839 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 302911 T852 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@b92c56 name:ZooKeeperConnection Watcher:127.0.0.1:55995/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 302912 T839 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 302912 T839 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test-files/solr/collection1/conf/solrconfig.xml to /configs/conf2/solrconfig.xml
   [junit4]   2> 302913 T839 oascc.SolrZkClient.makePath makePath: /configs/conf2/solrconfig.xml
   [junit4]   2> 302916 T839 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test-files/solr/collection1/conf/schema.xml to /configs/conf2/schema.xml
   [junit4]   2> 302917 T839 oascc.SolrZkClient.makePath makePath: /configs/conf2/schema.xml
   [junit4]   2> 302919 T839 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test-files/solr/collection1/conf/solrconfig.snippet.randomindexconfig.xml to /configs/conf2/solrconfig.snippet.randomindexconfig.xml
   [junit4]   2> 302919 T839 oascc.SolrZkClient.makePath makePath: /configs/conf2/solrconfig.snippet.randomindexconfig.xml
   [junit4]   2> 302921 T839 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test-files/solr/collection1/conf/stopwords.txt to /configs/conf2/stopwords.txt
   [junit4]   2> 302921 T839 oascc.SolrZkClient.makePath makePath: /configs/conf2/stopwords.txt
   [junit4]   2> 302923 T839 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test-files/solr/collection1/conf/protwords.txt to /configs/conf2/protwords.txt
   [junit4]   2> 302923 T839 oascc.SolrZkClient.makePath makePath: /configs/conf2/protwords.txt
   [junit4]   2> 302928 T839 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test-files/solr/collection1/conf/currency.xml to /configs/conf2/currency.xml
   [junit4]   2> 302928 T839 oascc.SolrZkClient.makePath makePath: /configs/conf2/currency.xml
   [junit4]   2> 302930 T839 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test-files/solr/collection1/conf/open-exchange-rates.json to /configs/conf2/open-exchange-rates.json
   [junit4]   2> 302931 T839 oascc.SolrZkClient.makePath makePath: /configs/conf2/open-exchange-rates.json
   [junit4]   2> 302933 T839 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test-files/solr/collection1/conf/mapping-ISOLatin1Accent.txt to /configs/conf2/mapping-ISOLatin1Accent.txt
   [junit4]   2> 302933 T839 oascc.SolrZkClient.makePath makePath: /configs/conf2/mapping-ISOLatin1Accent.txt
   [junit4]   2> 302935 T839 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test-files/solr/collection1/conf/old_synonyms.txt to /configs/conf2/old_synonyms.txt
   [junit4]   2> 302936 T839 oascc.SolrZkClient.makePath makePath: /configs/conf2/old_synonyms.txt
   [junit4]   2> 302938 T839 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test-files/solr/collection1/conf/synonyms.txt to /configs/conf2/synonyms.txt
   [junit4]   2> 302938 T839 oascc.SolrZkClient.makePath makePath: /configs/conf2/synonyms.txt
   [junit4]   2> 302941 T839 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test-files/solr/collection1/conf/elevate.xml to /configs/conf2/elevate.xml
   [junit4]   2> 302941 T839 oascc.SolrZkClient.makePath makePath: /configs/conf2/elevate.xml
   [junit4]   2> 303029 T839 oejs.Server.doStart jetty-8.1.10.v20130312
   [junit4]   2> 303034 T839 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:51250
   [junit4]   2> 303035 T839 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
   [junit4]   2> 303036 T839 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
   [junit4]   2> 303036 T839 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: ../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-controljetty-1389361240096
   [junit4]   2> 303036 T839 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-controljetty-1389361240096/'
   [junit4]   2> 303048 T839 oasc.ConfigSolr.fromFile Loading container configuration from /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-controljetty-1389361240096/solr.xml
   [junit4]   2> 303056 T839 oasc.CoreContainer.<init> New CoreContainer 21170106
   [junit4]   2> 303056 T839 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-controljetty-1389361240096/]
   [junit4]   2> 303057 T839 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 120000
   [junit4]   2> 303057 T839 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
   [junit4]   2> 303057 T839 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
   [junit4]   2> 303057 T839 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
   [junit4]   2> 303058 T839 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
   [junit4]   2> 303058 T839 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
   [junit4]   2> 303058 T839 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
   [junit4]   2> 303059 T839 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
   [junit4]   2> 303059 T839 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
   [junit4]   2> 303061 T839 oasl.LogWatcher.createWatcher SLF4J impl is org.slf4j.impl.Log4jLoggerFactory
   [junit4]   2> 303061 T839 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
   [junit4]   2> 303061 T839 oasc.CoreContainer.load Host Name: 127.0.0.1
   [junit4]   2> 303062 T839 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:55995/solr
   [junit4]   2> 303062 T839 oasc.ZkController.checkChrootPath zkHost includes chroot
   [junit4]   2> 303063 T839 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 303064 T863 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@4b1ad6 name:ZooKeeperConnection Watcher:127.0.0.1:55995 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 303065 T839 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 303067 T839 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 303068 T865 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@d36563 name:ZooKeeperConnection Watcher:127.0.0.1:55995/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 303068 T839 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 303069 T839 oascc.SolrZkClient.makePath makePath: /overseer/queue
   [junit4]   2> 303071 T839 oascc.SolrZkClient.makePath makePath: /overseer/collection-queue-work
   [junit4]   2> 303073 T839 oascc.SolrZkClient.makePath makePath: /live_nodes
   [junit4]   2> 303074 T839 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:51250_
   [junit4]   2> 303076 T839 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:51250_
   [junit4]   2> 303079 T839 oascc.SolrZkClient.makePath makePath: /overseer_elect
   [junit4]   2> 303081 T839 oascc.SolrZkClient.makePath makePath: /overseer_elect/election
   [junit4]   2> 303083 T839 oascc.SolrZkClient.makePath makePath: /overseer_elect/leader
   [junit4]   2> 303085 T839 oasc.Overseer.start Overseer (id=91053178218414085-127.0.0.1:51250_-n_0000000000) starting
   [junit4]   2> 303087 T839 oascc.SolrZkClient.makePath makePath: /overseer/queue-work
   [junit4]   2> 303089 T839 oascc.SolrZkClient.makePath makePath: /clusterstate.json
   [junit4]   2> 303089 T867 oasc.OverseerCollectionProcessor.run Process current queue of collection creations
   [junit4]   2> 303091 T839 oascc.SolrZkClient.makePath makePath: /aliases.json
   [junit4]   2> 303092 T839 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
   [junit4]   2> 303093 T866 oasc.Overseer$ClusterStateUpdater.run Starting to work on the main queue
   [junit4]   2> 303094 T839 oass.SolrDispatchFilter.init user.dir=/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1
   [junit4]   2> 303094 T839 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
   [junit4]   2> 303095 T839 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 303096 T870 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@1d33c22 name:ZooKeeperConnection Watcher:127.0.0.1:55995/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 303096 T839 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 303097 T839 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
   [junit4]   2> 303099 T839 oasc.ChaosMonkey.monkeyLog monkey: init - expire sessions:false cause connection loss:false
   [junit4]   2> 303165 T839 oejs.Server.doStart jetty-8.1.10.v20130312
   [junit4]   2> 303167 T839 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:55352
   [junit4]   2> 303167 T839 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
   [junit4]   2> 303168 T839 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
   [junit4]   2> 303168 T839 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: ./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty1-1389361240251
   [junit4]   2> 303168 T839 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: './org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty1-1389361240251/'
   [junit4]   2> 303179 T839 oasc.ConfigSolr.fromFile Loading container configuration from /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty1-1389361240251/solr.xml
   [junit4]   2> 303187 T839 oasc.CoreContainer.<init> New CoreContainer 22619867
   [junit4]   2> 303188 T839 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty1-1389361240251/]
   [junit4]   2> 303188 T839 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 120000
   [junit4]   2> 303189 T839 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
   [junit4]   2> 303189 T839 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
   [junit4]   2> 303189 T839 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
   [junit4]   2> 303189 T839 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
   [junit4]   2> 303190 T839 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
   [junit4]   2> 303190 T839 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
   [junit4]   2> 303190 T839 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
   [junit4]   2> 303191 T839 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
   [junit4]   2> 303193 T839 oasl.LogWatcher.createWatcher SLF4J impl is org.slf4j.impl.Log4jLoggerFactory
   [junit4]   2> 303193 T839 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
   [junit4]   2> 303193 T839 oasc.CoreContainer.load Host Name: 127.0.0.1
   [junit4]   2> 303194 T839 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:55995/solr
   [junit4]   2> 303194 T839 oasc.ZkController.checkChrootPath zkHost includes chroot
   [junit4]   2> 303195 T839 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 303196 T881 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@1ad70af name:ZooKeeperConnection Watcher:127.0.0.1:55995 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 303196 T839 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 303198 T839 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 303199 T883 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@151a477 name:ZooKeeperConnection Watcher:127.0.0.1:55995/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 303200 T839 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 303202 T839 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
   [junit4]   2> 304204 T839 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:55352_
   [junit4]   2> 304205 T839 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:55352_
   [junit4]   2> 304207 T870 oascc.ZkStateReader$3.process Updating live nodes... (2)
   [junit4]   2> 304208 T883 oascc.ZkStateReader$3.process Updating live nodes... (2)
   [junit4]   2> 304207 T865 oascc.ZkStateReader$3.process Updating live nodes... (2)
   [junit4]   2> 304212 T839 oass.SolrDispatchFilter.init user.dir=/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1
   [junit4]   2> 304212 T839 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
   [junit4]   2> 304283 T839 oejs.Server.doStart jetty-8.1.10.v20130312
   [junit4]   2> 304286 T839 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:43498
   [junit4]   2> 304286 T839 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
   [junit4]   2> 304287 T839 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
   [junit4]   2> 304287 T839 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: ./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty2-1389361241365
   [junit4]   2> 304287 T839 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: './org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty2-1389361241365/'
   [junit4]   2> 304297 T839 oasc.ConfigSolr.fromFile Loading container configuration from /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty2-1389361241365/solr.xml
   [junit4]   2> 304305 T839 oasc.CoreContainer.<init> New CoreContainer 11310468
   [junit4]   2> 304305 T839 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty2-1389361241365/]
   [junit4]   2> 304306 T839 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 120000
   [junit4]   2> 304306 T839 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
   [junit4]   2> 304306 T839 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
   [junit4]   2> 304307 T839 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
   [junit4]   2> 304307 T839 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
   [junit4]   2> 304307 T839 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
   [junit4]   2> 304307 T839 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
   [junit4]   2> 304308 T839 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
   [junit4]   2> 304308 T839 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
   [junit4]   2> 304310 T839 oasl.LogWatcher.createWatcher SLF4J impl is org.slf4j.impl.Log4jLoggerFactory
   [junit4]   2> 304311 T839 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
   [junit4]   2> 304311 T839 oasc.CoreContainer.load Host Name: 127.0.0.1
   [junit4]   2> 304312 T839 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:55995/solr
   [junit4]   2> 304312 T839 oasc.ZkController.checkChrootPath zkHost includes chroot
   [junit4]   2> 304313 T839 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 304315 T895 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@62f8e9 name:ZooKeeperConnection Watcher:127.0.0.1:55995 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 304315 T839 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 304317 T839 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 304319 T897 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@1eb2d06 name:ZooKeeperConnection Watcher:127.0.0.1:55995/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 304320 T839 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 304323 T839 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
   [junit4]   2> 305325 T839 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:43498_
   [junit4]   2> 305327 T839 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:43498_
   [junit4]   2> 305329 T883 oascc.ZkStateReader$3.process Updating live nodes... (3)
   [junit4]   2> 305329 T870 oascc.ZkStateReader$3.process Updating live nodes... (3)
   [junit4]   2> 305329 T865 oascc.ZkStateReader$3.process Updating live nodes... (3)
   [junit4]   2> 305329 T897 oascc.ZkStateReader$3.process Updating live nodes... (3)
   [junit4]   2> 305332 T839 oass.SolrDispatchFilter.init user.dir=/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1
   [junit4]   2> 305332 T839 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
   [junit4]   2> 305398 T839 oejs.Server.doStart jetty-8.1.10.v20130312
   [junit4]   2> 305399 T839 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:37470
   [junit4]   2> 305400 T839 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
   [junit4]   2> 305400 T839 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
   [junit4]   2> 305401 T839 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: ../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty3-1389361242484
   [junit4]   2> 305401 T839 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty3-1389361242484/'
   [junit4]   2> 305411 T839 oasc.ConfigSolr.fromFile Loading container configuration from /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty3-1389361242484/solr.xml
   [junit4]   2> 305419 T839 oasc.CoreContainer.<init> New CoreContainer 33234747
   [junit4]   2> 305419 T839 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty3-1389361242484/]
   [junit4]   2> 305420 T839 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 120000
   [junit4]   2> 305420 T839 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
   [junit4]   2> 305420 T839 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
   [junit4]   2> 305421 T839 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
   [junit4]   2> 305421 T839 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
   [junit4]   2> 305421 T839 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
   [junit4]   2> 305421 T839 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
   [junit4]   2> 305422 T839 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
   [junit4]   2> 305422 T839 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
   [junit4]   2> 305424 T839 oasl.LogWatcher.createWatcher SLF4J impl is org.slf4j.impl.Log4jLoggerFactory
   [junit4]   2> 305425 T839 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
   [junit4]   2> 305425 T839 oasc.CoreContainer.load Host Name: 127.0.0.1
   [junit4]   2> 305426 T839 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:55995/solr
   [junit4]   2> 305426 T839 oasc.ZkController.checkChrootPath zkHost includes chroot
   [junit4]   2> 305427 T839 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 305429 T909 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@156f5f2 name:ZooKeeperConnection Watcher:127.0.0.1:55995 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 305430 T839 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 305432 T839 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 305433 T911 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@190a35c name:ZooKeeperConnection Watcher:127.0.0.1:55995/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 305434 T839 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 305436 T839 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
   [junit4]   2> 306439 T839 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:37470_
   [junit4]   2> 306441 T839 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:37470_
   [junit4]   2> 306445 T911 oascc.ZkStateReader$3.process Updating live nodes... (4)
   [junit4]   2> 306445 T883 oascc.ZkStateReader$3.process Updating live nodes... (4)
   [junit4]   2> 306445 T870 oascc.ZkStateReader$3.process Updating live nodes... (4)
   [junit4]   2> 306445 T865 oascc.ZkStateReader$3.process Updating live nodes... (4)
   [junit4]   2> 306446 T897 oascc.ZkStateReader$3.process Updating live nodes... (4)
   [junit4]   2> 306451 T839 oass.SolrDispatchFilter.init user.dir=/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1
   [junit4]   2> 306451 T839 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
   [junit4]   2> 306523 T839 oejs.Server.doStart jetty-8.1.10.v20130312
   [junit4]   2> 306527 T839 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:54278
   [junit4]   2> 306528 T839 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
   [junit4]   2> 306528 T839 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
   [junit4]   2> 306529 T839 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: ./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1389361243604
   [junit4]   2> 306529 T839 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: './org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1389361243604/'
   [junit4]   2> 306540 T839 oasc.ConfigSolr.fromFile Loading container configuration from /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1389361243604/solr.xml
   [junit4]   2> 306565 T839 oasc.CoreContainer.<init> New CoreContainer 27855932
   [junit4]   2> 306565 T839 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1389361243604/]
   [junit4]   2> 306566 T839 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 120000
   [junit4]   2> 306566 T839 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
   [junit4]   2> 306566 T839 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
   [junit4]   2> 306566 T839 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
   [junit4]   2> 306567 T839 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
   [junit4]   2> 306567 T839 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
   [junit4]   2> 306567 T839 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
   [junit4]   2> 306567 T839 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
   [junit4]   2> 306568 T839 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
   [junit4]   2> 306570 T839 oasl.LogWatcher.createWatcher SLF4J impl is org.slf4j.impl.Log4jLoggerFactory
   [junit4]   2> 306570 T839 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
   [junit4]   2> 306570 T839 oasc.CoreContainer.load Host Name: 127.0.0.1
   [junit4]   2> 306571 T839 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:55995/solr
   [junit4]   2> 306571 T839 oasc.ZkController.checkChrootPath zkHost includes chroot
   [junit4]   2> 306572 T839 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 306573 T923 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@9b3bc0 name:ZooKeeperConnection Watcher:127.0.0.1:55995 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 306574 T839 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 306576 T839 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 306577 T925 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@1cc24f5 name:ZooKeeperConnection Watcher:127.0.0.1:55995/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 306577 T839 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 306580 T839 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
   [junit4]   2> 307583 T839 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:54278_
   [junit4]   2> 307584 T839 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:54278_
   [junit4]   2> 307591 T865 oascc.ZkStateReader$3.process Updating live nodes... (5)
   [junit4]   2> 307591 T897 oascc.ZkStateReader$3.process Updating live nodes... (5)
   [junit4]   2> 307592 T870 oascc.ZkStateReader$3.process Updating live nodes... (5)
   [junit4]   2> 307592 T925 oascc.ZkStateReader$3.process Updating live nodes... (5)
   [junit4]   2> 307592 T883 oascc.ZkStateReader$3.process Updating live nodes... (5)
   [junit4]   2> 307592 T911 oascc.ZkStateReader$3.process Updating live nodes... (5)
   [junit4]   2> 307595 T839 oass.SolrDispatchFilter.init user.dir=/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1
   [junit4]   2> 307596 T839 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
   [junit4]   2> 307608 T876 oasha.CollectionsHandler.handleCreateAction Creating Collection : replicationFactor=2&collection.configName=conf1&router.field=myOwnField&name=solrj_collection&router.name=compositeId&action=CREATE&numShards=2&wt=javabin&version=2
   [junit4]   2> 307610 T865 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/collection-queue-work state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 307611 T867 oasc.OverseerCollectionProcessor.run Overseer Collection Processor: Get the message id:/overseer/collection-queue-work/qn-0000000000 message:{
   [junit4]   2> 	  "operation":"createcollection",
   [junit4]   2> 	  "fromApi":"true",
   [junit4]   2> 	  "name":"solrj_collection",
   [junit4]   2> 	  "replicationFactor":"2",
   [junit4]   2> 	  "collection.configName":"conf1",
   [junit4]   2> 	  "numShards":"2",
   [junit4]   2> 	  "router.field":"myOwnField",
   [junit4]   2> 	  "router.name":"compositeId"}
   [junit4]   2> 307612 T867 oasc.OverseerCollectionProcessor.processMessage WARN OverseerCollectionProcessor.processMessage : createcollection , {
   [junit4]   2> 	  "operation":"createcollection",
   [junit4]   2> 	  "fromApi":"true",
   [junit4]   2> 	  "name":"solrj_collection",
   [junit4]   2> 	  "replicationFactor":"2",
   [junit4]   2> 	  "collection.configName":"conf1",
   [junit4]   2> 	  "numShards":"2",
   [junit4]   2> 	  "router.field":"myOwnField",
   [junit4]   2> 	  "router.name":"compositeId"}
   [junit4]   2> 307612 T867 oasc.OverseerCollectionProcessor.createConfNode creating collections conf node /collections/solrj_collection 
   [junit4]   2> 307612 T867 oascc.SolrZkClient.makePath makePath: /collections/solrj_collection
   [junit4]   2> 307616 T865 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 307617 T866 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 307617 T866 oasc.Overseer$ClusterStateUpdater.buildCollection building a new collection: solrj_collection
   [junit4]   2> 307617 T866 oasc.Overseer$ClusterStateUpdater.createCollection Create collection solrj_collection with shards [shard1, shard2]
   [junit4]   2> 307619 T865 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 307620 T911 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> 307620 T883 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> 307620 T865 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> 307620 T897 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> 307620 T870 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> 307620 T925 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> 307716 T867 oasc.OverseerCollectionProcessor.createCollection going to create cores replicas shardNames [shard1, shard2] , repFactor : 2
   [junit4]   2> 307716 T867 oasc.OverseerCollectionProcessor.createCollection Creating shard solrj_collection_shard1_replica1 as part of slice shard1 of collection solrj_collection on 127.0.0.1:55352_
   [junit4]   2> 307717 T867 oasc.OverseerCollectionProcessor.createCollection Creating shard solrj_collection_shard1_replica2 as part of slice shard1 of collection solrj_collection on 127.0.0.1:51250_
   [junit4]   2> 307717 T867 oasc.OverseerCollectionProcessor.createCollection Creating shard solrj_collection_shard2_replica1 as part of slice shard2 of collection solrj_collection on 127.0.0.1:54278_
   [junit4]   2> 307721 T877 oasc.ZkController.publish publishing core=solrj_collection_shard1_replica1 state=down
   [junit4]   2> 307722 T867 oasc.OverseerCollectionProcessor.createCollection Creating shard solrj_collection_shard2_replica2 as part of slice shard2 of collection solrj_collection on 127.0.0.1:43498_
   [junit4]   2> 307722 T865 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 307722 T877 oasc.ZkController.waitForCoreNodeName look for our core node name
   [junit4]   2> 307724 T920 oasc.ZkController.publish publishing core=solrj_collection_shard2_replica1 state=down
   [junit4]   2> 307724 T858 oasc.ZkController.publish publishing core=solrj_collection_shard1_replica2 state=down
   [junit4]   2> 307724 T891 oasc.ZkController.publish publishing core=solrj_collection_shard2_replica2 state=down
   [junit4]   2> 307868 T865 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 307868 T920 oasc.ZkController.waitForCoreNodeName look for our core node name
   [junit4]   2> 307868 T891 oasc.ZkController.waitForCoreNodeName look for our core node name
   [junit4]   2> 307868 T858 oasc.ZkController.waitForCoreNodeName look for our core node name
   [junit4]   2> 307868 T866 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 307870 T866 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:55352",
   [junit4]   2> 	  "core":"solrj_collection_shard1_replica1",
   [junit4]   2> 	  "roles":null,
   [junit4]   2> 	  "node_name":"127.0.0.1:55352_",
   [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> 307873 T866 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:54278",
   [junit4]   2> 	  "core":"solrj_collection_shard2_replica1",
   [junit4]   2> 	  "roles":null,
   [junit4]   2> 	  "node_name":"127.0.0.1:54278_",
   [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> 307878 T865 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 307879 T866 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:51250",
   [junit4]   2> 	  "core":"solrj_collection_shard1_replica2",
   [junit4]   2> 	  "roles":null,
   [junit4]   2> 	  "node_name":"127.0.0.1:51250_",
   [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> 307880 T865 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 307881 T866 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:43498",
   [junit4]   2> 	  "core":"solrj_collection_shard2_replica2",
   [junit4]   2> 	  "roles":null,
   [junit4]   2> 	  "node_name":"127.0.0.1:43498_",
   [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> 307882 T865 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 308065 T870 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> 308066 T883 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> 308065 T925 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> 308065 T865 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> 308065 T897 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> 308065 T911 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> 308724 T877 oasc.ZkController.waitForShardId waiting to find shard id in clusterstate for solrj_collection_shard1_replica1
   [junit4]   2> 308724 T877 oasc.SolrXMLCoresLocator.doPersist Persisted core descriptions to /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty1-1389361240251/solr.xml
   [junit4]   2> 308725 T877 oasc.CoreContainer.create Creating SolrCore 'solrj_collection_shard1_replica1' using instanceDir: ./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty1-1389361240251/solrj_collection_shard1_replica1
   [junit4]   2> 308725 T877 oasc.ZkController.createCollectionZkNode Check for collection zkNode:solrj_collection
   [junit4]   2> 308726 T877 oasc.ZkController.createCollectionZkNode Collection zkNode exists
   [junit4]   2> 308726 T877 oascc.ZkStateReader.readConfigName Load collection config from:/collections/solrj_collection
   [junit4]   2> 308727 T877 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: './org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty1-1389361240251/solrj_collection_shard1_replica1/'
   [junit4]   2> 308750 T877 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_47
   [junit4]   2> 308761 T877 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
   [junit4]   2> 308762 T877 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
   [junit4]   2> 308769 T877 oass.IndexSchema.readSchema [solrj_collection_shard1_replica1] Schema name=test
   [junit4]   2> 308869 T920 oasc.ZkController.waitForShardId waiting to find shard id in clusterstate for solrj_collection_shard2_replica1
   [junit4]   2> 308869 T891 oasc.ZkController.waitForShardId waiting to find shard id in clusterstate for solrj_collection_shard2_replica2
   [junit4]   2> 308869 T858 oasc.ZkController.waitForShardId waiting to find shard id in clusterstate for solrj_collection_shard1_replica2
   [junit4]   2> 308870 T891 oasc.SolrXMLCoresLocator.doPersist Persisted core descriptions to /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty2-1389361241365/solr.xml
   [junit4]   2> 308870 T920 oasc.SolrXMLCoresLocator.doPersist Persisted core descriptions to /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1389361243604/solr.xml
   [junit4]   2> 308871 T891 oasc.CoreContainer.create Creating SolrCore 'solrj_collection_shard2_replica2' using instanceDir: ./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty2-1389361241365/solrj_collection_shard2_replica2
   [junit4]   2> 308871 T891 oasc.ZkController.createCollectionZkNode Check for collection zkNode:solrj_collection
   [junit4]   2> 308871 T858 oasc.SolrXMLCoresLocator.doPersist Persisted core descriptions to /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-controljetty-1389361240096/solr.xml
   [junit4]   2> 308871 T920 oasc.CoreContainer.create Creating SolrCore 'solrj_collection_shard2_replica1' using instanceDir: ./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1389361243604/solrj_collection_shard2_replica1
   [junit4]   2> 308872 T920 oasc.ZkController.createCollectionZkNode Check for collection zkNode:solrj_collection
   [junit4]   2> 308872 T891 oasc.ZkController.createCollectionZkNode Collection zkNode exists
   [junit4]   2> 308873 T920 oasc.ZkController.createCollectionZkNode Collection zkNode exists
   [junit4]   2> 308873 T920 oascc.ZkStateReader.readConfigName Load collection config from:/collections/solrj_collection
   [junit4]   2> 308872 T858 oasc.CoreContainer.create Creating SolrCore 'solrj_collection_shard1_replica2' using instanceDir: ../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-controljetty-1389361240096/solrj_collection_shard1_replica2
   [junit4]   2> 308873 T891 oascc.ZkStateReader.readConfigName Load collection config from:/collections/solrj_collection
   [junit4]   2> 308874 T920 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: './org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1389361243604/solrj_collection_shard2_replica1/'
   [junit4]   2> 308873 T858 oasc.ZkController.createCollectionZkNode Check for collection zkNode:solrj_collection
   [junit4]   2> 308874 T891 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: './org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty2-1389361241365/solrj_collection_shard2_replica2/'
   [junit4]   2> 308875 T858 oasc.ZkController.createCollectionZkNode Collection zkNode exists
   [junit4]   2> 308875 T858 oascc.ZkStateReader.readConfigName Load collection config from:/collections/solrj_collection
   [junit4]   2> 308877 T858 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-controljetty-1389361240096/solrj_collection_shard1_replica2/'
   [junit4]   2> 308897 T920 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_47
   [junit4]   2> 308902 T891 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_47
   [junit4]   2> 308908 T858 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_47
   [junit4]   2> 308910 T920 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
   [junit4]   2> 308923 T920 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
   [junit4]   2> 308926 T891 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
   [junit4]   2> 308928 T891 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
   [junit4]   2> 308929 T920 oass.IndexSchema.readSchema [solrj_collection_shard2_replica1] Schema name=test
   [junit4]   2> 308931 T858 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
   [junit4]   2> 308936 T891 oass.IndexSchema.readSchema [solrj_collection_shard2_replica2] Schema name=test
   [junit4]   2> 308940 T858 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
   [junit4]   2> 308947 T877 oass.ByteField.init WARN ByteField is deprecated and will be removed in 5.0. You should use TrieIntField instead.
   [junit4]   2> 308952 T877 oass.ShortField.init WARN ShortField is deprecated and will be removed in 5.0. You should use TrieIntField instead.
   [junit4]   2> 308953 T858 oass.IndexSchema.readSchema [solrj_collection_shard1_replica2] Schema name=test
   [junit4]   2> 308954 T877 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
   [junit4]   2> 308959 T877 oass.IndexSchema.readSchema default search field in schema is text
   [junit4]   2> 308961 T877 oass.IndexSchema.readSchema unique key field: id
   [junit4]   2> 309015 T877 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
   [junit4]   2> 309018 T877 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
   [junit4]   2> 309021 T877 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
   [junit4]   2> 309022 T877 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
   [junit4]   2> 309023 T877 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
   [junit4]   2> 309023 T877 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
   [junit4]   2> 309024 T877 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
   [junit4]   2> 309024 T877 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
   [junit4]   2> 309025 T877 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
   [junit4]   2> 309025 T877 oasc.SolrCore.<init> [solrj_collection_shard1_replica1] Opening new SolrCore at ./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty1-1389361240251/solrj_collection_shard1_replica1/, dataDir=./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty1-1389361240251/solrj_collection_shard1_replica1/data/
   [junit4]   2> 309025 T877 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@1b3d9c4
   [junit4]   2> 309026 T877 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty1-1389361240251/solrj_collection_shard1_replica1/data
   [junit4]   2> 309026 T877 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty1-1389361240251/solrj_collection_shard1_replica1/data/index/
   [junit4]   2> 309027 T877 oasc.SolrCore.initIndex WARN [solrj_collection_shard1_replica1] Solr index directory './org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty1-1389361240251/solrj_collection_shard1_replica1/data/index' doesn't exist. Creating new index...
   [junit4]   2> 309027 T877 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty1-1389361240251/solrj_collection_shard1_replica1/data/index
   [junit4]   2> 309027 T877 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.MockRandomMergePolicy: org.apache.lucene.index.MockRandomMergePolicy@1bc89ab
   [junit4]   2> 309028 T877 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
   [junit4]   2> 		commit{dir=MockDirectoryWrapper(org.apache.lucene.store.RAMDirectory@1967aae lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@dce0a8),segFN=segments_1,generation=1}
   [junit4]   2> 309028 T877 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
   [junit4]   2> 309031 T877 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "nodistrib"
   [junit4]   2> 309031 T877 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "dedupe"
   [junit4]   2> 309032 T877 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
   [junit4]   2> 309032 T877 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "stored_sig"
   [junit4]   2> 309032 T877 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
   [junit4]   2> 309032 T877 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-explicit"
   [junit4]   2> 309066 T877 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-implicit"
   [junit4]   2> 309066 T877 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
   [junit4]   2> 309067 T877 oasc.SolrCore.loadUpdateProcessorChains no updateRequestProcessorChain defined as default, creating implicit default
   [junit4]   2> 309068 T877 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
   [junit4]   2> 309068 T877 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
   [junit4]   2> 309069 T877 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
   [junit4]   2> 309069 T877 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
   [junit4]   2> 309070 T877 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
   [junit4]   2> 309070 T877 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
   [junit4]   2> 309071 T877 oasc.RequestHandlers.initHandlersFromConfig created /admin/file: solr.admin.ShowFileRequestHandler
   [junit4]   2> 309074 T877 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
   [junit4]   2> 309076 T877 oasu.CommitTracker.<init> Hard AutoCommit: disabled
   [junit4]   2> 309076 T877 oasu.CommitTracker.<init> Soft AutoCommit: disabled
   [junit4]   2> 309077 T877 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: maxMergeAtOnce=15, maxMergeAtOnceExplicit=47, maxMergedSegmentMB=60.1572265625, floorSegmentMB=0.287109375, forceMergeDeletesPctAllowed=19.763076681213636, segmentsPerTier=43.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=1.0
   [junit4]   2> 309078 T877 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=1
   [junit4]   2> 		commit{dir=MockDirectoryWrapper(org.apache.lucene.store.RAMDirectory@1967aae lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@dce0a8),segFN=segments_1,generation=1}
   [junit4]   2> 309078 T877 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
   [junit4]   2> 309079 T877 oass.SolrIndexSearcher.<init> Opening Searcher@5d11f2 main
   [junit4]   2> 309082 T931 oasc.SolrCore.registerSearcher [solrj_collection_shard1_replica1] Registered new searcher Searcher@5d11f2 main{StandardDirectoryReader(segments_1:1:nrt)}
   [junit4]   2> 309083 T877 oasc.CoreContainer.registerCore registering core: solrj_collection_shard1_replica1
   [junit4]   2> 309083 T877 oasc.ZkController.register Register replica - core:solrj_collection_shard1_replica1 address:http://127.0.0.1:55352 collection:solrj_collection shard:shard1
   [junit4]   2> 309085 T877 oascc.SolrZkClient.makePath makePath: /collections/solrj_collection/leader_elect/shard1/election
   [junit4]   2> 309089 T877 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process for shard shard1
   [junit4]   2> 309091 T865 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 309091 T877 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up for shard shard1: total=2 found=1 timeoutin=0
   [junit4]   2> 309092 T877 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> 309091 T865 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 309092 T877 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new leader - try and sync
   [junit4]   2> 309092 T865 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> ASYNC  NEW_CORE C381 name=solrj_collection_shard1_replica1 org.apache.solr.core.SolrCore@d80551 url=http://127.0.0.1:55352/solrj_collection_shard1_replica1 node=127.0.0.1:55352_ C381_STATE=coll:solrj_collection core:solrj_collection_shard1_replica1 props:{state=down, base_url=http://127.0.0.1:55352, core=solrj_collection_shard1_replica1, node_name=127.0.0.1:55352_}
   [junit4]   2> 309092 T877 C381 P55352 oasc.SyncStrategy.sync Sync replicas to http://127.0.0.1:55352/solrj_collection_shard1_replica1/
   [junit4]   2> 309093 T877 C381 P55352 oasu.PeerSync.sync PeerSync: core=solrj_collection_shard1_replica1 url=http://127.0.0.1:55352 START replicas=[http://127.0.0.1:51250/solrj_collection_shard1_replica2/] nUpdates=100
   [junit4]   2> 309093 T866 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 309094 T877 C381 P55352 oasu.PeerSync.sync PeerSync: core=solrj_collection_shard1_replica1 url=http://127.0.0.1:55352 DONE.  We have no versions.  sync failed.
   [junit4]   2> 309094 T877 C381 P55352 oasc.SyncStrategy.syncReplicas Leader's attempt to sync with shard failed, moving to the next candidate
   [junit4]   2> 309094 T877 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> 309095 T877 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: http://127.0.0.1:55352/solrj_collection_shard1_replica1/ shard1
   [junit4]   2> 309095 T877 oascc.SolrZkClient.makePath makePath: /collections/solrj_collection/leaders/shard1
   [junit4]   2> 309101 T865 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 309103 T865 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 309105 T865 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 309176 T891 oass.ByteField.init WARN ByteField is deprecated and will be removed in 5.0. You should use TrieIntField instead.
   [junit4]   2> 309177 T891 oass.ShortField.init WARN ShortField is deprecated and will be removed in 5.0. You should use TrieIntField instead.
   [junit4]   2> 309179 T891 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
   [junit4]   2> 309185 T891 oass.IndexSchema.readSchema default search field in schema is text
   [junit4]   2> 309187 T920 oass.ByteField.init WARN ByteField is deprecated and will be removed in 5.0. You should use TrieIntField instead.
   [junit4]   2> 309188 T920 oass.ShortField.init WARN ShortField is deprecated and will be removed in 5.0. You should use TrieIntField instead.
   [junit4]   2> 309189 T920 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
   [junit4]   2> 309191 T891 oass.IndexSchema.readSchema unique key field: id
   [junit4]   2> 309194 T920 oass.IndexSchema.readSchema default search field in schema is text
   [junit4]   2> 309196 T920 oass.IndexSchema.readSchema unique key field: id
   [junit4]   2> 309226 T891 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
   [junit4]   2> 309228 T891 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
   [junit4]   2> 309231 T891 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
   [junit4]   2> 309232 T891 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
   [junit4]   2> 309233 T891 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
   [junit4]   2> 309233 T891 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
   [junit4]   2> 309235 T891 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
   [junit4]   2> 309235 T891 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
   [junit4]   2> 309236 T891 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
   [junit4]   2> 309236 T891 oasc.SolrCore.<init> [solrj_collection_shard2_replica2] Opening new SolrCore at ./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty2-1389361241365/solrj_collection_shard2_replica2/, dataDir=./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty2-1389361241365/solrj_collection_shard2_replica2/data/
   [junit4]   2> 309237 T891 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@1b3d9c4
   [junit4]   2> 309238 T858 oass.ByteField.init WARN ByteField is deprecated and will be removed in 5.0. You should use TrieIntField instead.
   [junit4]   2> 309238 T891 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty2-1389361241365/solrj_collection_shard2_replica2/data
   [junit4]   2> 309238 T858 oass.ShortField.init WARN ShortField is deprecated and will be removed in 5.0. You should use TrieIntField instead.
   [junit4]   2> 309238 T891 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty2-1389361241365/solrj_collection_shard2_replica2/data/index/
   [junit4]   2> 309239 T858 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
   [junit4]   2> 309239 T891 oasc.SolrCore.initIndex WARN [solrj_collection_shard2_replica2] Solr index directory './org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty2-1389361241365/solrj_collection_shard2_replica2/data/index' doesn't exist. Creating new index...
   [junit4]   2> 309240 T891 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty2-1389361241365/solrj_collection_shard2_replica2/data/index
   [junit4]   2> 309241 T891 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.MockRandomMergePolicy: org.apache.lucene.index.MockRandomMergePolicy@1cba705
   [junit4]   2> 309242 T891 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
   [junit4]   2> 		commit{dir=MockDirectoryWrapper(org.apache.lucene.store.RAMDirectory@1163ec9 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@d798b),segFN=segments_1,generation=1}
   [junit4]   2> 309242 T891 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
   [junit4]   2> 309243 T858 oass.IndexSchema.readSchema default search field in schema is text
   [junit4]   2> 309244 T858 oass.IndexSchema.readSchema unique key field: id
   [junit4]   2> 309246 T891 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "nodistrib"
   [junit4]   2> 309246 T891 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "dedupe"
   [junit4]   2> 309247 T891 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
   [junit4]   2> 309247 T891 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "stored_sig"
   [junit4]   2> 309248 T891 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
   [junit4]   2> 309248 T891 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-explicit"
   [junit4]   2> 309248 T891 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-implicit"
   [junit4]   2> 309249 T891 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
   [junit4]   2> 309249 T891 oasc.SolrCore.loadUpdateProcessorChains no updateRequestProcessorChain defined as default, creating implicit default
   [junit4]   2> 309250 T891 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
   [junit4]   2> 309250 T891 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
   [junit4]   2> 309251 T891 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
   [junit4]   2> 309251 T891 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
   [junit4]   2> 309252 T891 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
   [junit4]   2> 309252 T891 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
   [junit4]   2> 309253 T891 oasc.RequestHandlers.initHandlersFromConfig created /admin/file: solr.admin.ShowFileRequestHandler
   [junit4]   2> 309254 T891 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
   [junit4]   2> 309256 T891 oasu.CommitTracker.<init> Hard AutoCommit: disabled
   [junit4]   2> 309256 T891 oasu.CommitTracker.<init> Soft AutoCommit: disabled
   [junit4]   2> 309257 T891 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: maxMergeAtOnce=15, maxMergeAtOnceExplicit=47, maxMergedSegmentMB=60.1572265625, floorSegmentMB=0.287109375, forceMergeDeletesPctAllowed=19.763076681213636, segmentsPerTier=43.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=1.0
   [junit4]   2> 309257 T891 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=1
   [junit4]   2> 		commit{dir=MockDirectoryWrapper(org.apache.lucene.store.RAMDirectory@1163ec9 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@d798b),segFN=segments_1,generation=1}
   [junit4]   2> 309258 T891 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
   [junit4]   2> 309258 T891 oass.SolrIndexSearcher.<init> Opening Searcher@d62613 main
   [junit4]   2> 309261 T891 oasc.CoreContainer.registerCore registering core: solrj_collection_shard2_replica2
   [junit4]   2> 309262 T891 oasc.ZkController.register Register replica - core:solrj_collection_shard2_replica2 address:http://127.0.0.1:43498 collection:solrj_collection shard:shard2
   [junit4]   2> 309262 T934 oasc.SolrCore.registerSearcher [solrj_collection_shard2_replica2] Registered new searcher Searcher@d62613 main{StandardDirectoryReader(segments_1:1:nrt)}
   [junit4]   2> 309315 T865 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> 309316 T883 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> 309316 T870 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> 309316 T911 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> 309316 T897 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> 309317 T891 oascc.SolrZkClient.makePath makePath: /collections/solrj_collection/leader_elect/shard2/election
   [junit4]   2> 309317 T925 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> 309317 T877 oasc.ZkController.register We are http://127.0.0.1:55352/solrj_collection_shard1_replica1/ and leader is http://127.0.0.1:55352/solrj_collection_shard1_replica1/
   [junit4]   2> 309318 T877 oasc.ZkController.register No LogReplay needed for core=solrj_collection_shard1_replica1 baseURL=http://127.0.0.1:55352
   [junit4]   2> 309318 T877 oasc.ZkController.checkRecovery I am the leader, no recovery necessary
   [junit4]   2> 309318 T877 oasc.ZkController.publish publishing core=solrj_collection_shard1_replica1 state=active
   [junit4]   2> 309319 T920 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
   [junit4]   2> 309321 T877 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 309323 T877 oasc.SolrXMLCoresLocator.doPersist Persisted core descriptions to /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty1-1389361240251/solr.xml
   [junit4]   2> 309323 T877 oass.SolrDispatchFilter.handleAdminRequest [admin] webapp=null path=/admin/cores params={qt=/admin/cores&collection.configName=conf1&name=solrj_collection_shard1_replica1&action=CREATE&numShards=2&collection=solrj_collection&shard=shard1&wt=javabin&version=2} status=0 QTime=1602 
   [junit4]   2> 309323 T920 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
   [junit4]   2> 309325 T865 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 309326 T865 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 309326 T891 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process for shard shard2
   [junit4]   2> 309326 T866 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 309326 T920 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
   [junit4]   2> 309327 T866 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
   [junit4]   2> 	  "operation":"state",
   [junit4]   2> 	  "state":"active",
   [junit4]   2> 	  "base_url":"http://127.0.0.1:55352",
   [junit4]   2> 	  "core":"solrj_collection_shard1_replica1",
   [junit4]   2> 	  "roles":null,
   [junit4]   2> 	  "node_name":"127.0.0.1:55352_",
   [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":"core_node1"}
   [junit4]   2> 309328 T865 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 309328 T920 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
   [junit4]   2> 309328 T891 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up for shard shard2: total=2 found=1 timeoutin=0
   [junit4]   2> 309329 T891 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> 309329 T891 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new leader - try and sync
   [junit4]   2> 309328 T920 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
   [junit4]   2> ASYNC  NEW_CORE C382 name=solrj_collection_shard2_replica2 org.apache.solr.core.SolrCore@e193c7 url=http://127.0.0.1:43498/solrj_collection_shard2_replica2 node=127.0.0.1:43498_ C382_STATE=coll:solrj_collection core:solrj_collection_shard2_replica2 props:{state=down, base_url=http://127.0.0.1:43498, core=solrj_collection_shard2_replica2, node_name=127.0.0.1:43498_}
   [junit4]   2> 309330 T891 C382 P43498 oasc.SyncStrategy.sync Sync replicas to http://127.0.0.1:43498/solrj_collection_shard2_replica2/
   [junit4]   2> 309330 T920 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
   [junit4]   2> 309330 T891 C382 P43498 oasu.PeerSync.sync PeerSync: core=solrj_collection_shard2_replica2 url=http://127.0.0.1:43498 START replicas=[http://127.0.0.1:54278/solrj_collection_shard2_replica1/] nUpdates=100
   [junit4]   2> 309331 T920 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
   [junit4]   2> 309332 T865 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 309332 T920 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
   [junit4]   2> 309331 T891 C382 P43498 oasu.PeerSync.sync PeerSync: core=solrj_collection_shard2_replica2 url=http://127.0.0.1:43498 DONE.  We have no versions.  sync failed.
   [junit4]   2> 309333 T891 C382 P43498 oasc.SyncStrategy.syncReplicas Leader's attempt to sync with shard failed, moving to the next candidate
   [junit4]   2> 309333 T920 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
   [junit4]   2> 309334 T920 oasc.SolrCore.<init> [solrj_collection_shard2_replica1] Opening new SolrCore at ./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1389361243604/solrj_collection_shard2_replica1/, dataDir=./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1389361243604/solrj_collection_shard2_replica1/data/
   [junit4]   2> 309334 T920 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@1b3d9c4
   [junit4]   2> 309333 T891 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> 309335 T891 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: http://127.0.0.1:43498/solrj_collection_shard2_replica2/ shard2
   [junit4]   2> 309335 T891 oascc.SolrZkClient.makePath makePath: /collections/solrj_collection/leaders/shard2
   [junit4]   2> 309336 T920 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1389361243604/solrj_collection_shard2_replica1/data
   [junit4]   2> 309336 T920 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1389361243604/solrj_collection_shard2_replica1/data/index/
   [junit4]   2> 309337 T858 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
   [junit4]   2> 309337 T920 oasc.SolrCore.initIndex WARN [solrj_collection_shard2_replica1] Solr index directory './org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1389361243604/solrj_collection_shard2_replica1/data/index' doesn't exist. Creating new index...
   [junit4]   2> 309338 T920 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1389361243604/solrj_collection_shard2_replica1/data/index
   [junit4]   2> 309338 T920 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.MockRandomMergePolicy: org.apache.lucene.index.MockRandomMergePolicy@348bb8
   [junit4]   2> 309340 T920 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
   [junit4]   2> 		commit{dir=MockDirectoryWrapper(org.apache.lucene.store.RAMDirectory@1abc979 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@15a9447),segFN=segments_1,generation=1}
   [junit4]   2> 309340 T920 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
   [junit4]   2> 309342 T858 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
   [junit4]   2> 309344 T920 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "nodistrib"
   [junit4]   2> 309345 T920 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "dedupe"
   [junit4]   2> 309345 T865 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 309345 T920 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
   [junit4]   2> 309346 T920 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "stored_sig"
   [junit4]   2> 309346 T920 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
   [junit4]   2> 309346 T920 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-explicit"
   [junit4]   2> 309347 T920 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-implicit"
   [junit4]   2> 309348 T920 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
   [junit4]   2> 309348 T920 oasc.SolrCore.loadUpdateProcessorChains no updateRequestProcessorChain defined as default, creating implicit default
   [junit4]   2> 309348 T858 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
   [junit4]   2> 309349 T920 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
   [junit4]   2> 309349 T920 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
   [junit4]   2> 309350 T920 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
   [junit4]   2> 309350 T920 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
   [junit4]   2> 309350 T865 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 309350 T858 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
   [junit4]   2> 309351 T858 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
   [junit4]   2> 309351 T920 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
   [junit4]   2> 309351 T858 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
   [junit4]   2> 309352 T920 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
   [junit4]   2> 309353 T920 oasc.RequestHandlers.initHandlers

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

242484/nodes_used_collection_shard1_replica1/data/index [CachedDir<<refCount=0;path=../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty3-1389361242484/nodes_used_collection_shard1_replica1/data/index;done=false>>]
   [junit4]   2> 475037 T1028 oasc.CachingDirectoryFactory.close Closing directory: ../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty3-1389361242484/nodes_used_collection_shard1_replica1/data/index
   [junit4]   2> 475037 T1028 oasc.CachingDirectoryFactory.closeCacheValue looking to close ../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty3-1389361242484/nodes_used_collection_shard1_replica1/data [CachedDir<<refCount=0;path=../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty3-1389361242484/nodes_used_collection_shard1_replica1/data;done=false>>]
   [junit4]   2> 475037 T1028 oasc.CachingDirectoryFactory.close Closing directory: ../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty3-1389361242484/nodes_used_collection_shard1_replica1/data
   [junit4]   2> 475038 T1028 oascc.SolrZkClient.makePath makePath: /collections/nodes_used_collection/leaders/shard1
   [junit4]   2> 475038 T1028 oasc.SolrException.log ERROR There was a problem trying to register as the leader:org.apache.zookeeper.KeeperException$SessionExpiredException: KeeperErrorCode = Session expired for /collections
   [junit4]   2> 		at org.apache.zookeeper.KeeperException.create(KeeperException.java:127)
   [junit4]   2> 		at org.apache.zookeeper.KeeperException.create(KeeperException.java:51)
   [junit4]   2> 		at org.apache.zookeeper.ZooKeeper.exists(ZooKeeper.java: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:413)
   [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.ShardLeaderElectionContext.runLeaderProcess(ElectionContext.java:273)
   [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> 475038 T1028 oasc.LeaderElector$1.process WARN  org.apache.zookeeper.KeeperException$SessionExpiredException: KeeperErrorCode = Session expired for /collections/nodes_used_collection/leader_elect/shard1/election/91053178218414099-core_node3-n_0000000002
   [junit4]   2> 	at org.apache.zookeeper.KeeperException.create(KeeperException.java:127)
   [junit4]   2> 	at org.apache.zookeeper.KeeperException.create(KeeperException.java:51)
   [junit4]   2> 	at org.apache.zookeeper.ZooKeeper.delete(ZooKeeper.java:873)
   [junit4]   2> 	at org.apache.solr.common.cloud.SolrZkClient$2.execute(SolrZkClient.java:173)
   [junit4]   2> 	at org.apache.solr.common.cloud.SolrZkClient$2.execute(SolrZkClient.java:170)
   [junit4]   2> 	at org.apache.solr.common.cloud.ZkCmdExecutor.retryOperation(ZkCmdExecutor.java:73)
   [junit4]   2> 	at org.apache.solr.common.cloud.SolrZkClient.delete(SolrZkClient.java:170)
   [junit4]   2> 	at org.apache.solr.cloud.ElectionContext.cancelElection(ElectionContext.java:67)
   [junit4]   2> 	at org.apache.solr.cloud.ShardLeaderElectionContext.runLeaderProcess(ElectionContext.java:276)
   [junit4]   2> 	at org.apache.solr.cloud.LeaderElector.runIamLeaderProcess(LeaderElector.java:163)
   [junit4]   2> 	at org.apache.solr.cloud.LeaderElector.checkIfIamLeader(LeaderElector.java:107)
   [junit4]   2> 	at org.apache.solr.cloud.LeaderElector.access$000(LeaderElector.java:55)
   [junit4]   2> 	at org.apache.solr.cloud.LeaderElector$1.process(LeaderElector.java:136)
   [junit4]   2> 	at org.apache.zookeeper.ClientCnxn$EventThread.processEvent(ClientCnxn.java:519)
   [junit4]   2> 	at org.apache.zookeeper.ClientCnxn$EventThread.run(ClientCnxn.java:495)
   [junit4]   2> 
   [junit4]   2> 475039 T1028 oasc.LeaderElector$1.process WARN  org.apache.zookeeper.KeeperException$SessionExpiredException: KeeperErrorCode = Session expired for /collections/awholynewcollection_1/leader_elect/shard1/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> 475039 T1028 oascc.ZkStateReader$3.process WARN ZooKeeper watch triggered, but Solr cannot talk to ZK
   [junit4]   2> 475039 T1028 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 3)
   [junit4]   2> 475039 T1028 oascc.ZkStateReader$2.process WARN ZooKeeper watch triggered, but Solr cannot talk to ZK
   [junit4]   2> NOTE: test params are: codec=Lucene45, sim=RandomSimilarityProvider(queryNorm=false,coord=no): {}, locale=ar_DZ, timezone=Europe/Bucharest
   [junit4]   2> NOTE: Linux 3.8.0-35-generic i386/Oracle Corporation 1.8.0-ea (32-bit)/cpus=8,threads=1,free=277270008,total=510656512
   [junit4]   2> NOTE: All tests run in this JVM: [TestIndexSearcher, TestIndexingPerformance, TestStressReorder, AddBlockUpdateTest, SpellingQueryConverterTest, StandardRequestHandlerTest, TestHashPartitioner, TestSchemaSimilarityResource, DebugComponentTest, SolrPluginUtilsTest, BadIndexSchemaTest, RAMDirectoryFactoryTest, SuggesterTSTTest, IndexBasedSpellCheckerTest, TestNumberUtils, TestShardHandlerFactory, BadCopyFieldTest, DocValuesMultiTest, TestCloudManagedSchema, DocValuesMissingTest, PreAnalyzedUpdateProcessorTest, IndexSchemaRuntimeFieldTest, TestQuerySenderListener, HighlighterConfigTest, ParsingFieldUpdateProcessorsTest, TestFoldingMultitermQuery, HighlighterTest, UniqFieldsUpdateProcessorFactoryTest, TestFastOutputStream, TestAnalyzedSuggestions, HdfsUnloadDistributedZkTest, TestDistribDocBasedVersion, TestComponentsName, TestSolr4Spatial, TestDefaultSimilarityFactory, CurrencyFieldOpenExchangeTest, TestRecovery, HardAutoCommitTest, ShardSplitTest, TestUpdate, OpenExchangeRatesOrgProviderTest, TestSweetSpotSimilarityFactory, CollectionsAPIDistributedZkTest]
   [junit4] Completed on J1 in 173.32s, 1 test, 1 failure <<< FAILURES!

[...truncated 673 lines...]
BUILD FAILED
/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/build.xml:459: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/build.xml:439: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/build.xml:39: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/extra-targets.xml:37: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build.xml:189: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/common-build.xml:491: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/lucene/common-build.xml:1307: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/lucene/common-build.xml:940: There were test failures: 348 suites, 1525 tests, 1 failure, 35 ignored (6 assumptions)

Total time: 42 minutes 45 seconds
Build step 'Invoke Ant' marked build as failure
Description set: Java: 32bit/jdk1.8.0-ea-b121 -server -XX:+UseG1GC
Archiving artifacts
Recording test results
Email was triggered for: Failure
Sending email for trigger: Failure