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

[JENKINS] Lucene-Solr-trunk-Linux (32bit/ibm-j9-jdk7) - Build # 7977 - Failure!

Build: http://jenkins.thetaphi.de/job/Lucene-Solr-trunk-Linux/7977/
Java: 32bit/ibm-j9-jdk7 -Xjit:exclude={org/apache/lucene/util/fst/FST.pack(IIF)Lorg/apache/lucene/util/fst/FST;}

2 tests failed.
REGRESSION:  org.apache.solr.update.AutoCommitTest.testMaxTime

Error Message:
Exception during query

Stack Trace:
java.lang.RuntimeException: Exception during query
	at __randomizedtesting.SeedInfo.seed([1B07CD188D5EA844:81F3B0FA13C43478]:0)
	at org.apache.solr.SolrTestCaseJ4.assertQ(SolrTestCaseJ4.java:637)
	at org.apache.solr.update.AutoCommitTest.testMaxTime(AutoCommitTest.java:227)
	at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
	at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:88)
	at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:55)
	at java.lang.reflect.Method.invoke(Method.java:613)
	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:780)
Caused by: java.lang.RuntimeException: REQUEST FAILED: xpath=//result[@numFound=0]
	xml response was: <?xml version="1.0" encoding="UTF-8"?>
<response>
<lst name="responseHeader"><int name="status">0</int><int name="QTime">2272</int></lst><result name="response" numFound="1" start="0"><doc><int name="id">529</int><int name="range_facet_si">529</int><arr name="range_facet_l"><long>529</long></arr><arr name="range_facet_sl"><long>529</long></arr><arr name="field_t"><str>what's inside?</str></arr><arr name="subject"><str>info</str></arr><long name="_version_">1449497028160651264</long><int name="intDefault">42</int><date name="timestamp">2013-10-21T09:34:47.464Z</date><arr name="multiDefault"><str>muLti-Default</str></arr></doc></result>
</response>

	request was:q=id:529&start=0&qt=standard&version=2.2&rows=20
	at org.apache.solr.SolrTestCaseJ4.assertQ(SolrTestCaseJ4.java:630)
	... 41 more


FAILED:  org.apache.solr.cloud.BasicDistributedZk2Test.testDistribSearch

Error Message:
Expected content type application/octet-stream but got text/html;charset=ISO-8859-1. <html> <head> <meta http-equiv="Content-Type" content="text/html;charset=ISO-8859-1"/> <title>Error 404 Can not find: /sc_/i/onenodecollectioncore/update</title> </head> <body> <h2>HTTP ERROR: 404</h2> <p>Problem accessing /sc_/i/onenodecollectioncore/update. Reason: <pre>    Can not find: /sc_/i/onenodecollectioncore/update</pre></p> <hr /><i><small>Powered by Jetty://</small></i>                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                     </body> </html> 

Stack Trace:
org.apache.solr.client.solrj.impl.HttpSolrServer$RemoteSolrException: Expected content type application/octet-stream but got text/html;charset=ISO-8859-1. <html>
<head>
<meta http-equiv="Content-Type" content="text/html;charset=ISO-8859-1"/>
<title>Error 404 Can not find: /sc_/i/onenodecollectioncore/update</title>
</head>
<body>
<h2>HTTP ERROR: 404</h2>
<p>Problem accessing /sc_/i/onenodecollectioncore/update. Reason:
<pre>    Can not find: /sc_/i/onenodecollectioncore/update</pre></p>
<hr /><i><small>Powered by Jetty://</small></i>
                                                
                                                
                                                
                                                
                                                
                                                
                                                
                                                
                                                
                                                
                                                
                                                
                                                
                                                
                                                
                                                
                                                
                                                
                                                
                                                
</body>
</html>

	at __randomizedtesting.SeedInfo.seed([1B07CD188D5EA844:9AE14300FA01C878]:0)
	at org.apache.solr.client.solrj.impl.HttpSolrServer.request(HttpSolrServer.java:428)
	at org.apache.solr.client.solrj.impl.HttpSolrServer.request(HttpSolrServer.java:181)
	at org.apache.solr.client.solrj.request.AbstractUpdateRequest.process(AbstractUpdateRequest.java:117)
	at org.apache.solr.client.solrj.SolrServer.add(SolrServer.java:116)
	at org.apache.solr.client.solrj.SolrServer.add(SolrServer.java:102)
	at org.apache.solr.cloud.BasicDistributedZk2Test.testNodeWithoutCollectionForwarding(BasicDistributedZk2Test.java:196)
	at org.apache.solr.cloud.BasicDistributedZk2Test.doTest(BasicDistributedZk2Test.java:88)
	at org.apache.solr.BaseDistributedSearchTestCase.testDistribSearch(BaseDistributedSearchTestCase.java:835)
	at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
	at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:88)
	at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:55)
	at java.lang.reflect.Method.invoke(Method.java:613)
	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:780)




Build Log:
[...truncated 9794 lines...]
   [junit4] Suite: org.apache.solr.cloud.BasicDistributedZk2Test
   [junit4]   2> 17986 T34 oas.BaseDistributedSearchTestCase.initHostContext Setting hostContext system property: /sc_/i
   [junit4]   2> 17996 T34 oas.SolrTestCaseJ4.setUp ###Starting testDistribSearch
   [junit4]   2> Creating dataDir: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./solrtest-BasicDistributedZk2Test-1382347342074
   [junit4]   2> 17999 T34 oasc.ZkTestServer.run STARTING ZK TEST SERVER
   [junit4]   2> 18002 T35 oasc.ZkTestServer$ZKServerMain.runFromConfig Starting server
   [junit4]   2> 18102 T34 oasc.ZkTestServer.run start zk server on port:36150
   [junit4]   2> 18562 T34 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 18657 T43 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@99e09859 name:ZooKeeperConnection Watcher:127.0.0.1:36150 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 18658 T34 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 18659 T34 oascc.SolrZkClient.makePath makePath: /solr
   [junit4]   2> 18709 T34 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 18727 T45 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@6e77f4b6 name:ZooKeeperConnection Watcher:127.0.0.1:36150/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 18728 T34 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 18732 T34 oascc.SolrZkClient.makePath makePath: /collections/collection1
   [junit4]   2> 18749 T34 oascc.SolrZkClient.makePath makePath: /collections/collection1/shards
   [junit4]   2> 18754 T34 oascc.SolrZkClient.makePath makePath: /collections/control_collection
   [junit4]   2> 18759 T34 oascc.SolrZkClient.makePath makePath: /collections/control_collection/shards
   [junit4]   2> 18769 T34 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test-files/solr/collection1/conf/solrconfig-tlog.xml to /configs/conf1/solrconfig.xml
   [junit4]   2> 18776 T34 oascc.SolrZkClient.makePath makePath: /configs/conf1/solrconfig.xml
   [junit4]   2> 18785 T34 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test-files/solr/collection1/conf/schema.xml to /configs/conf1/schema.xml
   [junit4]   2> 18786 T34 oascc.SolrZkClient.makePath makePath: /configs/conf1/schema.xml
   [junit4]   2> 18792 T34 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test-files/solr/collection1/conf/solrconfig.snippet.randomindexconfig.xml to /configs/conf1/solrconfig.snippet.randomindexconfig.xml
   [junit4]   2> 18793 T34 oascc.SolrZkClient.makePath makePath: /configs/conf1/solrconfig.snippet.randomindexconfig.xml
   [junit4]   2> 18803 T34 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test-files/solr/collection1/conf/stopwords.txt to /configs/conf1/stopwords.txt
   [junit4]   2> 18805 T34 oascc.SolrZkClient.makePath makePath: /configs/conf1/stopwords.txt
   [junit4]   2> 18814 T34 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test-files/solr/collection1/conf/protwords.txt to /configs/conf1/protwords.txt
   [junit4]   2> 18815 T34 oascc.SolrZkClient.makePath makePath: /configs/conf1/protwords.txt
   [junit4]   2> 18822 T34 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test-files/solr/collection1/conf/currency.xml to /configs/conf1/currency.xml
   [junit4]   2> 18825 T34 oascc.SolrZkClient.makePath makePath: /configs/conf1/currency.xml
   [junit4]   2> 18848 T34 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test-files/solr/collection1/conf/open-exchange-rates.json to /configs/conf1/open-exchange-rates.json
   [junit4]   2> 18849 T34 oascc.SolrZkClient.makePath makePath: /configs/conf1/open-exchange-rates.json
   [junit4]   2> 18858 T34 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test-files/solr/collection1/conf/mapping-ISOLatin1Accent.txt to /configs/conf1/mapping-ISOLatin1Accent.txt
   [junit4]   2> 18859 T34 oascc.SolrZkClient.makePath makePath: /configs/conf1/mapping-ISOLatin1Accent.txt
   [junit4]   2> 18882 T34 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test-files/solr/collection1/conf/old_synonyms.txt to /configs/conf1/old_synonyms.txt
   [junit4]   2> 18883 T34 oascc.SolrZkClient.makePath makePath: /configs/conf1/old_synonyms.txt
   [junit4]   2> 18892 T34 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test-files/solr/collection1/conf/synonyms.txt to /configs/conf1/synonyms.txt
   [junit4]   2> 18893 T34 oascc.SolrZkClient.makePath makePath: /configs/conf1/synonyms.txt
   [junit4]   2> 19260 T34 oejs.Server.doStart jetty-8.1.10.v20130312
   [junit4]   2> 19405 T34 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:58043
   [junit4]   2> 19416 T34 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
   [junit4]   2> 19417 T34 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
   [junit4]   2> 19418 T34 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: ./org.apache.solr.cloud.BasicDistributedZk2Test-controljetty-1382347342986
   [junit4]   2> 19419 T34 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: './org.apache.solr.cloud.BasicDistributedZk2Test-controljetty-1382347342986/'
   [junit4]   2> 19432 T34 oasc.ConfigSolr.fromFile Loading container configuration from /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-controljetty-1382347342986/solr.xml
   [junit4]   2> 19485 T34 oasc.CoreContainer.<init> New CoreContainer -1583992189
   [junit4]   2> 19486 T34 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=./org.apache.solr.cloud.BasicDistributedZk2Test-controljetty-1382347342986/]
   [junit4]   2> 19494 T34 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 120000
   [junit4]   2> 19495 T34 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
   [junit4]   2> 19496 T34 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
   [junit4]   2> 19497 T34 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
   [junit4]   2> 19498 T34 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
   [junit4]   2> 19499 T34 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
   [junit4]   2> 19500 T34 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
   [junit4]   2> 19501 T34 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
   [junit4]   2> 19502 T34 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
   [junit4]   2> 19504 T34 oasl.LogWatcher.createWatcher SLF4J impl is org.slf4j.impl.Log4jLoggerFactory
   [junit4]   2> 19505 T34 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
   [junit4]   2> 19508 T34 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:36150/solr
   [junit4]   2> 19516 T34 oasc.ZkController.checkChrootPath zkHost includes chroot
   [junit4]   2> 19525 T34 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 19526 T57 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@a8430654 name:ZooKeeperConnection Watcher:127.0.0.1:36150 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 19527 T34 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 19534 T34 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 19536 T59 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@bec04fc1 name:ZooKeeperConnection Watcher:127.0.0.1:36150/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 19537 T34 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 19542 T34 oascc.SolrZkClient.makePath makePath: /overseer/queue
   [junit4]   2> 19551 T34 oascc.SolrZkClient.makePath makePath: /overseer/collection-queue-work
   [junit4]   2> 19565 T34 oascc.SolrZkClient.makePath makePath: /live_nodes
   [junit4]   2> 19579 T34 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:58043_sc_%2Fi
   [junit4]   2> 19582 T34 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:58043_sc_%2Fi
   [junit4]   2> 19589 T34 oascc.SolrZkClient.makePath makePath: /overseer_elect/election
   [junit4]   2> 19603 T34 oascc.SolrZkClient.makePath makePath: /overseer_elect/leader
   [junit4]   2> 19619 T34 oasc.Overseer.start Overseer (id=90593515415863299-127.0.0.1:58043_sc_%2Fi-n_0000000000) starting
   [junit4]   2> 19631 T34 oascc.SolrZkClient.makePath makePath: /overseer/queue-work
   [junit4]   2> 19644 T34 oascc.SolrZkClient.makePath makePath: /clusterstate.json
   [junit4]   2> 19644 T61 oasc.OverseerCollectionProcessor.run Process current queue of collection creations
   [junit4]   2> 19651 T34 oascc.SolrZkClient.makePath makePath: /aliases.json
   [junit4]   2> 19658 T34 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
   [junit4]   2> 19669 T60 oasc.Overseer$ClusterStateUpdater.run Starting to work on the main queue
   [junit4]   2> 19681 T62 oasc.ZkController.publish publishing core=collection1 state=down
   [junit4]   2> 19682 T62 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
   [junit4]   2> 19684 T62 oasc.ZkController.waitForCoreNodeName look for our core node name
   [junit4]   2> 21179 T60 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 21182 T60 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={
   [junit4]   2> 	  "operation":"state",
   [junit4]   2> 	  "state":"down",
   [junit4]   2> 	  "base_url":"http://127.0.0.1:58043/sc_/i",
   [junit4]   2> 	  "core":"collection1",
   [junit4]   2> 	  "roles":null,
   [junit4]   2> 	  "node_name":"127.0.0.1:58043_sc_%2Fi",
   [junit4]   2> 	  "shard":null,
   [junit4]   2> 	  "shard_range":null,
   [junit4]   2> 	  "shard_state":"active",
   [junit4]   2> 	  "shard_parent":null,
   [junit4]   2> 	  "collection":"control_collection",
   [junit4]   2> 	  "numShards":"1",
   [junit4]   2> 	  "core_node_name":"core_node1"}
   [junit4]   2> 21183 T60 oasc.Overseer$ClusterStateUpdater.createCollection Create collection control_collection with shards [shard1]
   [junit4]   2> 21187 T60 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard1
   [junit4]   2> 21307 T59 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 1)
   [junit4]   2> 21686 T62 oasc.ZkController.waitForShardId waiting to find shard id in clusterstate for collection1
   [junit4]   2> 21687 T62 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: ./org.apache.solr.cloud.BasicDistributedZk2Test-controljetty-1382347342986/collection1
   [junit4]   2> 21687 T62 oasc.ZkController.createCollectionZkNode Check for collection zkNode:control_collection
   [junit4]   2> 21688 T62 oasc.ZkController.createCollectionZkNode Collection zkNode exists
   [junit4]   2> 21689 T62 oasc.ZkController.readConfigName Load collection config from:/collections/control_collection
   [junit4]   2> 21691 T62 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: './org.apache.solr.cloud.BasicDistributedZk2Test-controljetty-1382347342986/collection1/'
   [junit4]   2> 21692 T62 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.BasicDistributedZk2Test-controljetty-1382347342986/collection1/lib/classes/' to classloader
   [junit4]   2> 21693 T62 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.BasicDistributedZk2Test-controljetty-1382347342986/collection1/lib/README' to classloader
   [junit4]   2> 21747 T62 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_50
   [junit4]   2> 21813 T62 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
   [junit4]   2> 21818 T62 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
   [junit4]   2> 21830 T62 oass.IndexSchema.readSchema [collection1] Schema name=test
   [junit4]   2> 22894 T62 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
   [junit4]   2> 22903 T62 oass.IndexSchema.readSchema default search field in schema is text
   [junit4]   2> 22906 T62 oass.IndexSchema.readSchema unique key field: id
   [junit4]   2> 22937 T62 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
   [junit4]   2> 22943 T62 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
   [junit4]   2> 22948 T62 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
   [junit4]   2> 22951 T62 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
   [junit4]   2> 22962 T62 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
   [junit4]   2> 22963 T62 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
   [junit4]   2> 22965 T62 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
   [junit4]   2> 22965 T62 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
   [junit4]   2> 22966 T62 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
   [junit4]   2> 22966 T62 oasc.SolrCore.<init> [collection1] Opening new SolrCore at ./org.apache.solr.cloud.BasicDistributedZk2Test-controljetty-1382347342986/collection1/, dataDir=./org.apache.solr.cloud.BasicDistributedZk2Test-1382347342074/control/data/
   [junit4]   2> 22967 T62 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@92dbe06e
   [junit4]   2> 22969 T62 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.BasicDistributedZk2Test-1382347342074/control/data
   [junit4]   2> 22970 T62 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=./org.apache.solr.cloud.BasicDistributedZk2Test-1382347342074/control/data/index/
   [junit4]   2> 22970 T62 oasc.SolrCore.initIndex WARN [collection1] Solr index directory './org.apache.solr.cloud.BasicDistributedZk2Test-1382347342074/control/data/index' doesn't exist. Creating new index...
   [junit4]   2> 22971 T62 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.BasicDistributedZk2Test-1382347342074/control/data/index
   [junit4]   2> 22971 T62 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: maxMergeAtOnce=46, maxMergeAtOnceExplicit=34, maxMergedSegmentMB=63.201171875, floorSegmentMB=1.3837890625, forceMergeDeletesPctAllowed=24.867285311280238, segmentsPerTier=36.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=1.0
   [junit4]   2> 22972 T62 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
   [junit4]   2> 		commit{dir=MockDirectoryWrapper(org.apache.lucene.store.RAMDirectory@27845189 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@7aeb5aef),segFN=segments_1,generation=1}
   [junit4]   2> 22973 T62 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
   [junit4]   2> 22982 T62 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "nodistrib"
   [junit4]   2> 22986 T62 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "dedupe"
   [junit4]   2> 22987 T62 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
   [junit4]   2> 22987 T62 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "stored_sig"
   [junit4]   2> 22988 T62 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
   [junit4]   2> 22988 T62 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-explicit"
   [junit4]   2> 22989 T62 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-implicit"
   [junit4]   2> 22990 T62 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
   [junit4]   2> 22990 T62 oasc.SolrCore.loadUpdateProcessorChains no updateRequestProcessorChain defined as default, creating implicit default
   [junit4]   2> 22993 T62 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
   [junit4]   2> 22994 T62 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
   [junit4]   2> 22995 T62 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
   [junit4]   2> 22995 T62 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
   [junit4]   2> 22997 T62 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
   [junit4]   2> 22997 T62 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
   [junit4]   2> 22999 T62 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
   [junit4]   2> 23002 T62 oasu.CommitTracker.<init> Hard AutoCommit: disabled
   [junit4]   2> 23002 T62 oasu.CommitTracker.<init> Soft AutoCommit: disabled
   [junit4]   2> 23004 T62 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.LogByteSizeMergePolicy: [LogByteSizeMergePolicy: minMergeSize=1677721, mergeFactor=40, maxMergeSize=2147483648, maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=false, maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.21338255964629615]
   [junit4]   2> 23005 T62 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=1
   [junit4]   2> 		commit{dir=MockDirectoryWrapper(org.apache.lucene.store.RAMDirectory@27845189 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@7aeb5aef),segFN=segments_1,generation=1}
   [junit4]   2> 23005 T62 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
   [junit4]   2> 23006 T62 oass.SolrIndexSearcher.<init> Opening Searcher@a645cc50 main
   [junit4]   2> 23018 T63 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@a645cc50 main{StandardDirectoryReader(segments_1:1:nrt)}
   [junit4]   2> 23030 T62 oasc.CoreContainer.registerCore registering core: collection1
   [junit4]   2> 23030 T62 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:58043/sc_/i collection:control_collection shard:shard1
   [junit4]   2> 23036 T62 oascc.SolrZkClient.makePath makePath: /collections/control_collection/leader_elect/shard1/election
   [junit4]   2> 23066 T62 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process for shard shard1
   [junit4]   2> 23071 T62 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Enough replicas found to continue.
   [junit4]   2> 23072 T62 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new leader - try and sync
   [junit4]   2> 23073 T62 oasc.SyncStrategy.sync Sync replicas to http://127.0.0.1:58043/sc_/i/collection1/
   [junit4]   2> 23074 T62 oasc.SyncStrategy.syncReplicas Sync Success - now sync replicas to me
   [junit4]   2> 23074 T62 oasc.SyncStrategy.syncToMe http://127.0.0.1:58043/sc_/i/collection1/ has no replicas
   [junit4]   2> 23075 T62 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: http://127.0.0.1:58043/sc_/i/collection1/ shard1
   [junit4]   2> 23075 T62 oascc.SolrZkClient.makePath makePath: /collections/control_collection/leaders/shard1
   [junit4]   2> 24326 T60 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 24338 T59 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 1)
   [junit4]   2> 24398 T62 oasc.ZkController.register We are http://127.0.0.1:58043/sc_/i/collection1/ and leader is http://127.0.0.1:58043/sc_/i/collection1/
   [junit4]   2> 24398 T62 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:58043/sc_/i
   [junit4]   2> 24399 T62 oasc.ZkController.checkRecovery I am the leader, no recovery necessary
   [junit4]   2> 24399 T62 oasc.ZkController.publish publishing core=collection1 state=active
   [junit4]   2> 24400 T62 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
   [junit4]   2> 24403 T62 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 24405 T34 oass.SolrDispatchFilter.init user.dir=/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1
   [junit4]   2> 24406 T34 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
   [junit4]   2> 24423 T34 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 24426 T66 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@3d807dbc name:ZooKeeperConnection Watcher:127.0.0.1:36150/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 24427 T34 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 24430 T34 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
   [junit4]   2> 24438 T34 oasc.ChaosMonkey.monkeyLog monkey: init - expire sessions:true cause connection loss:true
   [junit4]   2> 24592 T34 oejs.Server.doStart jetty-8.1.10.v20130312
   [junit4]   2> 24594 T34 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:52494
   [junit4]   2> 24595 T34 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
   [junit4]   2> 24596 T34 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
   [junit4]   2> 24597 T34 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: ../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty1-1382347348516
   [junit4]   2> 24597 T34 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty1-1382347348516/'
   [junit4]   2> 24612 T34 oasc.ConfigSolr.fromFile Loading container configuration from /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty1-1382347348516/solr.xml
   [junit4]   2> 24665 T34 oasc.CoreContainer.<init> New CoreContainer 709273993
   [junit4]   2> 24666 T34 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty1-1382347348516/]
   [junit4]   2> 24668 T34 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 120000
   [junit4]   2> 24669 T34 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
   [junit4]   2> 24670 T34 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
   [junit4]   2> 24670 T34 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
   [junit4]   2> 24671 T34 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
   [junit4]   2> 24672 T34 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
   [junit4]   2> 24673 T34 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
   [junit4]   2> 24674 T34 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
   [junit4]   2> 24675 T34 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
   [junit4]   2> 24677 T34 oasl.LogWatcher.createWatcher SLF4J impl is org.slf4j.impl.Log4jLoggerFactory
   [junit4]   2> 24678 T34 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
   [junit4]   2> 24679 T34 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:36150/solr
   [junit4]   2> 24680 T34 oasc.ZkController.checkChrootPath zkHost includes chroot
   [junit4]   2> 24682 T34 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 24685 T77 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@b6dfad9b name:ZooKeeperConnection Watcher:127.0.0.1:36150 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 24686 T34 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 24693 T34 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 24714 T79 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@b247734e name:ZooKeeperConnection Watcher:127.0.0.1:36150/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 24717 T34 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 24770 T34 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
   [junit4]   2> 25776 T34 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:52494_sc_%2Fi
   [junit4]   2> 25778 T34 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:52494_sc_%2Fi
   [junit4]   2> 25782 T66 oascc.ZkStateReader$3.process Updating live nodes... (2)
   [junit4]   2> 25782 T59 oascc.ZkStateReader$3.process Updating live nodes... (2)
   [junit4]   2> 25782 T79 oascc.ZkStateReader$3.process Updating live nodes... (2)
   [junit4]   2> 25791 T80 oasc.ZkController.publish publishing core=collection1 state=down
   [junit4]   2> 25792 T80 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
   [junit4]   2> 25795 T80 oasc.ZkController.waitForCoreNodeName look for our core node name
   [junit4]   2> 25850 T60 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 25852 T60 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={
   [junit4]   2> 	  "operation":"state",
   [junit4]   2> 	  "state":"active",
   [junit4]   2> 	  "base_url":"http://127.0.0.1:58043/sc_/i",
   [junit4]   2> 	  "core":"collection1",
   [junit4]   2> 	  "roles":null,
   [junit4]   2> 	  "node_name":"127.0.0.1:58043_sc_%2Fi",
   [junit4]   2> 	  "shard":"shard1",
   [junit4]   2> 	  "shard_range":null,
   [junit4]   2> 	  "shard_state":"active",
   [junit4]   2> 	  "shard_parent":null,
   [junit4]   2> 	  "collection":"control_collection",
   [junit4]   2> 	  "numShards":"1",
   [junit4]   2> 	  "core_node_name":"core_node1"}
   [junit4]   2> 25857 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:52494/sc_/i",
   [junit4]   2> 	  "core":"collection1",
   [junit4]   2> 	  "roles":null,
   [junit4]   2> 	  "node_name":"127.0.0.1:52494_sc_%2Fi",
   [junit4]   2> 	  "shard":null,
   [junit4]   2> 	  "shard_range":null,
   [junit4]   2> 	  "shard_state":"active",
   [junit4]   2> 	  "shard_parent":null,
   [junit4]   2> 	  "collection":"collection1",
   [junit4]   2> 	  "numShards":"2",
   [junit4]   2> 	  "core_node_name":"core_node1"}
   [junit4]   2> 25857 T60 oasc.Overseer$ClusterStateUpdater.createCollection Create collection collection1 with shards [shard1, shard2]
   [junit4]   2> 25858 T60 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard1
   [junit4]   2> 25864 T79 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> 25864 T59 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> 25865 T66 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> 26796 T80 oasc.ZkController.waitForShardId waiting to find shard id in clusterstate for collection1
   [junit4]   2> 26796 T80 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: ../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty1-1382347348516/collection1
   [junit4]   2> 26797 T80 oasc.ZkController.createCollectionZkNode Check for collection zkNode:collection1
   [junit4]   2> 26798 T80 oasc.ZkController.createCollectionZkNode Collection zkNode exists
   [junit4]   2> 26798 T80 oasc.ZkController.readConfigName Load collection config from:/collections/collection1
   [junit4]   2> 26800 T80 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty1-1382347348516/collection1/'
   [junit4]   2> 26800 T80 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.BasicDistributedZk2Test-jetty1-1382347348516/collection1/lib/classes/' to classloader
   [junit4]   2> 26801 T80 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.BasicDistributedZk2Test-jetty1-1382347348516/collection1/lib/README' to classloader
   [junit4]   2> 26843 T80 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_50
   [junit4]   2> 26893 T80 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
   [junit4]   2> 26899 T80 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
   [junit4]   2> 26931 T80 oass.IndexSchema.readSchema [collection1] Schema name=test
   [junit4]   2> 27434 T80 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
   [junit4]   2> 27444 T80 oass.IndexSchema.readSchema default search field in schema is text
   [junit4]   2> 27447 T80 oass.IndexSchema.readSchema unique key field: id
   [junit4]   2> 27486 T80 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
   [junit4]   2> 27495 T80 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
   [junit4]   2> 27508 T80 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
   [junit4]   2> 27515 T80 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
   [junit4]   2> 27515 T80 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
   [junit4]   2> 27516 T80 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
   [junit4]   2> 27519 T80 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
   [junit4]   2> 27520 T80 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
   [junit4]   2> 27520 T80 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
   [junit4]   2> 27521 T80 oasc.SolrCore.<init> [collection1] Opening new SolrCore at ../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty1-1382347348516/collection1/, dataDir=./org.apache.solr.cloud.BasicDistributedZk2Test-1382347342074/jetty1/
   [junit4]   2> 27521 T80 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@92dbe06e
   [junit4]   2> 27523 T80 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.BasicDistributedZk2Test-1382347342074/jetty1
   [junit4]   2> 27524 T80 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=./org.apache.solr.cloud.BasicDistributedZk2Test-1382347342074/jetty1/index/
   [junit4]   2> 27524 T80 oasc.SolrCore.initIndex WARN [collection1] Solr index directory './org.apache.solr.cloud.BasicDistributedZk2Test-1382347342074/jetty1/index' doesn't exist. Creating new index...
   [junit4]   2> 27525 T80 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.BasicDistributedZk2Test-1382347342074/jetty1/index
   [junit4]   2> 27526 T80 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: maxMergeAtOnce=46, maxMergeAtOnceExplicit=34, maxMergedSegmentMB=63.201171875, floorSegmentMB=1.3837890625, forceMergeDeletesPctAllowed=24.867285311280238, segmentsPerTier=36.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=1.0
   [junit4]   2> 27527 T80 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
   [junit4]   2> 		commit{dir=MockDirectoryWrapper(org.apache.lucene.store.RAMDirectory@391d0546 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@9d9ce933),segFN=segments_1,generation=1}
   [junit4]   2> 27528 T80 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
   [junit4]   2> 27540 T80 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "nodistrib"
   [junit4]   2> 27541 T80 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "dedupe"
   [junit4]   2> 27541 T80 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
   [junit4]   2> 27542 T80 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "stored_sig"
   [junit4]   2> 27543 T80 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
   [junit4]   2> 27543 T80 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-explicit"
   [junit4]   2> 27544 T80 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-implicit"
   [junit4]   2> 27545 T80 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
   [junit4]   2> 27545 T80 oasc.SolrCore.loadUpdateProcessorChains no updateRequestProcessorChain defined as default, creating implicit default
   [junit4]   2> 27547 T80 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
   [junit4]   2> 27549 T80 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
   [junit4]   2> 27550 T80 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
   [junit4]   2> 27551 T80 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
   [junit4]   2> 27553 T80 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
   [junit4]   2> 27554 T80 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
   [junit4]   2> 27556 T80 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
   [junit4]   2> 27560 T80 oasu.CommitTracker.<init> Hard AutoCommit: disabled
   [junit4]   2> 27560 T80 oasu.CommitTracker.<init> Soft AutoCommit: disabled
   [junit4]   2> 27564 T80 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.LogByteSizeMergePolicy: [LogByteSizeMergePolicy: minMergeSize=1677721, mergeFactor=40, maxMergeSize=2147483648, maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=false, maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.21338255964629615]
   [junit4]   2> 27566 T80 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=1
   [junit4]   2> 		commit{dir=MockDirectoryWrapper(org.apache.lucene.store.RAMDirectory@391d0546 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@9d9ce933),segFN=segments_1,generation=1}
   [junit4]   2> 27566 T80 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
   [junit4]   2> 27567 T80 oass.SolrIndexSearcher.<init> Opening Searcher@59f91d5f main
   [junit4]   2> 27598 T81 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@59f91d5f main{StandardDirectoryReader(segments_1:1:nrt)}
   [junit4]   2> 27615 T80 oasc.CoreContainer.registerCore registering core: collection1
   [junit4]   2> 27615 T80 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:52494/sc_/i collection:collection1 shard:shard1
   [junit4]   2> 27620 T80 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
   [junit4]   2> 27637 T80 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process for shard shard1
   [junit4]   2> 27641 T80 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Enough replicas found to continue.
   [junit4]   2> 27642 T80 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new leader - try and sync
   [junit4]   2> 27642 T80 oasc.SyncStrategy.sync Sync replicas to http://127.0.0.1:52494/sc_/i/collection1/
   [junit4]   2> 27643 T80 oasc.SyncStrategy.syncReplicas Sync Success - now sync replicas to me
   [junit4]   2> 27643 T80 oasc.SyncStrategy.syncToMe http://127.0.0.1:52494/sc_/i/collection1/ has no replicas
   [junit4]   2> 27644 T80 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: http://127.0.0.1:52494/sc_/i/collection1/ shard1
   [junit4]   2> 27644 T80 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
   [junit4]   2> 28882 T60 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 28901 T79 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> 28901 T66 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> 28901 T59 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> 28943 T80 oasc.ZkController.register We are http://127.0.0.1:52494/sc_/i/collection1/ and leader is http://127.0.0.1:52494/sc_/i/collection1/
   [junit4]   2> 28943 T80 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:52494/sc_/i
   [junit4]   2> 28944 T80 oasc.ZkController.checkRecovery I am the leader, no recovery necessary
   [junit4]   2> 28944 T80 oasc.ZkController.publish publishing core=collection1 state=active
   [junit4]   2> 28945 T80 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
   [junit4]   2> 28948 T80 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 28951 T34 oass.SolrDispatchFilter.init user.dir=/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1
   [junit4]   2> 28952 T34 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
   [junit4]   2> 29114 T34 oejs.Server.doStart jetty-8.1.10.v20130312
   [junit4]   2> 29118 T34 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:35018
   [junit4]   2> 29119 T34 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
   [junit4]   2> 29120 T34 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
   [junit4]   2> 29121 T34 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: ./org.apache.solr.cloud.BasicDistributedZk2Test-jetty2-1382347353030
   [junit4]   2> 29122 T34 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: './org.apache.solr.cloud.BasicDistributedZk2Test-jetty2-1382347353030/'
   [junit4]   2> 29136 T34 oasc.ConfigSolr.fromFile Loading container configuration from /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty2-1382347353030/solr.xml
   [junit4]   2> 29203 T34 oasc.CoreContainer.<init> New CoreContainer 1752683064
   [junit4]   2> 29204 T34 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=./org.apache.solr.cloud.BasicDistributedZk2Test-jetty2-1382347353030/]
   [junit4]   2> 29206 T34 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 120000
   [junit4]   2> 29207 T34 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
   [junit4]   2> 29208 T34 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
   [junit4]   2> 29209 T34 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
   [junit4]   2> 29210 T34 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
   [junit4]   2> 29211 T34 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
   [junit4]   2> 29212 T34 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
   [junit4]   2> 29213 T34 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
   [junit4]   2> 29214 T34 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
   [junit4]   2> 29216 T34 oasl.LogWatcher.createWatcher SLF4J impl is org.slf4j.impl.Log4jLoggerFactory
   [junit4]   2> 29217 T34 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
   [junit4]   2> 29218 T34 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:36150/solr
   [junit4]   2> 29219 T34 oasc.ZkController.checkChrootPath zkHost includes chroot
   [junit4]   2> 29221 T34 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 29223 T93 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@9a4b915a name:ZooKeeperConnection Watcher:127.0.0.1:36150 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 29224 T34 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 29230 T34 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 29233 T95 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@e530715d name:ZooKeeperConnection Watcher:127.0.0.1:36150/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 29235 T34 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 29241 T34 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
   [junit4]   2> 30247 T34 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:35018_sc_%2Fi
   [junit4]   2> 30249 T34 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:35018_sc_%2Fi
   [junit4]   2> 30254 T59 oascc.ZkStateReader$3.process Updating live nodes... (3)
   [junit4]   2> 30255 T79 oascc.ZkStateReader$3.process Updating live nodes... (3)
   [junit4]   2> 30254 T66 oascc.ZkStateReader$3.process Updating live nodes... (3)
   [junit4]   2> 30256 T95 oascc.ZkStateReader$3.process Updating live nodes... (3)
   [junit4]   2> 30266 T96 oasc.ZkController.publish publishing core=collection1 state=down
   [junit4]   2> 30267 T96 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
   [junit4]   2> 30281 T96 oasc.ZkController.waitForCoreNodeName look for our core node name
   [junit4]   2> 30415 T60 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 30417 T60 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
   [junit4]   2> 	  "operation":"state",
   [junit4]   2> 	  "state":"active",
   [junit4]   2> 	  "base_url":"http://127.0.0.1:52494/sc_/i",
   [junit4]   2> 	  "core":"collection1",
   [junit4]   2> 	  "roles":null,
   [junit4]   2> 	  "node_name":"127.0.0.1:52494_sc_%2Fi",
   [junit4]   2> 	  "shard":"shard1",
   [junit4]   2> 	  "shard_range":null,
   [junit4]   2> 	  "shard_state":"active",
   [junit4]   2> 	  "shard_parent":null,
   [junit4]   2> 	  "collection":"collection1",
   [junit4]   2> 	  "numShards":"2",
   [junit4]   2> 	  "core_node_name":"core_node1"}
   [junit4]   2> 30440 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:35018/sc_/i",
   [junit4]   2> 	  "core":"collection1",
   [junit4]   2> 	  "roles":null,
   [junit4]   2> 	  "node_name":"127.0.0.1:35018_sc_%2Fi",
   [junit4]   2> 	  "shard":null,
   [junit4]   2> 	  "shard_range":null,
   [junit4]   2> 	  "shard_state":"active",
   [junit4]   2> 	  "shard_parent":null,
   [junit4]   2> 	  "collection":"collection1",
   [junit4]   2> 	  "numShards":"2",
   [junit4]   2> 	  "core_node_name":"core_node2"}
   [junit4]   2> 30441 T60 oasc.Overseer$ClusterStateUpdater.updateState Collection already exists with numShards=2
   [junit4]   2> 30441 T60 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard2
   [junit4]   2> 30447 T79 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 3)
   [junit4]   2> 30447 T66 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 3)
   [junit4]   2> 30448 T59 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 3)
   [junit4]   2> 30447 T95 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 3)
   [junit4]   2> 31282 T96 oasc.ZkController.waitForShardId waiting to find shard id in clusterstate for collection1
   [junit4]   2> 31282 T96 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: ./org.apache.solr.cloud.BasicDistributedZk2Test-jetty2-1382347353030/collection1
   [junit4]   2> 31282 T96 oasc.ZkController.createCollectionZkNode Check for collection zkNode:collection1
   [junit4]   2> 31283 T96 oasc.ZkController.createCollectionZkNode Collection zkNode exists
   [junit4]   2> 31284 T96 oasc.ZkController.readConfigName Load collection config from:/collections/collection1
   [junit4]   2> 31285 T96 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: './org.apache.solr.cloud.BasicDistributedZk2Test-jetty2-1382347353030/collection1/'
   [junit4]   2> 31286 T96 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.BasicDistributedZk2Test-jetty2-1382347353030/collection1/lib/classes/' to classloader
   [junit4]   2> 31286 T96 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.BasicDistributedZk2Test-jetty2-1382347353030/collection1/lib/README' to classloader
   [junit4]   2> 31320 T96 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_50
   [junit4]   2> 31365 T96 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
   [junit4]   2> 31368 T96 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
   [junit4]   2> 31376 T96 oass.IndexSchema.readSchema [collection1] Schema name=test
   [junit4]   2> 31730 T96 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
   [junit4]   2> 31736 T96 oass.IndexSchema.readSchema default search field in schema is text
   [junit4]   2> 31738 T96 oass.IndexSchema.readSchema unique key field: id
   [junit4]   2> 31760 T96 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
   [junit4]   2> 31764 T96 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
   [junit4]   2> 31769 T96 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
   [junit4]   2> 31770 T96 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
   [junit4]   2> 31770 T96 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
   [junit4]   2> 31771 T96 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
   [junit4]   2> 31773 T96 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
   [junit4]   2> 31773 T96 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
   [junit4]   2> 31774 T96 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
   [junit4]   2> 31774 T96 oasc.SolrCore.<init> [collection1] Opening new SolrCore at ./org.apache.solr.cloud.BasicDistributedZk2Test-jetty2-1382347353030/collection1/, dataDir=./org.apache.solr.cloud.BasicDistributedZk2Test-1382347342074/jetty2/
   [junit4]   2> 31774 T96 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@92dbe06e
   [junit4]   2> 31776 T96 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.BasicDistributedZk2Test-1382347342074/jetty2
   [junit4]   2> 31776 T96 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=./org.apache.solr.cloud.BasicDistributedZk2Test-1382347342074/jetty2/index/
   [junit4]   2> 31777 T96 oasc.SolrCore.initIndex WARN [collection1] Solr index directory './org.apache.solr.cloud.BasicDistributedZk2Test-1382347342074/jetty2/index' doesn't exist. Creating new index...
   [junit4]   2> 31777 T96 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.BasicDistributedZk2Test-1382347342074/jetty2/index
   [junit4]   2> 31778 T96 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: maxMergeAtOnce=46, maxMergeAtOnceExplicit=34, maxMergedSegmentMB=63.201171875, floorSegmentMB=1.3837890625, forceMergeDeletesPctAllowed=24.867285311280238, segmentsPerTier=36.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=1.0
   [junit4]   2> 31779 T96 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
   [junit4]   2> 		commit{dir=MockDirectoryWrapper(org.apache.lucene.store.RAMDirectory@1907776d lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@fab8809a),segFN=segments_1,generation=1}
   [junit4]   2> 31779 T96 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
   [junit4]   2> 31795 T96 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "nodistrib"
   [junit4]   2> 31795 T96 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "dedupe"
   [junit4]   2> 31796 T96 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
   [junit4]   2> 31796 T96 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "stored_sig"
   [junit4]   2> 31797 T96 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
   [junit4]   2> 31797 T96 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-explicit"
   [junit4]   2> 31798 T96 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-implicit"
   [junit4]   2> 31798 T96 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
   [junit4]   2> 31798 T96 oasc.SolrCore.loadUpdateProcessorChains no updateRequestProcessorChain defined as default, creating implicit default
   [junit4]   2> 31799 T96 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
   [junit4]   2> 31801 T96 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
   [junit4]   2> 31801 T96 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
   [junit4]   2> 31802 T96 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
   [junit4]   2> 31803 T96 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
   [junit4]   2> 31803 T96 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
   [junit4]   2> 31805 T96 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
   [junit4]   2> 31807 T96 oasu.CommitTracker.<init> Hard AutoCommit: disabled
   [junit4]   2> 31808 T96 oasu.CommitTracker.<init> Soft AutoCommit: disabled
   [junit4]   2> 31809 T96 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.LogByteSizeMergePolicy: [LogByteSizeMergePolicy: minMergeSize=1677721, mergeFactor=40, maxMergeSize=2147483648, maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=false, maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.21338255964629615]
   [junit4]   2> 31810 T96 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=1
   [junit4]   2> 		commit{dir=MockDirectoryWrapper(org.apache.lucene.store.RAMDirectory@1907776d lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@fab8809a),segFN=segments_1,generation=1}
   [junit4]   2> 31810 T96 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
   [junit4]   2> 31811 T96 oass.SolrIndexSearcher.<init> Opening Searcher@3fc69410 main
   [junit4]   2> 31824 T97 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@3fc69410 main{StandardDirectoryReader(segments_1:1:nrt)}
   [junit4]   2> 31827 T96 oasc.CoreContainer.registerCore registering core: collection1
   [junit4]   2> 31827 T96 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:35018/sc_/i collection:collection1 shard:shard2
   [junit4]   2> 31829 T96 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard2/election
   [junit4]   2> 31842 T96 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process for shard shard2
   [junit4]   2> 31845 T96 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Enough replicas found to continue.
   [junit4]   2> 31846 T96 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new leader - try and sync
   [junit4]   2> 31846 T96 oasc.SyncStrategy.sync Sync replicas to http://127.0.0.1:35018/sc_/i/collection1/
   [junit4]   2> 31847 T96 oasc.SyncStrategy.syncReplicas Sync Success - now sync replicas to me
   [junit4]   2> 31847 T96 oasc.SyncStrategy.syncToMe http://127.0.0.1:35018/sc_/i/collection1/ has no replicas
   [junit4]   2> 31848 T96 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: http://127.0.0.1:35018/sc_/i/collection1/ shard2
   [junit4]   2> 31848 T96 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard2
   [junit4]   2> 31957 T60 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 31981 T79 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 3)
   [junit4]   2> 31981 T66 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 3)
   [junit4]   2> 31982 T59 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 3)
   [junit4]   2> 31984 T95 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 3)
   [junit4]   2> 32007 T96 oasc.ZkController.register We are http://127.0.0.1:35018/sc_/i/collection1/ and leader is http://127.0.0.1:35018/sc_/i/collection1/
   [junit4]   2> 32008 T96 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:35018/sc_/i
   [junit4]   2> 32008 T96 oasc.ZkController.checkRecovery I am the leader, no recovery necessary
   [junit4]   2> 32009 T96 oasc.ZkController.publish publishing core=collection1 state=active
   [junit4]   2> 32009 T96 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
   [junit4]   2> 32012 T96 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 32015 T34 oass.SolrDispatchFilter.init user.dir=/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1
   [junit4]   2> 32015 T34 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
   [junit4]   2> 32146 T34 oejs.Server.doStart jetty-8.1.10.v20130312
   [junit4]   2> 32150 T34 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:35318
   [junit4]   2> 32152 T34 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
   [junit4]   2> 32153 T34 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
   [junit4]   2> 32154 T34 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: ../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty3-1382347356094
   [junit4]   2> 32155 T34 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty3-1382347356094/'
   [junit4]   2> 32166 T34 oasc.ConfigSolr.fromFile Loading container configuration from /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty3-1382347356094/solr.xml
   [junit4]   2> 32199 T34 oasc.CoreContainer.<init> New CoreContainer -2128695842
   [junit4]   2> 32200 T34 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty3-1382347356094/]
   [junit4]   2> 32201 T34 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 120000
   [junit4]   2> 32202 T34 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
   [junit4]   2> 32202 T34 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
   [junit4]   2> 32203 T34 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
   [junit4]   2> 32203 T34 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
   [junit4]   2> 32204 T34 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
   [junit4]   2> 32204 T34 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
   [junit4]   2> 32205 T34 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
   [junit4]   2> 32206 T34 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
   [junit4]   2> 32207 T34 oasl.LogWatcher.createWatcher SLF4J impl is org.slf4j.impl.Log4jLoggerFactory
   [junit4]   2> 32207 T34 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
   [junit4]   2> 32208 T34 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:36150/solr
   [junit4]   2> 32209 T34 oasc.ZkController.checkChrootPath zkHost includes chroot
   [junit4]   2> 32210 T34 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 32212 T109 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@52e4107b name:ZooKeeperConnection Watcher:127.0.0.1:36150 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 32212 T34 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 32215 T34 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 32222 T111 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@df38aad2 name:ZooKeeperConnection Watcher:127.0.0.1:36150/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 32223 T34 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 32229 T34 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
   [junit4]   2> 33235 T34 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:35318_sc_%2Fi
   [junit4]   2> 33237 T34 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:35318_sc_%2Fi
   [junit4]   2> 33248 T66 oascc.ZkStateReader$3.process Updating live nodes... (4)
   [junit4]   2> 33249 T79 oascc.ZkStateReader$3.process Updating live nodes... (4)
   [junit4]   2> 33249 T59 oascc.ZkStateReader$3.process Updating live nodes... (4)
   [junit4]   2> 33249 T95 oascc.ZkStateReader$3.process Updating live nodes... (4)
   [junit4]   2> 33250 T111 oascc.ZkStateReader$3.process Updating live nodes... (4)
   [junit4]   2> 33258 T112 oasc.ZkController.publish publishing core=collection1 state=down
   [junit4]   2> 33259 T112 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
   [junit4]   2> 33261 T112 oasc.ZkController.waitForCoreNodeName look for our core node name
   [junit4]   2> 33493 T60 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 33495 T60 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
   [junit4]   2> 	  "operation":"state",
   [junit4]   2> 	  "state":"active",
   [junit4]   2> 	  "base_url":"http://127.0.0.1:35018/sc_/i",
   [junit4]   2> 	  "core":"collection1",
   [junit4]   2> 	  "roles":null,
   [junit4]   2> 	  "node_name":"127.0.0.1:35018_sc_%2Fi",
   [junit4]   2> 	  "shard":"shard2",
   [junit4]   2> 	  "shard_range":null,
   [junit4]   2> 	  "shard_state":"active",
   [junit4]   2> 	  "shard_parent":null,
   [junit4]   2> 	  "collection":"collection1",
   [junit4]   2> 	  "numShards":"2",
   [junit4]   2> 	  "core_node_name":"core_node2"}
   [junit4]   2> 33501 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:35318/sc_/i",
   [junit4]   2> 	  "core":"collection1",
   [junit4]   2> 	  "roles":null,
   [junit4]   2> 	  "node_name":"127.0.0.1:35318_sc_%2Fi",
   [junit4]   2> 	  "shard":null,
   [junit4]   2> 	  "shard_range":null,
   [junit4]   2> 	  "shard_state":"active",
   [junit4]   2> 	  "shard_parent":null,
   [junit4]   2> 	  "collection":"collection1",
   [junit4]   2> 	  "numShards":"2",
   [junit4]   2> 	  "core_node_name":"core_node3"}
   [junit4]   2> 33501 T60 oasc.Overseer$ClusterStateUpdater.updateState Collection already exists with numShards=2
   [junit4]   2> 33502 T60 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard1
   [junit4]   2> 33511 T95 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 4)
   [junit4]   2> 33511 T111 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 4)
   [junit4]   2> 33511 T59 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 4)
   [junit4]   2> 33511 T66 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 4)
   [junit4]   2> 33511 T79 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 4)
   [junit4]   2> 34262 T112 oasc.ZkController.waitForShardId waiting to find shard id in clusterstate for collection1
   [junit4]   2> 34262 T112 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: ../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty3-1382347356094/collection1
   [junit4]   2> 34263 T112 oasc.ZkController.createCollectionZkNode Check for collection zkNode:collection1
   [junit4]   2> 34264 T112 oasc.ZkController.createCollectionZkNode Collection zkNode exists
   [junit4]   2> 34264 T112 oasc.ZkController.readConfigName Load collection config from:/collections/collection1
   [junit4]   2> 34266 T112 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty3-1382347356094/collection1/'
   [junit4]   2> 34267 T112 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.BasicDistributedZk2Test-jetty3-1382347356094/collection1/lib/classes/' to classloader
   [junit4]   2> 34268 T112 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.BasicDistributedZk2Test-jetty3-1382347356094/collection1/lib/README' to classloader
   [junit4]   2> 34390 T112 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_50
   [junit4]   2> 34455 T112 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
   [junit4]   2> 34457 T112 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
   [junit4]   2> 34471 T112 oass.IndexSchema.readSchema [collection1] Schema name=test
   [junit4]   2> 35088 T112 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
   [junit4]   2> 35097 T112 oass.IndexSchema.readSchema default search field in schema is text
   [junit4]   2> 35101 T112 oass.IndexSchema.readSchema unique key field: id
   [junit4]   2> 35127 T112 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
   [junit4]   2> 35134 T112 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
   [junit4]   2> 35149 T112 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
   [junit4]   2> 35151 T112 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
   [junit4]   2> 35152 T112 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
   [junit4]   2> 35152 T112 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
   [junit4]   2> 35154 T112 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
   [junit4]   2> 35154 T112 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
   [junit4]   2> 35155 T112 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
   [junit4]   2> 35155 T112 oasc.SolrCore.<init> [collection1] Opening new SolrCore at ../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty3-1382347356094/collection1/, dataDir=./org.apache.solr.cloud.BasicDistributedZk2Test-1382347342074/jetty3/
   [junit4]   2> 35156 T112 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@92dbe06e
   [junit4]   2> 35157 T112 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.BasicDistributedZk2Test-1382347342074/jetty3
   [junit4]   2> 35158 T112 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=./org.apache.solr.cloud.BasicDistributedZk2Test-1382347342074/jetty3/index/
   [junit4]   2> 35158 T112 oasc.SolrCore.initIndex WARN [collection1] Solr index directory './org.apache.solr.cloud.BasicDistributedZk2Test-1382347342074/jetty3/index' doesn't exist. Creating new index...
   [junit4]   2> 35159 T112 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.BasicDistributedZk2Test-1382347342074/jetty3/index
   [junit4]   2> 35160 T112 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: maxMergeAtOnce=46, maxMergeAtOnceExplicit=34, maxMergedSegmentMB=63.201171875, floorSegmentMB=1.3837890625, forceMergeDeletesPctAllowed=24.867285311280238, segmentsPerTier=36.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=1.0
   [junit4]   2> 35161 T112 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
   [junit4]   2> 		commit{dir=MockDirectoryWrapper(org.apache.lucene.store.RAMDirectory@c6ce8921 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@fc7656ca),segFN=segments_1,generation=1}
   [junit4]   2> 35161 T112 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
   [junit4]   2> 35168 T112 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "nodistrib"
   [junit4]   2> 35169 T112 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "dedupe"
   [junit4]   2> 35169 T112 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
   [junit4]   2> 35170 T112 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "stored_sig"
   [junit4]   2> 35170 T112 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
   [junit4]   2> 35171 T112 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-explicit"
   [junit4]   2> 35172 T112 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-implicit"
   [junit4]   2> 35172 T112 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
   [junit4]   2> 35173 T112 oasc.SolrCore.loadUpdateProcessorChains no updateRequestProcessorChain defined as default, creating implicit default
   [junit4]   2> 35174 T112 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
   [junit4]   2> 35176 T112 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
   [junit4]   2> 35176 T112 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
   [junit4]   2> 35177 T112 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
   [junit4]   2> 35178 T112 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
   [junit4]   2> 35179 T112 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
   [junit4]   2> 35181 T112 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
   [junit4]   2> 35186 T112 oasu.CommitTracker.<init> Hard AutoCommit: disabled
   [junit4]   2> 35188 T112 oasu.CommitTracker.<init> Soft AutoCommit: disabled
   [junit4]   2> 35199 T112 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.LogByteSizeMergePolicy: [LogByteSizeMergePolicy: minMergeSize=1677721, mergeFactor=40, maxMergeSize=2147483648, maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=false, maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.21338255964629615]
   [junit4]   2> 35201 T112 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=1
   [junit4]   2> 		commit{dir=MockDirectoryWrapper(org.apache.lucene.store.RAMDirectory@c6ce8921 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@fc7656ca),segFN=segments_1,generation=1}
   [junit4]   2> 35201 T112 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
   [junit4]   2> 35202 T112 oass.SolrIndexSearcher.<init> Opening Searcher@dd106fa8 main
   [junit4]   2> 35220 T113 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@dd106fa8 main{StandardDirectoryReader(segments_1:1:nrt)}
   [junit4]   2> 35225 T112 oasc.CoreContainer.registerCore registering core: collection1

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

2278 T2414 oasup.LogUpdateProcessor.finish [collection1] {add=[500 (1449497037483540480)]} 0 1
   [junit4]   2> 772279 T2414 oasup.LogUpdateProcessor.finish [collection1] {add=[500 (1449497037485637632)]} 0 1
   [junit4]   2> 772280 T2414 oasup.LogUpdateProcessor.finish [collection1] {add=[500 (1449497037486686208)]} 0 1
   [junit4]   2> 772281 T2414 oasup.LogUpdateProcessor.finish [collection1] {add=[500 (1449497037487734784)]} 0 1
   [junit4]   2> 772282 T2414 oasup.LogUpdateProcessor.finish [collection1] {add=[500 (1449497037488783360)]} 0 1
   [junit4]   2> 772283 T2414 oasup.LogUpdateProcessor.finish [collection1] {add=[500 (1449497037489831936)]} 0 1
   [junit4]   2> 772284 T2414 oasup.LogUpdateProcessor.finish [collection1] {add=[500 (1449497037490880512)]} 0 1
   [junit4]   2> 772285 T2414 oasup.LogUpdateProcessor.finish [collection1] {add=[500 (1449497037491929088)]} 0 1
   [junit4]   2> 772286 T2414 oasup.LogUpdateProcessor.finish [collection1] {add=[500 (1449497037492977664)]} 0 1
   [junit4]   2> 772287 T2414 oasup.LogUpdateProcessor.finish [collection1] {add=[500 (1449497037494026240)]} 0 1
   [junit4]   2> 772287 T2414 C823 oasc.SolrCore.execute [collection1] webapp=null path=null params={q=id:500&start=0&qt=standard&version=2.2&rows=20} hits=0 status=0 QTime=0 
   [junit4]   2> 772289 T2414 oasup.LogUpdateProcessor.finish [collection1] {delete=[530 (-1449497037496123392)]} 0 1
   [junit4]   2> 772290 T2414 oasup.LogUpdateProcessor.finish [collection1] {delete=[530 (-1449497037497171968)]} 0 1
   [junit4]   2> 772291 T2414 oasup.LogUpdateProcessor.finish [collection1] {delete=[530 (-1449497037498220544)]} 0 1
   [junit4]   2> 772292 T2414 oasup.LogUpdateProcessor.finish [collection1] {delete=[530 (-1449497037499269120)]} 0 1
   [junit4]   2> 772292 T2414 oasup.LogUpdateProcessor.finish [collection1] {delete=[530 (-1449497037499269121)]} 0 1
   [junit4]   2> 772293 T2414 oasup.LogUpdateProcessor.finish [collection1] {delete=[530 (-1449497037500317696)]} 0 1
   [junit4]   2> 772294 T2414 oasup.LogUpdateProcessor.finish [collection1] {delete=[530 (-1449497037501366272)]} 0 1
   [junit4]   2> 772295 T2414 oasup.LogUpdateProcessor.finish [collection1] {delete=[530 (-1449497037502414848)]} 0 1
   [junit4]   2> 772296 T2414 oasup.LogUpdateProcessor.finish [collection1] {delete=[530 (-1449497037503463424)]} 0 1
   [junit4]   2> 772297 T2414 oasup.LogUpdateProcessor.finish [collection1] {delete=[530 (-1449497037504512000)]} 0 1
   [junit4]   2> 772297 T2414 C823 oasc.SolrCore.execute [collection1] webapp=null path=null params={q=id:530&start=0&qt=standard&version=2.2&rows=20} hits=1 status=0 QTime=0 
   [junit4]   2> 773289 T2423 oasu.DirectUpdateHandler2.commit start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=true,prepareCommit=false}
   [junit4]   2> 773291 T2423 oass.SolrIndexSearcher.<init> Opening Searcher@46a1bc62 main
   [junit4]   2> 773291 T2423 oasu.DirectUpdateHandler2.commit end_commit_flush
   [junit4]   2> 773292 T2422 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@46a1bc62 main{StandardDirectoryReader(segments_3:21:nrt _5(5.0):c10/9:delGen=1)}
   [junit4]   2> 773299 T2414 C823 oasc.SolrCore.execute [collection1] webapp=null path=null params={q=id:500&start=0&qt=standard&version=2.2&rows=20} hits=1 status=0 QTime=0 
   [junit4]   2> 773301 T2414 C823 oasc.SolrCore.execute [collection1] webapp=null path=null params={q=id:530&start=0&qt=standard&version=2.2&rows=20} hits=0 status=0 QTime=0 
   [junit4]   2> 773302 T2414 oas.SolrTestCaseJ4.tearDown ###Ending testCommitWithin
   [junit4]   2> 773304 T2414 oas.SolrTestCaseJ4.deleteCore ###deleteCore
   [junit4]   2> 773304 T2414 oasc.CoreContainer.shutdown Shutting down CoreContainer instance=748096826
   [junit4]   2> 773304 T2414 oasc.SolrCore.close [collection1]  CLOSING SolrCore org.apache.solr.core.SolrCore@cc7733a2
   [junit4]   2> 773312 T2414 oasu.DirectUpdateHandler2.close closing DirectUpdateHandler2{commits=3,autocommits=0,soft autocommits=3,optimizes=0,rollbacks=0,expungeDeletes=0,docsPending=12,adds=0,deletesById=0,deletesByQuery=0,errors=0,cumulative_adds=12,cumulative_deletesById=11,cumulative_deletesByQuery=0,cumulative_errors=0}
   [junit4]   2> 773313 T2414 oasu.SolrCoreState.decrefSolrCoreState Closing SolrCoreState
   [junit4]   2> 773313 T2414 oasu.DefaultSolrCoreState.closeIndexWriter SolrCoreState ref count has reached 0 - closing IndexWriter
   [junit4]   2> 773314 T2414 oasu.DefaultSolrCoreState.closeIndexWriter closing IndexWriter with IndexWriterCloser
   [junit4]   2> 773314 T2414 C823 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=2
   [junit4]   2> 		commit{dir=RateLimitedDirectoryWrapper(MockDirectoryWrapper(org.apache.lucene.store.RAMDirectory@375a5eb6 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@e91c3eef)),segFN=segments_3,generation=3}
   [junit4]   2> 		commit{dir=RateLimitedDirectoryWrapper(MockDirectoryWrapper(org.apache.lucene.store.RAMDirectory@375a5eb6 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@e91c3eef)),segFN=segments_4,generation=4}
   [junit4]   2> 773315 T2414 C823 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 4
   [junit4]   2> 773315 T2414 oasc.SolrCore.closeSearcher [collection1] Closing main searcher on request.
   [junit4]   2> 773316 T2414 oasc.CachingDirectoryFactory.close Closing MockDirectoryFactory - 2 directories currently being tracked
   [junit4]   2> 773316 T2414 oasc.CachingDirectoryFactory.closeCacheValue looking to close /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./solrtest-AutoCommitTest-1382348085082/index [CachedDir<<refCount=0;path=/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./solrtest-AutoCommitTest-1382348085082/index;done=false>>]
   [junit4]   2> 773317 T2414 oasc.CachingDirectoryFactory.close Closing directory: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./solrtest-AutoCommitTest-1382348085082/index
   [junit4]   2> 773317 T2414 oasc.CachingDirectoryFactory.closeCacheValue looking to close /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./solrtest-AutoCommitTest-1382348085082 [CachedDir<<refCount=0;path=/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./solrtest-AutoCommitTest-1382348085082;done=false>>]
   [junit4]   2> 773317 T2414 oasc.CachingDirectoryFactory.close Closing directory: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./solrtest-AutoCommitTest-1382348085082
   [junit4]   2> NOTE: test params are: codec=Lucene40, sim=RandomSimilarityProvider(queryNorm=true,coord=yes): {}, locale=kk, timezone=Pacific/Saipan
   [junit4]   2> NOTE: Linux 3.8.0-31-generic x86/IBM Corporation 1.7.0 (32-bit)/cpus=8,threads=1,free=83656904,total=266076160
   [junit4]   2> NOTE: All tests run in this JVM: [DistributedTermsComponentTest, LegacyHTMLStripCharFilterTest, TestLuceneMatchVersion, TestDocumentBuilder, TestSearchPerf, QueryElevationComponentTest, SoftAutoCommitTest, CacheHeaderTest, PrimitiveFieldTypeTest, QueryResultKeyTest, PeerSyncTest, TestDynamicFieldResource, SpatialFilterTest, DOMUtilTest, TestNoOpRegenerator, LoggingHandlerTest, ZkControllerTest, BlockCacheTest, SliceStateUpdateTest, ParsingFieldUpdateProcessorsTest, HdfsBasicDistributedZkTest, TestValueSourceCache, MoreLikeThisHandlerTest, TestBM25SimilarityFactory, TestPostingsSolrHighlighter, TestShardHandlerFactory, TestCopyFieldCollectionResource, TestCharFilters, BadComponentTest, TestElisionMultitermQuery, BasicDistributedZkTest, TestExtendedDismaxParser, UnloadDistributedZkTest, TestBadConfig, ShardRoutingTest, SystemInfoHandlerTest, WordBreakSolrSpellCheckerTest, RecoveryZkTest, TestStressVersions, BJQParserTest, TermVectorComponentTest, SearchHandlerTest, TestSchemaNameResource, SOLR749Test, TestCoreContainer, TestPseudoReturnFields, TestConfig, SuggesterFSTTest, TestLMJelinekMercerSimilarityFactory, TestGroupingSearch, SimpleFacetsTest, TestReversedWildcardFilterFactory, UpdateRequestProcessorFactoryTest, OverseerTest, HdfsCollectionsAPIDistributedZkTest, BasicFunctionalityTest, FileBasedSpellCheckerTest, SynonymTokenizerTest, TestSuggestSpellingConverter, SliceStateTest, TestJmxMonitoredMap, BlockDirectoryTest, TestJoin, TestFaceting, TestLRUCache, ScriptEngineTest, FieldMutatingUpdateProcessorTest, TestSolrXmlPersistence, SchemaVersionSpecificBehaviorTest, SyncSliceTest, QueryEqualityTest, AutoCommitTest]
   [junit4] Completed on J0 in 12.33s, 3 tests, 1 error <<< FAILURES!

[...truncated 531 lines...]
BUILD FAILED
/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/build.xml:422: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/build.xml:415: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/build.xml:39: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build.xml:189: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/common-build.xml:483: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/lucene/common-build.xml:1259: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/lucene/common-build.xml:902: There were test failures: 326 suites, 1449 tests, 2 errors, 35 ignored (6 assumptions)

Total time: 48 minutes 26 seconds
Build step 'Invoke Ant' marked build as failure
Description set: Java: 32bit/ibm-j9-jdk7 -Xjit:exclude={org/apache/lucene/util/fst/FST.pack(IIF)Lorg/apache/lucene/util/fst/FST;}
Archiving artifacts
Recording test results
Email was triggered for: Failure
Sending email for trigger: Failure