You are viewing a plain text version of this content. The canonical link for it is here.
Posted to dev@lucene.apache.org by Apache Jenkins Server <je...@builds.apache.org> on 2013/08/07 16:01:01 UTC

[JENKINS] Lucene-Solr-NightlyTests-trunk - Build # 343 - Still Failing

Build: https://builds.apache.org/job/Lucene-Solr-NightlyTests-trunk/343/

1 tests failed.
REGRESSION:  org.apache.solr.spelling.SpellCheckCollatorTest.testEstimatedHitCounts

Error Message:
Exception during query

Stack Trace:
java.lang.RuntimeException: Exception during query
	at __randomizedtesting.SeedInfo.seed([16B4D8F74E59EE10:270F66C2EB66FEC0]:0)
	at org.apache.solr.SolrTestCaseJ4.assertQ(SolrTestCaseJ4.java:635)
	at org.apache.solr.SolrTestCaseJ4.assertQ(SolrTestCaseJ4.java:602)
	at org.apache.solr.spelling.SpellCheckCollatorTest.testEstimatedHitCounts(SpellCheckCollatorTest.java:469)
	at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
	at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:57)
	at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
	at java.lang.reflect.Method.invoke(Method.java:606)
	at com.carrotsearch.randomizedtesting.RandomizedRunner.invoke(RandomizedRunner.java:1559)
	at com.carrotsearch.randomizedtesting.RandomizedRunner.access$600(RandomizedRunner.java:79)
	at com.carrotsearch.randomizedtesting.RandomizedRunner$6.evaluate(RandomizedRunner.java:737)
	at com.carrotsearch.randomizedtesting.RandomizedRunner$7.evaluate(RandomizedRunner.java:773)
	at com.carrotsearch.randomizedtesting.RandomizedRunner$8.evaluate(RandomizedRunner.java:787)
	at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:53)
	at org.apache.lucene.util.TestRuleSetupTeardownChained$1.evaluate(TestRuleSetupTeardownChained.java:50)
	at org.apache.lucene.util.TestRuleFieldCacheSanity$1.evaluate(TestRuleFieldCacheSanity.java:51)
	at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:46)
	at com.carrotsearch.randomizedtesting.rules.SystemPropertiesInvariantRule$1.evaluate(SystemPropertiesInvariantRule.java:55)
	at org.apache.lucene.util.TestRuleThreadAndTestName$1.evaluate(TestRuleThreadAndTestName.java:49)
	at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:70)
	at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:48)
	at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
	at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:358)
	at com.carrotsearch.randomizedtesting.ThreadLeakControl.forkTimeoutingTask(ThreadLeakControl.java:782)
	at com.carrotsearch.randomizedtesting.ThreadLeakControl$3.evaluate(ThreadLeakControl.java:442)
	at com.carrotsearch.randomizedtesting.RandomizedRunner.runSingleTest(RandomizedRunner.java:746)
	at com.carrotsearch.randomizedtesting.RandomizedRunner$3.evaluate(RandomizedRunner.java:648)
	at com.carrotsearch.randomizedtesting.RandomizedRunner$4.evaluate(RandomizedRunner.java:682)
	at com.carrotsearch.randomizedtesting.RandomizedRunner$5.evaluate(RandomizedRunner.java:693)
	at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
	at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:53)
	at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:46)
	at org.apache.lucene.util.TestRuleStoreClassName$1.evaluate(TestRuleStoreClassName.java:42)
	at com.carrotsearch.randomizedtesting.rules.SystemPropertiesInvariantRule$1.evaluate(SystemPropertiesInvariantRule.java:55)
	at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:39)
	at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:39)
	at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
	at org.apache.lucene.util.TestRuleAssertionsRequired$1.evaluate(TestRuleAssertionsRequired.java:43)
	at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:48)
	at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:70)
	at org.apache.lucene.util.TestRuleIgnoreTestSuites$1.evaluate(TestRuleIgnoreTestSuites.java:55)
	at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
	at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:358)
	at java.lang.Thread.run(Thread.java:724)
Caused by: java.lang.RuntimeException: REQUEST FAILED: xpath=//lst[@name='spellcheck']/lst[@name='suggestions']/lst[@name='collation']/int[@name='hits']=4
	xml response was: <?xml version="1.0" encoding="UTF-8"?>
<response>
<lst name="responseHeader"><int name="status">0</int><int name="QTime">8</int></lst><result name="response" numFound="0" start="0"></result><lst name="spellcheck"><lst name="suggestions"><lst name="metnoia"><int name="numFound">1</int><int name="startOffset">9</int><int name="endOffset">16</int><arr name="suggestion"><str>metanoia</str></arr></lst><lst name="collation"><str name="collationQuery">teststop:metanoia</str><int name="hits">17</int><lst name="misspellingsAndCorrections"><str name="metnoia">metanoia</str></lst></lst></lst></lst>
</response>

	request was:spellcheck=true&spellcheck.collateExtendedResults=true&q=teststop:metnoia&spellcheck.maxCollations=1&spellcheck.maxCollationTries=1&spellcheck.dictionary=direct&spellcheck.collateMaxCollectDocs=3&spellcheck.count=1&qt=spellCheckCompRH&spellcheck.collate=true
	at org.apache.solr.SolrTestCaseJ4.assertQ(SolrTestCaseJ4.java:628)
	... 42 more




Build Log:
[...truncated 9902 lines...]
   [junit4] Suite: org.apache.solr.spelling.SpellCheckCollatorTest
   [junit4]   2> 2399675 T4045 oas.SolrTestCaseJ4.initCore ####initCore
   [junit4]   2> Creating dataDir: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test/J1/./solrtest-SpellCheckCollatorTest-1375883796067
   [junit4]   2> 2399676 T4045 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test-files/solr/collection1/'
   [junit4]   2> 2399677 T4045 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test-files/solr/collection1/lib/classes/' to classloader
   [junit4]   2> 2399677 T4045 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test-files/solr/collection1/lib/README' to classloader
   [junit4]   2> 2399765 T4045 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_50
   [junit4]   2> 2399808 T4045 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig-spellcheckcomponent.xml
   [junit4]   2> 2399809 T4045 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
   [junit4]   2> 2399817 T4045 oass.IndexSchema.readSchema [null] Schema name=test
   [junit4]   2> 2400228 T4045 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
   [junit4]   2> 2400236 T4045 oass.IndexSchema.readSchema default search field in schema is text
   [junit4]   2> 2400238 T4045 oass.IndexSchema.readSchema unique key field: id
   [junit4]   2> 2400244 T4045 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
   [junit4]   2> 2400247 T4045 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
   [junit4]   2> 2400250 T4045 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
   [junit4]   2> 2400251 T4045 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
   [junit4]   2> 2400251 T4045 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
   [junit4]   2> 2400251 T4045 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
   [junit4]   2> 2400251 T4045 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
   [junit4]   2> 2400251 T4045 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
   [junit4]   2> 2400252 T4045 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
   [junit4]   2> 2400252 T4045 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test-files/solr
   [junit4]   2> 2400252 T4045 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test-files/solr/'
   [junit4]   2> 2400261 T4045 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
   [junit4]   2> 2400262 T4045 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test-files/solr
   [junit4]   2> 2400262 T4045 oasc.SolrResourceLoader.<init> new SolrResourceLoader for deduced Solr Home: '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test-files/solr/'
   [junit4]   2> 2400320 T4045 oasc.CoreContainer.<init> New CoreContainer 1414615201
   [junit4]   2> 2400321 T4045 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test-files/solr/]
   [junit4]   2> 2400322 T4045 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 0
   [junit4]   2> 2400322 T4045 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
   [junit4]   2> 2400322 T4045 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 0
   [junit4]   2> 2400323 T4045 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
   [junit4]   2> 2400323 T4045 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
   [junit4]   2> 2400323 T4045 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
   [junit4]   2> 2400323 T4045 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
   [junit4]   2> 2400323 T4045 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
   [junit4]   2> 2400324 T4045 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
   [junit4]   2> 2400324 T4045 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=0&connTimeout=0&retry=false
   [junit4]   2> 2400340 T4045 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
   [junit4]   2> 2400347 T4046 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test-files/solr/collection1
   [junit4]   2> 2400347 T4046 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test-files/solr/collection1/'
   [junit4]   2> 2400348 T4046 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test-files/solr/collection1/lib/classes/' to classloader
   [junit4]   2> 2400348 T4046 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test-files/solr/collection1/lib/README' to classloader
   [junit4]   2> 2400390 T4046 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_50
   [junit4]   2> 2400429 T4046 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig-spellcheckcomponent.xml
   [junit4]   2> 2400430 T4046 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
   [junit4]   2> 2400436 T4046 oass.IndexSchema.readSchema [collection1] Schema name=test
   [junit4]   2> 2400922 T4046 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
   [junit4]   2> 2400931 T4046 oass.IndexSchema.readSchema default search field in schema is text
   [junit4]   2> 2400935 T4046 oass.IndexSchema.readSchema unique key field: id
   [junit4]   2> 2400942 T4046 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
   [junit4]   2> 2400946 T4046 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
   [junit4]   2> 2400950 T4046 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
   [junit4]   2> 2400950 T4046 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
   [junit4]   2> 2400950 T4046 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
   [junit4]   2> 2400951 T4046 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
   [junit4]   2> 2400951 T4046 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
   [junit4]   2> 2400951 T4046 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
   [junit4]   2> 2400952 T4046 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
   [junit4]   2> 2400952 T4046 oasc.SolrCore.<init> [collection1] Opening new SolrCore at /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test-files/solr/collection1/, dataDir=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test/J1/./solrtest-SpellCheckCollatorTest-1375883796067/
   [junit4]   2> 2400952 T4046 oasc.SolrCore.<init> JMX monitoring not detected for core: collection1
   [junit4]   2> 2400953 T4046 oasc.CachingDirectoryFactory.get return new directory for /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test/J1/./solrtest-SpellCheckCollatorTest-1375883796067
   [junit4]   2> 2400953 T4046 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test/J1/./solrtest-SpellCheckCollatorTest-1375883796067/index/
   [junit4]   2> 2400953 T4046 oasc.SolrCore.initIndex WARN [collection1] Solr index directory '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test/J1/./solrtest-SpellCheckCollatorTest-1375883796067/index' doesn't exist. Creating new index...
   [junit4]   2> 2400954 T4046 oasc.CachingDirectoryFactory.get return new directory for /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test/J1/./solrtest-SpellCheckCollatorTest-1375883796067/index
   [junit4]   2> 2400955 T4046 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
   [junit4]   2> 		commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@7714200f lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@5a4c3855),segFN=segments_1,generation=1}
   [junit4]   2> 2400955 T4046 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
   [junit4]   2> 2400956 T4046 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
   [junit4]   2> 2400956 T4046 oasc.RequestHandlers.initHandlersFromConfig created spellCheckCompRH: org.apache.solr.handler.component.SearchHandler
   [junit4]   2> 2400957 T4046 oasc.RequestHandlers.initHandlersFromConfig created spellCheckCompRH1: org.apache.solr.handler.component.SearchHandler
   [junit4]   2> 2400957 T4046 oasc.RequestHandlers.initHandlersFromConfig created spellCheckWithWordbreak: org.apache.solr.handler.component.SearchHandler
   [junit4]   2> 2400960 T4046 oass.SolrIndexSearcher.<init> Opening Searcher@318e8f99 main
   [junit4]   2> 2400961 T4046 oasu.CommitTracker.<init> Hard AutoCommit: disabled
   [junit4]   2> 2400961 T4046 oasu.CommitTracker.<init> Soft AutoCommit: disabled
   [junit4]   2> 2400961 T4046 oashc.SpellCheckComponent.inform Initializing spell checkers
   [junit4]   2> 2400969 T4046 oashc.SpellCheckComponent.inform Registering newSearcher listener for spellchecker: default
   [junit4]   2> 2400982 T4046 oashc.SpellCheckComponent.inform Registering newSearcher listener for spellchecker: default_teststop
   [junit4]   2> 2400983 T4046 oass.DirectSolrSpellChecker.init init: {name=direct,classname=solr.DirectSolrSpellChecker,minQueryLength=3,maxQueryFrequency=100.0,field=teststop}
   [junit4]   2> 2400983 T4046 oass.DirectSolrSpellChecker.init init: {name=direct_lowerfilt,classname=solr.DirectSolrSpellChecker,minQueryLength=3,maxQueryFrequency=100.0,field=lowerfilt}
   [junit4]   2> 2400991 T4046 oashc.SpellCheckComponent.inform Registering newSearcher listener for spellchecker: threshold
   [junit4]   2> 2400991 T4046 oass.DirectSolrSpellChecker.init init: {name=threshold_direct,classname=solr.DirectSolrSpellChecker,field=lowerfilt,spellcheckIndexDir=spellcheckerThreshold,buildOnCommit=true,thresholdTokenFrequency=0.29}
   [junit4]   2> 2400992 T4046 oashc.SpellCheckComponent.inform Registering newSearcher listener for spellchecker: threshold_direct
   [junit4]   2> 2400999 T4046 oashc.SpellCheckComponent.inform Registering newSearcher listener for spellchecker: multipleFields
   [junit4]   2> 2401034 T4046 oashc.SpellCheckComponent.inform Registering newSearcher listener for spellchecker: freq
   [junit4]   2> 2401041 T4046 oashc.SpellCheckComponent.inform Registering newSearcher listener for spellchecker: fqcn
   [junit4]   2> 2401042 T4047 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@318e8f99 main{StandardDirectoryReader(segments_1:1)}
   [junit4]   2> 2401042 T4046 oasc.CoreContainer.registerCore registering core: collection1
   [junit4]   2> 2401055 T4045 oas.SolrTestCaseJ4.initCore ####initCore end
   [junit4]   2> ASYNC  NEW_CORE C21367 name=collection1 org.apache.solr.core.SolrCore@32af94b0
   [junit4]   2> 2401064 T4045 C21367 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=1
   [junit4]   2> 		commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@7714200f lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@5a4c3855),segFN=segments_1,generation=1}
   [junit4]   2> 2401064 T4045 C21367 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
   [junit4]   2> 2401065 T4045 C21367 oasup.LogUpdateProcessor.finish [collection1] webapp=null path=null params={} {add=[0]} 0 2
   [junit4]   2> 2401083 T4045 C21367 oasup.LogUpdateProcessor.finish [collection1] webapp=null path=null params={} {add=[1]} 0 0
   [junit4]   2> 2401090 T4045 C21367 oasup.LogUpdateProcessor.finish [collection1] webapp=null path=null params={} {add=[2]} 0 1
   [junit4]   2> 2401096 T4045 C21367 oasup.LogUpdateProcessor.finish [collection1] webapp=null path=null params={} {add=[3]} 0 1
   [junit4]   2> 2401104 T4045 C21367 oasup.LogUpdateProcessor.finish [collection1] webapp=null path=null params={} {add=[4]} 0 3
   [junit4]   2> 2401111 T4045 C21367 oasup.LogUpdateProcessor.finish [collection1] webapp=null path=null params={} {add=[5]} 0 1
   [junit4]   2> 2401116 T4045 C21367 oasup.LogUpdateProcessor.finish [collection1] webapp=null path=null params={} {add=[6]} 0 0
   [junit4]   2> 2401122 T4045 C21367 oasup.LogUpdateProcessor.finish [collection1] webapp=null path=null params={} {add=[7]} 0 0
   [junit4]   2> 2401128 T4045 C21367 oasup.LogUpdateProcessor.finish [collection1] webapp=null path=null params={} {add=[8]} 0 0
   [junit4]   2> 2401154 T4045 C21367 oasup.LogUpdateProcessor.finish [collection1] webapp=null path=null params={} {add=[9]} 0 20
   [junit4]   2> 2401160 T4045 C21367 oasup.LogUpdateProcessor.finish [collection1] webapp=null path=null params={} {add=[10]} 0 1
   [junit4]   2> 2401166 T4045 C21367 oasup.LogUpdateProcessor.finish [collection1] webapp=null path=null params={} {add=[11]} 0 1
   [junit4]   2> 2401171 T4045 C21367 oasup.LogUpdateProcessor.finish [collection1] webapp=null path=null params={} {add=[12]} 0 0
   [junit4]   2> 2401177 T4045 C21367 oasup.LogUpdateProcessor.finish [collection1] webapp=null path=null params={} {add=[13]} 0 0
   [junit4]   2> 2401211 T4045 C21367 oasup.LogUpdateProcessor.finish [collection1] webapp=null path=null params={} {add=[14]} 0 28
   [junit4]   2> 2401218 T4045 C21367 oasup.LogUpdateProcessor.finish [collection1] webapp=null path=null params={} {add=[15]} 0 1
   [junit4]   2> 2401223 T4045 C21367 oasup.LogUpdateProcessor.finish [collection1] webapp=null path=null params={} {add=[16]} 0 0
   [junit4]   2> 2401229 T4045 C21367 oasu.DirectUpdateHandler2.commit start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
   [junit4]   2> 2401254 T4045 C21367 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=2
   [junit4]   2> 		commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@7714200f lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@5a4c3855),segFN=segments_1,generation=1}
   [junit4]   2> 		commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@7714200f lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@5a4c3855),segFN=segments_2,generation=2}
   [junit4]   2> 2401254 T4045 C21367 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 2
   [junit4]   2> 2401259 T4045 C21367 oass.SolrIndexSearcher.<init> Opening Searcher@60a8d965 main
   [junit4]   2> 2401259 T4045 C21367 oasu.DirectUpdateHandler2.commit end_commit_flush
   [junit4]   2> 2401259 T4047 oashc.SpellCheckComponent$SpellCheckerListener.buildSpellIndex Building spell index for spell checker: default
   [junit4]   2> 2401346 T4047 oashc.SpellCheckComponent$SpellCheckerListener.buildSpellIndex Building spell index for spell checker: default_teststop
   [junit4]   2> 2401408 T4047 oashc.SpellCheckComponent$SpellCheckerListener.buildSpellIndex Building spell index for spell checker: threshold
   [junit4]   2> 2401421 T4047 oashc.SpellCheckComponent$SpellCheckerListener.buildSpellIndex Building spell index for spell checker: threshold_direct
   [junit4]   2> 2401422 T4047 oashc.SpellCheckComponent$SpellCheckerListener.buildSpellIndex Building spell index for spell checker: multipleFields
   [junit4]   2> 2401490 T4047 oashc.SpellCheckComponent$SpellCheckerListener.buildSpellIndex Building spell index for spell checker: freq
   [junit4]   2> 2401560 T4047 oashc.SpellCheckComponent$SpellCheckerListener.buildSpellIndex Building spell index for spell checker: fqcn
   [junit4]   2> 2401628 T4047 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@60a8d965 main{StandardDirectoryReader(segments_2:9:nrt _0(5.0):c5 _1(5.0):c5 _2(5.0):c5 _3(5.0):c2)}
   [junit4]   2> ASYNC  NEW_CORE C21368 name=collection1 org.apache.solr.core.SolrCore@32af94b0
   [junit4]   2> 2401628 T4045 C21368 oasup.LogUpdateProcessor.finish [collection1] webapp=null path=null params={} {commit=} 0 399
   [junit4]   2> 2401640 T4045 oas.SolrTestCaseJ4.setUp ###Starting testExtendedCollate
   [junit4]   2> 2401733 T4045 oas.SolrTestCaseJ4.tearDown ###Ending testExtendedCollate
   [junit4]   2> 2401739 T4045 oas.SolrTestCaseJ4.setUp ###Starting testCollateWithFilter
   [junit4]   2> 2401825 T4045 oas.SolrTestCaseJ4.tearDown ###Ending testCollateWithFilter
   [junit4]   2> 2401832 T4045 oas.SolrTestCaseJ4.setUp ###Starting testContextSensitiveCollate
   [junit4]   2> 2401866 T4045 C21368 oasc.SolrCore.execute [collection1] webapp=null path=null params={spellcheck=true&indent=true&spellcheck.maxResultsForSuggest=0&spellcheck.collateExtendedResults=true&spellcheck.extendedResults=true&spellcheck.maxCollations=1&spellcheck.maxCollationTries=10&spellcheck.collate=true&q=teststop:(flew+AND+form+AND+heathrow)&spellcheck.dictionary=direct&spellcheck.count=10&qt=spellCheckCompRH&spellcheck.build=true&spellcheck.alternativeTermCount=5} hits=0 status=0 QTime=34 
   [junit4]   2> 2401899 T4045 C21368 oasc.SolrCore.execute [collection1] webapp=null path=null params={spellcheck=true&indent=true&spellcheck.maxResultsForSuggest=1&spellcheck.collateExtendedResults=true&spellcheck.extendedResults=true&spellcheck.maxCollationTries=10&spellcheck.maxCollations=1&spellcheck.collate=true&q=teststop:(june+AND+customs)&spellcheck.dictionary=direct&spellcheck.count=10&qt=spellCheckCompRH&spellcheck.alternativeTermCount=5} hits=1 status=0 QTime=19 
   [junit4]   2> 2401999 T4045 C21368 oasc.SolrCore.execute [collection1] webapp=null path=null params={spellcheck=true&indent=true&spellcheck.maxResultsForSuggest=0&spellcheck.collateExtendedResults=true&spellcheck.extendedResults=true&spellcheck.maxCollations=1&spellcheck.maxCollationTries=10&spellcheck.collate=true&q=teststop:(flew+AND+form+AND+heathrow)&spellcheck.dictionary=default_teststop&spellcheck.count=10&qt=spellCheckCompRH&spellcheck.build=true&spellcheck.alternativeTermCount=5} hits=0 status=0 QTime=90 
   [junit4]   2> 2402017 T4045 C21368 oasc.SolrCore.execute [collection1] webapp=null path=null params={spellcheck=true&indent=true&spellcheck.maxResultsForSuggest=1&spellcheck.collateExtendedResults=true&spellcheck.extendedResults=true&spellcheck.maxCollationTries=10&spellcheck.maxCollations=1&spellcheck.collate=true&q=teststop:(june+AND+customs)&spellcheck.dictionary=default_teststop&spellcheck.count=10&qt=spellCheckCompRH&spellcheck.alternativeTermCount=5} hits=1 status=0 QTime=5 
   [junit4]   2> 2402027 T4045 oas.SolrTestCaseJ4.tearDown ###Ending testContextSensitiveCollate
   [junit4]   2> 2402035 T4045 oas.SolrTestCaseJ4.setUp ###Starting testCollateWithMultipleRequestHandlers
   [junit4]   2> 2402108 T4045 oas.SolrTestCaseJ4.tearDown ###Ending testCollateWithMultipleRequestHandlers
   [junit4]   2> 2402115 T4045 oas.SolrTestCaseJ4.setUp ###Starting testCollationWithHypens
   [junit4]   2> 2402260 T4045 oas.SolrTestCaseJ4.tearDown ###Ending testCollationWithHypens
   [junit4]   2> 2402267 T4045 oas.SolrTestCaseJ4.setUp ###Starting testCollateWithGrouping
   [junit4]   2> 2402336 T4045 oas.SolrTestCaseJ4.tearDown ###Ending testCollateWithGrouping
   [junit4]   2> 2402344 T4045 oas.SolrTestCaseJ4.setUp ###Starting testCollateWithOverride
   [junit4]   2> 2402446 T4045 C21368 oasc.SolrCore.execute [collection1] webapp=null path=null params={mm=1&spellcheck=true&q=partisian+politcal+mashine&spellcheck.maxCollations=10&spellcheck.maxCollationTries=10&qf=teststop&spellcheck.dictionary=direct&spellcheck.count=10&qt=spellCheckCompRH&spellcheck.collate=true&defType=edismax} hits=0 status=0 QTime=102 
   [junit4]   2> 2402493 T4045 C21368 oasc.SolrCore.execute [collection1] webapp=null path=null params={mm=1&spellcheck=true&spellcheck.collateParam.mm=100%25&q=partisian+politcal+mashine&spellcheck.maxCollations=10&spellcheck.maxCollationTries=10&qf=teststop&spellcheck.dictionary=direct&spellcheck.count=10&qt=spellCheckCompRH&spellcheck.collate=true&defType=edismax} hits=0 status=0 QTime=40 
   [junit4]   2> 2402496 T4045 oas.SolrTestCaseJ4.tearDown ###Ending testCollateWithOverride
   [junit4]   2> 2402502 T4045 oas.SolrTestCaseJ4.setUp ###Starting testEstimatedHitCounts
   [junit4]   2> 2402512 T4045 C21368 oasc.SolrCore.execute [collection1] webapp=null path=null params={spellcheck=true&spellcheck.collateExtendedResults=true&q=teststop:metnoia&spellcheck.maxCollations=1&spellcheck.maxCollationTries=1&spellcheck.dictionary=direct&spellcheck.count=1&qt=spellCheckCompRH&spellcheck.collate=true} hits=0 status=0 QTime=10 
   [junit4]   2> 2402526 T4045 C21368 oasc.SolrCore.execute [collection1] webapp=null path=null params={spellcheck=true&spellcheck.collateExtendedResults=true&q=teststop:metnoia&spellcheck.maxCollations=1&spellcheck.maxCollationTries=1&spellcheck.dictionary=direct&spellcheck.collateMaxCollectDocs=1&spellcheck.count=1&qt=spellCheckCompRH&spellcheck.collate=true} hits=0 status=0 QTime=11 
   [junit4]   2> 2402538 T4045 C21368 oasc.SolrCore.execute [collection1] webapp=null path=null params={spellcheck=true&spellcheck.collateExtendedResults=true&q=teststop:metnoia&spellcheck.maxCollations=1&spellcheck.maxCollationTries=1&spellcheck.dictionary=direct&spellcheck.collateMaxCollectDocs=3&spellcheck.count=1&qt=spellCheckCompRH&spellcheck.collate=true} hits=0 status=0 QTime=8 
   [junit4]   2> 2402542 T4045 oas.SolrTestCaseJ4.assertQ ERROR REQUEST FAILED: xpath=//lst[@name='spellcheck']/lst[@name='suggestions']/lst[@name='collation']/int[@name='hits']=4
   [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">8</int></lst><result name="response" numFound="0" start="0"></result><lst name="spellcheck"><lst name="suggestions"><lst name="metnoia"><int name="numFound">1</int><int name="startOffset">9</int><int name="endOffset">16</int><arr name="suggestion"><str>metanoia</str></arr></lst><lst name="collation"><str name="collationQuery">teststop:metanoia</str><int name="hits">17</int><lst name="misspellingsAndCorrections"><str name="metnoia">metanoia</str></lst></lst></lst></lst>
   [junit4]   2> 	</response>
   [junit4]   2> 	
   [junit4]   2> 		request was:spellcheck=true&spellcheck.collateExtendedResults=true&q=teststop:metnoia&spellcheck.maxCollations=1&spellcheck.maxCollationTries=1&spellcheck.dictionary=direct&spellcheck.collateMaxCollectDocs=3&spellcheck.count=1&qt=spellCheckCompRH&spellcheck.collate=true
   [junit4]   2> 2402544 T4045 oasc.SolrException.log ERROR REQUEST FAILED: spellcheck=true&spellcheck.collateExtendedResults=true&q=teststop:metnoia&spellcheck.maxCollations=1&spellcheck.maxCollationTries=1&spellcheck.dictionary=direct&spellcheck.collateMaxCollectDocs=3&spellcheck.count=1&qt=spellCheckCompRH&spellcheck.collate=true:java.lang.RuntimeException: REQUEST FAILED: xpath=//lst[@name='spellcheck']/lst[@name='suggestions']/lst[@name='collation']/int[@name='hits']=4
   [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">8</int></lst><result name="response" numFound="0" start="0"></result><lst name="spellcheck"><lst name="suggestions"><lst name="metnoia"><int name="numFound">1</int><int name="startOffset">9</int><int name="endOffset">16</int><arr name="suggestion"><str>metanoia</str></arr></lst><lst name="collation"><str name="collationQuery">teststop:metanoia</str><int name="hits">17</int><lst name="misspellingsAndCorrections"><str name="metnoia">metanoia</str></lst></lst></lst></lst>
   [junit4]   2> 	</response>
   [junit4]   2> 	
   [junit4]   2> 		request was:spellcheck=true&spellcheck.collateExtendedResults=true&q=teststop:metnoia&spellcheck.maxCollations=1&spellcheck.maxCollationTries=1&spellcheck.dictionary=direct&spellcheck.collateMaxCollectDocs=3&spellcheck.count=1&qt=spellCheckCompRH&spellcheck.collate=true
   [junit4]   2> 		at org.apache.solr.SolrTestCaseJ4.assertQ(SolrTestCaseJ4.java:628)
   [junit4]   2> 		at org.apache.solr.SolrTestCaseJ4.assertQ(SolrTestCaseJ4.java:602)
   [junit4]   2> 		at org.apache.solr.spelling.SpellCheckCollatorTest.testEstimatedHitCounts(SpellCheckCollatorTest.java:469)
   [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:1559)
   [junit4]   2> 		at com.carrotsearch.randomizedtesting.RandomizedRunner.access$600(RandomizedRunner.java:79)
   [junit4]   2> 		at com.carrotsearch.randomizedtesting.RandomizedRunner$6.evaluate(RandomizedRunner.java:737)
   [junit4]   2> 		at com.carrotsearch.randomizedtesting.RandomizedRunner$7.evaluate(RandomizedRunner.java:773)
   [junit4]   2> 		at com.carrotsearch.randomizedtesting.RandomizedRunner$8.evaluate(RandomizedRunner.java:787)
   [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.TestRuleFieldCacheSanity$1.evaluate(TestRuleFieldCacheSanity.java:51)
   [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:70)
   [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:358)
   [junit4]   2> 		at com.carrotsearch.randomizedtesting.ThreadLeakControl.forkTimeoutingTask(ThreadLeakControl.java:782)
   [junit4]   2> 		at com.carrotsearch.randomizedtesting.ThreadLeakControl$3.evaluate(ThreadLeakControl.java:442)
   [junit4]   2> 		at com.carrotsearch.randomizedtesting.RandomizedRunner.runSingleTest(RandomizedRunner.java:746)
   [junit4]   2> 		at com.carrotsearch.randomizedtesting.RandomizedRunner$3.evaluate(RandomizedRunner.java:648)
   [junit4]   2> 		at com.carrotsearch.randomizedtesting.RandomizedRunner$4.evaluate(RandomizedRunner.java:682)
   [junit4]   2> 		at com.carrotsearch.randomizedtesting.RandomizedRunner$5.evaluate(RandomizedRunner.java:693)
   [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 org.apache.lucene.util.TestRuleAssertionsRequired$1.evaluate(TestRuleAssertionsRequired.java:43)
   [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:70)
   [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:358)
   [junit4]   2> 		at java.lang.Thread.run(Thread.java:724)
   [junit4]   2> 	
   [junit4]   2> 2402546 T4045 oas.SolrTestCaseJ4.tearDown ###Ending testEstimatedHitCounts
   [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=SpellCheckCollatorTest -Dtests.method=testEstimatedHitCounts -Dtests.seed=16B4D8F74E59EE10 -Dtests.multiplier=2 -Dtests.nightly=true -Dtests.slow=true -Dtests.linedocsfile=/home/hudson/lucene-data/enwiki.random.lines.txt -Dtests.locale=nl -Dtests.timezone=America/Dawson -Dtests.file.encoding=US-ASCII
   [junit4] ERROR   0.06s J1 | SpellCheckCollatorTest.testEstimatedHitCounts <<<
   [junit4]    > Throwable #1: java.lang.RuntimeException: Exception during query
   [junit4]    > 	at __randomizedtesting.SeedInfo.seed([16B4D8F74E59EE10:270F66C2EB66FEC0]:0)
   [junit4]    > 	at org.apache.solr.SolrTestCaseJ4.assertQ(SolrTestCaseJ4.java:635)
   [junit4]    > 	at org.apache.solr.SolrTestCaseJ4.assertQ(SolrTestCaseJ4.java:602)
   [junit4]    > 	at org.apache.solr.spelling.SpellCheckCollatorTest.testEstimatedHitCounts(SpellCheckCollatorTest.java:469)
   [junit4]    > 	at java.lang.Thread.run(Thread.java:724)
   [junit4]    > Caused by: java.lang.RuntimeException: REQUEST FAILED: xpath=//lst[@name='spellcheck']/lst[@name='suggestions']/lst[@name='collation']/int[@name='hits']=4
   [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">8</int></lst><result name="response" numFound="0" start="0"></result><lst name="spellcheck"><lst name="suggestions"><lst name="metnoia"><int name="numFound">1</int><int name="startOffset">9</int><int name="endOffset">16</int><arr name="suggestion"><str>metanoia</str></arr></lst><lst name="collation"><str name="collationQuery">teststop:metanoia</str><int name="hits">17</int><lst name="misspellingsAndCorrections"><str name="metnoia">metanoia</str></lst></lst></lst></lst>
   [junit4]    > </response>
   [junit4]    > 	request was:spellcheck=true&spellcheck.collateExtendedResults=true&q=teststop:metnoia&spellcheck.maxCollations=1&spellcheck.maxCollationTries=1&spellcheck.dictionary=direct&spellcheck.collateMaxCollectDocs=3&spellcheck.count=1&qt=spellCheckCompRH&spellcheck.collate=true
   [junit4]    > 	at org.apache.solr.SolrTestCaseJ4.assertQ(SolrTestCaseJ4.java:628)
   [junit4]    > 	... 42 more
   [junit4]   2> 2402558 T4045 oas.SolrTestCaseJ4.deleteCore ###deleteCore
   [junit4]   2> 2402559 T4045 oasc.CoreContainer.shutdown Shutting down CoreContainer instance=1414615201
   [junit4]   2> 2402559 T4045 oasc.SolrCore.close [collection1]  CLOSING SolrCore org.apache.solr.core.SolrCore@32af94b0
   [junit4]   2> 2402559 T4045 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=17,cumulative_deletesById=0,cumulative_deletesByQuery=0,cumulative_errors=0}
   [junit4]   2> 2402560 T4045 oasu.SolrCoreState.decrefSolrCoreState Closing SolrCoreState
   [junit4]   2> 2402560 T4045 oasu.DefaultSolrCoreState.closeIndexWriter SolrCoreState ref count has reached 0 - closing IndexWriter
   [junit4]   2> 2402560 T4045 oasu.DefaultSolrCoreState.closeIndexWriter closing IndexWriter with IndexWriterCloser
   [junit4]   2> 2402561 T4045 oasc.SolrCore.closeSearcher [collection1] Closing main searcher on request.
   [junit4]   2> 2402561 T4045 oasc.CachingDirectoryFactory.close Closing MockDirectoryFactory - 2 directories currently being tracked
   [junit4]   2> 2402562 T4045 oasc.CachingDirectoryFactory.closeCacheValue looking to close /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test/J1/./solrtest-SpellCheckCollatorTest-1375883796067/index [CachedDir<<refCount=0;path=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test/J1/./solrtest-SpellCheckCollatorTest-1375883796067/index;done=false>>]
   [junit4]   2> 2402562 T4045 oasc.CachingDirectoryFactory.close Closing directory: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test/J1/./solrtest-SpellCheckCollatorTest-1375883796067/index
   [junit4]   2> 2402562 T4045 oasc.CachingDirectoryFactory.closeCacheValue looking to close /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test/J1/./solrtest-SpellCheckCollatorTest-1375883796067 [CachedDir<<refCount=0;path=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test/J1/./solrtest-SpellCheckCollatorTest-1375883796067;done=false>>]
   [junit4]   2> 2402563 T4045 oasc.CachingDirectoryFactory.close Closing directory: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test/J1/./solrtest-SpellCheckCollatorTest-1375883796067
   [junit4]   2> NOTE: test params are: codec=Lucene42: {range_facet_l=MockVariableIntBlock(baseBlockSize=72), lowerfilt1=Pulsing41(freqCutoff=12 minBlockSize=73 maxBlockSize=149), lowerfilt=PostingsFormat(name=Lucene41VarGapFixedInterval), teststop=PostingsFormat(name=Lucene41VarGapFixedInterval), end4=Pulsing41(freqCutoff=12 minBlockSize=73 maxBlockSize=149), end3=PostingsFormat(name=Lucene41VarGapFixedInterval), lowerfilt1and2=PostingsFormat(name=Lucene41VarGapFixedInterval), start1=Pulsing41(freqCutoff=12 minBlockSize=73 maxBlockSize=149), end2=PostingsFormat(name=Lucene41WithOrds), end1=MockVariableIntBlock(baseBlockSize=72), intDefault=MockVariableIntBlock(baseBlockSize=72), id=PostingsFormat(name=Lucene41WithOrds), timestamp=MockVariableIntBlock(baseBlockSize=72), range_facet_sl=Pulsing41(freqCutoff=12 minBlockSize=73 maxBlockSize=149), range_facet_si=PostingsFormat(name=Lucene41VarGapFixedInterval), start4=MockVariableIntBlock(baseBlockSize=72), start2=PostingsFormat(name=Lucene41VarGapFixedInterval), start3=PostingsFormat(name=Lucene41WithOrds), word=MockVariableIntBlock(baseBlockSize=72), gram2=PostingsFormat(name=Lucene41WithOrds), gram1=MockVariableIntBlock(baseBlockSize=72), multiDefault=PostingsFormat(name=Lucene41VarGapFixedInterval), gram4=Pulsing41(freqCutoff=12 minBlockSize=73 maxBlockSize=149), gram3=PostingsFormat(name=Lucene41VarGapFixedInterval)}, docValues:{timestamp=DocValuesFormat(name=Asserting)}, sim=RandomSimilarityProvider(queryNorm=false,coord=yes): {}, locale=nl, timezone=America/Dawson
   [junit4]   2> NOTE: FreeBSD 9.1-RELEASE-p3 amd64/Oracle Corporation 1.7.0_25 (64-bit)/cpus=16,threads=1,free=281063024,total=534052864
   [junit4]   2> NOTE: All tests run in this JVM: [IndexBasedSpellCheckerTest, CoreAdminCreateDiscoverTest, CoreContainerCoreInitFailuresTest, TestQueryTypes, ResourceLoaderTest, TestReload, UUIDFieldTest, TestCopyFieldCollectionResource, TestCSVLoader, SuggesterTSTTest, TestBinaryField, TestPhraseSuggestions, SuggesterWFSTTest, ConvertedLegacyTest, TestSweetSpotSimilarityFactory, HdfsUnloadDistributedZkTest, HighlighterTest, ChaosMonkeySafeLeaderTest, CurrencyFieldXmlFileTest, SimplePostToolTest, DistanceFunctionTest, TestFiltering, TestDFRSimilarityFactory, JSONWriterTest, BasicZkTest, TestUtils, HdfsBasicDistributedZk2Test, TestOmitPositions, TestCloudManagedSchema, SliceStateTest, PrimUtilsTest, OpenCloseCoreStressTest, PathHierarchyTokenizerFactoryTest, TestDefaultSimilarityFactory, AlternateDirectoryTest, DebugComponentTest, SolrRequestParserTest, LeaderElectionIntegrationTest, HighlighterConfigTest, TestFastWriter, PreAnalyzedFieldTest, TestRecoveryHdfs, HdfsCollectionsAPIDistributedZkTest, TestCoreDiscovery, BadIndexSchemaTest, TestCodecSupport, TestIndexSearcher, TestSolrDeletionPolicy2, TestJmxIntegration, TestZkChroot, DirectUpdateHandlerTest, FullSolrCloudDistribCmdsTest, StatsComponentTest, XsltUpdateRequestHandlerTest, CircularListTest, RequestHandlersTest, HardAutoCommitTest, TestMultiCoreConfBootstrap, TestUpdate, UniqFieldsUpdateProcessorFactoryTest, HdfsRecoveryZkTest, NoCacheHeaderTest, ShardSplitTest, TestRandomMergePolicy, BasicDistributedZk2Test, TestStressReorder, TestFuzzyAnalyzedSuggestions, TestAtomicUpdateErrorCases, DirectSolrSpellCheckerTest, TestSolr4Spatial, TestClassNameShortening, SolrCmdDistributorTest, DisMaxRequestHandlerTest, DefaultValueUpdateProcessorTest, ClusterStateTest, TestRandomFaceting, AutoCommitTest, TestDistributedGrouping, TestFaceting, TestRecovery, TestHashPartitioner, TermVectorComponentDistributedTest, TestJoin, SpellCheckComponentTest, PeerSyncTest, TestLazyCores, SoftAutoCommitTest, CurrencyFieldOpenExchangeTest, SpellCheckCollatorTest]
   [junit4] Completed on J1 in 2.93s, 8 tests, 1 error <<< FAILURES!

[...truncated 386 lines...]
BUILD FAILED
/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-trunk/build.xml:396: The following error occurred while executing this line:
/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-trunk/build.xml:369: The following error occurred while executing this line:
/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-trunk/build.xml:39: The following error occurred while executing this line:
/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build.xml:181: The following error occurred while executing this line:
/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/common-build.xml:449: The following error occurred while executing this line:
/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-trunk/lucene/common-build.xml:1230: The following error occurred while executing this line:
/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-trunk/lucene/common-build.xml:873: There were test failures: 317 suites, 1343 tests, 1 error, 32 ignored (4 assumptions)

Total time: 102 minutes 23 seconds
Build step 'Invoke Ant' marked build as failure
Archiving artifacts
Recording test results
Email was triggered for: Failure
Sending email for trigger: Failure



Re: [JENKINS] Lucene-Solr-NightlyTests-trunk - Build # 343 - Still Failing

Posted by Chris Hostetter <ho...@fucit.org>.
I can reproduce this -- it's probably related to the MP randomization i 
put in ... looks like it's doing exact numeric comparisons based on term 
stats.  I'll take a look later today...

ant test  -Dtestcase=SpellCheckCollatorTest -Dtests.method=testEstimatedHitCounts -Dtests.seed=16B4D8F74E59EE10 -Dtests.multiplier=2 -Dtests.nightly=true -Dtests.slow=true   -Dtests.locale=nl -Dtests.timezone=America/Dawson -Dtests.file.encoding=US-ASCII



: Date: Wed, 7 Aug 2013 14:01:01 +0000 (UTC)
: From: Apache Jenkins Server <je...@builds.apache.org>
: Reply-To: dev@lucene.apache.org
: To: dev@lucene.apache.org
: Subject: [JENKINS] Lucene-Solr-NightlyTests-trunk - Build # 343 - Still
:     Failing
: 
: Build: https://builds.apache.org/job/Lucene-Solr-NightlyTests-trunk/343/
: 
: 1 tests failed.
: REGRESSION:  org.apache.solr.spelling.SpellCheckCollatorTest.testEstimatedHitCounts
: 
: Error Message:
: Exception during query
: 
: Stack Trace:
: java.lang.RuntimeException: Exception during query
: 	at __randomizedtesting.SeedInfo.seed([16B4D8F74E59EE10:270F66C2EB66FEC0]:0)
: 	at org.apache.solr.SolrTestCaseJ4.assertQ(SolrTestCaseJ4.java:635)
: 	at org.apache.solr.SolrTestCaseJ4.assertQ(SolrTestCaseJ4.java:602)
: 	at org.apache.solr.spelling.SpellCheckCollatorTest.testEstimatedHitCounts(SpellCheckCollatorTest.java:469)
: 	at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
: 	at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:57)
: 	at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
: 	at java.lang.reflect.Method.invoke(Method.java:606)
: 	at com.carrotsearch.randomizedtesting.RandomizedRunner.invoke(RandomizedRunner.java:1559)
: 	at com.carrotsearch.randomizedtesting.RandomizedRunner.access$600(RandomizedRunner.java:79)
: 	at com.carrotsearch.randomizedtesting.RandomizedRunner$6.evaluate(RandomizedRunner.java:737)
: 	at com.carrotsearch.randomizedtesting.RandomizedRunner$7.evaluate(RandomizedRunner.java:773)
: 	at com.carrotsearch.randomizedtesting.RandomizedRunner$8.evaluate(RandomizedRunner.java:787)
: 	at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:53)
: 	at org.apache.lucene.util.TestRuleSetupTeardownChained$1.evaluate(TestRuleSetupTeardownChained.java:50)
: 	at org.apache.lucene.util.TestRuleFieldCacheSanity$1.evaluate(TestRuleFieldCacheSanity.java:51)
: 	at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:46)
: 	at com.carrotsearch.randomizedtesting.rules.SystemPropertiesInvariantRule$1.evaluate(SystemPropertiesInvariantRule.java:55)
: 	at org.apache.lucene.util.TestRuleThreadAndTestName$1.evaluate(TestRuleThreadAndTestName.java:49)
: 	at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:70)
: 	at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:48)
: 	at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
: 	at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:358)
: 	at com.carrotsearch.randomizedtesting.ThreadLeakControl.forkTimeoutingTask(ThreadLeakControl.java:782)
: 	at com.carrotsearch.randomizedtesting.ThreadLeakControl$3.evaluate(ThreadLeakControl.java:442)
: 	at com.carrotsearch.randomizedtesting.RandomizedRunner.runSingleTest(RandomizedRunner.java:746)
: 	at com.carrotsearch.randomizedtesting.RandomizedRunner$3.evaluate(RandomizedRunner.java:648)
: 	at com.carrotsearch.randomizedtesting.RandomizedRunner$4.evaluate(RandomizedRunner.java:682)
: 	at com.carrotsearch.randomizedtesting.RandomizedRunner$5.evaluate(RandomizedRunner.java:693)
: 	at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
: 	at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:53)
: 	at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:46)
: 	at org.apache.lucene.util.TestRuleStoreClassName$1.evaluate(TestRuleStoreClassName.java:42)
: 	at com.carrotsearch.randomizedtesting.rules.SystemPropertiesInvariantRule$1.evaluate(SystemPropertiesInvariantRule.java:55)
: 	at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:39)
: 	at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:39)
: 	at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
: 	at org.apache.lucene.util.TestRuleAssertionsRequired$1.evaluate(TestRuleAssertionsRequired.java:43)
: 	at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:48)
: 	at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:70)
: 	at org.apache.lucene.util.TestRuleIgnoreTestSuites$1.evaluate(TestRuleIgnoreTestSuites.java:55)
: 	at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
: 	at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:358)
: 	at java.lang.Thread.run(Thread.java:724)
: Caused by: java.lang.RuntimeException: REQUEST FAILED: xpath=//lst[@name='spellcheck']/lst[@name='suggestions']/lst[@name='collation']/int[@name='hits']=4
: 	xml response was: <?xml version="1.0" encoding="UTF-8"?>
: <response>
: <lst name="responseHeader"><int name="status">0</int><int name="QTime">8</int></lst><result name="response" numFound="0" start="0"></result><lst name="spellcheck"><lst name="suggestions"><lst name="metnoia"><int name="numFound">1</int><int name="startOffset">9</int><int name="endOffset">16</int><arr name="suggestion"><str>metanoia</str></arr></lst><lst name="collation"><str name="collationQuery">teststop:metanoia</str><int name="hits">17</int><lst name="misspellingsAndCorrections"><str name="metnoia">metanoia</str></lst></lst></lst></lst>
: </response>
: 
: 	request was:spellcheck=true&spellcheck.collateExtendedResults=true&q=teststop:metnoia&spellcheck.maxCollations=1&spellcheck.maxCollationTries=1&spellcheck.dictionary=direct&spellcheck.collateMaxCollectDocs=3&spellcheck.count=1&qt=spellCheckCompRH&spellcheck.collate=true
: 	at org.apache.solr.SolrTestCaseJ4.assertQ(SolrTestCaseJ4.java:628)
: 	... 42 more
: 
: 
: 
: 
: Build Log:
: [...truncated 9902 lines...]
:    [junit4] Suite: org.apache.solr.spelling.SpellCheckCollatorTest
:    [junit4]   2> 2399675 T4045 oas.SolrTestCaseJ4.initCore ####initCore
:    [junit4]   2> Creating dataDir: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test/J1/./solrtest-SpellCheckCollatorTest-1375883796067
:    [junit4]   2> 2399676 T4045 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test-files/solr/collection1/'
:    [junit4]   2> 2399677 T4045 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test-files/solr/collection1/lib/classes/' to classloader
:    [junit4]   2> 2399677 T4045 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test-files/solr/collection1/lib/README' to classloader
:    [junit4]   2> 2399765 T4045 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_50
:    [junit4]   2> 2399808 T4045 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig-spellcheckcomponent.xml
:    [junit4]   2> 2399809 T4045 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
:    [junit4]   2> 2399817 T4045 oass.IndexSchema.readSchema [null] Schema name=test
:    [junit4]   2> 2400228 T4045 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
:    [junit4]   2> 2400236 T4045 oass.IndexSchema.readSchema default search field in schema is text
:    [junit4]   2> 2400238 T4045 oass.IndexSchema.readSchema unique key field: id
:    [junit4]   2> 2400244 T4045 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
:    [junit4]   2> 2400247 T4045 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
:    [junit4]   2> 2400250 T4045 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
:    [junit4]   2> 2400251 T4045 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
:    [junit4]   2> 2400251 T4045 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
:    [junit4]   2> 2400251 T4045 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
:    [junit4]   2> 2400251 T4045 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
:    [junit4]   2> 2400251 T4045 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
:    [junit4]   2> 2400252 T4045 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
:    [junit4]   2> 2400252 T4045 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test-files/solr
:    [junit4]   2> 2400252 T4045 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test-files/solr/'
:    [junit4]   2> 2400261 T4045 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
:    [junit4]   2> 2400262 T4045 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test-files/solr
:    [junit4]   2> 2400262 T4045 oasc.SolrResourceLoader.<init> new SolrResourceLoader for deduced Solr Home: '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test-files/solr/'
:    [junit4]   2> 2400320 T4045 oasc.CoreContainer.<init> New CoreContainer 1414615201
:    [junit4]   2> 2400321 T4045 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test-files/solr/]
:    [junit4]   2> 2400322 T4045 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 0
:    [junit4]   2> 2400322 T4045 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
:    [junit4]   2> 2400322 T4045 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 0
:    [junit4]   2> 2400323 T4045 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
:    [junit4]   2> 2400323 T4045 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
:    [junit4]   2> 2400323 T4045 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
:    [junit4]   2> 2400323 T4045 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
:    [junit4]   2> 2400323 T4045 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
:    [junit4]   2> 2400324 T4045 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
:    [junit4]   2> 2400324 T4045 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=0&connTimeout=0&retry=false
:    [junit4]   2> 2400340 T4045 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
:    [junit4]   2> 2400347 T4046 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test-files/solr/collection1
:    [junit4]   2> 2400347 T4046 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test-files/solr/collection1/'
:    [junit4]   2> 2400348 T4046 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test-files/solr/collection1/lib/classes/' to classloader
:    [junit4]   2> 2400348 T4046 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test-files/solr/collection1/lib/README' to classloader
:    [junit4]   2> 2400390 T4046 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_50
:    [junit4]   2> 2400429 T4046 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig-spellcheckcomponent.xml
:    [junit4]   2> 2400430 T4046 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
:    [junit4]   2> 2400436 T4046 oass.IndexSchema.readSchema [collection1] Schema name=test
:    [junit4]   2> 2400922 T4046 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
:    [junit4]   2> 2400931 T4046 oass.IndexSchema.readSchema default search field in schema is text
:    [junit4]   2> 2400935 T4046 oass.IndexSchema.readSchema unique key field: id
:    [junit4]   2> 2400942 T4046 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
:    [junit4]   2> 2400946 T4046 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
:    [junit4]   2> 2400950 T4046 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
:    [junit4]   2> 2400950 T4046 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
:    [junit4]   2> 2400950 T4046 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
:    [junit4]   2> 2400951 T4046 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
:    [junit4]   2> 2400951 T4046 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
:    [junit4]   2> 2400951 T4046 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
:    [junit4]   2> 2400952 T4046 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
:    [junit4]   2> 2400952 T4046 oasc.SolrCore.<init> [collection1] Opening new SolrCore at /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test-files/solr/collection1/, dataDir=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test/J1/./solrtest-SpellCheckCollatorTest-1375883796067/
:    [junit4]   2> 2400952 T4046 oasc.SolrCore.<init> JMX monitoring not detected for core: collection1
:    [junit4]   2> 2400953 T4046 oasc.CachingDirectoryFactory.get return new directory for /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test/J1/./solrtest-SpellCheckCollatorTest-1375883796067
:    [junit4]   2> 2400953 T4046 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test/J1/./solrtest-SpellCheckCollatorTest-1375883796067/index/
:    [junit4]   2> 2400953 T4046 oasc.SolrCore.initIndex WARN [collection1] Solr index directory '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test/J1/./solrtest-SpellCheckCollatorTest-1375883796067/index' doesn't exist. Creating new index...
:    [junit4]   2> 2400954 T4046 oasc.CachingDirectoryFactory.get return new directory for /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test/J1/./solrtest-SpellCheckCollatorTest-1375883796067/index
:    [junit4]   2> 2400955 T4046 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
:    [junit4]   2> 		commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@7714200f lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@5a4c3855),segFN=segments_1,generation=1}
:    [junit4]   2> 2400955 T4046 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
:    [junit4]   2> 2400956 T4046 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
:    [junit4]   2> 2400956 T4046 oasc.RequestHandlers.initHandlersFromConfig created spellCheckCompRH: org.apache.solr.handler.component.SearchHandler
:    [junit4]   2> 2400957 T4046 oasc.RequestHandlers.initHandlersFromConfig created spellCheckCompRH1: org.apache.solr.handler.component.SearchHandler
:    [junit4]   2> 2400957 T4046 oasc.RequestHandlers.initHandlersFromConfig created spellCheckWithWordbreak: org.apache.solr.handler.component.SearchHandler
:    [junit4]   2> 2400960 T4046 oass.SolrIndexSearcher.<init> Opening Searcher@318e8f99 main
:    [junit4]   2> 2400961 T4046 oasu.CommitTracker.<init> Hard AutoCommit: disabled
:    [junit4]   2> 2400961 T4046 oasu.CommitTracker.<init> Soft AutoCommit: disabled
:    [junit4]   2> 2400961 T4046 oashc.SpellCheckComponent.inform Initializing spell checkers
:    [junit4]   2> 2400969 T4046 oashc.SpellCheckComponent.inform Registering newSearcher listener for spellchecker: default
:    [junit4]   2> 2400982 T4046 oashc.SpellCheckComponent.inform Registering newSearcher listener for spellchecker: default_teststop
:    [junit4]   2> 2400983 T4046 oass.DirectSolrSpellChecker.init init: {name=direct,classname=solr.DirectSolrSpellChecker,minQueryLength=3,maxQueryFrequency=100.0,field=teststop}
:    [junit4]   2> 2400983 T4046 oass.DirectSolrSpellChecker.init init: {name=direct_lowerfilt,classname=solr.DirectSolrSpellChecker,minQueryLength=3,maxQueryFrequency=100.0,field=lowerfilt}
:    [junit4]   2> 2400991 T4046 oashc.SpellCheckComponent.inform Registering newSearcher listener for spellchecker: threshold
:    [junit4]   2> 2400991 T4046 oass.DirectSolrSpellChecker.init init: {name=threshold_direct,classname=solr.DirectSolrSpellChecker,field=lowerfilt,spellcheckIndexDir=spellcheckerThreshold,buildOnCommit=true,thresholdTokenFrequency=0.29}
:    [junit4]   2> 2400992 T4046 oashc.SpellCheckComponent.inform Registering newSearcher listener for spellchecker: threshold_direct
:    [junit4]   2> 2400999 T4046 oashc.SpellCheckComponent.inform Registering newSearcher listener for spellchecker: multipleFields
:    [junit4]   2> 2401034 T4046 oashc.SpellCheckComponent.inform Registering newSearcher listener for spellchecker: freq
:    [junit4]   2> 2401041 T4046 oashc.SpellCheckComponent.inform Registering newSearcher listener for spellchecker: fqcn
:    [junit4]   2> 2401042 T4047 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@318e8f99 main{StandardDirectoryReader(segments_1:1)}
:    [junit4]   2> 2401042 T4046 oasc.CoreContainer.registerCore registering core: collection1
:    [junit4]   2> 2401055 T4045 oas.SolrTestCaseJ4.initCore ####initCore end
:    [junit4]   2> ASYNC  NEW_CORE C21367 name=collection1 org.apache.solr.core.SolrCore@32af94b0
:    [junit4]   2> 2401064 T4045 C21367 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=1
:    [junit4]   2> 		commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@7714200f lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@5a4c3855),segFN=segments_1,generation=1}
:    [junit4]   2> 2401064 T4045 C21367 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
:    [junit4]   2> 2401065 T4045 C21367 oasup.LogUpdateProcessor.finish [collection1] webapp=null path=null params={} {add=[0]} 0 2
:    [junit4]   2> 2401083 T4045 C21367 oasup.LogUpdateProcessor.finish [collection1] webapp=null path=null params={} {add=[1]} 0 0
:    [junit4]   2> 2401090 T4045 C21367 oasup.LogUpdateProcessor.finish [collection1] webapp=null path=null params={} {add=[2]} 0 1
:    [junit4]   2> 2401096 T4045 C21367 oasup.LogUpdateProcessor.finish [collection1] webapp=null path=null params={} {add=[3]} 0 1
:    [junit4]   2> 2401104 T4045 C21367 oasup.LogUpdateProcessor.finish [collection1] webapp=null path=null params={} {add=[4]} 0 3
:    [junit4]   2> 2401111 T4045 C21367 oasup.LogUpdateProcessor.finish [collection1] webapp=null path=null params={} {add=[5]} 0 1
:    [junit4]   2> 2401116 T4045 C21367 oasup.LogUpdateProcessor.finish [collection1] webapp=null path=null params={} {add=[6]} 0 0
:    [junit4]   2> 2401122 T4045 C21367 oasup.LogUpdateProcessor.finish [collection1] webapp=null path=null params={} {add=[7]} 0 0
:    [junit4]   2> 2401128 T4045 C21367 oasup.LogUpdateProcessor.finish [collection1] webapp=null path=null params={} {add=[8]} 0 0
:    [junit4]   2> 2401154 T4045 C21367 oasup.LogUpdateProcessor.finish [collection1] webapp=null path=null params={} {add=[9]} 0 20
:    [junit4]   2> 2401160 T4045 C21367 oasup.LogUpdateProcessor.finish [collection1] webapp=null path=null params={} {add=[10]} 0 1
:    [junit4]   2> 2401166 T4045 C21367 oasup.LogUpdateProcessor.finish [collection1] webapp=null path=null params={} {add=[11]} 0 1
:    [junit4]   2> 2401171 T4045 C21367 oasup.LogUpdateProcessor.finish [collection1] webapp=null path=null params={} {add=[12]} 0 0
:    [junit4]   2> 2401177 T4045 C21367 oasup.LogUpdateProcessor.finish [collection1] webapp=null path=null params={} {add=[13]} 0 0
:    [junit4]   2> 2401211 T4045 C21367 oasup.LogUpdateProcessor.finish [collection1] webapp=null path=null params={} {add=[14]} 0 28
:    [junit4]   2> 2401218 T4045 C21367 oasup.LogUpdateProcessor.finish [collection1] webapp=null path=null params={} {add=[15]} 0 1
:    [junit4]   2> 2401223 T4045 C21367 oasup.LogUpdateProcessor.finish [collection1] webapp=null path=null params={} {add=[16]} 0 0
:    [junit4]   2> 2401229 T4045 C21367 oasu.DirectUpdateHandler2.commit start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
:    [junit4]   2> 2401254 T4045 C21367 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=2
:    [junit4]   2> 		commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@7714200f lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@5a4c3855),segFN=segments_1,generation=1}
:    [junit4]   2> 		commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@7714200f lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@5a4c3855),segFN=segments_2,generation=2}
:    [junit4]   2> 2401254 T4045 C21367 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 2
:    [junit4]   2> 2401259 T4045 C21367 oass.SolrIndexSearcher.<init> Opening Searcher@60a8d965 main
:    [junit4]   2> 2401259 T4045 C21367 oasu.DirectUpdateHandler2.commit end_commit_flush
:    [junit4]   2> 2401259 T4047 oashc.SpellCheckComponent$SpellCheckerListener.buildSpellIndex Building spell index for spell checker: default
:    [junit4]   2> 2401346 T4047 oashc.SpellCheckComponent$SpellCheckerListener.buildSpellIndex Building spell index for spell checker: default_teststop
:    [junit4]   2> 2401408 T4047 oashc.SpellCheckComponent$SpellCheckerListener.buildSpellIndex Building spell index for spell checker: threshold
:    [junit4]   2> 2401421 T4047 oashc.SpellCheckComponent$SpellCheckerListener.buildSpellIndex Building spell index for spell checker: threshold_direct
:    [junit4]   2> 2401422 T4047 oashc.SpellCheckComponent$SpellCheckerListener.buildSpellIndex Building spell index for spell checker: multipleFields
:    [junit4]   2> 2401490 T4047 oashc.SpellCheckComponent$SpellCheckerListener.buildSpellIndex Building spell index for spell checker: freq
:    [junit4]   2> 2401560 T4047 oashc.SpellCheckComponent$SpellCheckerListener.buildSpellIndex Building spell index for spell checker: fqcn
:    [junit4]   2> 2401628 T4047 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@60a8d965 main{StandardDirectoryReader(segments_2:9:nrt _0(5.0):c5 _1(5.0):c5 _2(5.0):c5 _3(5.0):c2)}
:    [junit4]   2> ASYNC  NEW_CORE C21368 name=collection1 org.apache.solr.core.SolrCore@32af94b0
:    [junit4]   2> 2401628 T4045 C21368 oasup.LogUpdateProcessor.finish [collection1] webapp=null path=null params={} {commit=} 0 399
:    [junit4]   2> 2401640 T4045 oas.SolrTestCaseJ4.setUp ###Starting testExtendedCollate
:    [junit4]   2> 2401733 T4045 oas.SolrTestCaseJ4.tearDown ###Ending testExtendedCollate
:    [junit4]   2> 2401739 T4045 oas.SolrTestCaseJ4.setUp ###Starting testCollateWithFilter
:    [junit4]   2> 2401825 T4045 oas.SolrTestCaseJ4.tearDown ###Ending testCollateWithFilter
:    [junit4]   2> 2401832 T4045 oas.SolrTestCaseJ4.setUp ###Starting testContextSensitiveCollate
:    [junit4]   2> 2401866 T4045 C21368 oasc.SolrCore.execute [collection1] webapp=null path=null params={spellcheck=true&indent=true&spellcheck.maxResultsForSuggest=0&spellcheck.collateExtendedResults=true&spellcheck.extendedResults=true&spellcheck.maxCollations=1&spellcheck.maxCollationTries=10&spellcheck.collate=true&q=teststop:(flew+AND+form+AND+heathrow)&spellcheck.dictionary=direct&spellcheck.count=10&qt=spellCheckCompRH&spellcheck.build=true&spellcheck.alternativeTermCount=5} hits=0 status=0 QTime=34 
:    [junit4]   2> 2401899 T4045 C21368 oasc.SolrCore.execute [collection1] webapp=null path=null params={spellcheck=true&indent=true&spellcheck.maxResultsForSuggest=1&spellcheck.collateExtendedResults=true&spellcheck.extendedResults=true&spellcheck.maxCollationTries=10&spellcheck.maxCollations=1&spellcheck.collate=true&q=teststop:(june+AND+customs)&spellcheck.dictionary=direct&spellcheck.count=10&qt=spellCheckCompRH&spellcheck.alternativeTermCount=5} hits=1 status=0 QTime=19 
:    [junit4]   2> 2401999 T4045 C21368 oasc.SolrCore.execute [collection1] webapp=null path=null params={spellcheck=true&indent=true&spellcheck.maxResultsForSuggest=0&spellcheck.collateExtendedResults=true&spellcheck.extendedResults=true&spellcheck.maxCollations=1&spellcheck.maxCollationTries=10&spellcheck.collate=true&q=teststop:(flew+AND+form+AND+heathrow)&spellcheck.dictionary=default_teststop&spellcheck.count=10&qt=spellCheckCompRH&spellcheck.build=true&spellcheck.alternativeTermCount=5} hits=0 status=0 QTime=90 
:    [junit4]   2> 2402017 T4045 C21368 oasc.SolrCore.execute [collection1] webapp=null path=null params={spellcheck=true&indent=true&spellcheck.maxResultsForSuggest=1&spellcheck.collateExtendedResults=true&spellcheck.extendedResults=true&spellcheck.maxCollationTries=10&spellcheck.maxCollations=1&spellcheck.collate=true&q=teststop:(june+AND+customs)&spellcheck.dictionary=default_teststop&spellcheck.count=10&qt=spellCheckCompRH&spellcheck.alternativeTermCount=5} hits=1 status=0 QTime=5 
:    [junit4]   2> 2402027 T4045 oas.SolrTestCaseJ4.tearDown ###Ending testContextSensitiveCollate
:    [junit4]   2> 2402035 T4045 oas.SolrTestCaseJ4.setUp ###Starting testCollateWithMultipleRequestHandlers
:    [junit4]   2> 2402108 T4045 oas.SolrTestCaseJ4.tearDown ###Ending testCollateWithMultipleRequestHandlers
:    [junit4]   2> 2402115 T4045 oas.SolrTestCaseJ4.setUp ###Starting testCollationWithHypens
:    [junit4]   2> 2402260 T4045 oas.SolrTestCaseJ4.tearDown ###Ending testCollationWithHypens
:    [junit4]   2> 2402267 T4045 oas.SolrTestCaseJ4.setUp ###Starting testCollateWithGrouping
:    [junit4]   2> 2402336 T4045 oas.SolrTestCaseJ4.tearDown ###Ending testCollateWithGrouping
:    [junit4]   2> 2402344 T4045 oas.SolrTestCaseJ4.setUp ###Starting testCollateWithOverride
:    [junit4]   2> 2402446 T4045 C21368 oasc.SolrCore.execute [collection1] webapp=null path=null params={mm=1&spellcheck=true&q=partisian+politcal+mashine&spellcheck.maxCollations=10&spellcheck.maxCollationTries=10&qf=teststop&spellcheck.dictionary=direct&spellcheck.count=10&qt=spellCheckCompRH&spellcheck.collate=true&defType=edismax} hits=0 status=0 QTime=102 
:    [junit4]   2> 2402493 T4045 C21368 oasc.SolrCore.execute [collection1] webapp=null path=null params={mm=1&spellcheck=true&spellcheck.collateParam.mm=100%25&q=partisian+politcal+mashine&spellcheck.maxCollations=10&spellcheck.maxCollationTries=10&qf=teststop&spellcheck.dictionary=direct&spellcheck.count=10&qt=spellCheckCompRH&spellcheck.collate=true&defType=edismax} hits=0 status=0 QTime=40 
:    [junit4]   2> 2402496 T4045 oas.SolrTestCaseJ4.tearDown ###Ending testCollateWithOverride
:    [junit4]   2> 2402502 T4045 oas.SolrTestCaseJ4.setUp ###Starting testEstimatedHitCounts
:    [junit4]   2> 2402512 T4045 C21368 oasc.SolrCore.execute [collection1] webapp=null path=null params={spellcheck=true&spellcheck.collateExtendedResults=true&q=teststop:metnoia&spellcheck.maxCollations=1&spellcheck.maxCollationTries=1&spellcheck.dictionary=direct&spellcheck.count=1&qt=spellCheckCompRH&spellcheck.collate=true} hits=0 status=0 QTime=10 
:    [junit4]   2> 2402526 T4045 C21368 oasc.SolrCore.execute [collection1] webapp=null path=null params={spellcheck=true&spellcheck.collateExtendedResults=true&q=teststop:metnoia&spellcheck.maxCollations=1&spellcheck.maxCollationTries=1&spellcheck.dictionary=direct&spellcheck.collateMaxCollectDocs=1&spellcheck.count=1&qt=spellCheckCompRH&spellcheck.collate=true} hits=0 status=0 QTime=11 
:    [junit4]   2> 2402538 T4045 C21368 oasc.SolrCore.execute [collection1] webapp=null path=null params={spellcheck=true&spellcheck.collateExtendedResults=true&q=teststop:metnoia&spellcheck.maxCollations=1&spellcheck.maxCollationTries=1&spellcheck.dictionary=direct&spellcheck.collateMaxCollectDocs=3&spellcheck.count=1&qt=spellCheckCompRH&spellcheck.collate=true} hits=0 status=0 QTime=8 
:    [junit4]   2> 2402542 T4045 oas.SolrTestCaseJ4.assertQ ERROR REQUEST FAILED: xpath=//lst[@name='spellcheck']/lst[@name='suggestions']/lst[@name='collation']/int[@name='hits']=4
:    [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">8</int></lst><result name="response" numFound="0" start="0"></result><lst name="spellcheck"><lst name="suggestions"><lst name="metnoia"><int name="numFound">1</int><int name="startOffset">9</int><int name="endOffset">16</int><arr name="suggestion"><str>metanoia</str></arr></lst><lst name="collation"><str name="collationQuery">teststop:metanoia</str><int name="hits">17</int><lst name="misspellingsAndCorrections"><str name="metnoia">metanoia</str></lst></lst></lst></lst>
:    [junit4]   2> 	</response>
:    [junit4]   2> 	
:    [junit4]   2> 		request was:spellcheck=true&spellcheck.collateExtendedResults=true&q=teststop:metnoia&spellcheck.maxCollations=1&spellcheck.maxCollationTries=1&spellcheck.dictionary=direct&spellcheck.collateMaxCollectDocs=3&spellcheck.count=1&qt=spellCheckCompRH&spellcheck.collate=true
:    [junit4]   2> 2402544 T4045 oasc.SolrException.log ERROR REQUEST FAILED: spellcheck=true&spellcheck.collateExtendedResults=true&q=teststop:metnoia&spellcheck.maxCollations=1&spellcheck.maxCollationTries=1&spellcheck.dictionary=direct&spellcheck.collateMaxCollectDocs=3&spellcheck.count=1&qt=spellCheckCompRH&spellcheck.collate=true:java.lang.RuntimeException: REQUEST FAILED: xpath=//lst[@name='spellcheck']/lst[@name='suggestions']/lst[@name='collation']/int[@name='hits']=4
:    [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">8</int></lst><result name="response" numFound="0" start="0"></result><lst name="spellcheck"><lst name="suggestions"><lst name="metnoia"><int name="numFound">1</int><int name="startOffset">9</int><int name="endOffset">16</int><arr name="suggestion"><str>metanoia</str></arr></lst><lst name="collation"><str name="collationQuery">teststop:metanoia</str><int name="hits">17</int><lst name="misspellingsAndCorrections"><str name="metnoia">metanoia</str></lst></lst></lst></lst>
:    [junit4]   2> 	</response>
:    [junit4]   2> 	
:    [junit4]   2> 		request was:spellcheck=true&spellcheck.collateExtendedResults=true&q=teststop:metnoia&spellcheck.maxCollations=1&spellcheck.maxCollationTries=1&spellcheck.dictionary=direct&spellcheck.collateMaxCollectDocs=3&spellcheck.count=1&qt=spellCheckCompRH&spellcheck.collate=true
:    [junit4]   2> 		at org.apache.solr.SolrTestCaseJ4.assertQ(SolrTestCaseJ4.java:628)
:    [junit4]   2> 		at org.apache.solr.SolrTestCaseJ4.assertQ(SolrTestCaseJ4.java:602)
:    [junit4]   2> 		at org.apache.solr.spelling.SpellCheckCollatorTest.testEstimatedHitCounts(SpellCheckCollatorTest.java:469)
:    [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:1559)
:    [junit4]   2> 		at com.carrotsearch.randomizedtesting.RandomizedRunner.access$600(RandomizedRunner.java:79)
:    [junit4]   2> 		at com.carrotsearch.randomizedtesting.RandomizedRunner$6.evaluate(RandomizedRunner.java:737)
:    [junit4]   2> 		at com.carrotsearch.randomizedtesting.RandomizedRunner$7.evaluate(RandomizedRunner.java:773)
:    [junit4]   2> 		at com.carrotsearch.randomizedtesting.RandomizedRunner$8.evaluate(RandomizedRunner.java:787)
:    [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.TestRuleFieldCacheSanity$1.evaluate(TestRuleFieldCacheSanity.java:51)
:    [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:70)
:    [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:358)
:    [junit4]   2> 		at com.carrotsearch.randomizedtesting.ThreadLeakControl.forkTimeoutingTask(ThreadLeakControl.java:782)
:    [junit4]   2> 		at com.carrotsearch.randomizedtesting.ThreadLeakControl$3.evaluate(ThreadLeakControl.java:442)
:    [junit4]   2> 		at com.carrotsearch.randomizedtesting.RandomizedRunner.runSingleTest(RandomizedRunner.java:746)
:    [junit4]   2> 		at com.carrotsearch.randomizedtesting.RandomizedRunner$3.evaluate(RandomizedRunner.java:648)
:    [junit4]   2> 		at com.carrotsearch.randomizedtesting.RandomizedRunner$4.evaluate(RandomizedRunner.java:682)
:    [junit4]   2> 		at com.carrotsearch.randomizedtesting.RandomizedRunner$5.evaluate(RandomizedRunner.java:693)
:    [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 org.apache.lucene.util.TestRuleAssertionsRequired$1.evaluate(TestRuleAssertionsRequired.java:43)
:    [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:70)
:    [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:358)
:    [junit4]   2> 		at java.lang.Thread.run(Thread.java:724)
:    [junit4]   2> 	
:    [junit4]   2> 2402546 T4045 oas.SolrTestCaseJ4.tearDown ###Ending testEstimatedHitCounts
:    [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=SpellCheckCollatorTest -Dtests.method=testEstimatedHitCounts -Dtests.seed=16B4D8F74E59EE10 -Dtests.multiplier=2 -Dtests.nightly=true -Dtests.slow=true -Dtests.linedocsfile=/home/hudson/lucene-data/enwiki.random.lines.txt -Dtests.locale=nl -Dtests.timezone=America/Dawson -Dtests.file.encoding=US-ASCII
:    [junit4] ERROR   0.06s J1 | SpellCheckCollatorTest.testEstimatedHitCounts <<<
:    [junit4]    > Throwable #1: java.lang.RuntimeException: Exception during query
:    [junit4]    > 	at __randomizedtesting.SeedInfo.seed([16B4D8F74E59EE10:270F66C2EB66FEC0]:0)
:    [junit4]    > 	at org.apache.solr.SolrTestCaseJ4.assertQ(SolrTestCaseJ4.java:635)
:    [junit4]    > 	at org.apache.solr.SolrTestCaseJ4.assertQ(SolrTestCaseJ4.java:602)
:    [junit4]    > 	at org.apache.solr.spelling.SpellCheckCollatorTest.testEstimatedHitCounts(SpellCheckCollatorTest.java:469)
:    [junit4]    > 	at java.lang.Thread.run(Thread.java:724)
:    [junit4]    > Caused by: java.lang.RuntimeException: REQUEST FAILED: xpath=//lst[@name='spellcheck']/lst[@name='suggestions']/lst[@name='collation']/int[@name='hits']=4
:    [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">8</int></lst><result name="response" numFound="0" start="0"></result><lst name="spellcheck"><lst name="suggestions"><lst name="metnoia"><int name="numFound">1</int><int name="startOffset">9</int><int name="endOffset">16</int><arr name="suggestion"><str>metanoia</str></arr></lst><lst name="collation"><str name="collationQuery">teststop:metanoia</str><int name="hits">17</int><lst name="misspellingsAndCorrections"><str name="metnoia">metanoia</str></lst></lst></lst></lst>
:    [junit4]    > </response>
:    [junit4]    > 	request was:spellcheck=true&spellcheck.collateExtendedResults=true&q=teststop:metnoia&spellcheck.maxCollations=1&spellcheck.maxCollationTries=1&spellcheck.dictionary=direct&spellcheck.collateMaxCollectDocs=3&spellcheck.count=1&qt=spellCheckCompRH&spellcheck.collate=true
:    [junit4]    > 	at org.apache.solr.SolrTestCaseJ4.assertQ(SolrTestCaseJ4.java:628)
:    [junit4]    > 	... 42 more
:    [junit4]   2> 2402558 T4045 oas.SolrTestCaseJ4.deleteCore ###deleteCore
:    [junit4]   2> 2402559 T4045 oasc.CoreContainer.shutdown Shutting down CoreContainer instance=1414615201
:    [junit4]   2> 2402559 T4045 oasc.SolrCore.close [collection1]  CLOSING SolrCore org.apache.solr.core.SolrCore@32af94b0
:    [junit4]   2> 2402559 T4045 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=17,cumulative_deletesById=0,cumulative_deletesByQuery=0,cumulative_errors=0}
:    [junit4]   2> 2402560 T4045 oasu.SolrCoreState.decrefSolrCoreState Closing SolrCoreState
:    [junit4]   2> 2402560 T4045 oasu.DefaultSolrCoreState.closeIndexWriter SolrCoreState ref count has reached 0 - closing IndexWriter
:    [junit4]   2> 2402560 T4045 oasu.DefaultSolrCoreState.closeIndexWriter closing IndexWriter with IndexWriterCloser
:    [junit4]   2> 2402561 T4045 oasc.SolrCore.closeSearcher [collection1] Closing main searcher on request.
:    [junit4]   2> 2402561 T4045 oasc.CachingDirectoryFactory.close Closing MockDirectoryFactory - 2 directories currently being tracked
:    [junit4]   2> 2402562 T4045 oasc.CachingDirectoryFactory.closeCacheValue looking to close /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test/J1/./solrtest-SpellCheckCollatorTest-1375883796067/index [CachedDir<<refCount=0;path=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test/J1/./solrtest-SpellCheckCollatorTest-1375883796067/index;done=false>>]
:    [junit4]   2> 2402562 T4045 oasc.CachingDirectoryFactory.close Closing directory: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test/J1/./solrtest-SpellCheckCollatorTest-1375883796067/index
:    [junit4]   2> 2402562 T4045 oasc.CachingDirectoryFactory.closeCacheValue looking to close /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test/J1/./solrtest-SpellCheckCollatorTest-1375883796067 [CachedDir<<refCount=0;path=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test/J1/./solrtest-SpellCheckCollatorTest-1375883796067;done=false>>]
:    [junit4]   2> 2402563 T4045 oasc.CachingDirectoryFactory.close Closing directory: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test/J1/./solrtest-SpellCheckCollatorTest-1375883796067
:    [junit4]   2> NOTE: test params are: codec=Lucene42: {range_facet_l=MockVariableIntBlock(baseBlockSize=72), lowerfilt1=Pulsing41(freqCutoff=12 minBlockSize=73 maxBlockSize=149), lowerfilt=PostingsFormat(name=Lucene41VarGapFixedInterval), teststop=PostingsFormat(name=Lucene41VarGapFixedInterval), end4=Pulsing41(freqCutoff=12 minBlockSize=73 maxBlockSize=149), end3=PostingsFormat(name=Lucene41VarGapFixedInterval), lowerfilt1and2=PostingsFormat(name=Lucene41VarGapFixedInterval), start1=Pulsing41(freqCutoff=12 minBlockSize=73 maxBlockSize=149), end2=PostingsFormat(name=Lucene41WithOrds), end1=MockVariableIntBlock(baseBlockSize=72), intDefault=MockVariableIntBlock(baseBlockSize=72), id=PostingsFormat(name=Lucene41WithOrds), timestamp=MockVariableIntBlock(baseBlockSize=72), range_facet_sl=Pulsing41(freqCutoff=12 minBlockSize=73 maxBlockSize=149), range_facet_si=PostingsFormat(name=Lucene41VarGapFixedInterval), start4=MockVariableIntBlock(baseBlockSize=72), start2=PostingsFormat(name=L
 ucene41VarGapFixedInterval), start3=PostingsFormat(name=Lucene41WithOrds), word=MockVariableIntBlock(baseBlockSize=72), gram2=PostingsFormat(name=Lucene41WithOrds), gram1=MockVariableIntBlock(baseBlockSize=72), multiDefault=PostingsFormat(name=Lucene41VarGapFixedInterval), gram4=Pulsing41(freqCutoff=12 minBlockSize=73 maxBlockSize=149), gram3=PostingsFormat(name=Lucene41VarGapFixedInterval)}, docValues:{timestamp=DocValuesFormat(name=Asserting)}, sim=RandomSimilarityProvider(queryNorm=false,coord=yes): {}, locale=nl, timezone=America/Dawson
:    [junit4]   2> NOTE: FreeBSD 9.1-RELEASE-p3 amd64/Oracle Corporation 1.7.0_25 (64-bit)/cpus=16,threads=1,free=281063024,total=534052864
:    [junit4]   2> NOTE: All tests run in this JVM: [IndexBasedSpellCheckerTest, CoreAdminCreateDiscoverTest, CoreContainerCoreInitFailuresTest, TestQueryTypes, ResourceLoaderTest, TestReload, UUIDFieldTest, TestCopyFieldCollectionResource, TestCSVLoader, SuggesterTSTTest, TestBinaryField, TestPhraseSuggestions, SuggesterWFSTTest, ConvertedLegacyTest, TestSweetSpotSimilarityFactory, HdfsUnloadDistributedZkTest, HighlighterTest, ChaosMonkeySafeLeaderTest, CurrencyFieldXmlFileTest, SimplePostToolTest, DistanceFunctionTest, TestFiltering, TestDFRSimilarityFactory, JSONWriterTest, BasicZkTest, TestUtils, HdfsBasicDistributedZk2Test, TestOmitPositions, TestCloudManagedSchema, SliceStateTest, PrimUtilsTest, OpenCloseCoreStressTest, PathHierarchyTokenizerFactoryTest, TestDefaultSimilarityFactory, AlternateDirectoryTest, DebugComponentTest, SolrRequestParserTest, LeaderElectionIntegrationTest, HighlighterConfigTest, TestFastWriter, PreAnalyzedFieldTest, TestRecoveryHdfs, HdfsCollectionsAPIDi
 stributedZkTest, TestCoreDiscovery, BadIndexSchemaTest, TestCodecSupport, TestIndexSearcher, TestSolrDeletionPolicy2, TestJmxIntegration, TestZkChroot, DirectUpdateHandlerTest, FullSolrCloudDistribCmdsTest, StatsComponentTest, XsltUpdateRequestHandlerTest, CircularListTest, RequestHandlersTest, HardAutoCommitTest, TestMultiCoreConfBootstrap, TestUpdate, UniqFieldsUpdateProcessorFactoryTest, HdfsRecoveryZkTest, NoCacheHeaderTest, ShardSplitTest, TestRandomMergePolicy, BasicDistributedZk2Test, TestStressReorder, TestFuzzyAnalyzedSuggestions, TestAtomicUpdateErrorCases, DirectSolrSpellCheckerTest, TestSolr4Spatial, TestClassNameShortening, SolrCmdDistributorTest, DisMaxRequestHandlerTest, DefaultValueUpdateProcessorTest, ClusterStateTest, TestRandomFaceting, AutoCommitTest, TestDistributedGrouping, TestFaceting, TestRecovery, TestHashPartitioner, TermVectorComponentDistributedTest, TestJoin, SpellCheckComponentTest, PeerSyncTest, TestLazyCores, SoftAutoCommitTest, CurrencyFieldOpenExch
 angeTest, SpellCheckCollatorTest]
:    [junit4] Completed on J1 in 2.93s, 8 tests, 1 error <<< FAILURES!
: 
: [...truncated 386 lines...]
: BUILD FAILED
: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-trunk/build.xml:396: The following error occurred while executing this line:
: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-trunk/build.xml:369: The following error occurred while executing this line:
: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-trunk/build.xml:39: The following error occurred while executing this line:
: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build.xml:181: The following error occurred while executing this line:
: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/common-build.xml:449: The following error occurred while executing this line:
: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-trunk/lucene/common-build.xml:1230: The following error occurred while executing this line:
: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-trunk/lucene/common-build.xml:873: There were test failures: 317 suites, 1343 tests, 1 error, 32 ignored (4 assumptions)
: 
: Total time: 102 minutes 23 seconds
: Build step 'Invoke Ant' marked build as failure
: Archiving artifacts
: Recording test results
: Email was triggered for: Failure
: Sending email for trigger: Failure
: 
: 
: 

-Hoss