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/19 22:42:17 UTC

[JENKINS] Lucene-Solr-4.x-Linux (64bit/jdk1.7.0_51) - Build # 9057 - Still Failing!

Build: http://jenkins.thetaphi.de/job/Lucene-Solr-4.x-Linux/9057/
Java: 64bit/jdk1.7.0_51 -XX:-UseCompressedOops -XX:+UseParallelGC

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

Error Message:


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




Build Log:
[...truncated 9975 lines...]
   [junit4] Suite: org.apache.solr.cloud.CollectionsAPIDistributedZkTest
   [junit4]   2> 17793 T32 oas.BaseDistributedSearchTestCase.initHostContext Setting hostContext system property: /wzan/ik
   [junit4]   2> 17799 T32 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-1390166469975
   [junit4]   2> 17802 T32 oasc.ZkTestServer.run STARTING ZK TEST SERVER
   [junit4]   2> 17804 T33 oasc.ZkTestServer$ZKServerMain.runFromConfig Starting server
   [junit4]   2> 17904 T32 oasc.ZkTestServer.run start zk server on port:55600
   [junit4]   2> 17952 T32 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 18044 T39 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@4326412c name:ZooKeeperConnection Watcher:127.0.0.1:55600 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 18044 T32 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 18046 T32 oascc.SolrZkClient.makePath makePath: /solr
   [junit4]   2> 18079 T32 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 18082 T41 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@66ba60c7 name:ZooKeeperConnection Watcher:127.0.0.1:55600/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 18082 T32 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 18086 T32 oascc.SolrZkClient.makePath makePath: /collections/collection1
   [junit4]   2> 18092 T32 oascc.SolrZkClient.makePath makePath: /collections/collection1/shards
   [junit4]   2> 18096 T32 oascc.SolrZkClient.makePath makePath: /collections/control_collection
   [junit4]   2> 18100 T32 oascc.SolrZkClient.makePath makePath: /collections/control_collection/shards
   [junit4]   2> 18105 T32 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> 18114 T32 oascc.SolrZkClient.makePath makePath: /configs/conf1/solrconfig.xml
   [junit4]   2> 18120 T32 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> 18121 T32 oascc.SolrZkClient.makePath makePath: /configs/conf1/schema.xml
   [junit4]   2> 18125 T32 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> 18126 T32 oascc.SolrZkClient.makePath makePath: /configs/conf1/solrconfig.snippet.randomindexconfig.xml
   [junit4]   2> 18130 T32 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> 18131 T32 oascc.SolrZkClient.makePath makePath: /configs/conf1/stopwords.txt
   [junit4]   2> 18135 T32 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> 18136 T32 oascc.SolrZkClient.makePath makePath: /configs/conf1/protwords.txt
   [junit4]   2> 18140 T32 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> 18140 T32 oascc.SolrZkClient.makePath makePath: /configs/conf1/currency.xml
   [junit4]   2> 18144 T32 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> 18144 T32 oascc.SolrZkClient.makePath makePath: /configs/conf1/enumsConfig.xml
   [junit4]   2> 18148 T32 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> 18149 T32 oascc.SolrZkClient.makePath makePath: /configs/conf1/open-exchange-rates.json
   [junit4]   2> 18152 T32 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> 18153 T32 oascc.SolrZkClient.makePath makePath: /configs/conf1/mapping-ISOLatin1Accent.txt
   [junit4]   2> 18157 T32 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> 18157 T32 oascc.SolrZkClient.makePath makePath: /configs/conf1/old_synonyms.txt
   [junit4]   2> 18161 T32 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> 18161 T32 oascc.SolrZkClient.makePath makePath: /configs/conf1/synonyms.txt
   [junit4]   2> Using new style solr.xml
   [junit4]   2> 18166 T32 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 18168 T43 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@1e4546f8 name:ZooKeeperConnection Watcher:127.0.0.1:55600 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 18169 T32 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 18169 T32 oascc.SolrZkClient.makePath makePath: /solr
   [junit4]   2> 18176 T32 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 18178 T45 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@75fa563e name:ZooKeeperConnection Watcher:127.0.0.1:55600/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 18178 T32 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 18179 T32 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> 18179 T32 oascc.SolrZkClient.makePath makePath: /configs/conf2/solrconfig.xml
   [junit4]   2> 18185 T32 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> 18185 T32 oascc.SolrZkClient.makePath makePath: /configs/conf2/schema.xml
   [junit4]   2> 18190 T32 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> 18190 T32 oascc.SolrZkClient.makePath makePath: /configs/conf2/solrconfig.snippet.randomindexconfig.xml
   [junit4]   2> 18194 T32 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> 18194 T32 oascc.SolrZkClient.makePath makePath: /configs/conf2/stopwords.txt
   [junit4]   2> 18197 T32 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> 18198 T32 oascc.SolrZkClient.makePath makePath: /configs/conf2/protwords.txt
   [junit4]   2> 18202 T32 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> 18202 T32 oascc.SolrZkClient.makePath makePath: /configs/conf2/currency.xml
   [junit4]   2> 18205 T32 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> 18206 T32 oascc.SolrZkClient.makePath makePath: /configs/conf2/open-exchange-rates.json
   [junit4]   2> 18209 T32 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> 18209 T32 oascc.SolrZkClient.makePath makePath: /configs/conf2/mapping-ISOLatin1Accent.txt
   [junit4]   2> 18213 T32 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> 18213 T32 oascc.SolrZkClient.makePath makePath: /configs/conf2/old_synonyms.txt
   [junit4]   2> 18217 T32 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> 18217 T32 oascc.SolrZkClient.makePath makePath: /configs/conf2/synonyms.txt
   [junit4]   2> 18221 T32 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> 18222 T32 oascc.SolrZkClient.makePath makePath: /configs/conf2/elevate.xml
   [junit4]   2> 18427 T32 oejs.Server.doStart jetty-8.1.10.v20130312
   [junit4]   2> 18510 T32 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:40716
   [junit4]   2> 18524 T32 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
   [junit4]   2> 18525 T32 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
   [junit4]   2> 18525 T32 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-1390166470402
   [junit4]   2> 18526 T32 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-1390166470402/'
   [junit4]   2> 18550 T32 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-1390166470402/solr.xml
   [junit4]   2> 18601 T32 oasc.ConfigSolrXml.<init> Config-defined core root directory: 
   [junit4]   2> 18603 T32 oasc.CoreContainer.<init> New CoreContainer 150788628
   [junit4]   2> 18604 T32 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-1390166470402/]
   [junit4]   2> 18616 T32 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 90000
   [junit4]   2> 18617 T32 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
   [junit4]   2> 18617 T32 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
   [junit4]   2> 18618 T32 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
   [junit4]   2> 18618 T32 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
   [junit4]   2> 18619 T32 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
   [junit4]   2> 18619 T32 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
   [junit4]   2> 18619 T32 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
   [junit4]   2> 18620 T32 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
   [junit4]   2> 18624 T32 oasl.LogWatcher.createWatcher SLF4J impl is org.slf4j.impl.Log4jLoggerFactory
   [junit4]   2> 18625 T32 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
   [junit4]   2> 18625 T32 oasc.CoreContainer.load Host Name: 127.0.0.1
   [junit4]   2> 18626 T32 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:55600/solr
   [junit4]   2> 18634 T32 oasc.ZkController.checkChrootPath zkHost includes chroot
   [junit4]   2> 18636 T32 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 18641 T57 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@4ae85f19 name:ZooKeeperConnection Watcher:127.0.0.1:55600 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 18641 T32 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 18647 T32 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 18649 T59 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@6b089ee3 name:ZooKeeperConnection Watcher:127.0.0.1:55600/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 18649 T32 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 18655 T32 oascc.SolrZkClient.makePath makePath: /overseer/queue
   [junit4]   2> 18663 T32 oascc.SolrZkClient.makePath makePath: /overseer/collection-queue-work
   [junit4]   2> 18671 T32 oascc.SolrZkClient.makePath makePath: /live_nodes
   [junit4]   2> 18675 T32 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:40716_wzan%2Fik
   [junit4]   2> 18678 T32 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:40716_wzan%2Fik
   [junit4]   2> 18684 T32 oascc.SolrZkClient.makePath makePath: /overseer_elect
   [junit4]   2> 18688 T32 oascc.SolrZkClient.makePath makePath: /overseer_elect/election
   [junit4]   2> 18700 T32 oascc.SolrZkClient.makePath makePath: /overseer_elect/leader
   [junit4]   2> 18703 T32 oasc.Overseer.start Overseer (id=91105949782114309-127.0.0.1:40716_wzan%2Fik-n_0000000000) starting
   [junit4]   2> 18714 T32 oascc.SolrZkClient.makePath makePath: /overseer/queue-work
   [junit4]   2> 18728 T61 oasc.OverseerCollectionProcessor.run Process current queue of collection creations
   [junit4]   2> 18728 T32 oascc.SolrZkClient.makePath makePath: /clusterstate.json
   [junit4]   2> 18733 T32 oascc.SolrZkClient.makePath makePath: /aliases.json
   [junit4]   2> 18733 T61 oasc.OverseerCollectionProcessor.prioritizeOverseerNodes prioritizing overseer nodes
   [junit4]   2> 18740 T32 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
   [junit4]   2> 18749 T60 oasc.Overseer$ClusterStateUpdater.run Starting to work on the main queue
   [junit4]   2> 18752 T32 oasc.CorePropertiesLocator.discover Looking for core definitions underneath /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-1390166470402
   [junit4]   2> 18757 T32 oasc.CorePropertiesLocator.discoverUnder Found core conf in /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-1390166470402/conf/
   [junit4]   2> 18795 T32 oasc.CorePropertiesLocator.discover Found 1 core definitions
   [junit4]   2> 18796 T32 oass.SolrDispatchFilter.init user.dir=/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1
   [junit4]   2> 18796 T32 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
   [junit4]   2> 18822 T32 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 18824 T64 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@7f5579a1 name:ZooKeeperConnection Watcher:127.0.0.1:55600/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 18826 T32 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 18829 T32 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
   [junit4]   2> 18836 T32 oasc.ChaosMonkey.monkeyLog monkey: init - expire sessions:false cause connection loss:false
   [junit4]   2> 18925 T32 oejs.Server.doStart jetty-8.1.10.v20130312
   [junit4]   2> 18927 T32 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:35474
   [junit4]   2> 18928 T32 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
   [junit4]   2> 18929 T32 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
   [junit4]   2> 18929 T32 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: ./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty1-1390166471012
   [junit4]   2> 18930 T32 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: './org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty1-1390166471012/'
   [junit4]   2> 18948 T32 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-1390166471012/solr.xml
   [junit4]   2> 18994 T32 oasc.ConfigSolrXml.<init> Config-defined core root directory: 
   [junit4]   2> 18995 T32 oasc.CoreContainer.<init> New CoreContainer 1861990275
   [junit4]   2> 18995 T32 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty1-1390166471012/]
   [junit4]   2> 18996 T32 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 90000
   [junit4]   2> 18997 T32 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
   [junit4]   2> 18997 T32 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
   [junit4]   2> 18997 T32 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
   [junit4]   2> 18998 T32 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
   [junit4]   2> 18998 T32 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
   [junit4]   2> 18998 T32 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
   [junit4]   2> 18999 T32 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
   [junit4]   2> 18999 T32 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
   [junit4]   2> 19002 T32 oasl.LogWatcher.createWatcher SLF4J impl is org.slf4j.impl.Log4jLoggerFactory
   [junit4]   2> 19003 T32 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
   [junit4]   2> 19003 T32 oasc.CoreContainer.load Host Name: 127.0.0.1
   [junit4]   2> 19003 T32 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:55600/solr
   [junit4]   2> 19004 T32 oasc.ZkController.checkChrootPath zkHost includes chroot
   [junit4]   2> 19004 T32 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 19006 T75 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@4fcd3261 name:ZooKeeperConnection Watcher:127.0.0.1:55600 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 19007 T32 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 19010 T32 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 19012 T77 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@295fb895 name:ZooKeeperConnection Watcher:127.0.0.1:55600/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 19012 T32 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 19019 T32 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
   [junit4]   2> 20024 T32 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:35474_wzan%2Fik
   [junit4]   2> 20026 T32 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:35474_wzan%2Fik
   [junit4]   2> 20032 T64 oascc.ZkStateReader$3.process Updating live nodes... (2)
   [junit4]   2> 20032 T59 oascc.ZkStateReader$3.process Updating live nodes... (2)
   [junit4]   2> 20032 T77 oascc.ZkStateReader$3.process Updating live nodes... (2)
   [junit4]   2> 20042 T32 oasc.CorePropertiesLocator.discover Looking for core definitions underneath /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty1-1390166471012
   [junit4]   2> 20044 T32 oasc.CorePropertiesLocator.discoverUnder Found core conf in /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty1-1390166471012/conf/
   [junit4]   2> 20065 T32 oasc.CorePropertiesLocator.discover Found 1 core definitions
   [junit4]   2> 20066 T32 oass.SolrDispatchFilter.init user.dir=/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1
   [junit4]   2> 20066 T32 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
   [junit4]   2> 20140 T32 oejs.Server.doStart jetty-8.1.10.v20130312
   [junit4]   2> 20143 T32 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:53435
   [junit4]   2> 20143 T32 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
   [junit4]   2> 20144 T32 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
   [junit4]   2> 20144 T32 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-jetty2-1390166472243
   [junit4]   2> 20144 T32 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-jetty2-1390166472243/'
   [junit4]   2> 20156 T32 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-jetty2-1390166472243/solr.xml
   [junit4]   2> 20195 T32 oasc.ConfigSolrXml.<init> Config-defined core root directory: 
   [junit4]   2> 20196 T32 oasc.CoreContainer.<init> New CoreContainer 571059610
   [junit4]   2> 20196 T32 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-jetty2-1390166472243/]
   [junit4]   2> 20197 T32 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 90000
   [junit4]   2> 20198 T32 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
   [junit4]   2> 20198 T32 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
   [junit4]   2> 20198 T32 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
   [junit4]   2> 20198 T32 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
   [junit4]   2> 20199 T32 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
   [junit4]   2> 20199 T32 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
   [junit4]   2> 20200 T32 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
   [junit4]   2> 20200 T32 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
   [junit4]   2> 20203 T32 oasl.LogWatcher.createWatcher SLF4J impl is org.slf4j.impl.Log4jLoggerFactory
   [junit4]   2> 20204 T32 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
   [junit4]   2> 20204 T32 oasc.CoreContainer.load Host Name: 127.0.0.1
   [junit4]   2> 20204 T32 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:55600/solr
   [junit4]   2> 20205 T32 oasc.ZkController.checkChrootPath zkHost includes chroot
   [junit4]   2> 20206 T32 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 20208 T89 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@29646aeb name:ZooKeeperConnection Watcher:127.0.0.1:55600 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 20209 T32 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 20311 T32 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 20315 T91 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@3aafc3a2 name:ZooKeeperConnection Watcher:127.0.0.1:55600/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 20316 T32 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 20328 T32 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
   [junit4]   2> 21336 T32 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:53435_wzan%2Fik
   [junit4]   2> 21338 T32 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:53435_wzan%2Fik
   [junit4]   2> 21342 T64 oascc.ZkStateReader$3.process Updating live nodes... (3)
   [junit4]   2> 21342 T91 oascc.ZkStateReader$3.process Updating live nodes... (3)
   [junit4]   2> 21342 T77 oascc.ZkStateReader$3.process Updating live nodes... (3)
   [junit4]   2> 21342 T59 oascc.ZkStateReader$3.process Updating live nodes... (3)
   [junit4]   2> 21351 T32 oasc.CorePropertiesLocator.discover Looking for core definitions underneath /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-jetty2-1390166472243
   [junit4]   2> 21353 T32 oasc.CorePropertiesLocator.discoverUnder Found core conf in /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-jetty2-1390166472243/conf/
   [junit4]   2> 21382 T32 oasc.CorePropertiesLocator.discover Found 1 core definitions
   [junit4]   2> 21383 T32 oass.SolrDispatchFilter.init user.dir=/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1
   [junit4]   2> 21383 T32 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
   [junit4]   2> 21455 T32 oejs.Server.doStart jetty-8.1.10.v20130312
   [junit4]   2> 21457 T32 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:38500
   [junit4]   2> 21458 T32 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
   [junit4]   2> 21458 T32 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
   [junit4]   2> 21459 T32 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: ./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty3-1390166473560
   [junit4]   2> 21459 T32 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: './org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty3-1390166473560/'
   [junit4]   2> 21479 T32 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-jetty3-1390166473560/solr.xml
   [junit4]   2> 21536 T32 oasc.ConfigSolrXml.<init> Config-defined core root directory: 
   [junit4]   2> 21537 T32 oasc.CoreContainer.<init> New CoreContainer 967908115
   [junit4]   2> 21537 T32 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty3-1390166473560/]
   [junit4]   2> 21538 T32 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 90000
   [junit4]   2> 21539 T32 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
   [junit4]   2> 21539 T32 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
   [junit4]   2> 21539 T32 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
   [junit4]   2> 21540 T32 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
   [junit4]   2> 21540 T32 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
   [junit4]   2> 21540 T32 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
   [junit4]   2> 21540 T32 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
   [junit4]   2> 21541 T32 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
   [junit4]   2> 21544 T32 oasl.LogWatcher.createWatcher SLF4J impl is org.slf4j.impl.Log4jLoggerFactory
   [junit4]   2> 21545 T32 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
   [junit4]   2> 21545 T32 oasc.CoreContainer.load Host Name: 127.0.0.1
   [junit4]   2> 21545 T32 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:55600/solr
   [junit4]   2> 21546 T32 oasc.ZkController.checkChrootPath zkHost includes chroot
   [junit4]   2> 21546 T32 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 21548 T103 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@b7d5486 name:ZooKeeperConnection Watcher:127.0.0.1:55600 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 21549 T32 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 21553 T32 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 21556 T105 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@334c3ee7 name:ZooKeeperConnection Watcher:127.0.0.1:55600/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 21556 T32 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 21568 T32 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
   [junit4]   2> 22577 T32 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:38500_wzan%2Fik
   [junit4]   2> 22579 T32 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:38500_wzan%2Fik
   [junit4]   2> 22583 T64 oascc.ZkStateReader$3.process Updating live nodes... (4)
   [junit4]   2> 22584 T105 oascc.ZkStateReader$3.process Updating live nodes... (4)
   [junit4]   2> 22584 T59 oascc.ZkStateReader$3.process Updating live nodes... (4)
   [junit4]   2> 22584 T77 oascc.ZkStateReader$3.process Updating live nodes... (4)
   [junit4]   2> 22583 T91 oascc.ZkStateReader$3.process Updating live nodes... (4)
   [junit4]   2> 22591 T32 oasc.CorePropertiesLocator.discover Looking for core definitions underneath /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty3-1390166473560
   [junit4]   2> 22592 T32 oasc.CorePropertiesLocator.discoverUnder Found core conf in /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty3-1390166473560/conf/
   [junit4]   2> 22619 T32 oasc.CorePropertiesLocator.discover Found 1 core definitions
   [junit4]   2> 22620 T32 oass.SolrDispatchFilter.init user.dir=/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1
   [junit4]   2> 22620 T32 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
   [junit4]   2> 22710 T32 oejs.Server.doStart jetty-8.1.10.v20130312
   [junit4]   2> 22713 T32 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:45057
   [junit4]   2> 22713 T32 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
   [junit4]   2> 22714 T32 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
   [junit4]   2> 22714 T32 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: ./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1390166474797
   [junit4]   2> 22714 T32 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: './org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1390166474797/'
   [junit4]   2> 22726 T32 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-1390166474797/solr.xml
   [junit4]   2> 22768 T32 oasc.ConfigSolrXml.<init> Config-defined core root directory: 
   [junit4]   2> 22768 T32 oasc.CoreContainer.<init> New CoreContainer 798491079
   [junit4]   2> 22768 T32 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1390166474797/]
   [junit4]   2> 22770 T32 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 90000
   [junit4]   2> 22770 T32 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
   [junit4]   2> 22770 T32 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
   [junit4]   2> 22771 T32 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
   [junit4]   2> 22771 T32 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
   [junit4]   2> 22771 T32 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
   [junit4]   2> 22772 T32 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
   [junit4]   2> 22772 T32 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
   [junit4]   2> 22772 T32 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
   [junit4]   2> 22776 T32 oasl.LogWatcher.createWatcher SLF4J impl is org.slf4j.impl.Log4jLoggerFactory
   [junit4]   2> 22776 T32 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
   [junit4]   2> 22776 T32 oasc.CoreContainer.load Host Name: 127.0.0.1
   [junit4]   2> 22777 T32 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:55600/solr
   [junit4]   2> 22777 T32 oasc.ZkController.checkChrootPath zkHost includes chroot
   [junit4]   2> 22778 T32 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 22780 T117 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@249cc83a name:ZooKeeperConnection Watcher:127.0.0.1:55600 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 22780 T32 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 22783 T32 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 22785 T119 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@6a1873a3 name:ZooKeeperConnection Watcher:127.0.0.1:55600/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 22785 T32 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 22792 T32 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
   [junit4]   2> 23802 T32 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:45057_wzan%2Fik
   [junit4]   2> 23805 T32 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:45057_wzan%2Fik
   [junit4]   2> 23813 T59 oascc.ZkStateReader$3.process Updating live nodes... (5)
   [junit4]   2> 23813 T64 oascc.ZkStateReader$3.process Updating live nodes... (5)
   [junit4]   2> 23814 T77 oascc.ZkStateReader$3.process Updating live nodes... (5)
   [junit4]   2> 23814 T105 oascc.ZkStateReader$3.process Updating live nodes... (5)
   [junit4]   2> 23815 T119 oascc.ZkStateReader$3.process Updating live nodes... (5)
   [junit4]   2> 23814 T91 oascc.ZkStateReader$3.process Updating live nodes... (5)
   [junit4]   2> 23830 T32 oasc.CorePropertiesLocator.discover Looking for core definitions underneath /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1390166474797
   [junit4]   2> 23832 T32 oasc.CorePropertiesLocator.discoverUnder Found core conf in /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1390166474797/conf/
   [junit4]   2> 23866 T32 oasc.CorePropertiesLocator.discover Found 1 core definitions
   [junit4]   2> 23867 T32 oass.SolrDispatchFilter.init user.dir=/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1
   [junit4]   2> 23867 T32 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
   [junit4]   2> 24084 T72 oasha.CollectionsHandler.handleCreateAction Creating Collection : version=2&replicationFactor=2&numShards=2&name=solrj_collection&wt=javabin&router.field=myOwnField&action=CREATE&router.name=compositeId&collection.configName=conf1
   [junit4]   2> 24087 T59 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/collection-queue-work state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 24092 T61 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> 24094 T61 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> 24098 T61 oasc.OverseerCollectionProcessor.createConfNode creating collections conf node /collections/solrj_collection 
   [junit4]   2> 24099 T61 oascc.SolrZkClient.makePath makePath: /collections/solrj_collection
   [junit4]   2> 24106 T59 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 24110 T60 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 24111 T60 oasc.Overseer$ClusterStateUpdater.buildCollection building a new collection: solrj_collection
   [junit4]   2> 24112 T60 oasc.Overseer$ClusterStateUpdater.createCollection Create collection solrj_collection with shards [shard1, shard2]
   [junit4]   2> 24123 T59 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 24125 T77 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> 24126 T105 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> 24126 T91 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> 24126 T119 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> 24125 T59 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> 24125 T64 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> 24207 T61 oasc.OverseerCollectionProcessor.createCollection going to create cores replicas shardNames [shard1, shard2] , repFactor : 2
   [junit4]   2> 24208 T61 oasc.OverseerCollectionProcessor.createCollection Creating shard solrj_collection_shard1_replica1 as part of slice shard1 of collection solrj_collection on 127.0.0.1:45057_wzan%2Fik
   [junit4]   2> 24217 T61 oasc.OverseerCollectionProcessor.createCollection Creating shard solrj_collection_shard1_replica2 as part of slice shard1 of collection solrj_collection on 127.0.0.1:38500_wzan%2Fik
   [junit4]   2> 24219 T61 oasc.OverseerCollectionProcessor.createCollection Creating shard solrj_collection_shard2_replica1 as part of slice shard2 of collection solrj_collection on 127.0.0.1:53435_wzan%2Fik
   [junit4]   2> 24220 T61 oasc.OverseerCollectionProcessor.createCollection Creating shard solrj_collection_shard2_replica2 as part of slice shard2 of collection solrj_collection on 127.0.0.1:40716_wzan%2Fik
   [junit4]   2> 24242 T86 oasc.ZkController.publish publishing core=solrj_collection_shard2_replica1 state=down
   [junit4]   2> 24243 T113 oasc.ZkController.publish publishing core=solrj_collection_shard1_replica1 state=down
   [junit4]   2> 24242 T101 oasc.ZkController.publish publishing core=solrj_collection_shard1_replica2 state=down
   [junit4]   2> 24242 T52 oasc.ZkController.publish publishing core=solrj_collection_shard2_replica2 state=down
   [junit4]   2> 24246 T59 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 24246 T101 oasc.ZkController.waitForCoreNodeName look for our core node name
   [junit4]   2> 24246 T52 oasc.ZkController.waitForCoreNodeName look for our core node name
   [junit4]   2> 24246 T113 oasc.ZkController.waitForCoreNodeName look for our core node name
   [junit4]   2> 24246 T86 oasc.ZkController.waitForCoreNodeName look for our core node name
   [junit4]   2> 24248 T60 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 24250 T60 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:53435/wzan/ik",
   [junit4]   2> 	  "core":"solrj_collection_shard2_replica1",
   [junit4]   2> 	  "roles":null,
   [junit4]   2> 	  "node_name":"127.0.0.1:53435_wzan%2Fik",
   [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> 24256 T59 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 24257 T60 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:45057/wzan/ik",
   [junit4]   2> 	  "core":"solrj_collection_shard1_replica1",
   [junit4]   2> 	  "roles":null,
   [junit4]   2> 	  "node_name":"127.0.0.1:45057_wzan%2Fik",
   [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> 24263 T59 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 24265 T60 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:38500/wzan/ik",
   [junit4]   2> 	  "core":"solrj_collection_shard1_replica2",
   [junit4]   2> 	  "roles":null,
   [junit4]   2> 	  "node_name":"127.0.0.1:38500_wzan%2Fik",
   [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> 24270 T59 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 24272 T60 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:40716/wzan/ik",
   [junit4]   2> 	  "core":"solrj_collection_shard2_replica2",
   [junit4]   2> 	  "roles":null,
   [junit4]   2> 	  "node_name":"127.0.0.1:40716_wzan%2Fik",
   [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> 24277 T59 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 24383 T91 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> 24383 T59 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> 24383 T77 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> 24383 T119 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> 24383 T64 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> 24383 T105 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> 25247 T101 oasc.ZkController.waitForShardId waiting to find shard id in clusterstate for solrj_collection_shard1_replica2
   [junit4]   2> 25247 T52 oasc.ZkController.waitForShardId waiting to find shard id in clusterstate for solrj_collection_shard2_replica2
   [junit4]   2> 25248 T113 oasc.ZkController.waitForShardId waiting to find shard id in clusterstate for solrj_collection_shard1_replica1
   [junit4]   2> 25248 T86 oasc.ZkController.waitForShardId waiting to find shard id in clusterstate for solrj_collection_shard2_replica1
   [junit4]   2> 25252 T86 oasc.CoreContainer.create Creating SolrCore 'solrj_collection_shard2_replica1' using instanceDir: ../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty2-1390166472243/solrj_collection_shard2_replica1
   [junit4]   2> 25252 T101 oasc.CoreContainer.create Creating SolrCore 'solrj_collection_shard1_replica2' using instanceDir: ./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty3-1390166473560/solrj_collection_shard1_replica2
   [junit4]   2> 25252 T52 oasc.CoreContainer.create Creating SolrCore 'solrj_collection_shard2_replica2' using instanceDir: ../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-controljetty-1390166470402/solrj_collection_shard2_replica2
   [junit4]   2> 25252 T113 oasc.CoreContainer.create Creating SolrCore 'solrj_collection_shard1_replica1' using instanceDir: ./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1390166474797/solrj_collection_shard1_replica1
   [junit4]   2> 25253 T113 oasc.ZkController.createCollectionZkNode Check for collection zkNode:solrj_collection
   [junit4]   2> 25253 T52 oasc.ZkController.createCollectionZkNode Check for collection zkNode:solrj_collection
   [junit4]   2> 25252 T101 oasc.ZkController.createCollectionZkNode Check for collection zkNode:solrj_collection
   [junit4]   2> 25252 T86 oasc.ZkController.createCollectionZkNode Check for collection zkNode:solrj_collection
   [junit4]   2> 25254 T113 oasc.ZkController.createCollectionZkNode Collection zkNode exists
   [junit4]   2> 25255 T101 oasc.ZkController.createCollectionZkNode Collection zkNode exists
   [junit4]   2> 25255 T101 oascc.ZkStateReader.readConfigName Load collection config from:/collections/solrj_collection
   [junit4]   2> 25254 T52 oasc.ZkController.createCollectionZkNode Collection zkNode exists
   [junit4]   2> 25256 T52 oascc.ZkStateReader.readConfigName Load collection config from:/collections/solrj_collection
   [junit4]   2> 25255 T86 oasc.ZkController.createCollectionZkNode Collection zkNode exists
   [junit4]   2> 25256 T86 oascc.ZkStateReader.readConfigName Load collection config from:/collections/solrj_collection
   [junit4]   2> 25255 T113 oascc.ZkStateReader.readConfigName Load collection config from:/collections/solrj_collection
   [junit4]   2> 25257 T101 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: './org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty3-1390166473560/solrj_collection_shard1_replica2/'
   [junit4]   2> 25258 T52 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-1390166470402/solrj_collection_shard2_replica2/'
   [junit4]   2> 25259 T113 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: './org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1390166474797/solrj_collection_shard1_replica1/'
   [junit4]   2> 25259 T86 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-jetty2-1390166472243/solrj_collection_shard2_replica1/'
   [junit4]   2> 25355 T101 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_47
   [junit4]   2> 25362 T86 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_47
   [junit4]   2> 25363 T52 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_47
   [junit4]   2> 25367 T113 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_47
   [junit4]   2> 25431 T101 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
   [junit4]   2> 25433 T113 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
   [junit4]   2> 25433 T101 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
   [junit4]   2> 25436 T113 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
   [junit4]   2> 25438 T52 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
   [junit4]   2> 25441 T52 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
   [junit4]   2> 25446 T86 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
   [junit4]   2> 25449 T86 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
   [junit4]   2> 25459 T101 oass.IndexSchema.readSchema [solrj_collection_shard1_replica2] Schema name=test
   [junit4]   2> 25471 T113 oass.IndexSchema.readSchema [solrj_collection_shard1_replica1] Schema name=test
   [junit4]   2> 25475 T52 oass.IndexSchema.readSchema [solrj_collection_shard2_replica2] Schema name=test
   [junit4]   2> 25488 T86 oass.IndexSchema.readSchema [solrj_collection_shard2_replica1] Schema name=test
   [junit4]   2> 26066 T101 oass.ByteField.init WARN ByteField is deprecated and will be removed in 5.0. You should use TrieIntField instead.
   [junit4]   2> 26067 T101 oass.ShortField.init WARN ShortField is deprecated and will be removed in 5.0. You should use TrieIntField instead.
   [junit4]   2> 26070 T101 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
   [junit4]   2> 26084 T101 oass.IndexSchema.readSchema default search field in schema is text
   [junit4]   2> 26089 T101 oass.IndexSchema.readSchema unique key field: id
   [junit4]   2> 26123 T101 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
   [junit4]   2> 26128 T101 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
   [junit4]   2> 26133 T101 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
   [junit4]   2> 26135 T101 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
   [junit4]   2> 26135 T101 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
   [junit4]   2> 26136 T101 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
   [junit4]   2> 26137 T101 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
   [junit4]   2> 26138 T101 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
   [junit4]   2> 26138 T101 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
   [junit4]   2> 26139 T101 oasc.SolrCore.<init> [solrj_collection_shard1_replica2] Opening new SolrCore at ./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty3-1390166473560/solrj_collection_shard1_replica2/, dataDir=./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty3-1390166473560/solrj_collection_shard1_replica2/data/
   [junit4]   2> 26148 T86 oass.ByteField.init WARN ByteField is deprecated and will be removed in 5.0. You should use TrieIntField instead.
   [junit4]   2> 26149 T101 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@2ad5934b
   [junit4]   2> 26149 T86 oass.ShortField.init WARN ShortField is deprecated and will be removed in 5.0. You should use TrieIntField instead.
   [junit4]   2> 26151 T86 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
   [junit4]   2> 26172 T86 oass.IndexSchema.readSchema default search field in schema is text
   [junit4]   2> 26189 T101 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty3-1390166473560/solrj_collection_shard1_replica2/data
   [junit4]   2> 26190 T101 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty3-1390166473560/solrj_collection_shard1_replica2/data/index/
   [junit4]   2> 26190 T101 oasc.SolrCore.initIndex WARN [solrj_collection_shard1_replica2] Solr index directory './org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty3-1390166473560/solrj_collection_shard1_replica2/data/index' doesn't exist. Creating new index...
   [junit4]   2> 26191 T101 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty3-1390166473560/solrj_collection_shard1_replica2/data/index
   [junit4]   2> 26192 T101 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: maxMergeAtOnce=43, maxMergeAtOnceExplicit=25, maxMergedSegmentMB=89.5087890625, floorSegmentMB=1.318359375, forceMergeDeletesPctAllowed=2.4747250264904617, segmentsPerTier=10.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.24653459912727593
   [junit4]   2> 26193 T86 oass.IndexSchema.readSchema unique key field: id
   [junit4]   2> 26193 T101 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
   [junit4]   2> 		commit{dir=MockDirectoryWrapper(org.apache.lucene.store.RAMDirectory@7b545018 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@4ea0397f),segFN=segments_1,generation=1}
   [junit4]   2> 26194 T101 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
   [junit4]   2> 26216 T101 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "nodistrib"
   [junit4]   2> 26220 T52 oass.ByteField.init WARN ByteField is deprecated and will be removed in 5.0. You should use TrieIntField instead.
   [junit4]   2> 26221 T52 oass.ShortField.init WARN ShortField is deprecated and will be removed in 5.0. You should use TrieIntField instead.
   [junit4]   2> 26224 T52 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
   [junit4]   2> 26225 T113 oass.ByteField.init WARN ByteField is deprecated and will be removed in 5.0. You should use TrieIntField instead.
   [junit4]   2> 26226 T113 oass.ShortField.init WARN ShortField is deprecated and will be removed in 5.0. You should use TrieIntField instead.
   [junit4]   2> 26228 T113 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
   [junit4]   2> 26242 T86 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
   [junit4]   2> 26245 T52 oass.IndexSchema.readSchema default search field in schema is text
   [junit4]   2> 26249 T86 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
   [junit4]   2> 26251 T101 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "dedupe"
   [junit4]   2> 26251 T101 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
   [junit4]   2> 26252 T101 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "stored_sig"
   [junit4]   2> 26252 T113 oass.IndexSchema.readSchema default search field in schema is text
   [junit4]   2> 26250 T52 oass.IndexSchema.readSchema unique key field: id
   [junit4]   2> 26252 T101 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
   [junit4]   2> 26261 T86 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
   [junit4]   2> 26262 T101 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-explicit"
   [junit4]   2> 26263 T101 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-implicit"
   [junit4]   2> 26264 T101 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
   [junit4]   2> 26264 T101 oasc.SolrCore.loadUpdateProcessorChains no updateRequestProcessorChain defined as default, creating implicit default
   [junit4]   2> 26262 T113 oass.IndexSchema.readSchema unique key field: id
   [junit4]   2> 26264 T86 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
   [junit4]   2> 26267 T86 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
   [junit4]   2> 26268 T86 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
   [junit4]   2> 26268 T101 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
   [junit4]   2> 26270 T101 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
   [junit4]   2> 26270 T101 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
   [junit4]   2> 26271 T101 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
   [junit4]   2> 26272 T86 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
   [junit4]   2> 26273 T101 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
   [junit4]   2> 26274 T101 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
   [junit4]   2> 26276 T101 oasc.RequestHandlers.initHandlersFromConfig created /admin/file: solr.admin.ShowFileRequestHandler
   [junit4]   2> 26273 T86 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
   [junit4]   2> 26278 T86 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
   [junit4]   2> 26278 T86 oasc.SolrCore.<init> [solrj_collection_shard2_replica1] Opening new SolrCore at ../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty2-1390166472243/solrj_collection_shard2_replica1/, dataDir=../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty2-1390166472243/solrj_collection_shard2_replica1/data/
   [junit4]   2> 26279 T86 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@2ad5934b
   [junit4]   2> 26287 T101 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
   [junit4]   2> 26291 T86 oasc.CachingDirectoryFactory.get return new directory for ../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty2-1390166472243/solrj_collection_shard2_replica1/data
   [junit4]   2> 26291 T86 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty2-1390166472243/solrj_collection_shard2_replica1/data/index/
   [junit4]   2> 26291 T86 oasc.SolrCore.initIndex WARN [solrj_collection_shard2_replica1] Solr index directory '../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty2-1390166472243/solrj_collection_shard2_replica1/data/index' doesn't exist. Creating new index...
   [junit4]   2> 26292 T86 oasc.CachingDirectoryFactory.get return new directory for ../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty2-1390166472243/solrj_collection_shard2_replica1/data/index
   [junit4]   2> 26292 T86 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: maxMergeAtOnce=43, maxMergeAtOnceExplicit=25, maxMergedSegmentMB=89.5087890625, floorSegmentMB=1.318359375, forceMergeDeletesPctAllowed=2.4747250264904617, segmentsPerTier=10.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.24653459912727593
   [junit4]   2> 26293 T86 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
   [junit4]   2> 		commit{dir=MockDirectoryWrapper(org.apache.lucene.store.RAMDirectory@139890ac lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@1748bce2),segFN=segments_1,generation=1}
   [junit4]   2> 26294 T86 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
   [junit4]   2> 26299 T101 oasu.CommitTracker.<init> Hard AutoCommit: disabled
   [junit4]   2> 26300 T101 oasu.CommitTracker.<init> Soft AutoCommit: disabled
   [junit4]   2> 26302 T101 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: maxMergeAtOnce=12, maxMergeAtOnceExplicit=36, maxMergedSegmentMB=87.5439453125, floorSegmentMB=2.029296875, forceMergeDeletesPctAllowed=22.159169660299366, segmentsPerTier=35.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.608147706626239
   [junit4]   2> 26303 T101 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=1
   [junit4]   2> 		commit{dir=MockDirectoryWrapper(org.apache.lucene.store.RAMDirectory@7b545018 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@4ea0397f),segFN=segments_1,generation=1}
   [junit4]   2> 26304 T101 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
   [junit4]   2> 26304 T101 oass.SolrIndexSearcher.<init> Opening Searcher@1ac7e317 main
   [junit4]   2> 26304 T52 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
   [junit4]   2> 26317 T86 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "nodistrib"
   [junit4]   2> 26318 T86 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "dedupe"
   [junit4]   2> 26319 T86 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
   [junit4]   2> 26319 T52 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
   [junit4]   2> 26320 T86 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "stored_sig"
   [junit4]   2> 26327 T52 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
   [junit4]   2> 26328 T86 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
   [junit4]   2> 26329 T86 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-explicit"
   [junit4]   2> 26329 T125 oasc.SolrCore.registerSearcher [solrj_collection_shard1_replica2] Registered new searcher Searcher@1ac7e317 main{StandardDirectoryReader(segments_1:1:nrt)}
   [junit4]   2> 26331 T86 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-implicit"
   [junit4]   2> 26330 T52 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
   [junit4]   2> 26333 T52 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
   [junit4]   2> 26333 T52 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
   [junit4]   2> 26334 T113 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
   [junit4]   2> 26337 T52 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
   [junit4]   2> 26337 T52 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
   [junit4]   2> 26338 T52 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
   [junit4]   2> 26339 T52 oasc.SolrCore.<init> [solrj_collection_shard2_replica2] Opening new SolrCore at ../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-controljetty-1390166470402/solrj_collection_shard2_replica2/, dataDir=../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-controljetty-1390166470402/solrj_collection_shard2_replica2/data/
   [junit4]   2> 26339 T52 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@2ad5934b
   [junit4]   2> 26342 T52 oasc.CachingDirectoryFactory.get return new directory for ../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-controljetty-1390166470402/solrj_collection_shard2_replica2/data
   [junit4]   2> 26342 T52 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-controljetty-1390166470402/solrj_collection_shard2_replica2/data/index/
   [junit4]   2> 26343 T52 oasc.SolrCore.initIndex WARN [solrj_collection_shard2_replica2] Solr index directory '../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-controljetty-1390166470402/solrj_collection_shard2_replica2/data/index' doesn't exist. Creating new index...
   [junit4]   2> 26342 T86 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
   [junit4]   2> 26343 T101 oasc.CoreContainer.registerCore registering core: solrj_collection_shard1_replica2
   [junit4]   2> 26344 T52 oasc.CachingDirectoryFactory.get return new directory for ../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-controljetty-1390166470402/solrj_collection_shard2_replica2/data/index
   [junit4]   2> 26344 T101 oasc.ZkController.register Register replica - core:solrj_collection_shard1_replica2 address:http://127.0.0.1:38500/wzan/ik collection:solrj_collection shard:shard1
   [junit4]   2> 26344 T86 oasc.SolrCore.loadUpdateProcessorChains no updateRequestProcessorChain defined as default, creating implicit default
   [junit4]   2> 26345 T113 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
   [junit4]   2> 26345 T52 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: maxMergeAtOnce=43, maxMergeAtOnceExplicit=25, maxMergedSegmentMB=89.5087890625, floorSegmentMB=1.318359375, forceMergeDeletesPctAllowed=2.4747250264904617, segmentsPerTier=10.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.24653459912727593
   [junit4]   2> 26347 T86 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
   [junit4]   2> 26348 T52 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
   [junit4]   2> 		commit{dir=MockDirectoryWrapper(org.apache.lucene.store.RAMDirectory@72dd5a1f lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@79220f71),segFN=segments_1,generation=1}
   [junit4]   2> 26349 T52 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
   [junit4]   2> 26349 T86 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
   [junit4]   2> 26350 T86 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
   [junit4]   2> 26351 T86 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
   [junit4]   2> 26352 T86 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
   [junit4]   2> 26353 T101 oascc.SolrZkClient.makePath makePath: /collections/solrj_collection/leader_elect/shard1/election
   [junit4]   2> 26354 T86 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
   [junit4]   2> 26354 T113 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
   [junit4]   2> 26357 T86 oasc.RequestHandlers.initHandlersFromConfig created /admin/file: solr.admin.ShowFileRequestHandler
   [junit4]   2> 26360 T86 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
   [junit4]   2> 26362 T113 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
   [junit4]   2> 26362 T113 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
   [junit4]   2> 26363 T113 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
   [junit4]   2> 26366 T86 oasu.CommitTracker.<init> Hard AutoCommit: disabled
   [junit4]   2> 26366 T52 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "nodistrib"
   [junit4]   2> 26367 T86 oasu.CommitTracker.<init> Soft AutoCommit: disabled
   [junit4]   2> 26367 T52 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "dedupe"
   [junit4]   2> 26368 T113 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
   [junit4]   2> 26369 T86 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: maxMergeAtOnce=12, maxMergeAtOnceExplicit=36, maxMergedSegmentMB=87.5439453125, floorSegmentMB=2.029296875, forceMergeDeletesPctAllowed=22.159169660299366, segmentsPerTier=35.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.608147706626239
   [junit4]   2> 26369 T52 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
   [junit4]   2> 26370 T86 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=1
   [junit4]   2> 		commit{dir=MockDirectoryWrapper(org.apache.lucene.store.RAMDirectory@139890ac lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@1748bce2),segFN=segments_1,generation=1}
   [junit4]   2> 26371 T86 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
   [junit4]   2> 26372 T86 oass.SolrIndexSearcher.<init> Opening Searcher@5c1be6a0 main
   [junit4]   2> 26369 T113 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
   [junit4]   2> 26371 T52 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "stored_sig"
   [junit4]   2> 26373 T113 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
   [junit4]   2> 26374 T52 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
   [junit4]   2> 26374 T113 oasc.SolrCore.<init> [solrj_collection_shard1_replica1] Opening new SolrCore at ./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1390166474797/solrj_collection_shard1_replica1/, dataDir=./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1390166474797/solrj_collection_shard1_replica1/data/
   [junit4]   2> 26374 T52 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-explicit"
   [junit4]   2> 26375 T101 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process for shard shard1
   [junit4]   2> 26375 T52 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-implicit"
   [junit4]   2> 26376 T52 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
   [junit4]   2> 26376 T52 oasc.SolrCore.loadUpdateProcessorChains no updateRequestProcessorChain defined as default, creating implicit default
   [junit4]   2> 26377 T52 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
   [junit4]   2> 26379 T52 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
   [junit4]   2> 26379 T52 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
   [junit4]   2> 26380 T52 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
   [junit4]   2> 26380 T101 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up for shard shard1: total=2 found=1 timeoutin=179999
   [junit4]   2> 26381 T52 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
   [junit4]   2> 26375 T113 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@2ad5934b
   [junit4]   2> 26382 T52 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
   [junit4]   2> 26379 T59 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 26383 T113 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1390166474797/solrj_collection_shard1_replica1/data
   [junit4]   2> 26385 T113 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1390166474797/solrj_collection_shard1_replica1/data/index/
   [junit4]   2> 26385 T59 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 26386 T59 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 26386 T52 oasc.RequestHandlers.initHandlersFromConfig created /admin/file: solr.admin.ShowFileRequestHandler
   [junit4]   2> 26385 T127 oasc.SolrCore.registerSearcher [solrj_collection_shard2_replica1] Registered new searcher Searcher@5c1be6a0 main{StandardDirectoryReader(segments_1:1:nrt)}
   [junit4]   2> 26388 T60 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 26388 T52 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
   [junit4]   2> 26386 T113 oasc.SolrCore.initIndex WARN [solrj_collection_shard1_replica1] Solr index directory './org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1390166474797/solrj_collection_shard1_replica1/data/index' doesn't exist. Creating new index...
   [junit4]   2> 26392 T113 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1390166474797/solrj_collection_shard1_replica1/data/index
   [junit4]   2> 26393 T113 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: maxMergeAtOnce=43, maxMergeAtOnceExplicit=25, maxMergedSegmentMB=89.5087890625, floorSegmentMB=1.318359375, forceMergeDeletesPctAllowed=2.4747250264904617, segmentsPerTier=10.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.24653459912727593
   [junit4]   2> 26394 T52 oasu.CommitTracker.<init> Hard AutoCommit: disabled
   [junit4]   2> 26394 T113 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
   [junit4]   2> 		commit{dir=MockDirectoryWrapper(org.apache.lucene.store.RAMDirectory@5fa69521 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@4343c625),segFN=segments_1,generation=1}
   [junit4]   2> 26396 T59 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 26395 T52 oasu.CommitTracker.<init> Soft AutoCommit: disabled
   [junit4]   2> 26396 T113 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
   [junit4]   2> 26398 T64 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> 26398 T59 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> 26398 T77 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> 26399 T119 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> 26399 T91 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> 26399 T52 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: maxMergeAtOnce=12, maxMergeAtOnceExplicit=36, maxMergedSegmentMB=87.5439453125, floorSegmentMB=2.029296875, forceMergeDeletesPctAllowed=22.159169660299366, segmentsPerTier=35.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.608147706626239
   [junit4]   2> 26401 T105 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> 26401 T52 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=1
   [junit4]   2> 		commit{dir=MockDirectoryWrapper(org.apache.lucene.store.RAMDirectory@72dd5a1f lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@79220f71),segFN=segments_1,generation=1}
   [junit4]   2> 26404 T52 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
   [junit4]   2> 26405 T52 oass.SolrIndexSearcher.<init> Opening Searcher@5ecdb1d0 main
   [junit4]   2> 26408 T86 oasc.CoreContainer.registerCore registering core: solrj_collection_shard2_replica1
   [junit4]   2> 26408 T86 oasc.ZkController.register Register replica - core:solrj_col

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

, so become leader anyway
   [junit4]   2> 118371 T119 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: http://127.0.0.1:45057/wzan/ik/nodes_used_collection_shard2_replica2/ shard2
   [junit4]   2> 118372 T119 oasc.SolrCore.close [nodes_used_collection_shard2_replica2]  CLOSING SolrCore org.apache.solr.core.SolrCore@507104cd
   [junit4]   2> 118383 T119 oasu.DirectUpdateHandler2.close closing DirectUpdateHandler2{commits=0,autocommits=0,soft autocommits=0,optimizes=0,rollbacks=0,expungeDeletes=0,docsPending=0,adds=0,deletesById=0,deletesByQuery=0,errors=0,cumulative_adds=0,cumulative_deletesById=0,cumulative_deletesByQuery=0,cumulative_errors=0,transaction_logs_total_size=0,transaction_logs_total_number=0}
   [junit4]   2> 118383 T119 oasu.SolrCoreState.decrefSolrCoreState Closing SolrCoreState
   [junit4]   2> 118384 T119 oasu.DefaultSolrCoreState.closeIndexWriter SolrCoreState ref count has reached 0 - closing IndexWriter
   [junit4]   2> 118384 T119 oasu.DefaultSolrCoreState.closeIndexWriter closing IndexWriter with IndexWriterCloser
   [junit4]   2> 118384 T119 oasc.SolrCore.closeSearcher [nodes_used_collection_shard2_replica2] Closing main searcher on request.
   [junit4]   2> 118384 T119 oasc.CachingDirectoryFactory.close Closing MockDirectoryFactory - 2 directories currently being tracked
   [junit4]   2> 118385 T119 oasc.CachingDirectoryFactory.closeCacheValue looking to close ./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1390166474797/nodes_used_collection_shard2_replica2/data/index [CachedDir<<refCount=0;path=./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1390166474797/nodes_used_collection_shard2_replica2/data/index;done=false>>]
   [junit4]   2> 118385 T119 oasc.CachingDirectoryFactory.close Closing directory: ./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1390166474797/nodes_used_collection_shard2_replica2/data/index
   [junit4]   2> 118385 T119 oasc.CachingDirectoryFactory.closeCacheValue looking to close ./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1390166474797/nodes_used_collection_shard2_replica2/data [CachedDir<<refCount=0;path=./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1390166474797/nodes_used_collection_shard2_replica2/data;done=false>>]
   [junit4]   2> 118385 T119 oasc.CachingDirectoryFactory.close Closing directory: ./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1390166474797/nodes_used_collection_shard2_replica2/data
   [junit4]   2> 118385 T119 oascc.SolrZkClient.makePath makePath: /collections/nodes_used_collection/leaders/shard2
   [junit4]   2> 118386 T119 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:164)
   [junit4]   2> 		at org.apache.solr.cloud.LeaderElector.checkIfIamLeader(LeaderElector.java:108)
   [junit4]   2> 		at org.apache.solr.cloud.LeaderElector.access$000(LeaderElector.java:55)
   [junit4]   2> 		at org.apache.solr.cloud.LeaderElector$1.process(LeaderElector.java:137)
   [junit4]   2> 		at org.apache.zookeeper.ClientCnxn$EventThread.processEvent(ClientCnxn.java:519)
   [junit4]   2> 		at org.apache.zookeeper.ClientCnxn$EventThread.run(ClientCnxn.java:495)
   [junit4]   2> 	
   [junit4]   2> 118386 T119 oasc.LeaderElector$1.process WARN  org.apache.zookeeper.KeeperException$SessionExpiredException: KeeperErrorCode = Session expired for /collections/nodes_used_collection/leader_elect/shard2/election/91105949782114318-core_node2-n_0000000001
   [junit4]   2> 	at org.apache.zookeeper.KeeperException.create(KeeperException.java:127)
   [junit4]   2> 	at org.apache.zookeeper.KeeperException.create(KeeperException.java:51)
   [junit4]   2> 	at org.apache.zookeeper.ZooKeeper.delete(ZooKeeper.java:873)
   [junit4]   2> 	at org.apache.solr.common.cloud.SolrZkClient$2.execute(SolrZkClient.java:173)
   [junit4]   2> 	at org.apache.solr.common.cloud.SolrZkClient$2.execute(SolrZkClient.java:170)
   [junit4]   2> 	at org.apache.solr.common.cloud.ZkCmdExecutor.retryOperation(ZkCmdExecutor.java:73)
   [junit4]   2> 	at org.apache.solr.common.cloud.SolrZkClient.delete(SolrZkClient.java:170)
   [junit4]   2> 	at org.apache.solr.cloud.ElectionContext.cancelElection(ElectionContext.java:67)
   [junit4]   2> 	at org.apache.solr.cloud.ShardLeaderElectionContext.runLeaderProcess(ElectionContext.java:293)
   [junit4]   2> 	at org.apache.solr.cloud.LeaderElector.runIamLeaderProcess(LeaderElector.java:164)
   [junit4]   2> 	at org.apache.solr.cloud.LeaderElector.checkIfIamLeader(LeaderElector.java:108)
   [junit4]   2> 	at org.apache.solr.cloud.LeaderElector.access$000(LeaderElector.java:55)
   [junit4]   2> 	at org.apache.solr.cloud.LeaderElector$1.process(LeaderElector.java:137)
   [junit4]   2> 	at org.apache.zookeeper.ClientCnxn$EventThread.processEvent(ClientCnxn.java:519)
   [junit4]   2> 	at org.apache.zookeeper.ClientCnxn$EventThread.run(ClientCnxn.java:495)
   [junit4]   2> 
   [junit4]   2> 118386 T119 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 2)
   [junit4]   2> 118387 T119 oascc.ZkStateReader$2.process WARN ZooKeeper watch triggered, but Solr cannot talk to ZK
   [junit4]   2> 118387 T119 oasc.LeaderElector$1.process WARN  org.apache.zookeeper.KeeperException$SessionExpiredException: KeeperErrorCode = Session expired for /overseer_elect/election
   [junit4]   2> 	at org.apache.zookeeper.KeeperException.create(KeeperException.java:127)
   [junit4]   2> 	at org.apache.zookeeper.KeeperException.create(KeeperException.java:51)
   [junit4]   2> 	at org.apache.zookeeper.ZooKeeper.getChildren(ZooKeeper.java:1468)
   [junit4]   2> 	at org.apache.solr.common.cloud.SolrZkClient$6.execute(SolrZkClient.java:256)
   [junit4]   2> 	at org.apache.solr.common.cloud.SolrZkClient$6.execute(SolrZkClient.java:253)
   [junit4]   2> 	at org.apache.solr.common.cloud.ZkCmdExecutor.retryOperation(ZkCmdExecutor.java:73)
   [junit4]   2> 	at org.apache.solr.common.cloud.SolrZkClient.getChildren(SolrZkClient.java:253)
   [junit4]   2> 	at org.apache.solr.cloud.LeaderElector.checkIfIamLeader(LeaderElector.java:92)
   [junit4]   2> 	at org.apache.solr.cloud.LeaderElector.access$000(LeaderElector.java:55)
   [junit4]   2> 	at org.apache.solr.cloud.LeaderElector$1.process(LeaderElector.java:137)
   [junit4]   2> 	at org.apache.zookeeper.ClientCnxn$EventThread.processEvent(ClientCnxn.java:519)
   [junit4]   2> 	at org.apache.zookeeper.ClientCnxn$EventThread.run(ClientCnxn.java:495)
   [junit4]   2> 
   [junit4]   2> 118387 T119 oascc.ZkStateReader$3.process WARN ZooKeeper watch triggered, but Solr cannot talk to ZK
   [junit4]   2> NOTE: test params are: codec=Lucene42, sim=DefaultSimilarity, locale=bg_BG, timezone=Etc/GMT-7
   [junit4]   2> NOTE: Linux 3.8.0-35-generic amd64/Oracle Corporation 1.7.0_51 (64-bit)/cpus=8,threads=3,free=197604016,total=290979840
   [junit4]   2> NOTE: All tests run in this JVM: [FieldAnalysisRequestHandlerTest, SpellCheckComponentTest, TestComponentsName, FileUtilsTest, DistanceFunctionTest, CollectionsAPIDistributedZkTest]
   [junit4] Completed on J1 in 101.54s, 1 test, 1 failure <<< FAILURES!

[...truncated 1043 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:1308: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/lucene/common-build.xml:941: There were test failures: 354 suites, 1540 tests, 1 failure, 34 ignored (6 assumptions)

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