lucene-dev mailing list archives

Site index · List index
Message view « Date » · « Thread »
Top « Date » · « Thread »
From Apache Jenkins Server <jenk...@builds.apache.org>
Subject [JENKINS] Lucene-Solr-NightlyTests-trunk - Build # 674 - Still Failing
Date Mon, 03 Nov 2014 03:58:25 GMT
Build: https://builds.apache.org/job/Lucene-Solr-NightlyTests-trunk/674/

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

Error Message:
Shard split did not complete. Last recorded state: running expected:<[completed]> but was:<[running]>

Stack Trace:
org.junit.ComparisonFailure: Shard split did not complete. Last recorded state: running expected:<[completed]> but was:<[running]>
	at __randomizedtesting.SeedInfo.seed([80B8668EE9622AC1:15EE8969E3D4AFD]:0)
	at org.junit.Assert.assertEquals(Assert.java:125)
	at org.apache.solr.cloud.CollectionsAPIAsyncDistributedZkTest.testSolrJAPICalls(CollectionsAPIAsyncDistributedZkTest.java:114)
	at org.apache.solr.cloud.CollectionsAPIAsyncDistributedZkTest.doTest(CollectionsAPIAsyncDistributedZkTest.java:64)
	at org.apache.solr.BaseDistributedSearchTestCase.testDistribSearch(BaseDistributedSearchTestCase.java:869)
	at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
	at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:57)
	at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
	at java.lang.reflect.Method.invoke(Method.java:606)
	at com.carrotsearch.randomizedtesting.RandomizedRunner.invoke(RandomizedRunner.java:1618)
	at com.carrotsearch.randomizedtesting.RandomizedRunner$6.evaluate(RandomizedRunner.java:827)
	at com.carrotsearch.randomizedtesting.RandomizedRunner$7.evaluate(RandomizedRunner.java:863)
	at com.carrotsearch.randomizedtesting.RandomizedRunner$8.evaluate(RandomizedRunner.java:877)
	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.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:65)
	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:365)
	at com.carrotsearch.randomizedtesting.ThreadLeakControl.forkTimeoutingTask(ThreadLeakControl.java:798)
	at com.carrotsearch.randomizedtesting.ThreadLeakControl$3.evaluate(ThreadLeakControl.java:458)
	at com.carrotsearch.randomizedtesting.RandomizedRunner.runSingleTest(RandomizedRunner.java:836)
	at com.carrotsearch.randomizedtesting.RandomizedRunner$3.evaluate(RandomizedRunner.java:738)
	at com.carrotsearch.randomizedtesting.RandomizedRunner$4.evaluate(RandomizedRunner.java:772)
	at com.carrotsearch.randomizedtesting.RandomizedRunner$5.evaluate(RandomizedRunner.java:783)
	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 com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
	at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
	at org.apache.lucene.util.TestRuleAssertionsRequired$1.evaluate(TestRuleAssertionsRequired.java:54)
	at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:48)
	at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:65)
	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:365)
	at java.lang.Thread.run(Thread.java:745)


REGRESSION:  org.apache.solr.search.mlt.SimpleMLTQParserTest.doTest

Error Message:
Exception during query

Stack Trace:
java.lang.RuntimeException: Exception during query
	at __randomizedtesting.SeedInfo.seed([80B8668EE9622AC1:27FCDE2A84D93978]:0)
	at org.apache.solr.SolrTestCaseJ4.assertQ(SolrTestCaseJ4.java:723)
	at org.apache.solr.SolrTestCaseJ4.assertQ(SolrTestCaseJ4.java:690)
	at org.apache.solr.search.mlt.SimpleMLTQParserTest.doTest(SimpleMLTQParserTest.java:71)
	at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
	at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:57)
	at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
	at java.lang.reflect.Method.invoke(Method.java:606)
	at com.carrotsearch.randomizedtesting.RandomizedRunner.invoke(RandomizedRunner.java:1618)
	at com.carrotsearch.randomizedtesting.RandomizedRunner$6.evaluate(RandomizedRunner.java:827)
	at com.carrotsearch.randomizedtesting.RandomizedRunner$7.evaluate(RandomizedRunner.java:863)
	at com.carrotsearch.randomizedtesting.RandomizedRunner$8.evaluate(RandomizedRunner.java:877)
	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.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:65)
	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:365)
	at com.carrotsearch.randomizedtesting.ThreadLeakControl.forkTimeoutingTask(ThreadLeakControl.java:798)
	at com.carrotsearch.randomizedtesting.ThreadLeakControl$3.evaluate(ThreadLeakControl.java:458)
	at com.carrotsearch.randomizedtesting.RandomizedRunner.runSingleTest(RandomizedRunner.java:836)
	at com.carrotsearch.randomizedtesting.RandomizedRunner$3.evaluate(RandomizedRunner.java:738)
	at com.carrotsearch.randomizedtesting.RandomizedRunner$4.evaluate(RandomizedRunner.java:772)
	at com.carrotsearch.randomizedtesting.RandomizedRunner$5.evaluate(RandomizedRunner.java:783)
	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 com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
	at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
	at org.apache.lucene.util.TestRuleAssertionsRequired$1.evaluate(TestRuleAssertionsRequired.java:54)
	at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:48)
	at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:65)
	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:365)
	at java.lang.Thread.run(Thread.java:745)
Caused by: java.lang.RuntimeException: REQUEST FAILED: xpath=//result/doc[2]/int[@name='id'][.='13']
	xml response was: <?xml version="1.0" encoding="UTF-8"?>
<response>
<lst name="responseHeader"><int name="status">0</int><int name="QTime">35</int></lst><result name="response" numFound="14" start="0"><doc><int name="id">17</int><arr name="range_facet_l"><long>17</long></arr><arr name="lowerfilt"><str>The quote red fox jumped moon over the lazy brown dogs moon. Of course moon. Foxes and moon come back to the foxes and moon</str></arr><arr name="lowerfilt1and2"><str>The quote red fox jumped moon over the lazy brown dogs moon. Of course moon. Foxes and moon come back to the foxes and moon</str></arr><long name="_version_">1483718590381162496</long><arr name="multiDefault"><str>muLti-Default</str></arr><int name="intDefault">42</int><date name="timestamp">2014-11-03T03:11:52.42Z</date></doc><doc><int name="id">18</int><arr name="range_facet_l"><long>18</long></arr><arr name="lowerfilt"><str>The quote red fox jumped over the lazy brown dogs.</str></arr><arr name="lowerfilt1and2"><str>The quote red fox jumped over the lazy brown dogs.</str></arr><long name="_version_">1483718590383259648</long><arr name="multiDefault"><str>muLti-Default</str></arr><int name="intDefault">42</int><date name="timestamp">2014-11-03T03:11:52.423Z</date></doc><doc><int name="id">20</int><arr name="range_facet_l"><long>20</long></arr><arr name="lowerfilt"><str>The quote red fox jumped over the lazy brown dogs.</str></arr><arr name="lowerfilt1and2"><str>The quote red fox jumped over the lazy brown dogs.</str></arr><long name="_version_">1483718590388502528</long><arr name="multiDefault"><str>muLti-Default</str></arr><int name="intDefault">42</int><date name="timestamp">2014-11-03T03:11:52.428Z</date></doc><doc><int name="id">22</int><arr name="range_facet_l"><long>22</long></arr><arr name="lowerfilt"><str>The quote red fox jumped over the lazy brown dogs.</str></arr><arr name="lowerfilt1and2"><str>The quote red fox jumped over the lazy brown dogs.</str></arr><long name="_version_">1483718590392696832</long><arr name="multiDefault"><str>muLti-Default</str></arr><int name="intDefault">42</int><date name="timestamp">2014-11-03T03:11:52.432Z</date></doc><doc><int name="id">23</int><arr name="range_facet_l"><long>23</long></arr><arr name="lowerfilt"><str>The quote red fox jumped over the lazy brown dogs.</str></arr><arr name="lowerfilt1and2"><str>The quote red fox jumped over the lazy brown dogs.</str></arr><long name="_version_">1483718590394793984</long><arr name="multiDefault"><str>muLti-Default</str></arr><int name="intDefault">42</int><date name="timestamp">2014-11-03T03:11:52.434Z</date></doc><doc><int name="id">13</int><arr name="range_facet_l"><long>13</long></arr><arr name="lowerfilt"><str>The quote red fox jumped over the lazy brown dogs.</str></arr><arr name="lowerfilt1and2"><str>The quote red fox jumped over the lazy brown dogs.</str></arr><long name="_version_">1483718590364385280</long><arr name="multiDefault"><str>muLti-Default</str></arr><int name="intDefault">42</int><date name="timestamp">2014-11-03T03:11:52.405Z</date></doc><doc><int name="id">14</int><arr name="range_facet_l"><long>14</long></arr><arr name="lowerfilt"><str>The quote red fox jumped over the lazy brown dogs.</str></arr><arr name="lowerfilt1and2"><str>The quote red fox jumped over the lazy brown dogs.</str></arr><long name="_version_">1483718590366482432</long><arr name="multiDefault"><str>muLti-Default</str></arr><int name="intDefault">42</int><date name="timestamp">2014-11-03T03:11:52.407Z</date></doc><doc><int name="id">9</int><arr name="range_facet_l"><long>9</long></arr><arr name="lowerfilt"><str>The quick red fox jumped over the lazy big and large brown dogs.</str></arr><arr name="lowerfilt1and2"><str>The quick red fox jumped over the lazy big and large brown dogs.</str></arr><long name="_version_">1483718590349705216</long><arr name="multiDefault"><str>muLti-Default</str></arr><int name="intDefault">42</int><date name="timestamp">2014-11-03T03:11:52.391Z</date></doc><doc><int name="id">7</int><arr name="range_facet_l"><long>7</long></arr><arr name="lowerfilt"><str>mclaren moon or the moon and moon moon shine and the moon but moon was good foxes too</str></arr><arr name="lowerfilt1and2"><str>mclaren moon or the moon and moon moon shine and the moon but moon was good foxes too</str></arr><long name="_version_">1483718590345510912</long><arr name="multiDefault"><str>muLti-Default</str></arr><int name="intDefault">42</int><date name="timestamp">2014-11-03T03:11:52.387Z</date></doc><doc><int name="id">15</int><arr name="range_facet_l"><long>15</long></arr><arr name="lowerfilt"><str>The fat red fox jumped over the lazy brown dogs.</str></arr><arr name="lowerfilt1and2"><str>The fat red fox jumped over the lazy brown dogs.</str></arr><long name="_version_">1483718590375919616</long><arr name="multiDefault"><str>muLti-Default</str></arr><int name="intDefault">42</int><date name="timestamp">2014-11-03T03:11:52.415Z</date></doc></result>
</response>

	request was:q=%7B%21mlt+qf%3Dlowerfilt%7D17
	at org.apache.solr.SolrTestCaseJ4.assertQ(SolrTestCaseJ4.java:716)
	... 42 more




Build Log:
[...truncated 11925 lines...]
   [junit4] Suite: org.apache.solr.search.mlt.SimpleMLTQParserTest
   [junit4]   2> Creating dataDir: /usr/home/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test/J2/temp/solr.search.mlt.SimpleMLTQParserTest-80B8668EE9622AC1-001/init-core-data-001
   [junit4]   2> 2168892 T3971 oas.SolrTestCaseJ4.buildSSLConfig Randomized ssl (false) and clientAuth (true)
   [junit4]   2> 2168894 T3971 oas.SolrTestCaseJ4.initCore ####initCore
   [junit4]   2> 2168894 T3971 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/usr/home/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/core/src/test-files/solr/collection1/'
   [junit4]   2> 2168896 T3971 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/core/src/test-files/solr/collection1/lib/.svn/' to classloader
   [junit4]   2> 2168896 T3971 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/core/src/test-files/solr/collection1/lib/classes/' to classloader
   [junit4]   2> 2168897 T3971 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/core/src/test-files/solr/collection1/lib/README' to classloader
   [junit4]   2> 2169062 T3971 oasc.SolrConfig.<init> Using Lucene MatchVersion: 6.0.0
   [junit4]   2> 2169129 T3971 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
   [junit4]   2> 2169131 T3971 oass.IndexSchema.readSchema Reading Solr Schema from /usr/home/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/core/src/test-files/solr/collection1/conf/schema.xml
   [junit4]   2> 2169141 T3971 oass.IndexSchema.readSchema [null] Schema name=test
   [junit4]   2> 2169582 T3971 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
   [junit4]   2> 2169594 T3971 oass.IndexSchema.readSchema default search field in schema is text
   [junit4]   2> 2169597 T3971 oass.IndexSchema.readSchema unique key field: id
   [junit4]   2> 2169607 T3971 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
   [junit4]   2> 2169612 T3971 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
   [junit4]   2> 2169616 T3971 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
   [junit4]   2> 2169617 T3971 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
   [junit4]   2> 2169618 T3971 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
   [junit4]   2> 2169618 T3971 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
   [junit4]   2> 2169619 T3971 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
   [junit4]   2> 2169619 T3971 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
   [junit4]   2> 2169619 T3971 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
   [junit4]   2> 2169620 T3971 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: /usr/home/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/core/src/test-files/solr
   [junit4]   2> 2169620 T3971 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/usr/home/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/core/src/test-files/solr/'
   [junit4]   2> 2169713 T3971 oasc.CoreContainer.<init> New CoreContainer 1504592265
   [junit4]   2> 2169713 T3971 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=/usr/home/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/core/src/test-files/solr/]
   [junit4]   2> 2169714 T3971 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 0
   [junit4]   2> 2169715 T3971 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: null
   [junit4]   2> 2169715 T3971 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 0
   [junit4]   2> 2169715 T3971 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
   [junit4]   2> 2169715 T3971 oashc.HttpShardHandlerFactory.getParameter Setting maxConnections to: 10000
   [junit4]   2> 2169716 T3971 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
   [junit4]   2> 2169716 T3971 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
   [junit4]   2> 2169716 T3971 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
   [junit4]   2> 2169717 T3971 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
   [junit4]   2> 2169717 T3971 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
   [junit4]   2> 2169717 T3971 oasu.UpdateShardHandler.<init> Creating UpdateShardHandler HTTP client with params: socketTimeout=30000&connTimeout=30000&retry=false
   [junit4]   2> 2169718 T3971 oasl.LogWatcher.createWatcher SLF4J impl is org.slf4j.impl.Log4jLoggerFactory
   [junit4]   2> 2169718 T3971 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
   [junit4]   2> 2169718 T3971 oasc.CoreContainer.load Host Name: 
   [junit4]   2> 2169723 T3972 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/usr/home/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/core/src/test-files/solr/collection1/'
   [junit4]   2> 2169725 T3972 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/core/src/test-files/solr/collection1/lib/.svn/' to classloader
   [junit4]   2> 2169725 T3972 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/core/src/test-files/solr/collection1/lib/classes/' to classloader
   [junit4]   2> 2169725 T3972 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/core/src/test-files/solr/collection1/lib/README' to classloader
   [junit4]   2> 2169801 T3972 oasc.SolrConfig.<init> Using Lucene MatchVersion: 6.0.0
   [junit4]   2> 2169894 T3972 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
   [junit4]   2> 2169894 T3972 oass.IndexSchema.readSchema Reading Solr Schema from /usr/home/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/core/src/test-files/solr/collection1/conf/schema.xml
   [junit4]   2> 2169906 T3972 oass.IndexSchema.readSchema [collection1] Schema name=test
   [junit4]   2> 2170452 T3972 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
   [junit4]   2> 2170463 T3972 oass.IndexSchema.readSchema default search field in schema is text
   [junit4]   2> 2170466 T3972 oass.IndexSchema.readSchema unique key field: id
   [junit4]   2> 2170475 T3972 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
   [junit4]   2> 2170479 T3972 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
   [junit4]   2> 2170483 T3972 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
   [junit4]   2> 2170484 T3972 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
   [junit4]   2> 2170484 T3972 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
   [junit4]   2> 2170484 T3972 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
   [junit4]   2> 2170485 T3972 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
   [junit4]   2> 2170485 T3972 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
   [junit4]   2> 2170485 T3972 oasc.CoreContainer.create Creating SolrCore 'collection1' using configuration from instancedir /usr/home/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/core/src/test-files/solr/collection1/
   [junit4]   2> 2170486 T3972 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
   [junit4]   2> 2170486 T3972 oasc.SolrCore.<init> [collection1] Opening new SolrCore at /usr/home/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/core/src/test-files/solr/collection1/, dataDir=/usr/home/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test/J2/temp/solr.search.mlt.SimpleMLTQParserTest-80B8668EE9622AC1-001/init-core-data-001/
   [junit4]   2> 2170486 T3972 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@2ca6e9c5
   [junit4]   2> 2170488 T3972 oasc.CachingDirectoryFactory.get return new directory for /usr/home/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test/J2/temp/solr.search.mlt.SimpleMLTQParserTest-80B8668EE9622AC1-001/init-core-data-001
   [junit4]   2> 2170489 T3972 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=/usr/home/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test/J2/temp/solr.search.mlt.SimpleMLTQParserTest-80B8668EE9622AC1-001/init-core-data-001/index/
   [junit4]   2> 2170489 T3972 oasc.SolrCore.initIndex WARN [collection1] Solr index directory '/usr/home/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test/J2/temp/solr.search.mlt.SimpleMLTQParserTest-80B8668EE9622AC1-001/init-core-data-001/index' doesn't exist. Creating new index...
   [junit4]   2> 2170490 T3972 oasc.CachingDirectoryFactory.get return new directory for /usr/home/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test/J2/temp/solr.search.mlt.SimpleMLTQParserTest-80B8668EE9622AC1-001/init-core-data-001/index
   [junit4]   2> 2170490 T3972 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.LogByteSizeMergePolicy: [LogByteSizeMergePolicy: minMergeSize=1677721, mergeFactor=26, maxMergeSize=2147483648, maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=true, maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=1.0]
   [junit4]   2> 2170491 T3972 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
   [junit4]   2> 		commit{dir=RateLimitedDirectoryWrapper(MockDirectoryWrapper(NRTCachingDirectory(RAMDirectory(id=lucene-798c44a0); maxCacheMB=0.9677734375 maxMergeSizeMB=0.14453125))),segFN=segments_1,generation=1}
   [junit4]   2> 2170491 T3972 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
   [junit4]   2> 2170492 T3972 oasc.SolrCore.initWriters created xml: solr.XMLResponseWriter
   [junit4]   2> 2170497 T3972 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "dedupe"
   [junit4]   2> 2170497 T3972 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
   [junit4]   2> 2170497 T3972 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "dedupe-allfields"
   [junit4]   2> 2170498 T3972 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe-allfields"
   [junit4]   2> 2170498 T3972 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "stored_sig"
   [junit4]   2> 2170498 T3972 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
   [junit4]   2> 2170498 T3972 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "uniq-fields"
   [junit4]   2> 2170499 T3972 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "uniq-fields"
   [junit4]   2> 2170499 T3972 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-explicit"
   [junit4]   2> 2170499 T3972 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-implicit"
   [junit4]   2> 2170500 T3972 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
   [junit4]   2> 2170500 T3972 oasc.SolrCore.loadUpdateProcessorChains no updateRequestProcessorChain defined as default, creating implicit default
   [junit4]   2> 2170500 T3972 oasc.RequestHandlers.initHandlersFromConfig created /update/json: org.apache.solr.handler.UpdateRequestHandler
   [junit4]   2> 2170501 T3972 oasc.RequestHandlers.initHandlersFromConfig created /update/json/docs: org.apache.solr.handler.UpdateRequestHandler
   [junit4]   2> 2170501 T3972 oasc.RequestHandlers.initHandlersFromConfig created /update/csv: org.apache.solr.handler.UpdateRequestHandler
   [junit4]   2> 2170502 T3972 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
   [junit4]   2> 2170502 T3972 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
   [junit4]   2> 2170503 T3972 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
   [junit4]   2> 2170503 T3972 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
   [junit4]   2> 2170504 T3972 oasc.RequestHandlers.initHandlersFromConfig created dismax: solr.SearchHandler
   [junit4]   2> 2170504 T3972 oasc.RequestHandlers.initHandlersFromConfig created mock: org.apache.solr.core.MockQuerySenderListenerReqHandler
   [junit4]   2> 2170505 T3972 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
   [junit4]   2> 2170505 T3972 oasc.RequestHandlers.initHandlersFromConfig created /admin/file: solr.admin.ShowFileRequestHandler
   [junit4]   2> 2170506 T3972 oasc.RequestHandlers.initHandlersFromConfig created /admin/fileedit: solr.admin.EditFileRequestHandler
   [junit4]   2> 2170506 T3972 oasc.RequestHandlers.initHandlersFromConfig created defaults: solr.StandardRequestHandler
   [junit4]   2> 2170506 T3972 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.StandardRequestHandler
   [junit4]   2> 2170506 T3972 oasc.RequestHandlers.initHandlersFromConfig created lazy: solr.StandardRequestHandler
   [junit4]   2> 2170507 T3972 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
   [junit4]   2> 2170507 T3972 oasc.RequestHandlers.initHandlersFromConfig created /terms: org.apache.solr.handler.component.SearchHandler
   [junit4]   2> 2170508 T3972 oasc.RequestHandlers.initHandlersFromConfig created spellCheckCompRH: org.apache.solr.handler.component.SearchHandler
   [junit4]   2> 2170508 T3972 oasc.RequestHandlers.initHandlersFromConfig created spellCheckCompRH_Direct: org.apache.solr.handler.component.SearchHandler
   [junit4]   2> 2170509 T3972 oasc.RequestHandlers.initHandlersFromConfig created spellCheckWithWordbreak: org.apache.solr.handler.component.SearchHandler
   [junit4]   2> 2170509 T3972 oasc.RequestHandlers.initHandlersFromConfig created spellCheckWithWordbreak_Direct: org.apache.solr.handler.component.SearchHandler
   [junit4]   2> 2170510 T3972 oasc.RequestHandlers.initHandlersFromConfig created spellCheckCompRH1: org.apache.solr.handler.component.SearchHandler
   [junit4]   2> 2170510 T3972 oasc.RequestHandlers.initHandlersFromConfig created mltrh: org.apache.solr.handler.component.SearchHandler
   [junit4]   2> 2170511 T3972 oasc.RequestHandlers.initHandlersFromConfig created tvrh: org.apache.solr.handler.component.SearchHandler
   [junit4]   2> 2170511 T3972 oasc.RequestHandlers.initHandlersFromConfig created /mlt: solr.MoreLikeThisHandler
   [junit4]   2> 2170512 T3972 oasc.RequestHandlers.initHandlersFromConfig created /debug/dump: solr.DumpRequestHandler
   [junit4]   2> 2170530 T3972 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
   [junit4]   2> 2170532 T3972 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
   [junit4]   2> 2170534 T3972 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
   [junit4]   2> 2170536 T3972 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
   [junit4]   2> 2170538 T3972 oasc.SolrCore.initDeprecatedSupport WARN solrconfig.xml uses deprecated <admin/gettableFiles>, Please update your config to use the ShowFileRequestHandler.
   [junit4]   2> 2170540 T3972 oasu.CommitTracker.<init> Hard AutoCommit: disabled
   [junit4]   2> 2170541 T3972 oasu.CommitTracker.<init> Soft AutoCommit: disabled
   [junit4]   2> 2170541 T3972 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.MockRandomMergePolicy: org.apache.lucene.index.MockRandomMergePolicy@5338fc42
   [junit4]   2> 2170542 T3972 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=1
   [junit4]   2> 		commit{dir=RateLimitedDirectoryWrapper(MockDirectoryWrapper(NRTCachingDirectory(RAMDirectory(id=lucene-798c44a0); maxCacheMB=0.9677734375 maxMergeSizeMB=0.14453125))),segFN=segments_1,generation=1}
   [junit4]   2> 2170542 T3972 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
   [junit4]   2> 2170543 T3972 oass.SolrIndexSearcher.<init> Opening Searcher@4802039f[collection1] main
   [junit4]   2> 2170543 T3972 oasr.RestManager.init Initializing RestManager with initArgs: {storageIO=org.apache.solr.rest.ManagedResourceStorage$InMemoryStorageIO}
   [junit4]   2> 2170543 T3972 oasr.ManagedResourceStorage.load Reading _rest_managed.json using InMemoryStorage
   [junit4]   2> 2170544 T3972 oasr.ManagedResource.reloadFromStorage WARN No stored data found for /rest/managed
   [junit4]   2> 2170544 T3972 oasr.ManagedResourceStorage$JsonStorage.store Saved JSON object to path _rest_managed.json using InMemoryStorage
   [junit4]   2> 2170544 T3972 oasr.RestManager.init Initializing 0 registered ManagedResources
   [junit4]   2> 2170544 T3972 oashc.SpellCheckComponent.inform Initializing spell checkers
   [junit4]   2> 2170553 T3972 oass.DirectSolrSpellChecker.init init: {name=direct,classname=DirectSolrSpellChecker,field=lowerfilt,minQueryLength=3}
   [junit4]   2> 2170709 T3973 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@4802039f[collection1] main{ExitableDirectoryReader(UninvertingDirectoryReader())}
   [junit4]   2> 2170718 T3972 oasc.CoreContainer.registerCore registering core: collection1
   [junit4]   2> 2170731 T3971 oas.SolrTestCaseJ4.initCore ####initCore end
   [junit4]   2> 2170736 T3971 oas.SolrTestCaseJ4.setUp ###Starting doTest
   [junit4]   2> ASYNC  NEW_CORE C1732 name=collection1 org.apache.solr.core.SolrCore@2f77b967
   [junit4]   2> 2170739 T3971 C1732 oasup.LogUpdateProcessor.finish [collection1] webapp=null path=null params={} {add=[1 (1483718590329782272)]} 0 2
   [junit4]   2> 2170744 T3971 C1732 oasup.LogUpdateProcessor.finish [collection1] webapp=null path=null params={} {add=[2 (1483718590336073728)]} 0 1
   [junit4]   2> 2170745 T3971 C1732 oasup.LogUpdateProcessor.finish [collection1] webapp=null path=null params={} {add=[3 (1483718590338170880)]} 0 0
   [junit4]   2> 2170747 T3971 C1732 oasup.LogUpdateProcessor.finish [collection1] webapp=null path=null params={} {add=[4 (1483718590340268032)]} 0 0
   [junit4]   2> 2170749 T3971 C1732 oasup.LogUpdateProcessor.finish [collection1] webapp=null path=null params={} {add=[5 (1483718590341316608)]} 0 1
   [junit4]   2> 2170750 T3971 C1732 oasup.LogUpdateProcessor.finish [collection1] webapp=null path=null params={} {add=[6 (1483718590343413760)]} 0 0
   [junit4]   2> 2170753 T3971 C1732 oasup.LogUpdateProcessor.finish [collection1] webapp=null path=null params={} {add=[7 (1483718590345510912)]} 0 1
   [junit4]   2> 2170754 T3971 C1732 oasup.LogUpdateProcessor.finish [collection1] webapp=null path=null params={} {add=[8 (1483718590347608064)]} 0 0
   [junit4]   2> 2170757 T3971 C1732 oasup.LogUpdateProcessor.finish [collection1] webapp=null path=null params={} {add=[9 (1483718590349705216)]} 0 1
   [junit4]   2> 2170767 T3971 C1732 oasup.LogUpdateProcessor.finish [collection1] webapp=null path=null params={} {add=[10 (1483718590361239552)]} 0 1
   [junit4]   2> 2170768 T3971 C1732 oasup.LogUpdateProcessor.finish [collection1] webapp=null path=null params={} {add=[12 (1483718590362288128)]} 0 0
   [junit4]   2> 2170770 T3971 C1732 oasup.LogUpdateProcessor.finish [collection1] webapp=null path=null params={} {add=[13 (1483718590364385280)]} 0 0
   [junit4]   2> 2170779 T3971 C1732 oasup.LogUpdateProcessor.finish [collection1] webapp=null path=null params={} {add=[14 (1483718590366482432)]} 0 7
   [junit4]   2> 2170782 T3971 C1732 oasup.LogUpdateProcessor.finish [collection1] webapp=null path=null params={} {add=[15 (1483718590375919616)]} 0 2
   [junit4]   2> 2170784 T3971 C1732 oasup.LogUpdateProcessor.finish [collection1] webapp=null path=null params={} {add=[16 (1483718590378016768)]} 0 1
   [junit4]   2> 2170787 T3971 C1732 oasup.LogUpdateProcessor.finish [collection1] webapp=null path=null params={} {add=[17 (1483718590381162496)]} 0 2
   [junit4]   2> 2170789 T3971 C1732 oasup.LogUpdateProcessor.finish [collection1] webapp=null path=null params={} {add=[18 (1483718590383259648)]} 0 1
   [junit4]   2> 2170791 T3971 C1732 oasup.LogUpdateProcessor.finish [collection1] webapp=null path=null params={} {add=[19 (1483718590386405376)]} 0 1
   [junit4]   2> 2170794 T3971 C1732 oasup.LogUpdateProcessor.finish [collection1] webapp=null path=null params={} {add=[20 (1483718590388502528)]} 0 1
   [junit4]   2> 2170796 T3971 C1732 oasup.LogUpdateProcessor.finish [collection1] webapp=null path=null params={} {add=[21 (1483718590390599680)]} 0 1
   [junit4]   2> 2170798 T3971 C1732 oasup.LogUpdateProcessor.finish [collection1] webapp=null path=null params={} {add=[22 (1483718590392696832)]} 0 1
   [junit4]   2> 2170800 T3971 C1732 oasup.LogUpdateProcessor.finish [collection1] webapp=null path=null params={} {add=[23 (1483718590394793984)]} 0 1
   [junit4]   2> 2170802 T3971 C1732 oasup.LogUpdateProcessor.finish [collection1] webapp=null path=null params={} {add=[24 (1483718590396891136)]} 0 1
   [junit4]   2> 2170804 T3971 C1732 oasup.LogUpdateProcessor.finish [collection1] webapp=null path=null params={} {add=[25 (1483718590398988288)]} 0 1
   [junit4]   2> 2170805 T3971 C1732 oasu.DirectUpdateHandler2.commit start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
   [junit4]   2> 2170838 T3971 C1732 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=2
   [junit4]   2> 		commit{dir=RateLimitedDirectoryWrapper(MockDirectoryWrapper(NRTCachingDirectory(RAMDirectory(id=lucene-798c44a0); maxCacheMB=0.9677734375 maxMergeSizeMB=0.14453125))),segFN=segments_1,generation=1}
   [junit4]   2> 		commit{dir=RateLimitedDirectoryWrapper(MockDirectoryWrapper(NRTCachingDirectory(RAMDirectory(id=lucene-798c44a0); maxCacheMB=0.9677734375 maxMergeSizeMB=0.14453125))),segFN=segments_2,generation=2}
   [junit4]   2> 2170839 T3971 C1732 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 2
   [junit4]   2> 2170842 T3971 C1732 oass.SolrIndexSearcher.<init> Opening Searcher@6f93fae6[collection1] main
   [junit4]   2> 2170843 T3971 C1732 oasu.DirectUpdateHandler2.commit end_commit_flush
   [junit4]   2> 2170845 T3973 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@6f93fae6[collection1] main{ExitableDirectoryReader(UninvertingDirectoryReader(Uninverting(_2(6.0.0):C24)))}
   [junit4]   2> 2170846 T3971 C1732 oasup.LogUpdateProcessor.finish [collection1] webapp=null path=null params={} {commit=} 0 41
   [junit4]   2> 2170882 T3971 C1732 oasc.SolrCore.execute [collection1] webapp=null path=null params={q=%7B%21mlt+qf%3Dlowerfilt%7D17} hits=14 status=0 QTime=35 
   [junit4]   2> 2170889 T3971 oas.SolrTestCaseJ4.assertQ ERROR REQUEST FAILED: xpath=//result/doc[2]/int[@name='id'][.='13']
   [junit4]   2> 		xml response was: <?xml version="1.0" encoding="UTF-8"?>
   [junit4]   2> 	<response>
   [junit4]   2> 	<lst name="responseHeader"><int name="status">0</int><int name="QTime">35</int></lst><result name="response" numFound="14" start="0"><doc><int name="id">17</int><arr name="range_facet_l"><long>17</long></arr><arr name="lowerfilt"><str>The quote red fox jumped moon over the lazy brown dogs moon. Of course moon. Foxes and moon come back to the foxes and moon</str></arr><arr name="lowerfilt1and2"><str>The quote red fox jumped moon over the lazy brown dogs moon. Of course moon. Foxes and moon come back to the foxes and moon</str></arr><long name="_version_">1483718590381162496</long><arr name="multiDefault"><str>muLti-Default</str></arr><int name="intDefault">42</int><date name="timestamp">2014-11-03T03:11:52.42Z</date></doc><doc><int name="id">18</int><arr name="range_facet_l"><long>18</long></arr><arr name="lowerfilt"><str>The quote red fox jumped over the lazy brown dogs.</str></arr><arr name="lowerfilt1and2"><str>The quote red fox jumped over the lazy brown dogs.</str></arr><long name="_version_">1483718590383259648</long><arr name="multiDefault"><str>muLti-Default</str></arr><int name="intDefault">42</int><date name="timestamp">2014-11-03T03:11:52.423Z</date></doc><doc><int name="id">20</int><arr name="range_facet_l"><long>20</long></arr><arr name="lowerfilt"><str>The quote red fox jumped over the lazy brown dogs.</str></arr><arr name="lowerfilt1and2"><str>The quote red fox jumped over the lazy brown dogs.</str></arr><long name="_version_">1483718590388502528</long><arr name="multiDefault"><str>muLti-Default</str></arr><int name="intDefault">42</int><date name="timestamp">2014-11-03T03:11:52.428Z</date></doc><doc><int name="id">22</int><arr name="range_facet_l"><long>22</long></arr><arr name="lowerfilt"><str>The quote red fox jumped over the lazy brown dogs.</str></arr><arr name="lowerfilt1and2"><str>The quote red fox jumped over the lazy brown dogs.</str></arr><long name="_version_">1483718590392696832</long><arr name="multiDefault"><str>muLti-Default</str></arr><int name="intDefault">42</int><date name="timestamp">2014-11-03T03:11:52.432Z</date></doc><doc><int name="id">23</int><arr name="range_facet_l"><long>23</long></arr><arr name="lowerfilt"><str>The quote red fox jumped over the lazy brown dogs.</str></arr><arr name="lowerfilt1and2"><str>The quote red fox jumped over the lazy brown dogs.</str></arr><long name="_version_">1483718590394793984</long><arr name="multiDefault"><str>muLti-Default</str></arr><int name="intDefault">42</int><date name="timestamp">2014-11-03T03:11:52.434Z</date></doc><doc><int name="id">13</int><arr name="range_facet_l"><long>13</long></arr><arr name="lowerfilt"><str>The quote red fox jumped over the lazy brown dogs.</str></arr><arr name="lowerfilt1and2"><str>The quote red fox jumped over the lazy brown dogs.</str></arr><long name="_version_">1483718590364385280</long><arr name="multiDefault"><str>muLti-Default</str></arr><int name="intDefault">42</int><date name="timestamp">2014-11-03T03:11:52.405Z</date></doc><doc><int name="id">14</int><arr name="range_facet_l"><long>14</long></arr><arr name="lowerfilt"><str>The quote red fox jumped over the lazy brown dogs.</str></arr><arr name="lowerfilt1and2"><str>The quote red fox jumped over the lazy brown dogs.</str></arr><long name="_version_">1483718590366482432</long><arr name="multiDefault"><str>muLti-Default</str></arr><int name="intDefault">42</int><date name="timestamp">2014-11-03T03:11:52.407Z</date></doc><doc><int name="id">9</int><arr name="range_facet_l"><long>9</long></arr><arr name="lowerfilt"><str>The quick red fox jumped over the lazy big and large brown dogs.</str></arr><arr name="lowerfilt1and2"><str>The quick red fox jumped over the lazy big and large brown dogs.</str></arr><long name="_version_">1483718590349705216</long><arr name="multiDefault"><str>muLti-Default</str></arr><int name="intDefault">42</int><date name="timestamp">2014-11-03T03:11:52.391Z</date></doc><doc><int name="id">7</int><arr name="range_facet_l"><long>7</long></arr><arr name="lowerfilt"><str>mclaren moon or the moon and moon moon shine and the moon but moon was good foxes too</str></arr><arr name="lowerfilt1and2"><str>mclaren moon or the moon and moon moon shine and the moon but moon was good foxes too</str></arr><long name="_version_">1483718590345510912</long><arr name="multiDefault"><str>muLti-Default</str></arr><int name="intDefault">42</int><date name="timestamp">2014-11-03T03:11:52.387Z</date></doc><doc><int name="id">15</int><arr name="range_facet_l"><long>15</long></arr><arr name="lowerfilt"><str>The fat red fox jumped over the lazy brown dogs.</str></arr><arr name="lowerfilt1and2"><str>The fat red fox jumped over the lazy brown dogs.</str></arr><long name="_version_">1483718590375919616</long><arr name="multiDefault"><str>muLti-Default</str></arr><int name="intDefault">42</int><date name="timestamp">2014-11-03T03:11:52.415Z</date></doc></result>
   [junit4]   2> 	</response>
   [junit4]   2> 	
   [junit4]   2> 		request was:q=%7B%21mlt+qf%3Dlowerfilt%7D17
   [junit4]   2> 2170892 T3971 oasc.SolrException.log ERROR REQUEST FAILED: q=%7B%21mlt+qf%3Dlowerfilt%7D17:java.lang.RuntimeException: REQUEST FAILED: xpath=//result/doc[2]/int[@name='id'][.='13']
   [junit4]   2> 		xml response was: <?xml version="1.0" encoding="UTF-8"?>
   [junit4]   2> 	<response>
   [junit4]   2> 	<lst name="responseHeader"><int name="status">0</int><int name="QTime">35</int></lst><result name="response" numFound="14" start="0"><doc><int name="id">17</int><arr name="range_facet_l"><long>17</long></arr><arr name="lowerfilt"><str>The quote red fox jumped moon over the lazy brown dogs moon. Of course moon. Foxes and moon come back to the foxes and moon</str></arr><arr name="lowerfilt1and2"><str>The quote red fox jumped moon over the lazy brown dogs moon. Of course moon. Foxes and moon come back to the foxes and moon</str></arr><long name="_version_">1483718590381162496</long><arr name="multiDefault"><str>muLti-Default</str></arr><int name="intDefault">42</int><date name="timestamp">2014-11-03T03:11:52.42Z</date></doc><doc><int name="id">18</int><arr name="range_facet_l"><long>18</long></arr><arr name="lowerfilt"><str>The quote red fox jumped over the lazy brown dogs.</str></arr><arr name="lowerfilt1and2"><str>The quote red fox jumped over the lazy brown dogs.</str></arr><long name="_version_">1483718590383259648</long><arr name="multiDefault"><str>muLti-Default</str></arr><int name="intDefault">42</int><date name="timestamp">2014-11-03T03:11:52.423Z</date></doc><doc><int name="id">20</int><arr name="range_facet_l"><long>20</long></arr><arr name="lowerfilt"><str>The quote red fox jumped over the lazy brown dogs.</str></arr><arr name="lowerfilt1and2"><str>The quote red fox jumped over the lazy brown dogs.</str></arr><long name="_version_">1483718590388502528</long><arr name="multiDefault"><str>muLti-Default</str></arr><int name="intDefault">42</int><date name="timestamp">2014-11-03T03:11:52.428Z</date></doc><doc><int name="id">22</int><arr name="range_facet_l"><long>22</long></arr><arr name="lowerfilt"><str>The quote red fox jumped over the lazy brown dogs.</str></arr><arr name="lowerfilt1and2"><str>The quote red fox jumped over the lazy brown dogs.</str></arr><long name="_version_">1483718590392696832</long><arr name="multiDefault"><str>muLti-Default</str></arr><int name="intDefault">42</int><date name="timestamp">2014-11-03T03:11:52.432Z</date></doc><doc><int name="id">23</int><arr name="range_facet_l"><long>23</long></arr><arr name="lowerfilt"><str>The quote red fox jumped over the lazy brown dogs.</str></arr><arr name="lowerfilt1and2"><str>The quote red fox jumped over the lazy brown dogs.</str></arr><long name="_version_">1483718590394793984</long><arr name="multiDefault"><str>muLti-Default</str></arr><int name="intDefault">42</int><date name="timestamp">2014-11-03T03:11:52.434Z</date></doc><doc><int name="id">13</int><arr name="range_facet_l"><long>13</long></arr><arr name="lowerfilt"><str>The quote red fox jumped over the lazy brown dogs.</str></arr><arr name="lowerfilt1and2"><str>The quote red fox jumped over the lazy brown dogs.</str></arr><long name="_version_">1483718590364385280</long><arr name="multiDefault"><str>muLti-Default</str></arr><int name="intDefault">42</int><date name="timestamp">2014-11-03T03:11:52.405Z</date></doc><doc><int name="id">14</int><arr name="range_facet_l"><long>14</long></arr><arr name="lowerfilt"><str>The quote red fox jumped over the lazy brown dogs.</str></arr><arr name="lowerfilt1and2"><str>The quote red fox jumped over the lazy brown dogs.</str></arr><long name="_version_">1483718590366482432</long><arr name="multiDefault"><str>muLti-Default</str></arr><int name="intDefault">42</int><date name="timestamp">2014-11-03T03:11:52.407Z</date></doc><doc><int name="id">9</int><arr name="range_facet_l"><long>9</long></arr><arr name="lowerfilt"><str>The quick red fox jumped over the lazy big and large brown dogs.</str></arr><arr name="lowerfilt1and2"><str>The quick red fox jumped over the lazy big and large brown dogs.</str></arr><long name="_version_">1483718590349705216</long><arr name="multiDefault"><str>muLti-Default</str></arr><int name="intDefault">42</int><date name="timestamp">2014-11-03T03:11:52.391Z</date></doc><doc><int name="id">7</int><arr name="range_facet_l"><long>7</long></arr><arr name="lowerfilt"><str>mclaren moon or the moon and moon moon shine and the moon but moon was good foxes too</str></arr><arr name="lowerfilt1and2"><str>mclaren moon or the moon and moon moon shine and the moon but moon was good foxes too</str></arr><long name="_version_">1483718590345510912</long><arr name="multiDefault"><str>muLti-Default</str></arr><int name="intDefault">42</int><date name="timestamp">2014-11-03T03:11:52.387Z</date></doc><doc><int name="id">15</int><arr name="range_facet_l"><long>15</long></arr><arr name="lowerfilt"><str>The fat red fox jumped over the lazy brown dogs.</str></arr><arr name="lowerfilt1and2"><str>The fat red fox jumped over the lazy brown dogs.</str></arr><long name="_version_">1483718590375919616</long><arr name="multiDefault"><str>muLti-Default</str></arr><int name="intDefault">42</int><date name="timestamp">2014-11-03T03:11:52.415Z</date></doc></result>
   [junit4]   2> 	</response>
   [junit4]   2> 	
   [junit4]   2> 		request was:q=%7B%21mlt+qf%3Dlowerfilt%7D17
   [junit4]   2> 		at org.apache.solr.SolrTestCaseJ4.assertQ(SolrTestCaseJ4.java:716)
   [junit4]   2> 		at org.apache.solr.SolrTestCaseJ4.assertQ(SolrTestCaseJ4.java:690)
   [junit4]   2> 		at org.apache.solr.search.mlt.SimpleMLTQParserTest.doTest(SimpleMLTQParserTest.java:71)
   [junit4]   2> 		at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
   [junit4]   2> 		at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:57)
   [junit4]   2> 		at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
   [junit4]   2> 		at java.lang.reflect.Method.invoke(Method.java:606)
   [junit4]   2> 		at com.carrotsearch.randomizedtesting.RandomizedRunner.invoke(RandomizedRunner.java:1618)
   [junit4]   2> 		at com.carrotsearch.randomizedtesting.RandomizedRunner$6.evaluate(RandomizedRunner.java:827)
   [junit4]   2> 		at com.carrotsearch.randomizedtesting.RandomizedRunner$7.evaluate(RandomizedRunner.java:863)
   [junit4]   2> 		at com.carrotsearch.randomizedtesting.RandomizedRunner$8.evaluate(RandomizedRunner.java:877)
   [junit4]   2> 		at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:53)
   [junit4]   2> 		at org.apache.lucene.util.TestRuleSetupTeardownChained$1.evaluate(TestRuleSetupTeardownChained.java:50)
   [junit4]   2> 		at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:46)
   [junit4]   2> 		at com.carrotsearch.randomizedtesting.rules.SystemPropertiesInvariantRule$1.evaluate(SystemPropertiesInvariantRule.java:55)
   [junit4]   2> 		at org.apache.lucene.util.TestRuleThreadAndTestName$1.evaluate(TestRuleThreadAndTestName.java:49)
   [junit4]   2> 		at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:65)
   [junit4]   2> 		at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:48)
   [junit4]   2> 		at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
   [junit4]   2> 		at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:365)
   [junit4]   2> 		at com.carrotsearch.randomizedtesting.ThreadLeakControl.forkTimeoutingTask(ThreadLeakControl.java:798)
   [junit4]   2> 		at com.carrotsearch.randomizedtesting.ThreadLeakControl$3.evaluate(ThreadLeakControl.java:458)
   [junit4]   2> 		at com.carrotsearch.randomizedtesting.RandomizedRunner.runSingleTest(RandomizedRunner.java:836)
   [junit4]   2> 		at com.carrotsearch.randomizedtesting.RandomizedRunner$3.evaluate(RandomizedRunner.java:738)
   [junit4]   2> 		at com.carrotsearch.randomizedtesting.RandomizedRunner$4.evaluate(RandomizedRunner.java:772)
   [junit4]   2> 		at com.carrotsearch.randomizedtesting.RandomizedRunner$5.evaluate(RandomizedRunner.java:783)
   [junit4]   2> 		at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
   [junit4]   2> 		at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:53)
   [junit4]   2> 		at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:46)
   [junit4]   2> 		at org.apache.lucene.util.TestRuleStoreClassName$1.evaluate(TestRuleStoreClassName.java:42)
   [junit4]   2> 		at com.carrotsearch.randomizedtesting.rules.SystemPropertiesInvariantRule$1.evaluate(SystemPropertiesInvariantRule.java:55)
   [junit4]   2> 		at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:39)
   [junit4]   2> 		at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:39)
   [junit4]   2> 		at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
   [junit4]   2> 		at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
   [junit4]   2> 		at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
   [junit4]   2> 		at org.apache.lucene.util.TestRuleAssertionsRequired$1.evaluate(TestRuleAssertionsRequired.java:54)
   [junit4]   2> 		at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:48)
   [junit4]   2> 		at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:65)
   [junit4]   2> 		at org.apache.lucene.util.TestRuleIgnoreTestSuites$1.evaluate(TestRuleIgnoreTestSuites.java:55)
   [junit4]   2> 		at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
   [junit4]   2> 		at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:365)
   [junit4]   2> 		at java.lang.Thread.run(Thread.java:745)
   [junit4]   2> 	
   [junit4]   2> 2170894 T3971 oas.SolrTestCaseJ4.tearDown ###Ending doTest
   [junit4]   2> NOTE: download the large Jenkins line-docs file by running 'ant get-jenkins-line-docs' in the lucene directory.
   [junit4]   2> NOTE: reproduce with: ant test  -Dtestcase=SimpleMLTQParserTest -Dtests.method=doTest -Dtests.seed=80B8668EE9622AC1 -Dtests.multiplier=2 -Dtests.nightly=true -Dtests.slow=true -Dtests.linedocsfile=/home/jenkins/lucene-data/enwiki.random.lines.txt -Dtests.locale=mk -Dtests.timezone=PST8PDT -Dtests.asserts=true -Dtests.file.encoding=US-ASCII
   [junit4] ERROR   0.20s J2 | SimpleMLTQParserTest.doTest <<<
   [junit4]    > Throwable #1: java.lang.RuntimeException: Exception during query
   [junit4]    > 	at __randomizedtesting.SeedInfo.seed([80B8668EE9622AC1:27FCDE2A84D93978]:0)
   [junit4]    > 	at org.apache.solr.SolrTestCaseJ4.assertQ(SolrTestCaseJ4.java:723)
   [junit4]    > 	at org.apache.solr.SolrTestCaseJ4.assertQ(SolrTestCaseJ4.java:690)
   [junit4]    > 	at org.apache.solr.search.mlt.SimpleMLTQParserTest.doTest(SimpleMLTQParserTest.java:71)
   [junit4]    > 	at java.lang.Thread.run(Thread.java:745)
   [junit4]    > Caused by: java.lang.RuntimeException: REQUEST FAILED: xpath=//result/doc[2]/int[@name='id'][.='13']
   [junit4]    > 	xml response was: <?xml version="1.0" encoding="UTF-8"?>
   [junit4]    > <response>
   [junit4]    > <lst name="responseHeader"><int name="status">0</int><int name="QTime">35</int></lst><result name="response" numFound="14" start="0"><doc><int name="id">17</int><arr name="range_facet_l"><long>17</long></arr><arr name="lowerfilt"><str>The quote red fox jumped moon over the lazy brown dogs moon. Of course moon. Foxes and moon come back to the foxes and moon</str></arr><arr name="lowerfilt1and2"><str>The quote red fox jumped moon over the lazy brown dogs moon. Of course moon. Foxes and moon come back to the foxes and moon</str></arr><long name="_version_">1483718590381162496</long><arr name="multiDefault"><str>muLti-Default</str></arr><int name="intDefault">42</int><date name="timestamp">2014-11-03T03:11:52.42Z</date></doc><doc><int name="id">18</int><arr name="range_facet_l"><long>18</long></arr><arr name="lowerfilt"><str>The quote red fox jumped over the lazy brown dogs.</str></arr><arr name="lowerfilt1and2"><str>The quote red fox jumped over the lazy brown dogs.</str></arr><long name="_version_">1483718590383259648</long><arr name="multiDefault"><str>muLti-Default</str></arr><int name="intDefault">42</int><date name="timestamp">2014-11-03T03:11:52.423Z</date></doc><doc><int name="id">20</int><arr name="range_facet_l"><long>20</long></arr><arr name="lowerfilt"><str>The quote red fox jumped over the lazy brown dogs.</str></arr><arr name="lowerfilt1and2"><str>The quote red fox jumped over the lazy brown dogs.</str></arr><long name="_version_">1483718590388502528</long><arr name="multiDefault"><str>muLti-Default</str></arr><int name="intDefault">42</int><date name="timestamp">2014-11-03T03:11:52.428Z</date></doc><doc><int name="id">22</int><arr name="range_facet_l"><long>22</long></arr><arr name="lowerfilt"><str>The quote red fox jumped over the lazy brown dogs.</str></arr><arr name="lowerfilt1and2"><str>The quote red fox jumped over the lazy brown dogs.</str></arr><long name="_version_">1483718590392696832</long><arr name="multiDefault"><str>muLti-Default</str></arr><int name="intDefault">42</int><date name="timestamp">2014-11-03T03:11:52.432Z</date></doc><doc><int name="id">23</int><arr name="range_facet_l"><long>23</long></arr><arr name="lowerfilt"><str>The quote red fox jumped over the lazy brown dogs.</str></arr><arr name="lowerfilt1and2"><str>The quote red fox jumped over the lazy brown dogs.</str></arr><long name="_version_">1483718590394793984</long><arr name="multiDefault"><str>muLti-Default</str></arr><int name="intDefault">42</int><date name="timestamp">2014-11-03T03:11:52.434Z</date></doc><doc><int name="id">13</int><arr name="range_facet_l"><long>13</long></arr><arr name="lowerfilt"><str>The quote red fox jumped over the lazy brown dogs.</str></arr><arr name="lowerfilt1and2"><str>The quote red fox jumped over the lazy brown dogs.</str></arr><long name="_version_">1483718590364385280</long><arr name="multiDefault"><str>muLti-Default</str></arr><int name="intDefault">42</int><date name="timestamp">2014-11-03T03:11:52.405Z</date></doc><doc><int name="id">14</int><arr name="range_facet_l"><long>14</long></arr><arr name="lowerfilt"><str>The quote red fox jumped over the lazy brown dogs.</str></arr><arr name="lowerfilt1and2"><str>The quote red fox jumped over the lazy brown dogs.</str></arr><long name="_version_">1483718590366482432</long><arr name="multiDefault"><str>muLti-Default</str></arr><int name="intDefault">42</int><date name="timestamp">2014-11-03T03:11:52.407Z</date></doc><doc><int name="id">9</int><arr name="range_facet_l"><long>9</long></arr><arr name="lowerfilt"><str>The quick red fox jumped over the lazy big and large brown dogs.</str></arr><arr name="lowerfilt1and2"><str>The quick red fox jumped over the lazy big and large brown dogs.</str></arr><long name="_version_">1483718590349705216</long><arr name="multiDefault"><str>muLti-Default</str></arr><int name="intDefault">42</int><date name="timestamp">2014-11-03T03:11:52.391Z</date></doc><doc><int name="id">7</int><arr name="range_facet_l"><long>7</long></arr><arr name="lowerfilt"><str>mclaren moon or the moon and moon moon shine and the moon but moon was good foxes too</str></arr><arr name="lowerfilt1and2"><str>mclaren moon or the moon and moon moon shine and the moon but moon was good foxes too</str></arr><long name="_version_">1483718590345510912</long><arr name="multiDefault"><str>muLti-Default</str></arr><int name="intDefault">42</int><date name="timestamp">2014-11-03T03:11:52.387Z</date></doc><doc><int name="id">15</int><arr name="range_facet_l"><long>15</long></arr><arr name="lowerfilt"><str>The fat red fox jumped over the lazy brown dogs.</str></arr><arr name="lowerfilt1and2"><str>The fat red fox jumped over the lazy brown dogs.</str></arr><long name="_version_">1483718590375919616</long><arr name="multiDefault"><str>muLti-Default</str></arr><int name="intDefault">42</int><date name="timestamp">2014-11-03T03:11:52.415Z</date></doc></result>
   [junit4]    > </response>
   [junit4]    > 	request was:q=%7B%21mlt+qf%3Dlowerfilt%7D17
   [junit4]    > 	at org.apache.solr.SolrTestCaseJ4.assertQ(SolrTestCaseJ4.java:716)
   [junit4]    > 	... 42 more
   [junit4]   2> 2170927 T3971 oas.SolrTestCaseJ4.deleteCore ###deleteCore
   [junit4]   2> 2170927 T3971 oasc.CoreContainer.shutdown Shutting down CoreContainer instance=1504592265
   [junit4]   2> 2170928 T3971 oasc.SolrCore.close [collection1]  CLOSING SolrCore org.apache.solr.core.SolrCore@2f77b967
   [junit4]   2> 2170946 T3971 oasu.DirectUpdateHandler2.close closing DirectUpdateHandler2{commits=1,autocommits=0,soft autocommits=0,optimizes=0,rollbacks=0,expungeDeletes=0,docsPending=0,adds=0,deletesById=0,deletesByQuery=0,errors=0,cumulative_adds=24,cumulative_deletesById=0,cumulative_deletesByQuery=0,cumulative_errors=0,transaction_logs_total_size=1864,transaction_logs_total_number=1}
   [junit4]   2> 2170946 T3971 oasu.SolrCoreState.decrefSolrCoreState Closing SolrCoreState
   [junit4]   2> 2170946 T3971 oasu.DefaultSolrCoreState.closeIndexWriter SolrCoreState ref count has reached 0 - closing IndexWriter
   [junit4]   2> 2170946 T3971 oasu.DefaultSolrCoreState.closeIndexWriter closing IndexWriter with IndexWriterCloser
   [junit4]   2> ASYNC  NEW_CORE C1733 name=collection1 org.apache.solr.core.SolrCore@2f77b967
   [junit4]   2> 2170948 T3971 C1733 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=2
   [junit4]   2> 		commit{dir=RateLimitedDirectoryWrapper(MockDirectoryWrapper(NRTCachingDirectory(RAMDirectory(id=lucene-798c44a0); maxCacheMB=0.9677734375 maxMergeSizeMB=0.14453125))),segFN=segments_2,generation=2}
   [junit4]   2> 		commit{dir=RateLimitedDirectoryWrapper(MockDirectoryWrapper(NRTCachingDirectory(RAMDirectory(id=lucene-798c44a0); maxCacheMB=0.9677734375 maxMergeSizeMB=0.14453125))),segFN=segments_3,generation=3}
   [junit4]   2> 2170948 T3971 C1733 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 3
   [junit4]   2> 2170949 T3971 oasc.SolrCore.closeSearcher [collection1] Closing main searcher on request.
   [junit4]   2> 2170950 T3971 oasc.CachingDirectoryFactory.close Closing MockDirectoryFactory - 2 directories currently being tracked
   [junit4]   2> 2170950 T3971 oasc.CachingDirectoryFactory.closeCacheValue looking to close /usr/home/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test/J2/temp/solr.search.mlt.SimpleMLTQParserTest-80B8668EE9622AC1-001/init-core-data-001/index [CachedDir<<refCount=0;path=/usr/home/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test/J2/temp/solr.search.mlt.SimpleMLTQParserTest-80B8668EE9622AC1-001/init-core-data-001/index;done=false>>]
   [junit4]   2> 2170950 T3971 oasc.CachingDirectoryFactory.close Closing directory: /usr/home/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test/J2/temp/solr.search.mlt.SimpleMLTQParserTest-80B8668EE9622AC1-001/init-core-data-001/index
   [junit4]   2> 2170950 T3971 oasc.CachingDirectoryFactory.closeCacheValue looking to close /usr/home/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test/J2/temp/solr.search.mlt.SimpleMLTQParserTest-80B8668EE9622AC1-001/init-core-data-001 [CachedDir<<refCount=0;path=/usr/home/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test/J2/temp/solr.search.mlt.SimpleMLTQParserTest-80B8668EE9622AC1-001/init-core-data-001;done=false>>]
   [junit4]   2> 2170951 T3971 oasc.CachingDirectoryFactory.close Closing directory: /usr/home/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test/J2/temp/solr.search.mlt.SimpleMLTQParserTest-80B8668EE9622AC1-001/init-core-data-001
   [junit4]   2> NOTE: leaving temporary files on disk at: /usr/home/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test/J2/temp/solr.search.mlt.SimpleMLTQParserTest-80B8668EE9622AC1-001
   [junit4]   2> NOTE: test params are: codec=Asserting(Lucene50): {lowerfilt1and2=FSTOrd50, _version_=PostingsFormat(name=Asserting), range_facet_l=FSTOrd50, timestamp=FSTOrd50, id=TestBloomFilteredLucenePostings(BloomFilteringPostingsFormat(Lucene50(blocksize=128))), intDefault=PostingsFormat(name=Asserting), lowerfilt=FSTOrd50, multiDefault=FSTOrd50}, docValues:{timestamp=DocValuesFormat(name=Memory)}, sim=DefaultSimilarity, locale=mk, timezone=PST8PDT
   [junit4]   2> NOTE: FreeBSD 9.1-RELEASE-p3 amd64/Oracle Corporation 1.7.0_65 (64-bit)/cpus=16,threads=1,free=257392704,total=335020032
   [junit4]   2> NOTE: All tests run in this JVM: [TestShortCircuitedRequests, TestUpdate, ZkNodePropsTest, TestPerFieldSimilarity, TestManagedSchemaDynamicFieldResource, DistributedFacetPivotLargeTest, TestRemoteStreaming, TestChildDocTransformer, HttpPartitionTest, TestShardHandlerFactory, TestOverriddenPrefixQueryForCustomFieldType, TestDFRSimilarityFactory, SolrTestCaseJ4Test, QueryElevationComponentTest, HighlighterConfigTest, DistributedQueueTest, TestStressRecovery, TestQueryUtils, TestCharFilters, BasicDistributedZk2Test, RAMDirectoryFactoryTest, DefaultValueUpdateProcessorTest, TestSchemaNameResource, TestRequestStatusCollectionAPI, TestSolr4Spatial, NumericFieldsTest, BinaryUpdateRequestHandlerTest, TestElisionMultitermQuery, TestCloudInspectUtil, CopyFieldTest, LegacyHTMLStripCharFilterTest, TestRandomDVFaceting, DistribDocExpirationUpdateProcessorTest, TestSolrCoreProperties, CurrencyFieldXmlFileTest, TestMultiCoreConfBootstrap, TestDocBasedVersionConstraints, AnalyticsQueryTest, BasicFunctionalityTest, TestMaxScoreQueryParser, TestSolrQueryParser, LeaderFailoverAfterPartitionTest, TestReversedWildcardFilterFactory, InfoHandlerTest, CoreMergeIndexesAdminHandlerTest, TestCloudManagedSchemaConcurrent, UUIDUpdateProcessorFallbackTest, PingRequestHandlerTest, TestQuerySenderListener, TestSurroundQueryParser, TestDynamicFieldResource, DocValuesTest, SimpleMLTQParserTest]
   [junit4] Completed on J2 in 2.09s, 1 test, 1 error <<< FAILURES!

[...truncated 535 lines...]
   [junit4] Suite: org.apache.solr.cloud.CollectionsAPIAsyncDistributedZkTest
   [junit4]   2> Creating dataDir: /usr/home/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test/J3/temp/solr.cloud.CollectionsAPIAsyncDistributedZkTest-80B8668EE9622AC1-001/init-core-data-001
   [junit4]   2> 3280331 T12933 oas.SolrTestCaseJ4.buildSSLConfig Randomized ssl (true) and clientAuth (true)
   [junit4]   2> 3280331 T12933 oas.BaseDistributedSearchTestCase.initHostContext Setting hostContext system property: /
   [junit4]   2> 3280337 T12933 oas.SolrTestCaseJ4.setUp ###Starting testDistribSearch
   [junit4]   2> 3280347 T12933 oasc.ZkTestServer.run STARTING ZK TEST SERVER
   [junit4]   1> client port:0.0.0.0/0.0.0.0:0
   [junit4]   2> 3280348 T12934 oasc.ZkTestServer$ZKServerMain.runFromConfig Starting server
   [junit4]   2> 3280448 T12933 oasc.ZkTestServer.run start zk server on port:40912
   [junit4]   2> 3280449 T12933 oascc.SolrZkClient.createZkCredentialsToAddAutomatically Using default ZkCredentialsProvider
   [junit4]   2> 3280450 T12933 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 3280455 T12940 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@34d2cc2d name:ZooKeeperConnection Watcher:127.0.0.1:40912 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 3280456 T12933 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 3280456 T12933 oascc.SolrZkClient.createZkACLProvider Using default ZkACLProvider
   [junit4]   2> 3280457 T12933 oascc.SolrZkClient.makePath makePath: /solr
   [junit4]   2> 3280459 T12933 oascc.SolrZkClient.createZkCredentialsToAddAutomatically Using default ZkCredentialsProvider
   [junit4]   2> 3280461 T12933 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 3280462 T12942 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@4f9241b5 name:ZooKeeperConnection Watcher:127.0.0.1:40912/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 3280462 T12933 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 3280463 T12933 oascc.SolrZkClient.createZkACLProvider Using default ZkACLProvider
   [junit4]   2> 3280463 T12933 oascc.SolrZkClient.makePath makePath: /collections/collection1
   [junit4]   2> 3280465 T12933 oascc.SolrZkClient.makePath makePath: /collections/collection1/shards
   [junit4]   2> 3280468 T12933 oascc.SolrZkClient.makePath makePath: /collections/control_collection
   [junit4]   2> 3280469 T12933 oascc.SolrZkClient.makePath makePath: /collections/control_collection/shards
   [junit4]   2> 3280472 T12933 oasc.AbstractZkTestCase.putConfig put /usr/home/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/core/src/test-files/solr/collection1/conf/solrconfig-tlog.xml to /configs/conf1/solrconfig.xml
   [junit4]   2> 3280472 T12933 oascc.SolrZkClient.makePath makePath: /configs/conf1/solrconfig.xml
   [junit4]   2> 3280476 T12933 oasc.AbstractZkTestCase.putConfig put /usr/home/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/core/src/test-files/solr/collection1/conf/schema.xml to /configs/conf1/schema.xml
   [junit4]   2> 3280477 T12933 oascc.SolrZkClient.makePath makePath: /configs/conf1/schema.xml
   [junit4]   2> 3280583 T12933 oasc.AbstractZkTestCase.putConfig put /usr/home/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/core/src/test-files/solr/collection1/conf/solrconfig.snippet.randomindexconfig.xml to /configs/conf1/solrconfig.snippet.randomindexconfig.xml
   [junit4]   2> 3280584 T12933 oascc.SolrZkClient.makePath makePath: /configs/conf1/solrconfig.snippet.randomindexconfig.xml
   [junit4]   2> 3280586 T12933 oasc.AbstractZkTestCase.putConfig put /usr/home/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/core/src/test-files/solr/collection1/conf/stopwords.txt to /configs/conf1/stopwords.txt
   [junit4]   2> 3280587 T12933 oascc.SolrZkClient.makePath makePath: /configs/conf1/stopwords.txt
   [junit4]   2> 3280589 T12933 oasc.AbstractZkTestCase.putConfig put /usr/home/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/core/src/test-files/solr/collection1/conf/protwords.txt to /configs/conf1/protwords.txt
   [junit4]   2> 3280590 T12933 oascc.SolrZkClient.makePath makePath: /configs/conf1/protwords.txt
   [junit4]   2> 3280593 T12933 oasc.AbstractZkTestCase.putConfig put /usr/home/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/core/src/test-files/solr/collection1/conf/currency.xml to /configs/conf1/currency.xml
   [junit4]   2> 3280593 T12933 oascc.SolrZkClient.makePath makePath: /configs/conf1/currency.xml
   [junit4]   2> 3280595 T12933 oasc.AbstractZkTestCase.putConfig put /usr/home/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/core/src/test-files/solr/collection1/conf/enumsConfig.xml to /configs/conf1/enumsConfig.xml
   [junit4]   2> 3280596 T12933 oascc.SolrZkClient.makePath makePath: /configs/conf1/enumsConfig.xml
   [junit4]   2> 3280598 T12933 oasc.AbstractZkTestCase.putConfig put /usr/home/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/core/src/test-files/solr/collection1/conf/open-exchange-rates.json to /configs/conf1/open-exchange-rates.json
   [junit4]   2> 3280599 T12933 oascc.SolrZkClient.makePath makePath: /configs/conf1/open-exchange-rates.json
   [junit4]   2> 3280605 T12933 oasc.AbstractZkTestCase.putConfig put /usr/home/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/core/src/test-files/solr/collection1/conf/mapping-ISOLatin1Accent.txt to /configs/conf1/mapping-ISOLatin1Accent.txt
   [junit4]   2> 3280605 T12933 oascc.SolrZkClient.makePath makePath: /configs/conf1/mapping-ISOLatin1Accent.txt
   [junit4]   2> 3280608 T12933 oasc.AbstractZkTestCase.putConfig put /usr/home/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/core/src/test-files/solr/collection1/conf/old_synonyms.txt to /configs/conf1/old_synonyms.txt
   [junit4]   2> 3280608 T12933 oascc.SolrZkClient.makePath makePath: /configs/conf1/old_synonyms.txt
   [junit4]   2> 3280611 T12933 oasc.AbstractZkTestCase.putConfig put /usr/home/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/core/src/test-files/solr/collection1/conf/synonyms.txt to /configs/conf1/synonyms.txt
   [junit4]   2> 3280611 T12933 oascc.SolrZkClient.makePath makePath: /configs/conf1/synonyms.txt
   [junit4]   2> 3280614 T12933 oascc.SolrZkClient.createZkCredentialsToAddAutomatically Using default ZkCredentialsProvider
   [junit4]   2> 3280615 T12933 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 3280616 T12944 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@625a349b name:ZooKeeperConnection Watcher:127.0.0.1:40912/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 3280617 T12933 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 3280617 T12933 oascc.SolrZkClient.createZkACLProvider Using default ZkACLProvider
   [junit4]   2> 3283025 T12933 oejs.Server.doStart jetty-8.1.10.v20130312
   [junit4]   2> 3283030 T12933 oejus.SslContextFactory.doStart Enabled Protocols [SSLv2Hello, SSLv3, TLSv1, TLSv1.1, TLSv1.2] of [SSLv2Hello, SSLv3, TLSv1, TLSv1.1, TLSv1.2]
   [junit4]   2> 3283034 T12933 oejs.AbstractConnector.doStart Started SslSocketConnector@127.0.0.1:40916
   [junit4]   2> 3283037 T12933 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
   [junit4]   2> 3283037 T12933 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
   [junit4]   2> 3283037 T12933 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: /usr/home/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test/J3/temp/solr.cloud.CollectionsAPIAsyncDistributedZkTest-80B8668EE9622AC1-001/tempDir-002
   [junit4]   2> 3283038 T12933 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/usr/home/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test/J3/temp/solr.cloud.CollectionsAPIAsyncDistributedZkTest-80B8668EE9622AC1-001/tempDir-002/'
   [junit4]   2> 3283101 T12933 oasc.ConfigSolr.fromFile Loading container configuration from /usr/home/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test/J3/temp/solr.cloud.CollectionsAPIAsyncDistributedZkTest-80B8668EE9622AC1-001/tempDir-002/solr.xml
   [junit4]   2> 3283234 T12933 oasc.CoreContainer.<init> New CoreContainer 659255442
   [junit4]   2> 3283234 T12933 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=/usr/home/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test/J3/temp/solr.cloud.CollectionsAPIAsyncDistributedZkTest-80B8668EE9622AC1-001/tempDir-002/]
   [junit4]   2> 3283236 T12933 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 90000
   [junit4]   2> 3283236 T12933 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: 
   [junit4]   2> 3283236 T12933 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
   [junit4]   2> 3283237 T12933 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
   [junit4]   2> 3283237 T12933 oashc.HttpShardHandlerFactory.getParameter Setting maxConnections to: 10000
   [junit4]   2> 3283237 T12933 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
   [junit4]   2> 3283238 T12933 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
   [junit4]   2> 3283238 T12933 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
   [junit4]   2> 3283238 T12933 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
   [junit4]   2> 3283239 T12933 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
   [junit4]   2> 3283241 T12933 oasu.UpdateShardHandler.<init> Creating UpdateShardHandler HTTP client with params: socketTimeout=340000&connTimeout=45000&retry=false
   [junit4]   2> 3283244 T12933 oasl.LogWatcher.createWatcher SLF4J impl is org.slf4j.impl.Log4jLoggerFactory
   [junit4]   2> 3283244 T12933 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
   [junit4]   2> 3283244 T12933 oasc.CoreContainer.load Host Name: 127.0.0.1
   [junit4]   2> 3283245 T12933 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:40912/solr
   [junit4]   2> 3283245 T12933 oasc.ZkController.checkChrootPath zkHost includes chroot
   [junit4]   2> 3283246 T12933 oascc.SolrZkClient.createZkCredentialsToAddAutomatically Using default ZkCredentialsProvider
   [junit4]   2> 3283247 T12933 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 3283249 T12955 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@4aa8df28 name:ZooKeeperConnection Watcher:127.0.0.1:40912 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 3283249 T12933 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 3283250 T12933 oascc.SolrZkClient.createZkACLProvider Using default ZkACLProvider
   [junit4]   2> 3283252 T12933 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 3283253 T12957 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@44dcdf92 name:ZooKeeperConnection Watcher:127.0.0.1:40912/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 3283253 T12933 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 3283254 T12933 oascc.SolrZkClient.makePath makePath: /overseer/queue
   [junit4]   2> 3283257 T12933 oascc.SolrZkClient.makePath makePath: /overseer/collection-queue-work
   [junit4]   2> 3283259 T12933 oascc.SolrZkClient.makePath makePath: /overseer/collection-map-running
   [junit4]   2> 3283262 T12933 oascc.SolrZkClient.makePath makePath: /overseer/collection-map-completed
   [junit4]   2> 3283264 T12933 oascc.SolrZkClient.makePath makePath: /overseer/collection-map-failure
   [junit4]   2> 3283267 T12933 oascc.SolrZkClient.makePath makePath: /live_nodes
   [junit4]   2> 3283268 T12933 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:40916_
   [junit4]   2> 3283269 T12933 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:40916_
   [junit4]   2> 3283271 T12933 oascc.SolrZkClient.makePath makePath: /overseer_elect
   [junit4]   2> 3283273 T12933 oascc.SolrZkClient.makePath makePath: /overseer_elect/election
   [junit4]   2> 3283275 T12933 oasc.Overseer.close Overseer (id=null) closing
   [junit4]   2> 3283276 T12933 oasc.OverseerElectionContext.runLeaderProcess I am going to be the leader 127.0.0.1:40916_
   [junit4]   2> 3283277 T12933 oascc.SolrZkClient.makePath makePath: /overseer_elect/leader
   [junit4]   2> 3283279 T12933 oasc.Overseer.start Overseer (id=92732484566908932-127.0.0.1:40916_-n_0000000000) starting
   [junit4]   2> 3283281 T12933 oascc.SolrZkClient.makePath makePath: /overseer/queue-work
   [junit4]   2> 3283289 T12933 oasc.OverseerAutoReplicaFailoverThread.<init> Starting OverseerAutoReplicaFailoverThread autoReplicaFailoverWorkLoopDelay=10000 autoReplicaFailoverWaitAfterExpiration=30000 autoReplicaFailoverBadNodeExpiration=60000
   [junit4]   2> 3283289 T12959 oasc.OverseerCollectionProcessor.run Process current queue of collection creations
   [junit4]   2> 3283290 T12933 oascc.SolrZkClient.makePath makePath: /clusterstate.json
   [junit4]   2> 3283292 T12933 oascc.SolrZkClient.makePath makePath: /aliases.json
   [junit4]   2> 3283294 T12933 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
   [junit4]   2> 3283297 T12958 oasc.Overseer$ClusterStateUpdater.run Starting to work on the main queue
   [junit4]   2> 3283302 T12961 oasc.ZkController.publish publishing core=collection1 state=down collection=control_collection
   [junit4]   2> 3283302 T12961 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
   [junit4]   2> 3283303 T12961 oasc.ZkController.waitForCoreNodeName look for our core node name
   [junit4]   2> 3283303 T12962 oasc.DistributedQueue$LatchWatcher.process NodeChildrenChanged fired on path /overseer/queue state SyncConnected
   [junit4]   2> 3283306 T12958 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={
   [junit4]   2> 	  "shard":null,
   [junit4]   2> 	  "collection":"control_collection",
   [junit4]   2> 	  "operation":"state",
   [junit4]   2> 	  "base_url":"https://127.0.0.1:40916",
   [junit4]   2> 	  "node_name":"127.0.0.1:40916_",
   [junit4]   2> 	  "core":"collection1",
   [junit4]   2> 	  "numShards":"1",
   [junit4]   2> 	  "roles":null,
   [junit4]   2> 	  "state":"down"}
   [junit4]   2> 3283306 T12958 oasc.Overseer$ClusterStateUpdater.createCollection Create collection control_collection with shards [shard1]
   [junit4]   2> 3283306 T12958 oasc.Overseer$ClusterStateUpdater.createCollection state version control_collection 1
   [junit4]   2> 3283306 T12958 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard1
   [junit4]   2> 3283309 T12962 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> 3284303 T12961 oasc.ZkController.waitForShardId waiting to find shard id in clusterstate for collection1
   [junit4]   2> 3284304 T12961 oasc.ZkController.createCollectionZkNode Check for collection zkNode:control_collection
   [junit4]   2> 3284305 T12961 oasc.ZkController.createCollectionZkNode Collection zkNode exists
   [junit4]   2> 3284305 T12961 oascc.ZkStateReader.readConfigName Load collection config from:/collections/control_collection
   [junit4]   2> 3284306 T12961 oascc.ZkStateReader.readConfigName path=/collections/control_collection configName=conf1 specified config exists in ZooKeeper
   [junit4]   2> 3284306 T12961 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/usr/home/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test/J3/temp/solr.cloud.CollectionsAPIAsyncDistributedZkTest-80B8668EE9622AC1-001/tempDir-002/collection1/'
   [junit4]   2> 3284307 T12961 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test/J3/temp/solr.cloud.CollectionsAPIAsyncDistributedZkTest-80B8668EE9622AC1-001/tempDir-002/collection1/lib/.svn/' to classloader
   [junit4]   2> 3284308 T12961 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test/J3/temp/solr.cloud.CollectionsAPIAsyncDistributedZkTest-80B8668EE9622AC1-001/tempDir-002/collection1/lib/README' to classloader
   [junit4]   2> 3284309 T12961 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test/J3/temp/solr.cloud.CollectionsAPIAsyncDistributedZkTest-80B8668EE9622AC1-001/tempDir-002/collection1/lib/classes/' to classloader
   [junit4]   2> 3284405 T12961 oasc.SolrConfig.<init> Using Lucene MatchVersion: 6.0.0
   [junit4]   2> 3284504 T12961 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
   [junit4]   2> 3284605 T12961 oass.IndexSchema.readSchema Reading Solr Schema from /configs/conf1/schema.xml
   [junit4]   2> 3284615 T12961 oass.IndexSchema.readSchema [collection1] Schema name=test
   [junit4]   2> 3285193 T12961 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
   [junit4]   2> 3285267 T12961 oass.IndexSchema.readSchema default search field in schema is text
   [junit4]   2> 3285270 T12961 oass.IndexSchema.readSchema unique key field: id
   [junit4]   2> 3285281 T12961 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
   [junit4]   2> 3285307 T12961 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
   [junit4]   2> 3285311 T12961 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
   [junit4]   2> 3285312 T12961 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
   [junit4]   2> 3285313 T12961 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
   [junit4]   2> 3285313 T12961 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
   [junit4]   2> 3285314 T12961 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
   [junit4]   2> 3285314 T12961 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
   [junit4]   2> 3285314 T12961 oasc.CoreContainer.create Creating SolrCore 'collection1' using configuration from collection control_collection
   [junit4]   2> 3285315 T12961 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
   [junit4]   2> 3285315 T12961 oasc.SolrCore.<init> [collection1] Opening new SolrCore at /usr/home/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test/J3/temp/solr.cloud.CollectionsAPIAsyncDistributedZkTest-80B8668EE9622AC1-001/tempDir-002/collection1/, dataDir=/usr/home/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test/J3/temp/solr.cloud.CollectionsAPIAsyncDistributedZkTest-80B8668EE9622AC1-001/tempDir-002/collection1/data/
   [junit4]   2> 3285315 T12961 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@7cdf0e95
   [junit4]   2> 3285316 T12961 oasc.CachingDirectoryFactory.get return new directory for /usr/home/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test/J3/temp/solr.cloud.CollectionsAPIAsyncDistributedZkTest-80B8668EE9622AC1-001/tempDir-002/collection1/data
   [junit4]   2> 3285316 T12961 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=/usr/home/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test/J3/temp/solr.cloud.CollectionsAPIAsyncDistributedZkTest-80B8668EE9622AC1-001/tempDir-002/collection1/data/index/
   [junit4]   2> 3285317 T12961 oasc.SolrCore.initIndex WARN [collection1] Solr index directory '/usr/home/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test/J3/temp/solr.cloud.CollectionsAPIAsyncDistributedZkTest-80B8668EE9622AC1-001/tempDir-002/collection1/data/index' doesn't exist. Creating new index...
   [junit4]   2> 3285317 T12961 oasc.CachingDirectoryFactory.get return new directory for /usr/home/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test/J3/temp/solr.cloud.CollectionsAPIAsyncDistributedZkTest-80B8668EE9622AC1-001/tempDir-002/collection1/data/index
   [junit4]   2> 3285318 T12961 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.AlcoholicMergePolicy: [AlcoholicMergePolicy: minMergeSize=0, mergeFactor=10, maxMergeSize=728475722, maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=true, maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.1]
   [junit4]   2> 3285318 T12961 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
   [junit4]   2> 		commit{dir=MockDirectoryWrapper(RAMDirectory(id=lucene-3edf547a)),segFN=segments_1,generation=1}
   [junit4]   2> 3285319 T12961 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
   [junit4]   2> 3285323 T12961 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "nodistrib"
   [junit4]   2> 3285324 T12961 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "dedupe"
   [junit4]   2> 3285324 T12961 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
   [junit4]   2> 3285325 T12961 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "stored_sig"
   [junit4]   2> 3285325 T12961 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
   [junit4]   2> 3285325 T12961 oasup.UpdateR

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

terCloser
   [junit4]   2> 3498109 T12933 oasc.SolrCore.closeSearcher [testasynccollectioncreation_shard1_replica2] Closing main searcher on request.
   [junit4]   2> 3498110 T12933 oasc.CachingDirectoryFactory.close Closing MockDirectoryFactory - 2 directories currently being tracked
   [junit4]   2> 3498110 T12933 oasc.CachingDirectoryFactory.closeCacheValue looking to close /usr/home/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test/J3/../../../../../../../../../../../usr/home/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test/J3/temp/solr.cloud.CollectionsAPIAsyncDistributedZkTest-80B8668EE9622AC1-001/tempDir-003/testasynccollectioncreation_shard1_replica2/data [CachedDir<<refCount=0;path=/usr/home/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test/J3/../../../../../../../../../../../usr/home/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test/J3/temp/solr.cloud.CollectionsAPIAsyncDistributedZkTest-80B8668EE9622AC1-001/tempDir-003/testasynccollectioncreation_shard1_replica2/data;done=false>>]
   [junit4]   2> 3498111 T12933 oasc.CachingDirectoryFactory.close Closing directory: /usr/home/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test/J3/../../../../../../../../../../../usr/home/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test/J3/temp/solr.cloud.CollectionsAPIAsyncDistributedZkTest-80B8668EE9622AC1-001/tempDir-003/testasynccollectioncreation_shard1_replica2/data
   [junit4]   2> 3498111 T12933 oasc.CachingDirectoryFactory.closeCacheValue looking to close /usr/home/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test/J3/../../../../../../../../../../../usr/home/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test/J3/temp/solr.cloud.CollectionsAPIAsyncDistributedZkTest-80B8668EE9622AC1-001/tempDir-003/testasynccollectioncreation_shard1_replica2/data/index [CachedDir<<refCount=0;path=/usr/home/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test/J3/../../../../../../../../../../../usr/home/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test/J3/temp/solr.cloud.CollectionsAPIAsyncDistributedZkTest-80B8668EE9622AC1-001/tempDir-003/testasynccollectioncreation_shard1_replica2/data/index;done=false>>]
   [junit4]   2> 3498112 T12933 oasc.CachingDirectoryFactory.close Closing directory: /usr/home/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test/J3/../../../../../../../../../../../usr/home/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test/J3/temp/solr.cloud.CollectionsAPIAsyncDistributedZkTest-80B8668EE9622AC1-001/tempDir-003/testasynccollectioncreation_shard1_replica2/data/index
   [junit4]   2> 3498112 T12933 oasc.Overseer.close Overseer (id=92732484566908935-127.0.0.1:40920_-n_0000000001) closing
   [junit4]   2> 3498113 T13305 oasc.Overseer$ClusterStateUpdater.run Overseer Loop exiting : 127.0.0.1:40920_
   [junit4]   2> 3499615 T13304 oascc.ZkStateReader$3.process WARN ZooKeeper watch triggered, but Solr cannot talk to ZK
   [junit4]   2> 3499632 T12933 oejsh.ContextHandler.doStop stopped o.e.j.s.ServletContextHandler{/,null}
   [junit4]   2> 3504634 T12933 oas.SolrTestCaseJ4.tearDown ###Ending testDistribSearch
   [junit4]   2> 3504637 T12933 oasc.ZkTestServer.send4LetterWord connecting to 127.0.0.1:40912 40912
   [junit4]   2> 3504996 T12934 oasc.ZkTestServer.send4LetterWord connecting to 127.0.0.1:40912 40912
   [junit4]   2> 3504998 T12934 oasc.ZkTestServer$ZKServerMain.runFromConfig WARN Watch limit violations: 
   [junit4]   2> 	Maximum concurrent create/delete watches above limit:
   [junit4]   2> 	
   [junit4]   2> 		3	/solr/clusterstate.json
   [junit4]   2> 		3	/solr/aliases.json
   [junit4]   2> 	
   [junit4]   2> 	Maximum concurrent children watches above limit:
   [junit4]   2> 	
   [junit4]   2> 		3	/solr/live_nodes
   [junit4]   2> 		2	/solr/overseer/queue
   [junit4]   2> 	
   [junit4]   2> NOTE: download the large Jenkins line-docs file by running 'ant get-jenkins-line-docs' in the lucene directory.
   [junit4]   2> NOTE: reproduce with: ant test  -Dtestcase=CollectionsAPIAsyncDistributedZkTest -Dtests.method=testDistribSearch -Dtests.seed=80B8668EE9622AC1 -Dtests.multiplier=2 -Dtests.nightly=true -Dtests.slow=true -Dtests.linedocsfile=/home/jenkins/lucene-data/enwiki.random.lines.txt -Dtests.locale=da -Dtests.timezone=Africa/Gaborone -Dtests.asserts=true -Dtests.file.encoding=US-ASCII
   [junit4] FAILURE  225s J3 | CollectionsAPIAsyncDistributedZkTest.testDistribSearch <<<
   [junit4]    > Throwable #1: org.junit.ComparisonFailure: Shard split did not complete. Last recorded state: running expected:<[completed]> but was:<[running]>
   [junit4]    > 	at __randomizedtesting.SeedInfo.seed([80B8668EE9622AC1:15EE8969E3D4AFD]:0)
   [junit4]    > 	at org.apache.solr.cloud.CollectionsAPIAsyncDistributedZkTest.testSolrJAPICalls(CollectionsAPIAsyncDistributedZkTest.java:114)
   [junit4]    > 	at org.apache.solr.cloud.CollectionsAPIAsyncDistributedZkTest.doTest(CollectionsAPIAsyncDistributedZkTest.java:64)
   [junit4]    > 	at org.apache.solr.BaseDistributedSearchTestCase.testDistribSearch(BaseDistributedSearchTestCase.java:869)
   [junit4]    > 	at java.lang.Thread.run(Thread.java:745)
   [junit4]   2> 3505034 T12933 oas.SolrTestCaseJ4.deleteCore ###deleteCore
   [junit4]   2> NOTE: leaving temporary files on disk at: /usr/home/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test/J3/temp/solr.cloud.CollectionsAPIAsyncDistributedZkTest-80B8668EE9622AC1-001
   [junit4]   2> 224709 T12932 ccr.ThreadLeakControl.checkThreadLeaks WARNING Will linger awaiting termination of 1 leaked thread(s).
   [junit4]   2> NOTE: test params are: codec=Asserting(Lucene50): {}, docValues:{}, sim=DefaultSimilarity, locale=da, timezone=Africa/Gaborone
   [junit4]   2> NOTE: FreeBSD 9.1-RELEASE-p3 amd64/Oracle Corporation 1.7.0_65 (64-bit)/cpus=16,threads=1,free=108130400,total=415236096
   [junit4]   2> NOTE: All tests run in this JVM: [TestPHPSerializedResponseWriter, FieldMutatingUpdateProcessorTest, TestMissingGroups, TestCSVResponseWriter, RequestHandlersTest, TestSort, TestSchemaSimilarityResource, TestIntervalFaceting, TestFreeTextSuggestions, TestRecoveryHdfs, TestDocSet, TestFieldResource, TestManagedSchema, CoreContainerCoreInitFailuresTest, ResponseLogComponentTest, LoggingHandlerTest, WordBreakSolrSpellCheckerTest, ZkCLITest, BlockDirectoryTest, TestSearchPerf, EchoParamsTest, TestIndexSearcher, OutOfBoxZkACLAndCredentialsProvidersTest, TestSimpleQParserPlugin, RollingRestartTest, TestInitQParser, SolrIndexSplitterTest, SliceStateTest, MultiThreadedOCPTest, TriLevelCompositeIdRoutingTest, DocumentAnalysisRequestHandlerTest, QueryResultKeyTest, ConnectionManagerTest, AsyncMigrateRouteKeyTest, SpellCheckComponentTest, TestSolrXml, UUIDFieldTest, TestJoin, TestManagedStopFilterFactory, TestCustomSort, BlockCacheTest, ClusterStateUpdateTest, TestDistribDocBasedVersion, TestManagedSchemaFieldResource, TestLMJelinekMercerSimilarityFactory, TermVectorComponentDistributedTest, UniqFieldsUpdateProcessorFactoryTest, TestFastLRUCache, IndexBasedSpellCheckerTest, FieldAnalysisRequestHandlerTest, TestSolrXmlPersistence, TestSolr4Spatial2, LeaderElectionTest, TestDistributedSearch, SuggesterTest, TestStressLucene, SuggesterWFSTTest, SchemaVersionSpecificBehaviorTest, XsltUpdateRequestHandlerTest, StandardRequestHandlerTest, XmlUpdateRequestHandlerTest, RequiredFieldsTest, SolrPluginUtilsTest, ReturnFieldsTest, JsonLoaderTest, TestBinaryResponseWriter, SolrIndexConfigTest, TestSolrDeletionPolicy2, TestBinaryField, TestDefaultSimilarityFactory, TimeZoneUtilsTest, OpenExchangeRatesOrgProviderTest, TestSuggestSpellingConverter, SpellingQueryConverterTest, TestLRUCache, TestDocumentBuilder, CursorPagingTest, TestCursorMarkWithoutUniqueKey, TestHighlightDedupGrouping, TestTolerantSearch, AssignTest, CollectionsAPIAsyncDistributedZkTest]
   [junit4] Completed on J3 in 225.00s, 1 test, 1 failure <<< FAILURES!

[...truncated 281 lines...]
BUILD FAILED
/usr/home/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-trunk/build.xml:532: The following error occurred while executing this line:
/usr/home/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-trunk/build.xml:473: The following error occurred while executing this line:
/usr/home/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-trunk/build.xml:61: The following error occurred while executing this line:
/usr/home/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-trunk/extra-targets.xml:39: The following error occurred while executing this line:
/usr/home/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build.xml:189: The following error occurred while executing this line:
/usr/home/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/common-build.xml:502: The following error occurred while executing this line:
/usr/home/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-trunk/lucene/common-build.xml:1358: The following error occurred while executing this line:
/usr/home/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-trunk/lucene/common-build.xml:965: There were test failures: 441 suites, 1801 tests, 1 error, 1 failure, 54 ignored (9 assumptions)

Total time: 196 minutes 3 seconds
Build step 'Invoke Ant' marked build as failure
Archiving artifacts
Sending artifact delta relative to Lucene-Solr-NightlyTests-trunk #664
Archived 5 artifacts
Archive block size is 32768
Received 0 blocks and 461342789 bytes
Compression is 0.0%
Took 1 min 35 sec
Recording test results
Email was triggered for: Failure
Sending email for trigger: Failure



Mime
View raw message