You are viewing a plain text version of this content. The canonical link for it is here.
Posted to dev@lucene.apache.org by Policeman Jenkins Server <je...@thetaphi.de> on 2013/09/08 11:25:55 UTC
[JENKINS] Lucene-Solr-trunk-Linux (64bit/jdk1.8.0-ea-b102) - Build
# 7371 - Failure!
Build: http://jenkins.thetaphi.de/job/Lucene-Solr-trunk-Linux/7371/
Java: 64bit/jdk1.8.0-ea-b102 -XX:+UseCompressedOops -XX:+UseSerialGC
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([EAD13915CDD8580D:DB6A872068E748DD]:0)
at org.apache.solr.SolrTestCaseJ4.assertQ(SolrTestCaseJ4.java:637)
at org.apache.solr.SolrTestCaseJ4.assertQ(SolrTestCaseJ4.java:604)
at org.apache.solr.spelling.SpellCheckCollatorTest.testEstimatedHitCounts(SpellCheckCollatorTest.java:521)
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:491)
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' and 6 <= . and . <= 10]
xml response was: <?xml version="1.0" encoding="UTF-8"?>
<response>
<lst name="responseHeader"><int name="status">0</int><int name="QTime">18</int></lst><result name="response" numFound="0" start="0"></result><lst name="spellcheck"><lst name="suggestions"><lst name="everother"><int name="numFound">1</int><int name="startOffset">9</int><int name="endOffset">18</int><arr name="suggestion"><str>everyother</str></arr></lst><lst name="collation"><str name="collationQuery">teststop:everyother</str><int name="hits">12</int><lst name="misspellingsAndCorrections"><str name="everother">everyother</str></lst></lst></lst></lst>
</response>
request was:spellcheck=true&spellcheck.dictionary=direct&spellcheck.count=1&spellcheck.collate=true&spellcheck.maxCollationTries=1&spellcheck.maxCollations=1&spellcheck.collateExtendedResults=true&qt=spellCheckCompRH&q=teststop%3Aeverother&spellcheck.collateMaxCollectDocs=5
at org.apache.solr.SolrTestCaseJ4.assertQ(SolrTestCaseJ4.java:630)
... 42 more
Build Log:
[...truncated 10060 lines...]
[junit4] Suite: org.apache.solr.spelling.SpellCheckCollatorTest
[junit4] 2> 729334 T3219 oas.SolrTestCaseJ4.initCore ####initCore
[junit4] 2> Creating dataDir: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./solrtest-SpellCheckCollatorTest-1378632037958
[junit4] 2> 729334 T3219 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test-files/solr/collection1/'
[junit4] 2> 729335 T3219 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test-files/solr/collection1/lib/classes/' to classloader
[junit4] 2> 729335 T3219 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test-files/solr/collection1/lib/README' to classloader
[junit4] 2> 729362 T3219 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_50
[junit4] 2> 729385 T3219 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig-spellcheckcomponent.xml
[junit4] 2> 729385 T3219 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4] 2> 729391 T3219 oass.IndexSchema.readSchema [null] Schema name=test
[junit4] 2> 729525 T3219 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4] 2> 729530 T3219 oass.IndexSchema.readSchema default search field in schema is text
[junit4] 2> 729532 T3219 oass.IndexSchema.readSchema unique key field: id
[junit4] 2> 729536 T3219 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4] 2> 729538 T3219 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4] 2> 729540 T3219 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4] 2> 729540 T3219 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4] 2> 729540 T3219 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4] 2> 729541 T3219 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4] 2> 729541 T3219 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4] 2> 729541 T3219 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4] 2> 729542 T3219 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4] 2> 729542 T3219 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test-files/solr
[junit4] 2> 729542 T3219 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test-files/solr/'
[junit4] 2> 729552 T3219 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4] 2> 729553 T3219 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test-files/solr
[junit4] 2> 729553 T3219 oasc.SolrResourceLoader.<init> new SolrResourceLoader for deduced Solr Home: '/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test-files/solr/'
[junit4] 2> 729577 T3219 oasc.CoreContainer.<init> New CoreContainer 773331102
[junit4] 2> 729577 T3219 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test-files/solr/]
[junit4] 2> 729578 T3219 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 0
[junit4] 2> 729578 T3219 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4] 2> 729578 T3219 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 0
[junit4] 2> 729578 T3219 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4] 2> 729579 T3219 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4] 2> 729579 T3219 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4] 2> 729579 T3219 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4] 2> 729579 T3219 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4] 2> 729579 T3219 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4] 2> 729580 T3219 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=0&connTimeout=0&retry=false
[junit4] 2> 729584 T3219 oasl.LogWatcher.createWatcher SLF4J impl is org.slf4j.impl.Log4jLoggerFactory
[junit4] 2> 729584 T3219 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
[junit4] 2> 729585 T3220 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test-files/solr/collection1
[junit4] 2> 729585 T3220 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test-files/solr/collection1/'
[junit4] 2> 729586 T3220 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test-files/solr/collection1/lib/classes/' to classloader
[junit4] 2> 729586 T3220 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test-files/solr/collection1/lib/README' to classloader
[junit4] 2> 729599 T3220 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_50
[junit4] 2> 729607 T3220 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig-spellcheckcomponent.xml
[junit4] 2> 729607 T3220 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4] 2> 729611 T3220 oass.IndexSchema.readSchema [null] Schema name=test
[junit4] 2> 729724 T3220 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4] 2> 729728 T3220 oass.IndexSchema.readSchema default search field in schema is text
[junit4] 2> 729730 T3220 oass.IndexSchema.readSchema unique key field: id
[junit4] 2> 729733 T3220 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4] 2> 729735 T3220 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4] 2> 729736 T3220 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4] 2> 729737 T3220 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4] 2> 729737 T3220 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4] 2> 729737 T3220 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4] 2> 729737 T3220 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4] 2> 729738 T3220 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4] 2> 729738 T3220 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4] 2> 729738 T3220 oasc.SolrCore.<init> [collection1] Opening new SolrCore at /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test-files/solr/collection1/, dataDir=/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./solrtest-SpellCheckCollatorTest-1378632037958/
[junit4] 2> 729738 T3220 oasc.SolrCore.<init> JMX monitoring not detected for core: collection1
[junit4] 2> 729739 T3220 oasc.CachingDirectoryFactory.get return new directory for /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./solrtest-SpellCheckCollatorTest-1378632037958
[junit4] 2> 729739 T3220 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./solrtest-SpellCheckCollatorTest-1378632037958/index/
[junit4] 2> 729739 T3220 oasc.SolrCore.initIndex WARN [collection1] Solr index directory '/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./solrtest-SpellCheckCollatorTest-1378632037958/index' doesn't exist. Creating new index...
[junit4] 2> 729739 T3220 oasc.CachingDirectoryFactory.get return new directory for /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./solrtest-SpellCheckCollatorTest-1378632037958/index
[junit4] 2> 729740 T3220 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.LogDocMergePolicy: [LogDocMergePolicy: minMergeSize=1000, mergeFactor=9, maxMergeSize=9223372036854775807, maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=true, maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.19655727215449226]
[junit4] 2> 729740 T3220 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
[junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@6aee2c57 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@71d2fe81),segFN=segments_1,generation=1}
[junit4] 2> 729741 T3220 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4] 2> 729741 T3220 oasc.SolrCore.loadUpdateProcessorChains no updateRequestProcessorChain defined as default, creating implicit default
[junit4] 2> 729742 T3220 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4] 2> 729742 T3220 oasc.RequestHandlers.initHandlersFromConfig created spellCheckCompRH: org.apache.solr.handler.component.SearchHandler
[junit4] 2> 729742 T3220 oasc.RequestHandlers.initHandlersFromConfig created spellCheckCompRH1: org.apache.solr.handler.component.SearchHandler
[junit4] 2> 729742 T3220 oasc.RequestHandlers.initHandlersFromConfig created spellCheckWithWordbreak: org.apache.solr.handler.component.SearchHandler
[junit4] 2> 729743 T3220 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4] 2> 729743 T3220 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4] 2> 729744 T3220 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: maxMergeAtOnce=37, maxMergeAtOnceExplicit=46, maxMergedSegmentMB=90.5234375, floorSegmentMB=1.33984375, forceMergeDeletesPctAllowed=2.4116757593865588, segmentsPerTier=18.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.705701395780085
[junit4] 2> 729744 T3220 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=1
[junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@6aee2c57 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@71d2fe81),segFN=segments_1,generation=1}
[junit4] 2> 729744 T3220 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4] 2> 729744 T3220 oass.SolrIndexSearcher.<init> Opening Searcher@e984b76 main
[junit4] 2> 729745 T3220 oashc.SpellCheckComponent.inform Initializing spell checkers
[junit4] 2> 729765 T3220 oashc.SpellCheckComponent.inform Registering newSearcher listener for spellchecker: default
[junit4] 2> 729769 T3220 oashc.SpellCheckComponent.inform Registering newSearcher listener for spellchecker: default_teststop
[junit4] 2> 729769 T3220 oass.DirectSolrSpellChecker.init init: {name=direct,classname=solr.DirectSolrSpellChecker,minQueryLength=3,maxQueryFrequency=100.0,field=teststop}
[junit4] 2> 729770 T3220 oass.DirectSolrSpellChecker.init init: {name=direct_lowerfilt,classname=solr.DirectSolrSpellChecker,minQueryLength=3,maxQueryFrequency=100.0,field=lowerfilt}
[junit4] 2> 729773 T3220 oashc.SpellCheckComponent.inform Registering newSearcher listener for spellchecker: threshold
[junit4] 2> 729773 T3220 oass.DirectSolrSpellChecker.init init: {name=threshold_direct,classname=solr.DirectSolrSpellChecker,field=lowerfilt,spellcheckIndexDir=spellcheckerThreshold,buildOnCommit=true,thresholdTokenFrequency=0.29}
[junit4] 2> 729774 T3220 oashc.SpellCheckComponent.inform Registering newSearcher listener for spellchecker: threshold_direct
[junit4] 2> 729777 T3220 oashc.SpellCheckComponent.inform Registering newSearcher listener for spellchecker: multipleFields
[junit4] 2> 729788 T3220 oashc.SpellCheckComponent.inform Registering newSearcher listener for spellchecker: freq
[junit4] 2> 729792 T3220 oashc.SpellCheckComponent.inform Registering newSearcher listener for spellchecker: fqcn
[junit4] 2> 729792 T3221 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@e984b76 main{StandardDirectoryReader(segments_1:1:nrt)}
[junit4] 2> 729793 T3220 oasc.CoreContainer.registerCore registering core: collection1
[junit4] 2> 729795 T3219 oas.SolrTestCaseJ4.initCore ####initCore end
[junit4] 2> ASYNC NEW_CORE C2985 name=collection1 org.apache.solr.core.SolrCore@52b353f1
[junit4] 2> 729797 T3219 C2985 oasup.LogUpdateProcessor.finish [collection1] webapp=null path=null params={} {add=[0]} 0 0
[junit4] 2> 729802 T3219 C2985 oasup.LogUpdateProcessor.finish [collection1] webapp=null path=null params={} {add=[1]} 0 0
[junit4] 2> 729810 T3219 C2985 oasup.LogUpdateProcessor.finish [collection1] webapp=null path=null params={} {add=[2]} 0 6
[junit4] 2> 729813 T3219 C2985 oasup.LogUpdateProcessor.finish [collection1] webapp=null path=null params={} {add=[3]} 0 1
[junit4] 2> 729815 T3219 C2985 oasup.LogUpdateProcessor.finish [collection1] webapp=null path=null params={} {add=[4]} 0 0
[junit4] 2> 729819 T3219 C2985 oasup.LogUpdateProcessor.finish [collection1] webapp=null path=null params={} {add=[5]} 0 2
[junit4] 2> 729823 T3219 C2985 oasup.LogUpdateProcessor.finish [collection1] webapp=null path=null params={} {add=[6]} 0 1
[junit4] 2> ASYNC NEW_CORE C2986 name=collection1 org.apache.solr.core.SolrCore@52b353f1
[junit4] 2> 729835 T3219 C2986 oasup.LogUpdateProcessor.finish [collection1] webapp=null path=null params={} {add=[7]} 0 0
[junit4] 2> 729839 T3219 C2986 oasup.LogUpdateProcessor.finish [collection1] webapp=null path=null params={} {add=[8]} 0 2
[junit4] 2> 729841 T3219 C2986 oasup.LogUpdateProcessor.finish [collection1] webapp=null path=null params={} {add=[9]} 0 0
[junit4] 2> 729844 T3219 C2986 oasup.LogUpdateProcessor.finish [collection1] webapp=null path=null params={} {add=[10]} 0 1
[junit4] 2> 729847 T3219 C2986 oasup.LogUpdateProcessor.finish [collection1] webapp=null path=null params={} {add=[11]} 0 2
[junit4] 2> 729850 T3219 C2986 oasup.LogUpdateProcessor.finish [collection1] webapp=null path=null params={} {add=[12]} 0 1
[junit4] 2> 729852 T3219 C2986 oasup.LogUpdateProcessor.finish [collection1] webapp=null path=null params={} {add=[13]} 0 0
[junit4] 2> 729856 T3219 C2986 oasup.LogUpdateProcessor.finish [collection1] webapp=null path=null params={} {add=[14]} 0 2
[junit4] 2> 729858 T3219 C2986 oasup.LogUpdateProcessor.finish [collection1] webapp=null path=null params={} {add=[15]} 0 0
[junit4] 2> 729860 T3219 C2986 oasup.LogUpdateProcessor.finish [collection1] webapp=null path=null params={} {add=[16]} 0 0
[junit4] 2> 729862 T3219 C2986 oasu.DirectUpdateHandler2.commit start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4] 2> 729867 T3219 C2986 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=2
[junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@6aee2c57 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@71d2fe81),segFN=segments_1,generation=1}
[junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@6aee2c57 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@71d2fe81),segFN=segments_2,generation=2}
[junit4] 2> 729868 T3219 C2986 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 2
[junit4] 2> 729869 T3219 C2986 oass.SolrIndexSearcher.<init> Opening Searcher@3f146689 main
[junit4] 2> 729869 T3219 C2986 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4] 2> 729869 T3221 oashc.SpellCheckComponent$SpellCheckerListener.buildSpellIndex Building spell index for spell checker: default
[junit4] 2> 729920 T3221 oashc.SpellCheckComponent$SpellCheckerListener.buildSpellIndex Building spell index for spell checker: default_teststop
[junit4] 2> 729984 T3221 oashc.SpellCheckComponent$SpellCheckerListener.buildSpellIndex Building spell index for spell checker: threshold
[junit4] 2> 730011 T3221 oashc.SpellCheckComponent$SpellCheckerListener.buildSpellIndex Building spell index for spell checker: threshold_direct
[junit4] 2> 730011 T3221 oashc.SpellCheckComponent$SpellCheckerListener.buildSpellIndex Building spell index for spell checker: multipleFields
[junit4] 2> 730076 T3221 oashc.SpellCheckComponent$SpellCheckerListener.buildSpellIndex Building spell index for spell checker: freq
[junit4] 2> 730131 T3221 oashc.SpellCheckComponent$SpellCheckerListener.buildSpellIndex Building spell index for spell checker: fqcn
[junit4] 2> 730181 T3221 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@3f146689 main{StandardDirectoryReader(segments_2:13:nrt _0(5.0):c3 _1(5.0):c3 _2(5.0):c3 _3(5.0):c3 _4(5.0):c3 _5(5.0):c2)}
[junit4] 2> 730181 T3219 C2986 oasup.LogUpdateProcessor.finish [collection1] webapp=null path=null params={} {commit=} 0 319
[junit4] 2> 730184 T3219 oas.SolrTestCaseJ4.setUp ###Starting testCollationWithHypens
[junit4] 2> 730293 T3219 oas.SolrTestCaseJ4.tearDown ###Ending testCollationWithHypens
[junit4] 2> 730297 T3219 oas.SolrTestCaseJ4.setUp ###Starting testCollateWithMultipleRequestHandlers
[junit4] 2> 730383 T3219 oas.SolrTestCaseJ4.tearDown ###Ending testCollateWithMultipleRequestHandlers
[junit4] 2> 730392 T3219 oas.SolrTestCaseJ4.setUp ###Starting testEstimatedHitCounts
[junit4] 2> ASYNC NEW_CORE C2987 name=collection1 org.apache.solr.core.SolrCore@52b353f1
[junit4] 2> 730472 T3219 C2987 oasc.SolrCore.execute [collection1] webapp=null path=null params={spellcheck=true&spellcheck.dictionary=direct&spellcheck.count=1&spellcheck.collate=true&spellcheck.maxCollationTries=1&spellcheck.maxCollations=1&spellcheck.collateExtendedResults=true&qt=spellCheckCompRH&q=teststop%3Ametnoia} hits=0 status=0 QTime=80
[junit4] 2> 730490 T3219 C2987 oasc.SolrCore.execute [collection1] webapp=null path=null params={spellcheck=true&spellcheck.dictionary=direct&spellcheck.count=1&spellcheck.collate=true&spellcheck.maxCollationTries=1&spellcheck.maxCollations=1&spellcheck.collateExtendedResults=true&qt=spellCheckCompRH&q=teststop%3Ametnoia&spellcheck.collateMaxCollectDocs=0} hits=0 status=0 QTime=17
[junit4] 2> 730510 T3219 C2987 oasc.SolrCore.execute [collection1] webapp=null path=null params={spellcheck=true&spellcheck.dictionary=direct&spellcheck.count=1&spellcheck.collate=true&spellcheck.maxCollationTries=1&spellcheck.maxCollations=1&spellcheck.collateExtendedResults=true&qt=spellCheckCompRH&q=teststop%3Ametnoia&spellcheck.collateMaxCollectDocs=30} hits=0 status=0 QTime=19
[junit4] 2> 730529 T3219 C2987 oasc.SolrCore.execute [collection1] webapp=null path=null params={spellcheck=true&spellcheck.dictionary=direct&spellcheck.count=1&spellcheck.collate=true&spellcheck.maxCollationTries=1&spellcheck.maxCollations=1&spellcheck.collateExtendedResults=true&qt=spellCheckCompRH&q=teststop%3Ametnoia&spellcheck.collateMaxCollectDocs=100} hits=0 status=0 QTime=18
[junit4] 2> 730545 T3219 C2987 oasc.SolrCore.execute [collection1] webapp=null path=null params={spellcheck=true&spellcheck.dictionary=direct&spellcheck.count=1&spellcheck.collate=true&spellcheck.maxCollationTries=1&spellcheck.maxCollations=1&spellcheck.collateExtendedResults=true&qt=spellCheckCompRH&q=teststop%3Ametnoia&spellcheck.collateMaxCollectDocs=10000} hits=0 status=0 QTime=15
[junit4] 2> 730561 T3219 C2987 oasc.SolrCore.execute [collection1] webapp=null path=null params={spellcheck=true&spellcheck.dictionary=direct&spellcheck.count=1&spellcheck.collate=true&spellcheck.maxCollationTries=1&spellcheck.maxCollations=1&spellcheck.collateExtendedResults=true&qt=spellCheckCompRH&q=teststop%3Ametnoia&spellcheck.collateMaxCollectDocs=15} hits=0 status=0 QTime=15
[junit4] 2> 730603 T3219 C2987 oasc.SolrCore.execute [collection1] webapp=null path=null params={spellcheck=true&spellcheck.dictionary=direct&spellcheck.count=1&spellcheck.collate=true&spellcheck.maxCollationTries=1&spellcheck.maxCollations=1&spellcheck.collateExtendedResults=true&qt=spellCheckCompRH&q=teststop%3Ametnoia&spellcheck.collateMaxCollectDocs=13} hits=0 status=0 QTime=34
[junit4] 2> 730615 T3219 C2987 oasc.SolrCore.execute [collection1] webapp=null path=null params={spellcheck=true&spellcheck.dictionary=direct&spellcheck.count=1&spellcheck.collate=true&spellcheck.maxCollationTries=1&spellcheck.maxCollations=1&spellcheck.collateExtendedResults=true&qt=spellCheckCompRH&q=teststop%3Ametnoia&spellcheck.collateMaxCollectDocs=16} hits=0 status=0 QTime=11
[junit4] 2> 730626 T3219 C2987 oasc.SolrCore.execute [collection1] webapp=null path=null params={spellcheck=true&spellcheck.dictionary=direct&spellcheck.count=1&spellcheck.collate=true&spellcheck.maxCollationTries=1&spellcheck.maxCollations=1&spellcheck.collateExtendedResults=true&qt=spellCheckCompRH&q=teststop%3Ametnoia&spellcheck.collateMaxCollectDocs=12} hits=0 status=0 QTime=10
[junit4] 2> 730636 T3219 C2987 oasc.SolrCore.execute [collection1] webapp=null path=null params={spellcheck=true&spellcheck.dictionary=direct&spellcheck.count=1&spellcheck.collate=true&spellcheck.maxCollationTries=1&spellcheck.maxCollations=1&spellcheck.collateExtendedResults=true&qt=spellCheckCompRH&q=teststop%3Ametnoia&spellcheck.collateMaxCollectDocs=10} hits=0 status=0 QTime=9
[junit4] 2> 730646 T3219 C2987 oasc.SolrCore.execute [collection1] webapp=null path=null params={spellcheck=true&spellcheck.dictionary=direct&spellcheck.count=1&spellcheck.collate=true&spellcheck.maxCollationTries=1&spellcheck.maxCollations=1&spellcheck.collateExtendedResults=true&qt=spellCheckCompRH&q=teststop%3Ametnoia&spellcheck.collateMaxCollectDocs=13} hits=0 status=0 QTime=8
[junit4] 2> 730656 T3219 C2987 oasc.SolrCore.execute [collection1] webapp=null path=null params={spellcheck=true&spellcheck.dictionary=direct&spellcheck.count=1&spellcheck.collate=true&spellcheck.maxCollationTries=1&spellcheck.maxCollations=1&spellcheck.collateExtendedResults=true&qt=spellCheckCompRH&q=teststop%3Ametnoia&spellcheck.collateMaxCollectDocs=1} hits=0 status=0 QTime=9
[junit4] 2> 730666 T3219 C2987 oasc.SolrCore.execute [collection1] webapp=null path=null params={spellcheck=true&spellcheck.dictionary=direct&spellcheck.count=1&spellcheck.collate=true&spellcheck.maxCollationTries=1&spellcheck.maxCollations=1&spellcheck.collateExtendedResults=true&qt=spellCheckCompRH&q=teststop%3Ametnoia&spellcheck.collateMaxCollectDocs=9} hits=0 status=0 QTime=9
[junit4] 2> 730681 T3219 C2987 oasc.SolrCore.execute [collection1] webapp=null path=null params={spellcheck=true&spellcheck.dictionary=direct&spellcheck.count=1&spellcheck.collate=true&spellcheck.maxCollationTries=1&spellcheck.maxCollations=1&spellcheck.collateExtendedResults=true&qt=spellCheckCompRH&q=teststop%3Ametnoia&spellcheck.collateMaxCollectDocs=14} hits=0 status=0 QTime=14
[junit4] 2> 730688 T3219 C2987 oasc.SolrCore.execute [collection1] webapp=null path=null params={spellcheck=true&spellcheck.dictionary=direct&spellcheck.count=1&spellcheck.collate=true&spellcheck.maxCollationTries=1&spellcheck.maxCollations=1&spellcheck.collateExtendedResults=true&qt=spellCheckCompRH&q=teststop%3Ametnoia&spellcheck.collateMaxCollectDocs=13} hits=0 status=0 QTime=6
[junit4] 2> 730703 T3219 C2987 oasc.SolrCore.execute [collection1] webapp=null path=null params={spellcheck=true&spellcheck.dictionary=direct&spellcheck.count=1&spellcheck.collate=true&spellcheck.maxCollationTries=1&spellcheck.maxCollations=1&spellcheck.collateExtendedResults=true&qt=spellCheckCompRH&q=teststop%3Ametnoia&spellcheck.collateMaxCollectDocs=17} hits=0 status=0 QTime=14
[junit4] 2> 730709 T3219 C2987 oasc.SolrCore.execute [collection1] webapp=null path=null params={spellcheck=true&spellcheck.dictionary=direct&spellcheck.count=1&spellcheck.collate=true&spellcheck.maxCollationTries=1&spellcheck.maxCollations=1&spellcheck.collateExtendedResults=true&qt=spellCheckCompRH&q=teststop%3Ametnoia&spellcheck.collateMaxCollectDocs=3} hits=0 status=0 QTime=5
[junit4] 2> 730716 T3219 C2987 oasc.SolrCore.execute [collection1] webapp=null path=null params={spellcheck=true&spellcheck.dictionary=direct&spellcheck.count=1&spellcheck.collate=true&spellcheck.maxCollationTries=1&spellcheck.maxCollations=1&spellcheck.collateExtendedResults=true&qt=spellCheckCompRH&q=teststop%3Ametnoia&spellcheck.collateMaxCollectDocs=12} hits=0 status=0 QTime=6
[junit4] 2> 730722 T3219 C2987 oasc.SolrCore.execute [collection1] webapp=null path=null params={spellcheck=true&spellcheck.dictionary=direct&spellcheck.count=1&spellcheck.collate=true&spellcheck.maxCollationTries=1&spellcheck.maxCollations=1&spellcheck.collateExtendedResults=true&qt=spellCheckCompRH&q=teststop%3Ametnoia&spellcheck.collateMaxCollectDocs=8} hits=0 status=0 QTime=5
[junit4] 2> 730729 T3219 C2987 oasc.SolrCore.execute [collection1] webapp=null path=null params={spellcheck=true&spellcheck.dictionary=direct&spellcheck.count=1&spellcheck.collate=true&spellcheck.maxCollationTries=1&spellcheck.maxCollations=1&spellcheck.collateExtendedResults=true&qt=spellCheckCompRH&q=teststop%3Ametnoia&spellcheck.collateMaxCollectDocs=7} hits=0 status=0 QTime=6
[junit4] 2> 730736 T3219 C2987 oasc.SolrCore.execute [collection1] webapp=null path=null params={spellcheck=true&spellcheck.dictionary=direct&spellcheck.count=1&spellcheck.collate=true&spellcheck.maxCollationTries=1&spellcheck.maxCollations=1&spellcheck.collateExtendedResults=true&qt=spellCheckCompRH&q=teststop%3Ametnoia&spellcheck.collateMaxCollectDocs=10} hits=0 status=0 QTime=6
[junit4] 2> 730754 T3219 C2987 oasc.SolrCore.execute [collection1] webapp=null path=null params={spellcheck=true&spellcheck.dictionary=direct&spellcheck.count=1&spellcheck.collate=true&spellcheck.maxCollationTries=1&spellcheck.maxCollations=1&spellcheck.collateExtendedResults=true&qt=spellCheckCompRH&q=teststop%3Ametnoia&spellcheck.collateMaxCollectDocs=5} hits=0 status=0 QTime=17
[junit4] 2> 730760 T3219 C2987 oasc.SolrCore.execute [collection1] webapp=null path=null params={spellcheck=true&spellcheck.dictionary=direct&spellcheck.count=1&spellcheck.collate=true&spellcheck.maxCollationTries=1&spellcheck.maxCollations=1&spellcheck.collateExtendedResults=true&qt=spellCheckCompRH&q=teststop%3Ametnoia&spellcheck.collateMaxCollectDocs=7} hits=0 status=0 QTime=5
[junit4] 2> ASYNC NEW_CORE C2988 name=collection1 org.apache.solr.core.SolrCore@52b353f1
[junit4] 2> 730788 T3219 C2988 oasc.SolrCore.execute [collection1] webapp=null path=null params={spellcheck=true&spellcheck.dictionary=direct&spellcheck.count=1&spellcheck.collate=true&spellcheck.maxCollationTries=1&spellcheck.maxCollations=1&spellcheck.collateExtendedResults=true&qt=spellCheckCompRH&q=teststop%3Ametnoia&spellcheck.collateMaxCollectDocs=7} hits=0 status=0 QTime=27
[junit4] 2> 730793 T3219 C2988 oasc.SolrCore.execute [collection1] webapp=null path=null params={spellcheck=true&spellcheck.dictionary=direct&spellcheck.count=1&spellcheck.collate=true&spellcheck.maxCollationTries=1&spellcheck.maxCollations=1&spellcheck.collateExtendedResults=true&qt=spellCheckCompRH&q=teststop%3Ametnoia&spellcheck.collateMaxCollectDocs=16} hits=0 status=0 QTime=4
[junit4] 2> 730809 T3219 C2988 oasc.SolrCore.execute [collection1] webapp=null path=null params={spellcheck=true&spellcheck.dictionary=direct&spellcheck.count=1&spellcheck.collate=true&spellcheck.maxCollationTries=1&spellcheck.maxCollations=1&spellcheck.collateExtendedResults=true&qt=spellCheckCompRH&q=teststop%3Ametnoia&spellcheck.collateMaxCollectDocs=4} hits=0 status=0 QTime=15
[junit4] 2> 730814 T3219 C2988 oasc.SolrCore.execute [collection1] webapp=null path=null params={spellcheck=true&spellcheck.dictionary=direct&spellcheck.count=1&spellcheck.collate=true&spellcheck.maxCollationTries=1&spellcheck.maxCollations=1&spellcheck.collateExtendedResults=true&qt=spellCheckCompRH&q=teststop%3Ametnoia&spellcheck.collateMaxCollectDocs=4} hits=0 status=0 QTime=4
[junit4] 2> 730835 T3219 C2988 oasc.SolrCore.execute [collection1] webapp=null path=null params={spellcheck=true&spellcheck.dictionary=direct&spellcheck.count=1&spellcheck.collate=true&spellcheck.maxCollationTries=1&spellcheck.maxCollations=1&spellcheck.collateExtendedResults=true&qt=spellCheckCompRH&q=teststop%3Ametnoia&spellcheck.collateMaxCollectDocs=5} hits=0 status=0 QTime=20
[junit4] 2> 730840 T3219 C2988 oasc.SolrCore.execute [collection1] webapp=null path=null params={spellcheck=true&spellcheck.dictionary=direct&spellcheck.count=1&spellcheck.collate=true&spellcheck.maxCollationTries=1&spellcheck.maxCollations=1&spellcheck.collateExtendedResults=true&qt=spellCheckCompRH&q=teststop%3Ametnoia&spellcheck.collateMaxCollectDocs=4} hits=0 status=0 QTime=4
[junit4] 2> 730846 T3219 C2988 oasc.SolrCore.execute [collection1] webapp=null path=null params={spellcheck=true&spellcheck.dictionary=direct&spellcheck.count=1&spellcheck.collate=true&spellcheck.maxCollationTries=1&spellcheck.maxCollations=1&spellcheck.collateExtendedResults=true&qt=spellCheckCompRH&q=teststop%3Ametnoia&spellcheck.collateMaxCollectDocs=7} hits=0 status=0 QTime=4
[junit4] 2> 730863 T3219 C2988 oasc.SolrCore.execute [collection1] webapp=null path=null params={spellcheck=true&spellcheck.dictionary=direct&spellcheck.count=1&spellcheck.collate=true&spellcheck.maxCollationTries=1&spellcheck.maxCollations=1&spellcheck.collateExtendedResults=true&qt=spellCheckCompRH&q=teststop%3Ametnoia&spellcheck.collateMaxCollectDocs=5} hits=0 status=0 QTime=15
[junit4] 2> 730868 T3219 C2988 oasc.SolrCore.execute [collection1] webapp=null path=null params={spellcheck=true&spellcheck.dictionary=direct&spellcheck.count=1&spellcheck.collate=true&spellcheck.maxCollationTries=1&spellcheck.maxCollations=1&spellcheck.collateExtendedResults=true&qt=spellCheckCompRH&q=teststop%3Ametnoia&spellcheck.collateMaxCollectDocs=15} hits=0 status=0 QTime=4
[junit4] 2> 730873 T3219 C2988 oasc.SolrCore.execute [collection1] webapp=null path=null params={spellcheck=true&spellcheck.dictionary=direct&spellcheck.count=1&spellcheck.collate=true&spellcheck.maxCollationTries=1&spellcheck.maxCollations=1&spellcheck.collateExtendedResults=true&qt=spellCheckCompRH&q=teststop%3Ametnoia&spellcheck.collateMaxCollectDocs=13} hits=0 status=0 QTime=4
[junit4] 2> 730895 T3219 C2988 oasc.SolrCore.execute [collection1] webapp=null path=null params={spellcheck=true&spellcheck.dictionary=direct&spellcheck.count=1&spellcheck.collate=true&spellcheck.maxCollationTries=1&spellcheck.maxCollations=1&spellcheck.collateExtendedResults=true&qt=spellCheckCompRH&q=teststop%3Ametnoia&spellcheck.collateMaxCollectDocs=4} hits=0 status=0 QTime=5
[junit4] 2> 730900 T3219 C2988 oasc.SolrCore.execute [collection1] webapp=null path=null params={spellcheck=true&spellcheck.dictionary=direct&spellcheck.count=1&spellcheck.collate=true&spellcheck.maxCollationTries=1&spellcheck.maxCollations=1&spellcheck.collateExtendedResults=true&qt=spellCheckCompRH&q=teststop%3Ametnoia&spellcheck.collateMaxCollectDocs=7} hits=0 status=0 QTime=4
[junit4] 2> 730905 T3219 C2988 oasc.SolrCore.execute [collection1] webapp=null path=null params={spellcheck=true&spellcheck.dictionary=direct&spellcheck.count=1&spellcheck.collate=true&spellcheck.maxCollationTries=1&spellcheck.maxCollations=1&spellcheck.collateExtendedResults=true&qt=spellCheckCompRH&q=teststop%3Ametnoia&spellcheck.collateMaxCollectDocs=2} hits=0 status=0 QTime=4
[junit4] 2> 730932 T3219 C2988 oasc.SolrCore.execute [collection1] webapp=null path=null params={spellcheck=true&spellcheck.dictionary=direct&spellcheck.count=1&spellcheck.collate=true&spellcheck.maxCollationTries=1&spellcheck.maxCollations=1&spellcheck.collateExtendedResults=true&qt=spellCheckCompRH&q=teststop%3Ametnoia&spellcheck.collateMaxCollectDocs=16} hits=0 status=0 QTime=26
[junit4] 2> 730937 T3219 C2988 oasc.SolrCore.execute [collection1] webapp=null path=null params={spellcheck=true&spellcheck.dictionary=direct&spellcheck.count=1&spellcheck.collate=true&spellcheck.maxCollationTries=1&spellcheck.maxCollations=1&spellcheck.collateExtendedResults=true&qt=spellCheckCompRH&q=teststop%3Ametnoia&spellcheck.collateMaxCollectDocs=3} hits=0 status=0 QTime=4
[junit4] 2> 730943 T3219 C2988 oasc.SolrCore.execute [collection1] webapp=null path=null params={spellcheck=true&spellcheck.dictionary=direct&spellcheck.count=1&spellcheck.collate=true&spellcheck.maxCollationTries=1&spellcheck.maxCollations=1&spellcheck.collateExtendedResults=true&qt=spellCheckCompRH&q=teststop%3Ametnoia&spellcheck.collateMaxCollectDocs=14} hits=0 status=0 QTime=5
[junit4] 2> 730948 T3219 C2988 oasc.SolrCore.execute [collection1] webapp=null path=null params={spellcheck=true&spellcheck.dictionary=direct&spellcheck.count=1&spellcheck.collate=true&spellcheck.maxCollationTries=1&spellcheck.maxCollations=1&spellcheck.collateExtendedResults=true&qt=spellCheckCompRH&q=teststop%3Ametnoia&spellcheck.collateMaxCollectDocs=2} hits=0 status=0 QTime=4
[junit4] 2> 730953 T3219 C2988 oasc.SolrCore.execute [collection1] webapp=null path=null params={spellcheck=true&spellcheck.dictionary=direct&spellcheck.count=1&spellcheck.collate=true&spellcheck.maxCollationTries=1&spellcheck.maxCollations=1&spellcheck.collateExtendedResults=true&qt=spellCheckCompRH&q=teststop%3Ametnoia&spellcheck.collateMaxCollectDocs=4} hits=0 status=0 QTime=4
[junit4] 2> 730971 T3219 C2988 oasc.SolrCore.execute [collection1] webapp=null path=null params={spellcheck=true&spellcheck.dictionary=direct&spellcheck.count=1&spellcheck.collate=true&spellcheck.maxCollationTries=1&spellcheck.maxCollations=1&spellcheck.collateExtendedResults=true&qt=spellCheckCompRH&q=teststop%3Ametnoia&spellcheck.collateMaxCollectDocs=16} hits=0 status=0 QTime=4
[junit4] 2> 730991 T3219 C2988 oasc.SolrCore.execute [collection1] webapp=null path=null params={spellcheck=true&spellcheck.dictionary=direct&spellcheck.count=1&spellcheck.collate=true&spellcheck.maxCollationTries=1&spellcheck.maxCollations=1&spellcheck.collateExtendedResults=true&qt=spellCheckCompRH&q=teststop%3Ametnoia&spellcheck.collateMaxCollectDocs=4} hits=0 status=0 QTime=19
[junit4] 2> 731000 T3219 C2988 oasc.SolrCore.execute [collection1] webapp=null path=null params={spellcheck=true&spellcheck.dictionary=direct&spellcheck.count=1&spellcheck.collate=true&spellcheck.maxCollationTries=1&spellcheck.maxCollations=1&spellcheck.collateExtendedResults=true&qt=spellCheckCompRH&q=teststop%3Ametnoia&spellcheck.collateMaxCollectDocs=9} hits=0 status=0 QTime=7
[junit4] 2> 731021 T3219 C2988 oasc.SolrCore.execute [collection1] webapp=null path=null params={spellcheck=true&spellcheck.dictionary=direct&spellcheck.count=1&spellcheck.collate=true&spellcheck.maxCollationTries=1&spellcheck.maxCollations=1&spellcheck.collateExtendedResults=true&qt=spellCheckCompRH&q=teststop%3Ametnoia&spellcheck.collateMaxCollectDocs=8} hits=0 status=0 QTime=20
[junit4] 2> 731026 T3219 C2988 oasc.SolrCore.execute [collection1] webapp=null path=null params={spellcheck=true&spellcheck.dictionary=direct&spellcheck.count=1&spellcheck.collate=true&spellcheck.maxCollationTries=1&spellcheck.maxCollations=1&spellcheck.collateExtendedResults=true&qt=spellCheckCompRH&q=teststop%3Ametnoia&spellcheck.collateMaxCollectDocs=13} hits=0 status=0 QTime=4
[junit4] 2> 731031 T3219 C2988 oasc.SolrCore.execute [collection1] webapp=null path=null params={spellcheck=true&spellcheck.dictionary=direct&spellcheck.count=1&spellcheck.collate=true&spellcheck.maxCollationTries=1&spellcheck.maxCollations=1&spellcheck.collateExtendedResults=true&qt=spellCheckCompRH&q=teststop%3Ametnoia&spellcheck.collateMaxCollectDocs=1} hits=0 status=0 QTime=4
[junit4] 2> ASYNC NEW_CORE C2989 name=collection1 org.apache.solr.core.SolrCore@52b353f1
[junit4] 2> 731050 T3219 C2989 oasc.SolrCore.execute [collection1] webapp=null path=null params={spellcheck=true&spellcheck.dictionary=direct&spellcheck.count=1&spellcheck.collate=true&spellcheck.maxCollationTries=1&spellcheck.maxCollations=1&spellcheck.collateExtendedResults=true&qt=spellCheckCompRH&q=teststop%3Aeverother&spellcheck.collateMaxCollectDocs=5} hits=0 status=0 QTime=18
[junit4] 2> 731051 T3219 oas.SolrTestCaseJ4.assertQ ERROR REQUEST FAILED: xpath=//lst[@name='spellcheck']/lst[@name='suggestions']/lst[@name='collation']/int[@name='hits' and 6 <= . and . <= 10]
[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">18</int></lst><result name="response" numFound="0" start="0"></result><lst name="spellcheck"><lst name="suggestions"><lst name="everother"><int name="numFound">1</int><int name="startOffset">9</int><int name="endOffset">18</int><arr name="suggestion"><str>everyother</str></arr></lst><lst name="collation"><str name="collationQuery">teststop:everyother</str><int name="hits">12</int><lst name="misspellingsAndCorrections"><str name="everother">everyother</str></lst></lst></lst></lst>
[junit4] 2> </response>
[junit4] 2>
[junit4] 2> request was:spellcheck=true&spellcheck.dictionary=direct&spellcheck.count=1&spellcheck.collate=true&spellcheck.maxCollationTries=1&spellcheck.maxCollations=1&spellcheck.collateExtendedResults=true&qt=spellCheckCompRH&q=teststop%3Aeverother&spellcheck.collateMaxCollectDocs=5
[junit4] 2> 731052 T3219 oasc.SolrException.log ERROR REQUEST FAILED: spellcheck=true&spellcheck.dictionary=direct&spellcheck.count=1&spellcheck.collate=true&spellcheck.maxCollationTries=1&spellcheck.maxCollations=1&spellcheck.collateExtendedResults=true&qt=spellCheckCompRH&q=teststop%3Aeverother&spellcheck.collateMaxCollectDocs=5:java.lang.RuntimeException: REQUEST FAILED: xpath=//lst[@name='spellcheck']/lst[@name='suggestions']/lst[@name='collation']/int[@name='hits' and 6 <= . and . <= 10]
[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">18</int></lst><result name="response" numFound="0" start="0"></result><lst name="spellcheck"><lst name="suggestions"><lst name="everother"><int name="numFound">1</int><int name="startOffset">9</int><int name="endOffset">18</int><arr name="suggestion"><str>everyother</str></arr></lst><lst name="collation"><str name="collationQuery">teststop:everyother</str><int name="hits">12</int><lst name="misspellingsAndCorrections"><str name="everother">everyother</str></lst></lst></lst></lst>
[junit4] 2> </response>
[junit4] 2>
[junit4] 2> request was:spellcheck=true&spellcheck.dictionary=direct&spellcheck.count=1&spellcheck.collate=true&spellcheck.maxCollationTries=1&spellcheck.maxCollations=1&spellcheck.collateExtendedResults=true&qt=spellCheckCompRH&q=teststop%3Aeverother&spellcheck.collateMaxCollectDocs=5
[junit4] 2> at org.apache.solr.SolrTestCaseJ4.assertQ(SolrTestCaseJ4.java:630)
[junit4] 2> at org.apache.solr.SolrTestCaseJ4.assertQ(SolrTestCaseJ4.java:604)
[junit4] 2> at org.apache.solr.spelling.SpellCheckCollatorTest.testEstimatedHitCounts(SpellCheckCollatorTest.java:521)
[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:491)
[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> 731053 T3219 oas.SolrTestCaseJ4.tearDown ###Ending testEstimatedHitCounts
[junit4] 2> NOTE: reproduce with: ant test -Dtestcase=SpellCheckCollatorTest -Dtests.method=testEstimatedHitCounts -Dtests.seed=EAD13915CDD8580D -Dtests.multiplier=3 -Dtests.slow=true -Dtests.locale=en_SG -Dtests.timezone=Australia/Lindeman -Dtests.file.encoding=UTF-8
[junit4] ERROR 0.75s J0 | SpellCheckCollatorTest.testEstimatedHitCounts <<<
[junit4] > Throwable #1: java.lang.RuntimeException: Exception during query
[junit4] > at __randomizedtesting.SeedInfo.seed([EAD13915CDD8580D:DB6A872068E748DD]:0)
[junit4] > at org.apache.solr.SolrTestCaseJ4.assertQ(SolrTestCaseJ4.java:637)
[junit4] > at org.apache.solr.SolrTestCaseJ4.assertQ(SolrTestCaseJ4.java:604)
[junit4] > at org.apache.solr.spelling.SpellCheckCollatorTest.testEstimatedHitCounts(SpellCheckCollatorTest.java:521)
[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' and 6 <= . and . <= 10]
[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">18</int></lst><result name="response" numFound="0" start="0"></result><lst name="spellcheck"><lst name="suggestions"><lst name="everother"><int name="numFound">1</int><int name="startOffset">9</int><int name="endOffset">18</int><arr name="suggestion"><str>everyother</str></arr></lst><lst name="collation"><str name="collationQuery">teststop:everyother</str><int name="hits">12</int><lst name="misspellingsAndCorrections"><str name="everother">everyother</str></lst></lst></lst></lst>
[junit4] > </response>
[junit4] > request was:spellcheck=true&spellcheck.dictionary=direct&spellcheck.count=1&spellcheck.collate=true&spellcheck.maxCollationTries=1&spellcheck.maxCollations=1&spellcheck.collateExtendedResults=true&qt=spellCheckCompRH&q=teststop%3Aeverother&spellcheck.collateMaxCollectDocs=5
[junit4] > at org.apache.solr.SolrTestCaseJ4.assertQ(SolrTestCaseJ4.java:630)
[junit4] > ... 42 more
[junit4] 2> 731137 T3219 oas.SolrTestCaseJ4.setUp ###Starting testContextSensitiveCollate
[junit4] 2> 731146 T3219 C2989 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=9
[junit4] 2> 731154 T3219 C2989 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=6
[junit4] 2> 731324 T3219 C2989 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=152
[junit4] 2> 731327 T3219 C2989 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=1
[junit4] 2> 731329 T3219 oas.SolrTestCaseJ4.tearDown ###Ending testContextSensitiveCollate
[junit4] 2> 731334 T3219 oas.SolrTestCaseJ4.setUp ###Starting testCollateWithGrouping
[junit4] 2> 731403 T3219 oas.SolrTestCaseJ4.tearDown ###Ending testCollateWithGrouping
[junit4] 2> 731408 T3219 oas.SolrTestCaseJ4.setUp ###Starting testCollateWithOverride
[junit4] 2> 731424 T3219 C2989 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=16
[junit4] 2> 731437 T3219 C2989 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=12
[junit4] 2> 731438 T3219 oas.SolrTestCaseJ4.tearDown ###Ending testCollateWithOverride
[junit4] 2> 731455 T3219 oas.SolrTestCaseJ4.setUp ###Starting testCollateWithFilter
[junit4] 2> 731516 T3219 oas.SolrTestCaseJ4.tearDown ###Ending testCollateWithFilter
[junit4] 2> 731520 T3219 oas.SolrTestCaseJ4.setUp ###Starting testExtendedCollate
[junit4] 2> 731603 T3219 oas.SolrTestCaseJ4.tearDown ###Ending testExtendedCollate
[junit4] 2> 731605 T3219 oas.SolrTestCaseJ4.deleteCore ###deleteCore
[junit4] 2> 731605 T3219 oasc.CoreContainer.shutdown Shutting down CoreContainer instance=773331102
[junit4] 2> 731605 T3219 oasc.SolrCore.close [collection1] CLOSING SolrCore org.apache.solr.core.SolrCore@52b353f1
[junit4] 2> 731607 T3219 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> 731607 T3219 oasu.SolrCoreState.decrefSolrCoreState Closing SolrCoreState
[junit4] 2> 731608 T3219 oasu.DefaultSolrCoreState.closeIndexWriter SolrCoreState ref count has reached 0 - closing IndexWriter
[junit4] 2> 731608 T3219 oasu.DefaultSolrCoreState.closeIndexWriter closing IndexWriter with IndexWriterCloser
[junit4] 2> 731608 T3219 oasc.SolrCore.closeSearcher [collection1] Closing main searcher on request.
[junit4] 2> 731609 T3219 oasc.CachingDirectoryFactory.close Closing MockDirectoryFactory - 2 directories currently being tracked
[junit4] 2> 731609 T3219 oasc.CachingDirectoryFactory.closeCacheValue looking to close /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./solrtest-SpellCheckCollatorTest-1378632037958 [CachedDir<<refCount=0;path=/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./solrtest-SpellCheckCollatorTest-1378632037958;done=false>>]
[junit4] 2> 731609 T3219 oasc.CachingDirectoryFactory.close Closing directory: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./solrtest-SpellCheckCollatorTest-1378632037958
[junit4] 2> 731610 T3219 oasc.CachingDirectoryFactory.closeCacheValue looking to close /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./solrtest-SpellCheckCollatorTest-1378632037958/index [CachedDir<<refCount=0;path=/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./solrtest-SpellCheckCollatorTest-1378632037958/index;done=false>>]
[junit4] 2> 731610 T3219 oasc.CachingDirectoryFactory.close Closing directory: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./solrtest-SpellCheckCollatorTest-1378632037958/index
[junit4] 2> NOTE: test params are: codec=HighCompressionCompressingStoredFields(storedFieldsFormat=CompressingStoredFieldsFormat(compressionMode=HIGH_COMPRESSION, chunkSize=237), termVectorsFormat=CompressingTermVectorsFormat(compressionMode=HIGH_COMPRESSION, chunkSize=237)), sim=DefaultSimilarity, locale=en_SG, timezone=Australia/Lindeman
[junit4] 2> NOTE: Linux 3.2.0-52-generic amd64/Oracle Corporation 1.8.0-ea (64-bit)/cpus=8,threads=1,free=54078840,total=183742464
[junit4] 2> NOTE: All tests run in this JVM: [TestCoreContainer, TestJmxMonitoredMap, SolrTestCaseJ4Test, ZkControllerTest, TestLMDirichletSimilarityFactory, ClusterStateTest, DistributedTermsComponentTest, TestJoin, CacheHeaderTest, CopyFieldTest, FileBasedSpellCheckerTest, SystemInfoHandlerTest, HdfsCollectionsAPIDistributedZkTest, SearchHandlerTest, ZkCLITest, ResponseLogComponentTest, HdfsBasicDistributedZk2Test, TestSchemaVersionResource, TestSchemaSimilarityResource, MBeansHandlerTest, LeaderElectionTest, DOMUtilTest, TestQueryUtils, StatelessScriptUpdateProcessorFactoryTest, TestSearchPerf, ResourceLoaderTest, URLClassifyProcessorTest, LoggingHandlerTest, TestSolrXmlPersistor, DistributedQueryElevationComponentTest, UnloadDistributedZkTest, SliceStateTest, MoreLikeThisHandlerTest, TestFunctionQuery, TestElisionMultitermQuery, DateMathParserTest, SuggesterFSTTest, HdfsLockFactoryTest, BinaryUpdateRequestHandlerTest, PolyFieldTest, WordBreakSolrSpellCheckerTest, TestSort, DocumentBuilderTest, FastVectorHighlighterTest, DocValuesMissingTest, ExternalFileFieldSortTest, UpdateParamsTest, SolrCoreTest, TestPostingsSolrHighlighter, CachingDirectoryFactoryTest, ScriptEngineTest, TestMergePolicyConfig, TestSolrXml, QueryParsingTest, DirectUpdateHandlerOptimizeTest, OverseerCollectionProcessorTest, OverseerTest, SyncSliceTest, TestShardHandlerFactory, TestSolrDeletionPolicy1, SpatialFilterTest, PrimitiveFieldTypeTest, PreAnalyzedUpdateProcessorTest, AutoCommitTest, SpellPossibilityIteratorTest, TestDynamicFieldResource, RegexBoostProcessorTest, TestPerFieldSimilarity, TestBM25SimilarityFactory, SoftAutoCommitTest, ShowFileRequestHandlerTest, TestImplicitCoreProperties, TestReversedWildcardFilterFactory, CircularListTest, TestFieldTypeResource, SimpleFacetsTest, TestGroupingSearch, SliceStateUpdateTest, TestReplicationHandler, BasicDistributedZkTest, BasicZkTest, TestRandomFaceting, TestDistributedGrouping, TestHashPartitioner, TestStressReorder, StatsComponentTest, QueryElevationComponentTest, BadIndexSchemaTest, ConvertedLegacyTest, TestIndexSearcher, CurrencyFieldOpenExchangeTest, SolrIndexSplitterTest, SignatureUpdateProcessorFactoryTest, SpellCheckCollatorTest]
[junit4] Completed on J0 in 2.32s, 8 tests, 1 error <<< FAILURES!
[...truncated 394 lines...]
BUILD FAILED
/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/build.xml:396: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/build.xml:376: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/build.xml:39: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build.xml:189: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/common-build.xml:455: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/lucene/common-build.xml:1230: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/lucene/common-build.xml:873: There were test failures: 324 suites, 1413 tests, 1 error, 38 ignored (6 assumptions)
Total time: 35 minutes 51 seconds
Build step 'Invoke Ant' marked build as failure
Description set: Java: 64bit/jdk1.8.0-ea-b102 -XX:+UseCompressedOops -XX:+UseSerialGC
Archiving artifacts
Recording test results
Email was triggered for: Failure
Sending email for trigger: Failure
[JENKINS] Lucene-Solr-trunk-Linux (32bit/jdk1.8.0-ea-b102) - Build
# 7372 - Still Failing!
Posted by Policeman Jenkins Server <je...@thetaphi.de>.
Build: http://jenkins.thetaphi.de/job/Lucene-Solr-trunk-Linux/7372/
Java: 32bit/jdk1.8.0-ea-b102 -server -XX:+UseConcMarkSweepGC
1 tests failed.
FAILED: org.apache.solr.client.solrj.embedded.SolrExampleJettyTest.testChineseDefaults
Error Message:
IOException occured when talking to server at: https://127.0.0.1:32992/solr/collection1
Stack Trace:
org.apache.solr.client.solrj.SolrServerException: IOException occured when talking to server at: https://127.0.0.1:32992/solr/collection1
at __randomizedtesting.SeedInfo.seed([6EEA9062DF94C2A1:D4A98E25AC12477B]:0)
at org.apache.solr.client.solrj.impl.HttpSolrServer.request(HttpSolrServer.java:436)
at org.apache.solr.client.solrj.impl.HttpSolrServer.request(HttpSolrServer.java:180)
at org.apache.solr.client.solrj.request.AbstractUpdateRequest.process(AbstractUpdateRequest.java:117)
at org.apache.solr.client.solrj.SolrServer.commit(SolrServer.java:168)
at org.apache.solr.client.solrj.SolrServer.commit(SolrServer.java:146)
at org.apache.solr.client.solrj.SolrExampleTests.testChineseDefaults(SolrExampleTests.java:1280)
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:491)
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: org.apache.http.NoHttpResponseException: The target server failed to respond
at org.apache.http.impl.conn.DefaultHttpResponseParser.parseHead(DefaultHttpResponseParser.java:95)
at org.apache.http.impl.conn.DefaultHttpResponseParser.parseHead(DefaultHttpResponseParser.java:62)
at org.apache.http.impl.io.AbstractMessageParser.parse(AbstractMessageParser.java:254)
at org.apache.http.impl.AbstractHttpClientConnection.receiveResponseHeader(AbstractHttpClientConnection.java:289)
at org.apache.http.impl.conn.DefaultClientConnection.receiveResponseHeader(DefaultClientConnection.java:252)
at org.apache.http.impl.conn.ManagedClientConnectionImpl.receiveResponseHeader(ManagedClientConnectionImpl.java:191)
at org.apache.http.protocol.HttpRequestExecutor.doReceiveResponse(HttpRequestExecutor.java:300)
at org.apache.http.protocol.HttpRequestExecutor.execute(HttpRequestExecutor.java:127)
at org.apache.http.impl.client.DefaultRequestDirector.tryExecute(DefaultRequestDirector.java:717)
at org.apache.http.impl.client.DefaultRequestDirector.execute(DefaultRequestDirector.java:522)
at org.apache.http.impl.client.AbstractHttpClient.execute(AbstractHttpClient.java:906)
at org.apache.http.impl.client.AbstractHttpClient.execute(AbstractHttpClient.java:805)
at org.apache.http.impl.client.AbstractHttpClient.execute(AbstractHttpClient.java:784)
at org.apache.solr.client.solrj.impl.HttpSolrServer.request(HttpSolrServer.java:365)
... 45 more
Build Log:
[...truncated 10889 lines...]
[junit4] Suite: org.apache.solr.client.solrj.embedded.SolrExampleJettyTest
[junit4] 2> 34113 T70 oas.SolrJettyTestBase.beforeSolrJettyTestBase Randomized ssl (true) and clientAuth (false)
[junit4] 2> 34114 T70 oas.SolrTestCaseJ4.initCore ####initCore
[junit4] 2> Creating dataDir: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-solrj/test/J1/./solrtest-SolrExampleJettyTest-1378638202911
[junit4] 2> 34114 T70 oas.SolrTestCaseJ4.initCore ####initCore end
[junit4] 2> 34120 T70 oejs.Server.doStart jetty-8.1.10.v20130312
[junit4] 2> 34310 T70 oejus.SslContextFactory.doStart Enabled Protocols [SSLv2Hello, SSLv3, TLSv1, TLSv1.1, TLSv1.2] of [SSLv2Hello, SSLv3, TLSv1, TLSv1.1, TLSv1.2]
[junit4] 2> 34314 T70 oejs.AbstractConnector.doStart Started SslSelectChannelConnector@127.0.0.1:32992
[junit4] 2> 34315 T70 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4] 2> 34315 T70 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4] 2> 34315 T70 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/example/solr
[junit4] 2> 34316 T70 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/example/solr/'
[junit4] 2> 34333 T70 oasc.ConfigSolr.fromFile Loading container configuration from /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/example/solr/solr.xml
[junit4] 2> 34382 T70 oasc.ConfigSolrXml.<init> Config-defined core root directory:
[junit4] 2> 34383 T70 oasc.CoreContainer.<init> New CoreContainer 20669492
[junit4] 2> 34383 T70 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/example/solr/]
[junit4] 2> 34384 T70 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 0
[junit4] 2> 34384 T70 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4] 2> 34384 T70 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 0
[junit4] 2> 34384 T70 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4] 2> 34385 T70 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4] 2> 34385 T70 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4] 2> 34385 T70 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4] 2> 34385 T70 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4] 2> 34386 T70 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4] 2> 34386 T70 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=0&connTimeout=0&retry=false
[junit4] 2> 34388 T70 oasl.LogWatcher.createWatcher SLF4J impl is org.slf4j.impl.Log4jLoggerFactory
[junit4] 2> 34389 T70 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
[junit4] 2> 34390 T70 oasc.CorePropertiesLocator.discover Looking for core definitions underneath /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/example/solr
[junit4] 2> 34391 T70 oasc.CorePropertiesLocator.discoverUnder Found core collection1 in /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/example/solr/collection1/
[junit4] 2> 34394 T70 oasc.CorePropertiesLocator.discover Found 1 core definitions
[junit4] 2> 34401 T80 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/example/solr/collection1
[junit4] 2> 34402 T80 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/example/solr/collection1/'
[junit4] 2> 34436 T80 oasc.SolrConfig.initLibs Adding specified lib dirs to ClassLoader
[junit4] 2> 34436 T80 oasc.SolrResourceLoader.addToClassLoader WARN No files added to classloader from lib: ../../../contrib/extraction/lib (resolved as: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/example/solr/collection1/../../../contrib/extraction/lib).
[junit4] 2> 34437 T80 oasc.SolrResourceLoader.addToClassLoader WARN Can't find (or read) directory to add to classloader: ../../../dist/ (resolved as: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/example/solr/collection1/../../../dist).
[junit4] 2> 34437 T80 oasc.SolrResourceLoader.addToClassLoader WARN No files added to classloader from lib: ../../../contrib/clustering/lib/ (resolved as: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/example/solr/collection1/../../../contrib/clustering/lib).
[junit4] 2> 34437 T80 oasc.SolrResourceLoader.addToClassLoader WARN Can't find (or read) directory to add to classloader: ../../../dist/ (resolved as: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/example/solr/collection1/../../../dist).
[junit4] 2> 34438 T80 oasc.SolrResourceLoader.addToClassLoader WARN No files added to classloader from lib: ../../../contrib/langid/lib/ (resolved as: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/example/solr/collection1/../../../contrib/langid/lib).
[junit4] 2> 34438 T80 oasc.SolrResourceLoader.addToClassLoader WARN Can't find (or read) directory to add to classloader: ../../../dist/ (resolved as: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/example/solr/collection1/../../../dist).
[junit4] 2> 34438 T80 oasc.SolrResourceLoader.addToClassLoader WARN No files added to classloader from lib: ../../../contrib/velocity/lib (resolved as: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/example/solr/collection1/../../../contrib/velocity/lib).
[junit4] 2> 34438 T80 oasc.SolrResourceLoader.addToClassLoader WARN Can't find (or read) directory to add to classloader: ../../../dist/ (resolved as: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/example/solr/collection1/../../../dist).
[junit4] 2> 34464 T80 oasu.SolrIndexConfig.<init> IndexWriter infoStream solr logging is enabled
[junit4] 2> 34466 T80 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_50
[junit4] 2> 34531 T80 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4] 2> 34532 T80 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4] 2> 34549 T80 oass.IndexSchema.readSchema [null] Schema name=example
[junit4] 2> 34832 T80 oass.IndexSchema.readSchema unique key field: id
[junit4] 2> 34846 T80 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4] 2> 34850 T80 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4] 2> 34877 T80 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4] 2> 34878 T80 oasc.SolrCore.<init> [collection1] Opening new SolrCore at /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/example/solr/collection1/, dataDir=/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-solrj/test/J1/solrtest-SolrExampleJettyTest-1378638202911/
[junit4] 2> 34878 T80 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@15f13d6
[junit4] 2> 34879 T80 oasc.SolrCore.initListeners [collection1] Added SolrEventListener for newSearcher: org.apache.solr.core.QuerySenderListener{queries=[]}
[junit4] 2> 34879 T80 oasc.SolrCore.initListeners [collection1] Added SolrEventListener for firstSearcher: org.apache.solr.core.QuerySenderListener{queries=[{q=static firstSearcher warming in solrconfig.xml}]}
[junit4] 2> 34888 T80 oasc.CachingDirectoryFactory.get return new directory for /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-solrj/test/J1/solrtest-SolrExampleJettyTest-1378638202911
[junit4] 2> 34888 T80 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-solrj/test/J1/solrtest-SolrExampleJettyTest-1378638202911/index/
[junit4] 2> 34889 T80 oasc.SolrCore.initIndex WARN [collection1] Solr index directory '/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-solrj/test/J1/solrtest-SolrExampleJettyTest-1378638202911/index' doesn't exist. Creating new index...
[junit4] 2> 34889 T80 oasc.CachingDirectoryFactory.get return new directory for /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-solrj/test/J1/solrtest-SolrExampleJettyTest-1378638202911/index
[junit4] 2> 34890 T80 oasu.LoggingInfoStream.message [IFD][coreLoadExecutor-18-thread-1]: init: current segments file is "null"; deletionPolicy=org.apache.solr.core.IndexDeletionPolicyWrapper@16174d7
[junit4] 2> 34890 T80 oasu.LoggingInfoStream.message [IFD][coreLoadExecutor-18-thread-1]: now checkpoint "" [0 segments ; isCommit = false]
[junit4] 2> 34890 T80 oasu.LoggingInfoStream.message [IFD][coreLoadExecutor-18-thread-1]: 0 msec to checkpoint
[junit4] 2> 34891 T80 oasu.LoggingInfoStream.message [IW][coreLoadExecutor-18-thread-1]: init: create=true
[junit4] 2> 34891 T80 oasu.LoggingInfoStream.message [IW][coreLoadExecutor-18-thread-1]:
[junit4] 2> dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@186207d lockFactory=org.apache.lucene.store.NativeFSLockFactory@101ac3)
[junit4] 2> index=
[junit4] 2> version=5.0-SNAPSHOT
[junit4] 2> matchVersion=LUCENE_50
[junit4] 2> analyzer=null
[junit4] 2> ramBufferSizeMB=100.0
[junit4] 2> maxBufferedDocs=-1
[junit4] 2> maxBufferedDeleteTerms=-1
[junit4] 2> mergedSegmentWarmer=null
[junit4] 2> delPolicy=org.apache.solr.core.IndexDeletionPolicyWrapper
[junit4] 2> commit=null
[junit4] 2> openMode=CREATE
[junit4] 2> similarity=org.apache.lucene.search.similarities.DefaultSimilarity
[junit4] 2> mergeScheduler=ConcurrentMergeScheduler: maxThreadCount=1, maxMergeCount=2, mergeThreadPriority=-1
[junit4] 2> default WRITE_LOCK_TIMEOUT=1000
[junit4] 2> writeLockTimeout=1000
[junit4] 2> codec=Lucene45
[junit4] 2> infoStream=org.apache.solr.update.LoggingInfoStream
[junit4] 2> mergePolicy=[TieredMergePolicy: maxMergeAtOnce=10, maxMergeAtOnceExplicit=30, maxMergedSegmentMB=5120.0, floorSegmentMB=2.0, forceMergeDeletesPctAllowed=10.0, segmentsPerTier=10.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.0
[junit4] 2> indexerThreadPool=org.apache.lucene.index.ThreadAffinityDocumentsWriterThreadPool@4ef334
[junit4] 2> readerPooling=false
[junit4] 2> perThreadHardLimitMB=1945
[junit4] 2> useCompoundFile=false
[junit4] 2>
[junit4] 2> 34891 T80 oasu.LoggingInfoStream.message [IW][coreLoadExecutor-18-thread-1]: now flush at close waitForMerges=true
[junit4] 2> 34892 T80 oasu.LoggingInfoStream.message [IW][coreLoadExecutor-18-thread-1]: start flush: applyAllDeletes=true
[junit4] 2> 34892 T80 oasu.LoggingInfoStream.message [IW][coreLoadExecutor-18-thread-1]: index before flush
[junit4] 2> 34892 T80 oasu.LoggingInfoStream.message [DW][coreLoadExecutor-18-thread-1]: coreLoadExecutor-18-thread-1 startFullFlush
[junit4] 2> 34892 T80 oasu.LoggingInfoStream.message [DW][coreLoadExecutor-18-thread-1]: anyChanges? numDocsInRam=0 deletes=false hasTickets:false pendingChangesInFullFlush: false
[junit4] 2> 34892 T80 oasu.LoggingInfoStream.message [DW][coreLoadExecutor-18-thread-1]: coreLoadExecutor-18-thread-1 finishFullFlush success=true
[junit4] 2> 34893 T80 oasu.LoggingInfoStream.message [IW][coreLoadExecutor-18-thread-1]: apply all deletes during flush
[junit4] 2> 34893 T80 oasu.LoggingInfoStream.message [BD][coreLoadExecutor-18-thread-1]: prune sis=org.apache.lucene.index.SegmentInfos@7620fc minGen=9223372036854775807 packetCount=0
[junit4] 2> 34893 T80 oasu.LoggingInfoStream.message [CMS][coreLoadExecutor-18-thread-1]: now merge
[junit4] 2> 34893 T80 oasu.LoggingInfoStream.message [CMS][coreLoadExecutor-18-thread-1]: index:
[junit4] 2> 34894 T80 oasu.LoggingInfoStream.message [CMS][coreLoadExecutor-18-thread-1]: no more merges pending; now return
[junit4] 2> 34894 T80 oasu.LoggingInfoStream.message [IW][coreLoadExecutor-18-thread-1]: waitForMerges
[junit4] 2> 34894 T80 oasu.LoggingInfoStream.message [IW][coreLoadExecutor-18-thread-1]: waitForMerges done
[junit4] 2> 34894 T80 oasu.LoggingInfoStream.message [IW][coreLoadExecutor-18-thread-1]: now call final commit()
[junit4] 2> 34894 T80 oasu.LoggingInfoStream.message [IW][coreLoadExecutor-18-thread-1]: commit: start
[junit4] 2> 34895 T80 oasu.LoggingInfoStream.message [IW][coreLoadExecutor-18-thread-1]: commit: enter lock
[junit4] 2> 34895 T80 oasu.LoggingInfoStream.message [IW][coreLoadExecutor-18-thread-1]: commit: now prepare
[junit4] 2> 34895 T80 oasu.LoggingInfoStream.message [IW][coreLoadExecutor-18-thread-1]: prepareCommit: flush
[junit4] 2> 34895 T80 oasu.LoggingInfoStream.message [IW][coreLoadExecutor-18-thread-1]: index before flush
[junit4] 2> 34895 T80 oasu.LoggingInfoStream.message [DW][coreLoadExecutor-18-thread-1]: coreLoadExecutor-18-thread-1 startFullFlush
[junit4] 2> 34896 T80 oasu.LoggingInfoStream.message [DW][coreLoadExecutor-18-thread-1]: anyChanges? numDocsInRam=0 deletes=false hasTickets:false pendingChangesInFullFlush: false
[junit4] 2> 34896 T80 oasu.LoggingInfoStream.message [IW][coreLoadExecutor-18-thread-1]: apply all deletes during flush
[junit4] 2> 34896 T80 oasu.LoggingInfoStream.message [BD][coreLoadExecutor-18-thread-1]: prune sis=org.apache.lucene.index.SegmentInfos@7620fc minGen=9223372036854775807 packetCount=0
[junit4] 2> 34896 T80 oasu.LoggingInfoStream.message [DW][coreLoadExecutor-18-thread-1]: coreLoadExecutor-18-thread-1 finishFullFlush success=true
[junit4] 2> 34897 T80 oasu.LoggingInfoStream.message [IW][coreLoadExecutor-18-thread-1]: startCommit(): start
[junit4] 2> 34897 T80 oasu.LoggingInfoStream.message [IW][coreLoadExecutor-18-thread-1]: startCommit index= changeCount=1
[junit4] 2> 34897 T80 oasu.LoggingInfoStream.message [IW][coreLoadExecutor-18-thread-1]: done all syncs: []
[junit4] 2> 34897 T80 oasu.LoggingInfoStream.message [IW][coreLoadExecutor-18-thread-1]: commit: pendingCommit != null
[junit4] 2> 34898 T80 oasu.LoggingInfoStream.message [IW][coreLoadExecutor-18-thread-1]: commit: wrote segments file "segments_1"
[junit4] 2> 34898 T80 oasu.LoggingInfoStream.message [IFD][coreLoadExecutor-18-thread-1]: now checkpoint "" [0 segments ; isCommit = true]
[junit4] 2> 34898 T80 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
[junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@186207d lockFactory=org.apache.lucene.store.NativeFSLockFactory@101ac3),segFN=segments_1,generation=1}
[junit4] 2> 34898 T80 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4] 2> 34899 T80 oasu.LoggingInfoStream.message [IFD][coreLoadExecutor-18-thread-1]: 0 msec to checkpoint
[junit4] 2> 34899 T80 oasu.LoggingInfoStream.message [IW][coreLoadExecutor-18-thread-1]: commit: done
[junit4] 2> 34899 T80 oasu.LoggingInfoStream.message [IW][coreLoadExecutor-18-thread-1]: at close:
[junit4] 2> 34900 T80 oasc.SolrCore.initWriters created json: solr.JSONResponseWriter
[junit4] 2> 34900 T80 oasc.SolrCore.initWriters adding lazy queryResponseWriter: solr.VelocityResponseWriter
[junit4] 2> 34900 T80 oasc.SolrCore.initWriters created velocity: solr.VelocityResponseWriter
[junit4] 2> 34900 T80 oasc.SolrCore.initWriters created xslt: solr.XSLTResponseWriter
[junit4] 2> 34900 T80 oasr.XSLTResponseWriter.init xsltCacheLifetimeSeconds=5
[junit4] 2> 34903 T80 oasc.SolrCore.loadUpdateProcessorChains no updateRequestProcessorChain defined as default, creating implicit default
[junit4] 2> 34904 T80 oasc.RequestHandlers.initHandlersFromConfig created /select: solr.SearchHandler
[junit4] 2> 34904 T80 oasc.RequestHandlers.initHandlersFromConfig created /query: solr.SearchHandler
[junit4] 2> 34905 T80 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4] 2> 34905 T80 oasc.RequestHandlers.initHandlersFromConfig created /browse: solr.SearchHandler
[junit4] 2> 34905 T80 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4] 2> 34906 T80 oasc.RequestHandlers.initHandlersFromConfig created /update/json: solr.JsonUpdateRequestHandler
[junit4] 2> 34906 T80 oasc.RequestHandlers.initHandlersFromConfig created /update/csv: solr.CSVRequestHandler
[junit4] 2> 34906 T80 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.extraction.ExtractingRequestHandler
[junit4] 2> 34907 T80 oasc.RequestHandlers.initHandlersFromConfig created /update/extract: solr.extraction.ExtractingRequestHandler
[junit4] 2> 34907 T80 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.FieldAnalysisRequestHandler
[junit4] 2> 34907 T80 oasc.RequestHandlers.initHandlersFromConfig created /analysis/field: solr.FieldAnalysisRequestHandler
[junit4] 2> 34907 T80 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.DocumentAnalysisRequestHandler
[junit4] 2> 34908 T80 oasc.RequestHandlers.initHandlersFromConfig created /analysis/document: solr.DocumentAnalysisRequestHandler
[junit4] 2> 34908 T80 oasc.RequestHandlers.initHandlersFromConfig created /admin/: solr.admin.AdminHandlers
[junit4] 2> 34908 T80 oasc.RequestHandlers.initHandlersFromConfig created /admin/ping: solr.PingRequestHandler
[junit4] 2> 34909 T80 oasc.RequestHandlers.initHandlersFromConfig created /debug/dump: solr.DumpRequestHandler
[junit4] 2> 34909 T80 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4] 2> 34909 T80 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.SearchHandler
[junit4] 2> 34909 T80 oasc.RequestHandlers.initHandlersFromConfig created /spell: solr.SearchHandler
[junit4] 2> 34909 T80 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.SearchHandler
[junit4] 2> 34910 T80 oasc.RequestHandlers.initHandlersFromConfig created /tvrh: solr.SearchHandler
[junit4] 2> 34910 T80 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: org.apache.solr.handler.js.JavaScriptRequestHandler
[junit4] 2> 34910 T80 oasc.RequestHandlers.initHandlersFromConfig created /js: org.apache.solr.handler.js.JavaScriptRequestHandler
[junit4] 2> 34910 T80 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.SearchHandler
[junit4] 2> 34910 T80 oasc.RequestHandlers.initHandlersFromConfig created /terms: solr.SearchHandler
[junit4] 2> 34910 T80 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.SearchHandler
[junit4] 2> 34911 T80 oasc.RequestHandlers.initHandlersFromConfig created /elevate: solr.SearchHandler
[junit4] 2> 34913 T80 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4] 2> 34914 T80 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4] 2> 34916 T80 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4] 2> 34919 T80 oasu.CommitTracker.<init> Hard AutoCommit: if uncommited for 15000ms;
[junit4] 2> 34919 T80 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4] 2> 34920 T80 oasu.LoggingInfoStream.message [IFD][coreLoadExecutor-18-thread-1]: init: current segments file is "segments_1"; deletionPolicy=org.apache.solr.core.IndexDeletionPolicyWrapper@16174d7
[junit4] 2> 34921 T80 oasu.LoggingInfoStream.message [IFD][coreLoadExecutor-18-thread-1]: init: load commit "segments_1"
[junit4] 2> 34921 T80 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=1
[junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@186207d lockFactory=org.apache.lucene.store.NativeFSLockFactory@101ac3),segFN=segments_1,generation=1}
[junit4] 2> 34921 T80 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4] 2> 34922 T80 oasu.LoggingInfoStream.message [IFD][coreLoadExecutor-18-thread-1]: now checkpoint "" [0 segments ; isCommit = false]
[junit4] 2> 34922 T80 oasu.LoggingInfoStream.message [IFD][coreLoadExecutor-18-thread-1]: 0 msec to checkpoint
[junit4] 2> 34922 T80 oasu.LoggingInfoStream.message [IW][coreLoadExecutor-18-thread-1]: init: create=false
[junit4] 2> 34922 T80 oasu.LoggingInfoStream.message [IW][coreLoadExecutor-18-thread-1]:
[junit4] 2> dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@186207d lockFactory=org.apache.lucene.store.NativeFSLockFactory@101ac3)
[junit4] 2> index=
[junit4] 2> version=5.0-SNAPSHOT
[junit4] 2> matchVersion=LUCENE_50
[junit4] 2> analyzer=null
[junit4] 2> ramBufferSizeMB=100.0
[junit4] 2> maxBufferedDocs=-1
[junit4] 2> maxBufferedDeleteTerms=-1
[junit4] 2> mergedSegmentWarmer=null
[junit4] 2> delPolicy=org.apache.solr.core.IndexDeletionPolicyWrapper
[junit4] 2> commit=null
[junit4] 2> openMode=APPEND
[junit4] 2> similarity=org.apache.lucene.search.similarities.DefaultSimilarity
[junit4] 2> mergeScheduler=ConcurrentMergeScheduler: maxThreadCount=1, maxMergeCount=2, mergeThreadPriority=-1
[junit4] 2> default WRITE_LOCK_TIMEOUT=1000
[junit4] 2> writeLockTimeout=1000
[junit4] 2> codec=Lucene45
[junit4] 2> infoStream=org.apache.solr.update.LoggingInfoStream
[junit4] 2> mergePolicy=[TieredMergePolicy: maxMergeAtOnce=10, maxMergeAtOnceExplicit=30, maxMergedSegmentMB=5120.0, floorSegmentMB=2.0, forceMergeDeletesPctAllowed=10.0, segmentsPerTier=10.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.0
[junit4] 2> indexerThreadPool=org.apache.lucene.index.ThreadAffinityDocumentsWriterThreadPool@159892f
[junit4] 2> readerPooling=false
[junit4] 2> perThreadHardLimitMB=1945
[junit4] 2> useCompoundFile=false
[junit4] 2>
[junit4] 2> 34923 T80 oasu.LoggingInfoStream.message [IW][coreLoadExecutor-18-thread-1]: flush at getReader
[junit4] 2> 34923 T80 oasu.LoggingInfoStream.message [DW][coreLoadExecutor-18-thread-1]: coreLoadExecutor-18-thread-1 startFullFlush
[junit4] 2> 34923 T80 oasu.LoggingInfoStream.message [DW][coreLoadExecutor-18-thread-1]: anyChanges? numDocsInRam=0 deletes=false hasTickets:false pendingChangesInFullFlush: false
[junit4] 2> 34924 T80 oasu.LoggingInfoStream.message [IW][coreLoadExecutor-18-thread-1]: apply all deletes during flush
[junit4] 2> 34924 T80 oasu.LoggingInfoStream.message [BD][coreLoadExecutor-18-thread-1]: prune sis=org.apache.lucene.index.SegmentInfos@13a9d21 minGen=9223372036854775807 packetCount=0
[junit4] 2> 34924 T80 oasu.LoggingInfoStream.message [IW][coreLoadExecutor-18-thread-1]: return reader version=1 reader=StandardDirectoryReader(segments_1:1:nrt)
[junit4] 2> 34924 T80 oasu.LoggingInfoStream.message [DW][coreLoadExecutor-18-thread-1]: coreLoadExecutor-18-thread-1 finishFullFlush success=true
[junit4] 2> 34925 T80 oasu.LoggingInfoStream.message [IW][coreLoadExecutor-18-thread-1]: getReader took 2 msec
[junit4] 2> 34925 T80 oass.SolrIndexSearcher.<init> Opening Searcher@1277f46 main
[junit4] 2> 34925 T80 oashc.SpellCheckComponent.inform Initializing spell checkers
[junit4] 2> 34926 T80 oass.DirectSolrSpellChecker.init init: {name=default,field=text,classname=solr.DirectSolrSpellChecker,distanceMeasure=internal,accuracy=0.5,maxEdits=2,minPrefix=1,maxInspections=5,minQueryLength=4,maxQueryFrequency=0.01}
[junit4] 2> 34926 T80 oashc.SpellCheckComponent.inform No queryConverter defined, using default converter
[junit4] 2> 34927 T80 oashc.QueryElevationComponent.inform Loading QueryElevation from: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/example/solr/collection1/conf/elevate.xml
[junit4] 2> 34938 T80 oash.ReplicationHandler.inform Commits will be reserved for 10000
[junit4] 2> 34938 T81 oasc.QuerySenderListener.newSearcher QuerySenderListener sending requests to Searcher@1277f46 main{StandardDirectoryReader(segments_1:1:nrt)}
[junit4] 2> ASYNC NEW_CORE C36 name=collection1 org.apache.solr.core.SolrCore@670355
[junit4] 2> 34941 T81 C36 oasc.SolrCore.execute [collection1] webapp=null path=null params={event=firstSearcher&q=static+firstSearcher+warming+in+solrconfig.xml&distrib=false} hits=0 status=0 QTime=1
[junit4] 2> 34941 T81 oasc.QuerySenderListener.newSearcher QuerySenderListener done.
[junit4] 2> 34941 T81 oashc.SpellCheckComponent$SpellCheckerListener.newSearcher Loading spell index for spellchecker: default
[junit4] 2> 34941 T81 oashc.SpellCheckComponent$SpellCheckerListener.newSearcher Loading spell index for spellchecker: wordbreak
[junit4] 2> 34942 T81 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@1277f46 main{StandardDirectoryReader(segments_1:1:nrt)}
[junit4] 2> 34944 T80 oasc.CoreContainer.registerCore registering core: collection1
[junit4] 2> 34945 T70 oass.SolrDispatchFilter.init user.dir=/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-solrj/test/J1
[junit4] 2> 34945 T70 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4] 2> 34946 T70 oas.SolrJettyTestBase.createJetty Jetty Assigned Port#32992
[junit4] 2> 34952 T70 oas.SolrTestCaseJ4.setUp ###Starting testFaceting
[junit4] 2> 34953 T70 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4] 2> ASYNC NEW_CORE C37 name=collection1 org.apache.solr.core.SolrCore@670355
[junit4] 2> 35103 T78 C37 oasu.LoggingInfoStream.message [DW][qtp25819770-78]: anyChanges? numDocsInRam=0 deletes=true hasTickets:false pendingChangesInFullFlush: false
[junit4] 2> 35104 T78 C37 oasu.LoggingInfoStream.message [IW][qtp25819770-78]: nrtIsCurrent: infoVersion matches: true; DW changes: true; BD changes: false
[junit4] 2> 35104 T78 C37 oasu.LoggingInfoStream.message [DW][qtp25819770-78]: anyChanges? numDocsInRam=0 deletes=true hasTickets:false pendingChangesInFullFlush: false
[junit4] 2> 35104 T78 C37 oasu.LoggingInfoStream.message [IW][qtp25819770-78]: flush at getReader
[junit4] 2> 35104 T78 C37 oasu.LoggingInfoStream.message [DW][qtp25819770-78]: qtp25819770-78 startFullFlush
[junit4] 2> 35105 T78 C37 oasu.LoggingInfoStream.message [DW][qtp25819770-78]: anyChanges? numDocsInRam=0 deletes=true hasTickets:false pendingChangesInFullFlush: false
[junit4] 2> 35105 T78 C37 oasu.LoggingInfoStream.message [DW][qtp25819770-78]: qtp25819770-78: flush naked frozen global deletes
[junit4] 2> 35105 T78 C37 oasu.LoggingInfoStream.message [BD][qtp25819770-78]: push deletes 1 deleted queries bytesUsed=32 delGen=2 packetCount=1 totBytesUsed=32
[junit4] 2> 35106 T78 C37 oasu.LoggingInfoStream.message [DW][qtp25819770-78]: flush: push buffered deletes: 1 deleted queries bytesUsed=32
[junit4] 2> 35106 T78 C37 oasu.LoggingInfoStream.message [IW][qtp25819770-78]: apply all deletes during flush
[junit4] 2> 35106 T78 C37 oasu.LoggingInfoStream.message [BD][qtp25819770-78]: prune sis=org.apache.lucene.index.SegmentInfos@13a9d21 minGen=9223372036854775807 packetCount=1
[junit4] 2> 35106 T78 C37 oasu.LoggingInfoStream.message [BD][qtp25819770-78]: pruneDeletes: prune 1 packets; 0 packets remain
[junit4] 2> 35107 T78 C37 oasu.LoggingInfoStream.message [IW][qtp25819770-78]: return reader version=1 reader=StandardDirectoryReader(segments_1:1:nrt)
[junit4] 2> 35107 T78 C37 oasu.LoggingInfoStream.message [DW][qtp25819770-78]: qtp25819770-78 finishFullFlush success=true
[junit4] 2> 35107 T78 C37 oasu.LoggingInfoStream.message [IW][qtp25819770-78]: getReader took 3 msec
[junit4] 2> 35108 T78 C37 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {deleteByQuery=*:* (-1445606933291597824)} 0 6
[junit4] 2> 35114 T79 C37 oasu.DirectUpdateHandler2.commit start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4] 2> 35115 T79 C37 oasu.DirectUpdateHandler2.commit No uncommitted changes. Skipping IW.commit.
[junit4] 2> 35115 T79 C37 oasu.LoggingInfoStream.message [DW][qtp25819770-79]: anyChanges? numDocsInRam=0 deletes=false hasTickets:false pendingChangesInFullFlush: false
[junit4] 2> 35116 T79 C37 oasu.LoggingInfoStream.message [IW][qtp25819770-79]: nrtIsCurrent: infoVersion matches: true; DW changes: false; BD changes: false
[junit4] 2> 35116 T79 C37 oasu.LoggingInfoStream.message [DW][qtp25819770-79]: anyChanges? numDocsInRam=0 deletes=false hasTickets:false pendingChangesInFullFlush: false
[junit4] 2> 35116 T79 C37 oass.SolrIndexSearcher.<init> Opening Searcher@19e375 main
[junit4] 2> 35117 T79 C37 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4] 2> 35117 T81 oasc.QuerySenderListener.newSearcher QuerySenderListener sending requests to Searcher@19e375 main{StandardDirectoryReader(segments_1:1:nrt)}
[junit4] 2> 35117 T81 oasc.QuerySenderListener.newSearcher QuerySenderListener done.
[junit4] 2> 35118 T81 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@19e375 main{StandardDirectoryReader(segments_1:1:nrt)}
[junit4] 2> 35119 T79 C37 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={waitSearcher=true&commit=true&wt=javabin&version=2&softCommit=false} {commit=} 0 5
[junit4] 2> 35123 T78 C37 oasc.SolrCore.execute [collection1] webapp=/solr path=/select params={q=*:*&wt=javabin&version=2} hits=0 status=0 QTime=1
[junit4] 2> 35132 T76 C37 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[1 (1445606933318860800), 2 (1445606933320957952), 3 (1445606933320957953), 4 (1445606933322006528), 5 (1445606933322006529), 6 (1445606933322006530), 7 (1445606933322006531), 8 (1445606933322006532), 9 (1445606933322006533), 10 (1445606933323055104)]} 0 5
[junit4] 2> 35136 T79 C37 oasu.DirectUpdateHandler2.commit start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4] 2> 35136 T79 C37 oasu.LoggingInfoStream.message [IW][qtp25819770-79]: commit: start
[junit4] 2> 35136 T79 C37 oasu.LoggingInfoStream.message [IW][qtp25819770-79]: commit: enter lock
[junit4] 2> 35137 T79 C37 oasu.LoggingInfoStream.message [IW][qtp25819770-79]: commit: now prepare
[junit4] 2> 35137 T79 C37 oasu.LoggingInfoStream.message [IW][qtp25819770-79]: prepareCommit: flush
[junit4] 2> 35137 T79 C37 oasu.LoggingInfoStream.message [IW][qtp25819770-79]: index before flush
[junit4] 2> 35138 T79 C37 oasu.LoggingInfoStream.message [DW][qtp25819770-79]: qtp25819770-79 startFullFlush
[junit4] 2> 35138 T79 C37 oasu.LoggingInfoStream.message [DW][qtp25819770-79]: anyChanges? numDocsInRam=10 deletes=true hasTickets:false pendingChangesInFullFlush: false
[junit4] 2> 35138 T79 C37 oasu.LoggingInfoStream.message [DWFC][qtp25819770-79]: addFlushableState DocumentsWriterPerThread [pendingDeletes=gen=0 9 deleted terms (unique count=9) bytesUsed=1234, segment=_0, aborting=false, numDocsInRAM=10, deleteQueue=DWDQ: [ generation: 2 ]]
[junit4] 2> 35139 T79 C37 oasu.LoggingInfoStream.message [DWPT][qtp25819770-79]: flush postings as segment _0 numDocs=10
[junit4] 2> 35141 T79 C37 oasu.LoggingInfoStream.message [DWPT][qtp25819770-79]: new segment has 0 deleted docs
[junit4] 2> 35141 T79 C37 oasu.LoggingInfoStream.message [DWPT][qtp25819770-79]: new segment has no vectors; norms; no docValues; prox; freqs
[junit4] 2> 35141 T79 C37 oasu.LoggingInfoStream.message [DWPT][qtp25819770-79]: flushedFiles=[_0.fnm, _0_Lucene41_0.doc, _0_Lucene41_0.pos, _0.nvd, _0.fdx, _0.nvm, _0_Lucene41_0.tim, _0_Lucene41_0.tip, _0.fdt]
[junit4] 2> 35142 T79 C37 oasu.LoggingInfoStream.message [DWPT][qtp25819770-79]: flushed codec=Lucene45
[junit4] 2> 35142 T79 C37 oasu.LoggingInfoStream.message [DWPT][qtp25819770-79]: flushed: segment=_0 ramUsed=0.081 MB newFlushedSize(includes docstores)=0.001 MB docs/MB=7,704.453
[junit4] 2> 35143 T79 C37 oasu.LoggingInfoStream.message [DW][qtp25819770-79]: publishFlushedSegment seg-private deletes=null
[junit4] 2> 35143 T79 C37 oasu.LoggingInfoStream.message [IW][qtp25819770-79]: publishFlushedSegment
[junit4] 2> 35143 T79 C37 oasu.LoggingInfoStream.message [BD][qtp25819770-79]: push deletes 10 deleted terms (unique count=10) bytesUsed=1024 delGen=4 packetCount=1 totBytesUsed=1024
[junit4] 2> 35144 T79 C37 oasu.LoggingInfoStream.message [IW][qtp25819770-79]: publish sets newSegment delGen=5 seg=_0(5.0):C10
[junit4] 2> 35144 T79 C37 oasu.LoggingInfoStream.message [IFD][qtp25819770-79]: now checkpoint "_0(5.0):C10" [1 segments ; isCommit = false]
[junit4] 2> 35144 T79 C37 oasu.LoggingInfoStream.message [IFD][qtp25819770-79]: 0 msec to checkpoint
[junit4] 2> 35145 T79 C37 oasu.LoggingInfoStream.message [IW][qtp25819770-79]: apply all deletes during flush
[junit4] 2> 35145 T79 C37 oasu.LoggingInfoStream.message [BD][qtp25819770-79]: applyDeletes: infos=[_0(5.0):C10] packetCount=1
[junit4] 2> 35145 T79 C37 oasu.LoggingInfoStream.message [BD][qtp25819770-79]: applyDeletes took 0 msec
[junit4] 2> 35146 T79 C37 oasu.LoggingInfoStream.message [BD][qtp25819770-79]: prune sis=org.apache.lucene.index.SegmentInfos@13a9d21 minGen=6 packetCount=1
[junit4] 2> 35146 T79 C37 oasu.LoggingInfoStream.message [BD][qtp25819770-79]: pruneDeletes: prune 1 packets; 0 packets remain
[junit4] 2> 35146 T79 C37 oasu.LoggingInfoStream.message [DW][qtp25819770-79]: qtp25819770-79 finishFullFlush success=true
[junit4] 2> 35147 T79 C37 oasu.LoggingInfoStream.message [TMP][qtp25819770-79]: findMerges: 1 segments
[junit4] 2> 35147 T79 C37 oasu.LoggingInfoStream.message [TMP][qtp25819770-79]: seg=_0(5.0):C10 size=0.001 MB [floored]
[junit4] 2> 35147 T79 C37 oasu.LoggingInfoStream.message [TMP][qtp25819770-79]: allowedSegmentCount=1 vs count=1 (eligible count=1) tooBigCount=0
[junit4] 2> 35148 T79 C37 oasu.LoggingInfoStream.message [CMS][qtp25819770-79]: now merge
[junit4] 2> 35148 T79 C37 oasu.LoggingInfoStream.message [CMS][qtp25819770-79]: index: _0(5.0):C10
[junit4] 2> 35148 T79 C37 oasu.LoggingInfoStream.message [CMS][qtp25819770-79]: no more merges pending; now return
[junit4] 2> 35149 T79 C37 oasu.LoggingInfoStream.message [IW][qtp25819770-79]: startCommit(): start
[junit4] 2> 35149 T79 C37 oasu.LoggingInfoStream.message [IW][qtp25819770-79]: startCommit index=_0(5.0):C10 changeCount=3
[junit4] 2> 35150 T79 C37 oasu.LoggingInfoStream.message [IW][qtp25819770-79]: done all syncs: [_0.fnm, _0_Lucene41_0.doc, _0_Lucene41_0.pos, _0.nvd, _0.fdx, _0.si, _0.nvm, _0_Lucene41_0.tim, _0.fdt, _0_Lucene41_0.tip]
[junit4] 2> 35150 T79 C37 oasu.LoggingInfoStream.message [IW][qtp25819770-79]: commit: pendingCommit != null
[junit4] 2> 35150 T79 C37 oasu.LoggingInfoStream.message [IW][qtp25819770-79]: commit: wrote segments file "segments_2"
[junit4] 2> 35151 T79 C37 oasu.LoggingInfoStream.message [IFD][qtp25819770-79]: now checkpoint "_0(5.0):C10" [1 segments ; isCommit = true]
[junit4] 2> 35151 T79 C37 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=2
[junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@186207d lockFactory=org.apache.lucene.store.NativeFSLockFactory@101ac3),segFN=segments_1,generation=1}
[junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@186207d lockFactory=org.apache.lucene.store.NativeFSLockFactory@101ac3),segFN=segments_2,generation=2}
[junit4] 2> 35151 T79 C37 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 2
[junit4] 2> 35152 T79 C37 oasu.LoggingInfoStream.message [IFD][qtp25819770-79]: deleteCommits: now decRef commit "segments_1"
[junit4] 2> 35152 T79 C37 oasu.LoggingInfoStream.message [IFD][qtp25819770-79]: delete "segments_1"
[junit4] 2> 35152 T79 C37 oasu.LoggingInfoStream.message [IFD][qtp25819770-79]: 1 msec to checkpoint
[junit4] 2> 35152 T79 C37 oasu.LoggingInfoStream.message [IW][qtp25819770-79]: commit: done
[junit4] 2> 35153 T79 C37 oasu.LoggingInfoStream.message [DW][qtp25819770-79]: anyChanges? numDocsInRam=0 deletes=false hasTickets:false pendingChangesInFullFlush: false
[junit4] 2> 35153 T79 C37 oasu.LoggingInfoStream.message [IW][qtp25819770-79]: nrtIsCurrent: infoVersion matches: false; DW changes: false; BD changes: false
[junit4] 2> 35153 T79 C37 oasu.LoggingInfoStream.message [IW][qtp25819770-79]: flush at getReader
[junit4] 2> 35153 T79 C37 oasu.LoggingInfoStream.message [DW][qtp25819770-79]: qtp25819770-79 startFullFlush
[junit4] 2> 35154 T79 C37 oasu.LoggingInfoStream.message [DW][qtp25819770-79]: anyChanges? numDocsInRam=0 deletes=false hasTickets:false pendingChangesInFullFlush: false
[junit4] 2> 35154 T79 C37 oasu.LoggingInfoStream.message [IW][qtp25819770-79]: apply all deletes during flush
[junit4] 2> 35154 T79 C37 oasu.LoggingInfoStream.message [BD][qtp25819770-79]: applyDeletes: no deletes; skipping
[junit4] 2> 35154 T79 C37 oasu.LoggingInfoStream.message [BD][qtp25819770-79]: prune sis=org.apache.lucene.index.SegmentInfos@13a9d21 minGen=6 packetCount=0
[junit4] 2> 35155 T79 C37 oasu.LoggingInfoStream.message [IW][qtp25819770-79]: return reader version=3 reader=StandardDirectoryReader(segments_2:3:nrt _0(5.0):C10)
[junit4] 2> 35155 T79 C37 oasu.LoggingInfoStream.message [DW][qtp25819770-79]: qtp25819770-79 finishFullFlush success=true
[junit4] 2> 35156 T79 C37 oasu.LoggingInfoStream.message [IW][qtp25819770-79]: getReader took 3 msec
[junit4] 2> 35156 T79 C37 oass.SolrIndexSearcher.<init> Opening Searcher@14d51e2 main
[junit4] 2> 35156 T79 C37 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4] 2> 35156 T81 oasc.QuerySenderListener.newSearcher QuerySenderListener sending requests to Searcher@14d51e2 main{StandardDirectoryReader(segments_2:3:nrt _0(5.0):C10)}
[junit4] 2> 35157 T81 oasc.QuerySenderListener.newSearcher QuerySenderListener done.
[junit4] 2> 35159 T81 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@14d51e2 main{StandardDirectoryReader(segments_2:3:nrt _0(5.0):C10)}
[junit4] 2> 35159 T79 C37 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={waitSearcher=true&commit=true&wt=javabin&version=2&softCommit=false} {commit=} 0 23
[junit4] 2> 35163 T77 C37 oasr.UnInvertedField.<init> UnInverted multi-valued field {field=features,memSize=4564,tindexSize=44,time=0,phase1=0,nTerms=4,bigTerms=2,termInstances=4,uses=0}
[junit4] 2> 35164 T77 C37 oasc.SolrCore.execute [collection1] webapp=/solr path=/select params={facet=true&facet.mincount=0&q=*:*&facet.field=features&wt=javabin&version=2&rows=0} hits=10 status=0 QTime=1
[junit4] 2> 35168 T78 C37 oasc.SolrCore.execute [collection1] webapp=/solr path=/select params={facet=true&facet.mincount=0&q=*:*&facet.field=features&wt=javabin&fq=features:two&version=2&rows=0} hits=5 status=0 QTime=1
[junit4] 2> 35172 T76 C37 oasc.SolrCore.execute [collection1] webapp=/solr path=/select params={facet=true&facet.mincount=4&q=*:*&facet.field=features&wt=javabin&fq=features:two&version=2&rows=0} hits=5 status=0 QTime=1
[junit4] 2> 35175 T79 C37 oasc.SolrCore.execute [collection1] webapp=/solr path=/select params={facet=true&facet.mincount=-1&q=*:*&facet.field=features&wt=javabin&fq=features:two&version=2&rows=0} hits=5 status=0 QTime=1
[junit4] 2> 35176 T70 oas.SolrTestCaseJ4.tearDown ###Ending testFaceting
[junit4] 2> 35182 T70 oas.SolrTestCaseJ4.setUp ###Starting testBadSetup
[junit4] 2> 35182 T70 oas.SolrTestCaseJ4.tearDown ###Ending testBadSetup
[junit4] 2> 35189 T70 oas.SolrTestCaseJ4.setUp ###Starting testUpdateField
[junit4] 2> 35192 T77 C37 oasu.LoggingInfoStream.message [DW][qtp25819770-77]: anyChanges? numDocsInRam=0 deletes=true hasTickets:false pendingChangesInFullFlush: false
[junit4] 2> 35193 T77 C37 oasu.LoggingInfoStream.message [IW][qtp25819770-77]: nrtIsCurrent: infoVersion matches: true; DW changes: true; BD changes: false
[junit4] 2> 35193 T77 C37 oasu.LoggingInfoStream.message [DW][qtp25819770-77]: anyChanges? numDocsInRam=0 deletes=true hasTickets:false pendingChangesInFullFlush: false
[junit4] 2> 35193 T77 C37 oasu.LoggingInfoStream.message [IW][qtp25819770-77]: flush at getReader
[junit4] 2> 35194 T77 C37 oasu.LoggingInfoStream.message [DW][qtp25819770-77]: qtp25819770-77 startFullFlush
[junit4] 2> 35194 T77 C37 oasu.LoggingInfoStream.message [DW][qtp25819770-77]: anyChanges? numDocsInRam=0 deletes=true hasTickets:false pendingChangesInFullFlush: false
[junit4] 2> 35194 T77 C37 oasu.LoggingInfoStream.message [DW][qtp25819770-77]: qtp25819770-77: flush naked frozen global deletes
[junit4] 2> 35194 T77 C37 oasu.LoggingInfoStream.message [BD][qtp25819770-77]: push deletes 1 deleted queries bytesUsed=32 delGen=8 packetCount=1 totBytesUsed=32
[junit4] 2> 35195 T77 C37 oasu.LoggingInfoStream.message [DW][qtp25819770-77]: flush: push buffered deletes: 1 deleted queries bytesUsed=32
[junit4] 2> 35195 T77 C37 oasu.LoggingInfoStream.message [IW][qtp25819770-77]: apply all deletes during flush
[junit4] 2> 35195 T77 C37 oasu.LoggingInfoStream.message [BD][qtp25819770-77]: applyDeletes: infos=[_0(5.0):C10] packetCount=1
[junit4] 2> 35196 T77 C37 oasu.LoggingInfoStream.message [BD][qtp25819770-77]: seg=_0(5.0):C10 segGen=6 coalesced deletes=[CoalescedDeletes(termSets=1,queries=1)] newDelCount=10 100% deleted
[junit4] 2> 35196 T77 C37 oasu.LoggingInfoStream.message [BD][qtp25819770-77]: applyDeletes took 1 msec
[junit4] 2> 35196 T77 C37 oasu.LoggingInfoStream.message [IFD][qtp25819770-77]: now checkpoint "_0(5.0):C10/10" [1 segments ; isCommit = false]
[junit4] 2> 35197 T77 C37 oasu.LoggingInfoStream.message [IFD][qtp25819770-77]: 0 msec to checkpoint
[junit4] 2> 35197 T77 C37 oasu.LoggingInfoStream.message [IW][qtp25819770-77]: drop 100% deleted segments: _0(5.0):C10/10
[junit4] 2> 35197 T77 C37 oasu.LoggingInfoStream.message [IFD][qtp25819770-77]: now checkpoint "" [0 segments ; isCommit = false]
[junit4] 2> 35197 T77 C37 oasu.LoggingInfoStream.message [IFD][qtp25819770-77]: 0 msec to checkpoint
[junit4] 2> 35198 T77 C37 oasu.LoggingInfoStream.message [BD][qtp25819770-77]: prune sis=org.apache.lucene.index.SegmentInfos@13a9d21 minGen=9223372036854775807 packetCount=1
[junit4] 2> 35198 T77 C37 oasu.LoggingInfoStream.message [BD][qtp25819770-77]: pruneDeletes: prune 1 packets; 0 packets remain
[junit4] 2> 35198 T77 C37 oasu.LoggingInfoStream.message [IW][qtp25819770-77]: return reader version=5 reader=StandardDirectoryReader(segments_2:5:nrt)
[junit4] 2> 35198 T77 C37 oasu.LoggingInfoStream.message [DW][qtp25819770-77]: qtp25819770-77 finishFullFlush success=true
[junit4] 2> 35199 T77 C37 oasu.LoggingInfoStream.message [IW][qtp25819770-77]: getReader took 6 msec
[junit4] 2> 35199 T77 C37 oass.SolrIndexSearcher.<init> Opening Searcher@152b1 realtime
[junit4] 2> 35199 T77 C37 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {deleteByQuery=*:* (-1445606933385969664)} 0 7
[junit4] 2> 35203 T78 C37 oasu.DirectUpdateHandler2.commit start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4] 2> 35203 T78 C37 oasu.LoggingInfoStream.message [IW][qtp25819770-78]: commit: start
[junit4] 2> 35204 T78 C37 oasu.LoggingInfoStream.message [IW][qtp25819770-78]: commit: enter lock
[junit4] 2> 35204 T78 C37 oasu.LoggingInfoStream.message [IW][qtp25819770-78]: commit: now prepare
[junit4] 2> 35204 T78 C37 oasu.LoggingInfoStream.message [IW][qtp25819770-78]: prepareCommit: flush
[junit4] 2> 35204 T78 C37 oasu.LoggingInfoStream.message [IW][qtp25819770-78]: index before flush
[junit4] 2> 35205 T78 C37 oasu.LoggingInfoStream.message [DW][qtp25819770-78]: qtp25819770-78 startFullFlush
[junit4] 2> 35205 T78 C37 oasu.LoggingInfoStream.message [DW][qtp25819770-78]: anyChanges? numDocsInRam=0 deletes=false hasTickets:false pendingChangesInFullFlush: false
[junit4] 2> 35205 T78 C37 oasu.LoggingInfoStream.message [IW][qtp25819770-78]: apply all deletes during flush
[junit4] 2> 35205 T78 C37 oasu.LoggingInfoStream.message [BD][qtp25819770-78]: prune sis=org.apache.lucene.index.SegmentInfos@13a9d21 minGen=9223372036854775807 packetCount=0
[junit4] 2> 35205 T78 C37 oasu.LoggingInfoStream.message [DW][qtp25819770-78]: qtp25819770-78 finishFullFlush success=true
[junit4] 2> 35206 T78 C37 oasu.LoggingInfoStream.message [IW][qtp25819770-78]: startCommit(): start
[junit4] 2> 35206 T78 C37 oasu.LoggingInfoStream.message [IW][qtp25819770-78]: startCommit index= changeCount=6
[junit4] 2> 35206 T78 C37 oasu.LoggingInfoStream.message [IW][qtp25819770-78]: done all syncs: []
[junit4] 2> 35206 T78 C37 oasu.LoggingInfoStream.message [IW][qtp25819770-78]: commit: pendingCommit != null
[junit4] 2> 35207 T78 C37 oasu.LoggingInfoStream.message [IW][qtp25819770-78]: commit: wrote segments file "segments_3"
[junit4] 2> 35207 T78 C37 oasu.LoggingInfoStream.message [IFD][qtp25819770-78]: now checkpoint "" [0 segments ; isCommit = true]
[junit4] 2> 35207 T78 C37 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=2
[junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@186207d lockFactory=org.apache.lucene.store.NativeFSLockFactory@101ac3),segFN=segments_2,generation=2}
[junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@186207d lockFactory=org.apache.lucene.store.NativeFSLockFactory@101ac3),segFN=segments_3,generation=3}
[junit4] 2> 35207 T78 C37 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 3
[junit4] 2> 35208 T78 C37 oasu.LoggingInfoStream.message [IFD][qtp25819770-78]: deleteCommits: now decRef commit "segments_2"
[junit4] 2> 35208 T78 C37 oasu.LoggingInfoStream.message [IFD][qtp25819770-78]: delete "_0.fnm"
[junit4] 2> 35208 T78 C37 oasu.LoggingInfoStream.message [IFD][qtp25819770-78]: delete "_0_Lucene41_0.doc"
[junit4] 2> 35208 T78 C37 oasu.LoggingInfoStream.message [IFD][qtp25819770-78]: unable to remove file "_0_Lucene41_0.doc": java.io.IOException: MockDirectoryWrapper: file "_0_Lucene41_0.doc" is still open: cannot delete; Will re-try later.
[junit4] 2> 35209 T78 C37 oasu.LoggingInfoStream.message [IFD][qtp25819770-78]: delete "_0_Lucene41_0.pos"
[junit4] 2> 35209 T78 C37 oasu.LoggingInfoStream.message [IFD][qtp25819770-78]: unable to remove file "_0_Lucene41_0.pos": java.io.IOException: MockDirectoryWrapper: file "_0_Lucene41_0.pos" is still open: cannot delete; Will re-try later.
[junit4] 2> 35209 T78 C37 oasu.LoggingInfoStream.message [IFD][qtp25819770-78]: delete "_0.nvd"
[junit4] 2> 35209 T78 C37 oasu.LoggingInfoStream.message [IFD][qtp25819770-78]: unable to remove file "_0.nvd": java.io.IOException: MockDirectoryWrapper: file "_0.nvd" is still open: cannot delete; Will re-try later.
[junit4] 2> 35210 T78 C37 oasu.LoggingInfoStream.message [IFD][qtp25819770-78]: delete "segments_2"
[junit4] 2> 35210 T78 C37 oasu.LoggingInfoStream.message [IFD][qtp25819770-78]: delete "_0.fdx"
[junit4] 2> 35210 T78 C37 oasu.LoggingInfoStream.message [IFD][qtp25819770-78]: delete "_0.si"
[junit4] 2> 35210 T78 C37 oasu.LoggingInfoStream.message [IFD][qtp25819770-78]: delete "_0.nvm"
[junit4] 2> 35210 T78 C37 oasu.LoggingInfoStream.message [IFD][qtp25819770-78]: delete "_0_Lucene41_0.tim"
[junit4] 2> 35211 T78 C37 oasu.LoggingInfoStream.message [IFD][qtp25819770-78]: unable to remove file "_0_Lucene41_0.tim": java.io.IOException: MockDirectoryWrapper: file "_0_Lucene41_0.tim" is still open: cannot delete; Will re-try later.
[junit4] 2> 35211 T78 C37 oasu.LoggingInfoStream.message [IFD][qtp25819770-78]: delete "_0.fdt"
[junit4] 2> 35211 T78 C37 oasu.LoggingInfoStream.message [IFD][qtp25819770-78]: unable to remove file "_0.fdt": java.io.IOException: MockDirectoryWrapper: file "_0.fdt" is still open: cannot delete; Will re-try later.
[junit4] 2> 35211 T78 C37 oasu.LoggingInfoStream.message [IFD][qtp25819770-78]: delete "_0_Lucene41_0.tip"
[junit4] 2> 35212 T78 C37 oasu.LoggingInfoStream.message [IFD][qtp25819770-78]: 4 msec to checkpoint
[junit4] 2> 35212 T78 C37 oasu.LoggingInfoStream.message [IW][qtp25819770-78]: commit: done
[junit4] 2> 35212 T78 C37 oasu.LoggingInfoStream.message [DW][qtp25819770-78]: anyChanges? numDocsInRam=0 deletes=false hasTickets:false pendingChangesInFullFlush: false
[junit4] 2> 35212 T78 C37 oasu.LoggingInfoStream.message [IW][qtp25819770-78]: nrtIsCurrent: infoVersion matches: true; DW changes: false; BD changes: false
[junit4] 2> 35213 T78 C37 oasu.LoggingInfoStream.message [DW][qtp25819770-78]: anyChanges? numDocsInRam=0 deletes=false hasTickets:false pendingChangesInFullFlush: false
[junit4] 2> 35213 T78 C37 oass.SolrIndexSearcher.<init> Opening Searcher@4270c2 main
[junit4] 2> 35213 T78 C37 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4] 2> 35213 T81 oasc.QuerySenderListener.newSearcher QuerySenderListener sending requests to Searcher@4270c2 main{StandardDirectoryReader(segments_2:5:nrt)}
[junit4] 2> 35214 T81 oasc.QuerySenderListener.newSearcher QuerySenderListener done.
[junit4] 2> 35216 T81 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@4270c2 main{StandardDirectoryReader(segments_2:5:nrt)}
[junit4] 2> 35216 T81 oasu.LoggingInfoStream.message [IFD][searcherExecutor-19-thread-1]: delete pending file _0_Lucene41_0.doc
[junit4] 2> 35216 T81 oasu.LoggingInfoStream.message [IFD][searcherExecutor-19-thread-1]: delete "_0_Lucene41_0.doc"
[junit4] 2> 35216 T81 oasu.LoggingInfoStream.message [IFD][searcherExecutor-19-thread-1]: delete pending file _0_Lucene41_0.pos
[junit4] 2> 35217 T81 oasu.LoggingInfoStream.message [IFD][searcherExecutor-19-thread-1]: delete "_0_Lucene41_0.pos"
[junit4] 2> 35217 T81 oasu.LoggingInfoStream.message [IFD][searcherExecutor-19-thread-1]: delete pending file _0.nvd
[junit4] 2> 35217 T81 oasu.LoggingInfoStream.message [IFD][searcherExecutor-19-thread-1]: delete "_0.nvd"
[junit4] 2> 35217 T81 oasu.LoggingInfoStream.message [IFD][searcherExecutor-19-thread-1]: delete pending file _0_Lucene41_0.tim
[junit4] 2> 35217 T81 oasu.LoggingInfoStream.message [IFD][searcherExecutor-19-thread-1]: delete "_0_Lucene41_0.tim"
[junit4] 2> 35218 T81 oasu.LoggingInfoStream.message [IFD][searcherExecutor-19-thread-1]: delete pending file _0.fdt
[junit4] 2> 35218 T81 oasu.LoggingInfoStream.message [IFD][searcherExecutor-19-thread-1]: delete "_0.fdt"
[junit4] 2> 35218 T78 C37 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={waitSearcher=true&commit=true&wt=javabin&version=2&softCommit=false} {commit=} 0 15
[junit4] 2> 35222 T76 C37 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[unique (1445606933416378368)]} 0 1
[junit4] 2> 35225 T79 C37 oasu.DirectUpdateHandler2.commit start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4] 2> 35225 T79 C37 oasu.LoggingInfoStream.message [IW][qtp25819770-79]: commit: start
[junit4] 2> 35226 T79 C37 oasu.LoggingInfoStream.message [IW][qtp25819770-79]: commit: enter lock
[junit4] 2> 35226 T79 C37 oasu.LoggingInfoStream.message [IW][qtp25819770-79]: commit: now prepare
[junit4] 2> 35226 T79 C37 oasu.LoggingInfoStream.message [IW][qtp25819770-79]: prepareCommit: flush
[junit4] 2> 35226 T79 C37 oasu.LoggingInfoStream.message [IW][qtp25819770-79]: index before flush
[junit4] 2> 35226 T79 C37 oasu.LoggingInfoStream.message [DW][qtp25819770-79]: qtp25819770-79 startFullFlush
[junit4] 2> 35227 T79 C37 oasu.LoggingInfoStream.message [DW][qtp25819770-79]: anyChanges? numDocsInRam=1 deletes=true hasTickets:false pendingChangesInFullFlush: false
[junit4] 2> 35227 T79 C37 oasu.LoggingInfoStream.message [DWFC][qtp25819770-79]: addFlushableState DocumentsWriterPerThread [pendingDeletes=gen=0, segment=_1, aborting=false, numDocsInRAM=1, deleteQueue=DWDQ: [ generation: 6 ]]
[junit4] 2> 35227 T79 C37 oasu.LoggingInfoStream.message [DWPT][qtp25819770-79]: flush postings as segment _1 numDocs=1
[junit4] 2> 35228 T79 C37 oasu.LoggingInfoStream.message [DWPT][qtp25819770-79]: new segment has 0 deleted docs
[junit4] 2> 35228 T79 C37 oasu.LoggingInfoStream.message [DWPT][qtp25819770-79]: new segment has no vectors; norms; no docValues; prox; freqs
[junit4] 2> 35229 T79 C37 oasu.LoggingInfoStream.message [DWPT][qtp25819770-79]: flushedFiles=[_1.nvm, _1_Lucene41_0.pos, _1.fdx, _1_Lucene41_0.doc, _1.fdt, _1_Lucene41_0.tim, _1.nvd, _1_Lucene41_0.tip, _1.fnm]
[junit4] 2> 35229 T79 C37 oasu.LoggingInfoStream.message [DWPT][qtp25819770-79]: flushed codec=Lucene45
[junit4] 2> 35230 T79 C37 oasu.LoggingInfoStream.message [DWPT][qtp25819770-79]: flushed: segment=_1 ramUsed=0.079 MB newFlushedSize(includes docstores)=0.001 MB docs/MB=942.117
[junit4] 2> 35230 T79 C37 oasu.LoggingInfoStream.message [DW][qtp25819770-79]: publishFlushedSegment seg-private deletes=null
[junit4] 2> 35230 T79 C37 oasu.LoggingInfoStream.message [IW][qtp25819770-79]: publishFlushedSegment
[junit4] 2> 35230 T79 C37 oasu.LoggingInfoStream.message [BD][qtp25819770-79]: push deletes 1 deleted terms (unique count=1) bytesUsed=1024 delGen=11 packetCount=1 totBytesUsed=1024
[junit4] 2> 35231 T79 C37 oasu.LoggingInfoStream.message [IW][qtp25819770-79]: publish sets newSegment delGen=12 seg=_1(5.0):C1
[junit4] 2> 35231 T79 C37 oasu.LoggingInfoStream.message [IFD][qtp25819770-79]: now checkpoint "_1(5.0):C1" [1 segments ; isCommit = false]
[junit4] 2> 35231 T79 C37 oasu.LoggingInfoStream.message [IFD][qtp25819770-79]: 0 msec to checkpoint
[junit4] 2> 35231 T79 C37 oasu.LoggingInfoStream.message [IW][qtp25819770-79]: apply all deletes during flush
[junit4] 2> 35232 T79 C37 oasu.LoggingInfoStream.message [BD][qtp25819770-79]: applyDeletes: infos=[_1(5.0):C1] packetCount=1
[junit4] 2> 35232 T79 C37 oasu.LoggingInfoStream.message [BD][qtp25819770-79]: applyDeletes took 0 msec
[junit4] 2> 35232 T79 C37 oasu.LoggingInfoStream.message [BD][qtp25819770-79]: prune sis=org.apache.lucene.index.SegmentInfos@13a9d21 minGen=13 packetCount=1
[junit4] 2> 35232 T79 C37 oasu.LoggingInfoStream.message [BD][qtp25819770-79]: pruneDeletes: prune 1 packets; 0 packets remain
[junit4] 2> 35233 T79 C37 oasu.LoggingInfoStream.message [DW][qtp25819770-79]: qtp25819770-79 finishFullFlush success=true
[junit4] 2> 35233 T79 C37 oasu.LoggingInfoStream.message [TMP][qtp25819770-79]: findMerges: 1 segments
[junit4] 2> 35233 T79 C37 oasu.LoggingInfoStream.message [TMP][qtp25819770-79]: seg=_1(5.0):C1 size=0.001 MB [floored]
[junit4] 2> 35233 T79 C37 oasu.LoggingInfoStream.message [TMP][qtp25819770-79]: allowedSegmentCount=1 vs count=1 (eligible count=1) tooBigCount=0
[junit4] 2> 35234 T79 C37 oasu.LoggingInfoStream.message [CMS][qtp25819770-79]: now merge
[junit4] 2> 35234 T79 C37 oasu.LoggingInfoStream.message [CMS][qtp25819770-79]: index: _1(5.0):C1
[junit4] 2> 35234 T79 C37 oasu.LoggingInfoStream.message [CMS][qtp25819770-79]: no more merges pending; now return
[junit4] 2> 35234 T79 C37 oasu.LoggingInfoStream.message [IW][qtp25819770-79]: startCommit(): start
[junit4] 2> 35234 T79 C37 oasu.LoggingInfoStream.message [IW][qtp25819770-79]: startCommit index=_1(5.0):C1 changeCount=9
[junit4] 2> 35235 T79 C37 oasu.LoggingInfoStream.message [IW][qtp25819770-79]: done all syncs: [_1.fdx, _1_Lucene41_0.pos, _1.nvm, _1_Lucene41_0.doc, _1.fdt, _1.si, _1_Lucene41_0.tim, _1.nvd, _1_Lucene41_0.tip, _1.fnm]
[junit4] 2> 35235 T79 C37 oasu.LoggingInfoStream.message [IW][qtp25819770-79]: commit: pendingCommit != null
[junit4] 2> 35235 T79 C37 oasu.LoggingInfoStream.message [IW][qtp25819770-79]: commit: wrote segments file "segments_4"
[junit4] 2> 35235 T79 C37 oasu.LoggingInfoStream.message [IFD][qtp25819770-79]: now checkpoint "_1(5.0):C1" [1 segments ; isCommit = true]
[junit4] 2> 35236 T79 C37 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=2
[junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@186207d lockFactory=org.apache.lucene.store.NativeFSLockFactory@101ac3),segFN=segments_3,generation=3}
[junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@186207d lockFactory=org.apache.lucene.store.NativeFSLockFactory@101ac3),segFN=segments_4,generation=4}
[junit4] 2> 35236 T79 C37 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 4
[junit4] 2> 35236 T79 C37 oasu.LoggingInfoStream.message [IFD][qtp25819770-79]: deleteCommits: now decRef commit "segments_3"
[junit4] 2> 35236 T79 C37 oasu.LoggingInfoStream.message [IFD][qtp25819770-79]: delete "segments_3"
[junit4] 2> 35237 T79 C37 oasu.LoggingInfoStream.message [IFD][qtp25819770-79]: 1 msec to checkpoint
[junit4] 2> 35237 T79 C37 oasu.LoggingInfoStream.message [IW][qtp25819770-79]: commit: done
[junit4] 2> 35238 T79 C37 oasu.LoggingInfoStream.message [DW][qtp25819770-79]: anyChanges? numDocsInRam=0 deletes=false hasTickets:false pendingChangesInFullFlush: false
[junit4] 2> 35239 T79 C37 oasu.LoggingInfoStream.message [IW][qtp25819770-79]: nrtIsCurrent: infoVersion matches: false; DW changes: false; BD changes: false
[junit4] 2> 35239 T79 C37 oasu.LoggingInfoStream.message [IW][qtp25819770-79]: flush at getReader
[junit4] 2> 35239 T79 C37 oasu.LoggingInfoStream.message [DW][qtp25819770-79]: qtp25819770-79 startFullFlush
[junit4] 2> 35239 T79 C37 oasu.LoggingInfoStream.message [DW][qtp25819770-79]: anyChanges? numDocsInRam=0 deletes=false hasTickets:false pendingChangesInFullFlush: false
[junit4] 2> 35239 T79 C37 oasu.LoggingInfoStream.message [IW][qtp25819770-79]: apply all deletes during flush
[junit4] 2> 35240 T79 C37 oasu.LoggingInfoStream.message [BD][qtp25819770-79]: applyDeletes: no deletes; skipping
[junit4] 2> 35240 T79 C37 oasu.LoggingInfoStream.message [BD][qtp25819770-79]: prune sis=org.apache.lucene.index.SegmentInfos@13a9d21 minGen=13 packetCount=0
[junit4] 2> 35241 T79 C37 oasu.LoggingInfoStream.message [IW][qtp25819770-79]: return reader version=7 reader=StandardDirectoryReader(segments_4:7:nrt _1(5.0):C1)
[junit4] 2> 35241 T79 C37 oasu.LoggingInfoStream.message [DW][qtp25819770-79]: qtp25819770-79 finishFullFlush success=true
[junit4] 2> 35241 T79 C37 oasu.LoggingInfoStream.message [IW][qtp25819770-79]: getReader took 2 msec
[junit4] 2> 35241 T79 C37 oass.SolrIndexSearcher.<init> Opening Searcher@191dec3 main
[junit4] 2> 35242 T79 C37 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4] 2> 35242 T81 oasc.QuerySenderListener.newSearcher QuerySenderListener sending requests to Searcher@191dec3 main{StandardDirectoryReader(segments_4:7:nrt _1(5.0):C1)}
[junit4] 2> 35242 T81 oasc.QuerySenderListener.newSearcher QuerySenderListener done.
[junit4] 2> 35243 T81 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@191dec3 main{StandardDirectoryReader(segments_4:7:nrt _1(5.0):C1)}
[junit4] 2> 35244 T79 C37 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={waitSearcher=true&commit=true&wt=javabin&version=2&softCommit=false} {commit=} 0 19
[junit4] 2> 35248 T77 C37 oasc.SolrCore.execute [collection1] webapp=/solr path=/select params={fl=id,price_f,name,_version_&q=*:*&wt=javabin&version=2} hits=1 status=0 QTime=1
[junit4] 2> 35251 T78 C37 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {} 0 0
[junit4] 2> 35256 T76 C37 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[unique (1445606933452029952)]} 0 1
[junit4] 2> 35259 T79 C37 oasu.DirectUpdateHandler2.commit start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4] 2> 35260 T79 C37 oasu.LoggingInfoStream.message [IW][qtp25819770-79]: commit: start
[junit4] 2> 35260 T79 C37 oasu.LoggingInfoStream.message [IW][qtp25819770-79]: commit: enter lock
[junit4] 2> 35260 T79 C37 oasu.LoggingInfoStream.message [IW][qtp25819770-79]: commit: now prepare
[junit4] 2> 35260 T79 C37 oasu.LoggingInfoStream.message [IW][qtp25819770-79]: prepareCommit: flush
[junit4] 2> 35261 T79 C37 oasu.LoggingInfoStream.message [IW][qtp25819770-79]: index before flush _1(5.0):C1
[junit4] 2> 35261 T79 C37 oasu.LoggingInfoStream.message [DW][qtp25819770-79]: qtp25819770-79 startFullFlush
[junit4] 2> 35261 T79 C37 oasu.LoggingInfoStream.message [DW][qtp25819770-79]: anyChanges? numDocsInRam=1 deletes=true hasTickets:false pendingChangesInFullFlush: false
[junit4] 2> 35261 T79 C37 oasu.LoggingInfoStream.message [DWFC][qtp25819770-79]: addFlushableState DocumentsWriterPerThread [pendingDeletes=gen=0, segment=_2, aborting=false, numDocsInRAM=1, deleteQueue=DWDQ: [ generation: 8 ]]
[junit4] 2> 35262 T79 C37 oasu.LoggingInfoStream.message [DWPT][qtp25819770-79]: flush postings as segment _2 numDocs=1
[junit4] 2> 35263 T79 C37 oasu.LoggingInfoStream.message [DWPT][qtp25819770-79]: new segment has 0 deleted docs
[junit4] 2> 35263 T79 C37 oasu.LoggingInfoStream.message [DWPT][qtp25819770-79]: new segment has no vectors; norms; no docValues; prox; freqs
[junit4] 2> 35263 T79 C37 oasu.LoggingInfoStream.message [DWPT][qtp25819770-79]: flushedFiles=[_2_Lucene41_0.pos, _2.nvm, _2_Lucene41_0.tim, _2.nvd, _2.fdt, _2_Lucene41_0.doc, _2_Lucene41_0.tip, _2.fdx, _2.fnm]
[junit4] 2> 35263 T79 C37 oasu.LoggingInfoStream.message [DWPT][qtp25819770-79]: flushed codec=Lucene45
[junit4] 2> 35264 T79 C37 oasu.LoggingInfoStream.message [DWPT][qtp25819770-79]: flushed: segment=_2 ramUsed=0.079 MB newFlushedSize(includes docstores)=0.001 MB docs/MB=942.117
[junit4] 2> 35264 T79 C37 oasu.LoggingInfoStream.message [DW][qtp25819770-79]: publishFlushedSegment seg-private deletes=null
[junit4] 2> 35264 T79 C37 oasu.LoggingInfoStream.message [IW][qtp25819770-79]: publishFlushedSegment
[junit4] 2> 35265 T79 C37 oasu.LoggingInfoStream.message [BD][qtp25819770-79]: push deletes 1 deleted terms (unique count=1) bytesUsed=1024 delGen=15 packetCount=1 totBytesUsed=1024
[junit4] 2> 35265 T79 C37 oasu.LoggingInfoStream.message [IW][qtp25819770-79]: publish sets newSegment delGen=16 seg=_2(5.0):C1
[junit4] 2> 35265 T79 C37 oasu.LoggingInfoStream.message [IFD][qtp25819770-79]: now checkpoint "_1(5.0):C1 _2(5.0):C1" [2 segments ; isCommit = false]
[junit4] 2> 35265 T79 C37 oasu.LoggingInfoStream.message [IFD][qtp25819770-79]: 0 msec to checkpoint
[junit4] 2> 35266 T79 C37 oasu.LoggingInfoStream.message [IW][qtp25819770-79]: apply all deletes during flush
[junit4] 2> 35266 T79 C37 oasu.LoggingInfoStream.message [BD][qtp25819770-79]: applyDeletes: infos=[_1(5.0):C1, _2(5.0):C1] packetCount=1
[junit4] 2> 35266 T79 C37 oasu.LoggingInfoStream.message [BD][qtp25819770-79]: seg=_1(5.0):C1 segGen=13 coalesced deletes=[CoalescedDeletes(termSets=1,queries=0)] newDelCount=1 100% deleted
[junit4] 2> 35267 T79 C37 oasu.LoggingInfoStream.message [BD][qtp25819770-79]: applyDeletes took 1 msec
[junit4] 2> 35267 T79 C37 oasu.LoggingInfoStream.message [IFD][qtp25819770-79]: now checkpoint "_1(5.0):C1/1 _2(5.0):C1" [2 segments ; isCommit = false]
[junit4] 2> 35267 T79 C37 oasu.LoggingInfoStream.message [IFD][qtp25819770-79]: 0 msec to checkpoint
[junit4] 2> 35267 T79 C37 oasu.LoggingInfoStream.message [IW][qtp25819770-79]: drop 100% deleted segments: _1(5.0):C1/1
[junit4] 2> 35268 T79 C37 oasu.LoggingInfoStream.message [IFD][qtp25819770-79]: now checkpoint "_2(5.0):C1" [1 segments ; isCommit = false]
[junit4] 2> 35268 T79 C37 oasu.LoggingInfoStream.message [IFD][qtp25819770-79]: 0 msec to checkpoint
[junit4] 2> 35268 T79 C37 oasu.LoggingInfoStream.message [BD][qtp25819770-79]: prune sis=org.apache.lucene.index.SegmentInfos@13a9d21 minGen=17 packetCount=1
[junit4] 2> 35268 T79 C37 oasu.LoggingInfoStream.message [BD][qtp25819770-79]: pruneDeletes: prune 1 packets; 0 packets remain
[junit4] 2> 35269 T79 C37 oasu.LoggingInfoStream.message [DW][qtp25819770-79]: qtp25819770-79 finishFullFlush success=true
[junit4] 2> 35269 T79 C37 oasu.LoggingInfoStream.message [TMP][qtp25819770-79]: findMerges: 1 segments
[junit4] 2> 35269 T79 C37 oasu.LoggingInfoStream.message [TMP][qtp25819770-79]: seg=_2(5.0):C1 size=0.001 MB [floored]
[junit4] 2> 35269 T79 C37 oasu.LoggingInfoStream.message [TMP][qtp25819770-79]: allowedSegmentCount=1 vs count=1 (eligible count=1) tooBigCount=0
[junit4] 2> 35270 T79 C37 oasu.LoggingInfoStream.message [CMS][qtp25819770-79]: now merge
[junit4] 2> 35270 T79 C37 oasu.LoggingInfoStream.message [CMS][qtp25819770-79]: index: _2(5.0):C1
[junit4] 2> 35270 T79 C37 oasu.LoggingInfoStream.message [CMS][qtp25819770-79]: no more merges pending; now return
[junit4] 2> 35270 T79 C37 oasu.LoggingInfoStream.message [IW][qtp25819770-79]: startCommit(): start
[junit4] 2> 35271 T79 C37 oasu.LoggingInfoStream.message [IW][qtp25819770-79]: startCommit index=_2(5.0):C1 changeCount=14
[junit4] 2> 35271 T79 C37 oasu.LoggingInfoStream.message [IW][qtp25819770-79]: done all syncs: [_2.si, _2_Lucene41_0.pos, _2_Lucene41_0.tim, _2.nvm, _2.nvd, _2.fdt, _2_Lucene41_0.doc, _2_Lucene41_0.tip, _2.fdx, _2.fnm]
[junit4] 2> 35271 T79 C37 oasu.LoggingInfoStream.message [IW][qtp25819770-79]: commit: pendingCommit != null
[junit4] 2> 35272 T79 C37 oasu.LoggingInfoStream.message [IW][qtp25819770-79]: commit: wrote segments file "segments_5"
[junit4] 2> 35272 T79 C37 oasu.LoggingInfoStream.message [IFD][qtp25819770-79]: now checkpoint "_2(5.0):C1" [1 segments ; isCommit = true]
[junit4] 2> 35272 T79 C37 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=2
[junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@186207d lockFactory=org.apache.lucene.store.NativeFSLockFactory@101ac3),segFN=segments_4,generation=4}
[junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@186207d lockFactory=org.apache.lucene.store.NativeFSLockFactory@101ac3),segFN=segments_5,generation=5}
[junit4] 2> 35272 T79 C37 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 5
[junit4] 2> 35273 T79 C37 oasu.LoggingInfoStream.message [IFD][qtp25819770-79]: deleteCommits: now decRef commit "segments_4"
[junit4] 2> 35273 T79 C37 oasu.LoggingInfoStream.message [IFD][qtp25819770-79]: delete "_1.fdx"
[junit4] 2> 35273 T79 C37 oasu.LoggingInfoStream.message [IFD][qtp25819770-79]: delete "_1_Lucene41_0.pos"
[junit4] 2> 35273 T79 C37 oasu.LoggingInfoStream.message [IFD][qtp25819770-79]: unable to remove file "_1_Lucene41_0.pos": java.io.IOException: MockDirectoryWrapper: file "_1_Lucene41_0.pos" is still open: cannot delete; Will re-try later.
[junit4] 2> 35274 T79 C37 oasu.LoggingInfoStream.message [IFD][qtp25819770-79]: delete "_1.nvm"
[junit4] 2> 35274 T79 C37 oasu.LoggingInfoStream.message [IFD][qtp25819770-79]: delete "_1_Lucene41_0.doc"
[junit4] 2> 35274 T79 C37 oasu.LoggingInfoStream.message [IFD][qtp25819770-79]: unable to remove file "_1_Lucene41_0.doc": java.io.IOException: MockDirectoryWrapper: file "_1_Lucene41_0.doc" is still open: cannot delete; Will re-try later.
[junit4] 2> 35274 T79 C37 oasu.LoggingInfoStream.message [IFD][qtp25819770-79]: delete "_1.fdt"
[junit4] 2> 35275 T79 C37 oasu.LoggingInfoStream.message [IFD][qtp25819770-79]: unable to remove file "_1.fdt": java.io.IOException: MockDirectoryWrapper: file "_1.fdt" is still open: cannot delete; Will re-try later.
[junit4] 2> 35275 T79 C37 oasu.LoggingInfoStream.message [IFD][qtp25819770-79]: delete "_1.si"
[junit4] 2> 35275 T79 C37 oasu.LoggingInfoStream.message [IFD][qtp25819770-79]: delete "_1_Lucene41_0.tim"
[junit4] 2> 35276 T79 C37 oasu.LoggingInfoStream.message [IFD][qtp25819770-79]: unable to remove file "_1_Lucene41_0.tim": java.io.IOException: MockDirectoryWrapper: file "_1_Lucene41_0.tim" is still open: cannot delete; Will re-try later.
[junit4] 2> 35276 T79 C37 oasu.LoggingInfoStream.message [IFD][qtp25819770-79]: delete "_1.nvd"
[junit4] 2> 35276 T79 C37 oasu.LoggingInfoStream.message [IFD][qtp25819770-79]: unable to remove file "_1.nvd": java.io.IOException: MockDirectoryWrapper: file "_1.nvd" is still open: cannot delete; Will re-try later.
[junit4] 2> 35276 T79 C37 oasu.LoggingInfoStream.message [IFD][qtp25819770-79]: delete "_1_Lucene41_0.tip"
[junit4] 2> 35277 T79 C37 oasu.LoggingInfoStream.message [IFD][qtp25819770-79]: delete "_1.fnm"
[junit4] 2> 35277 T79 C37 oasu.LoggingInfoStream.message [IFD][qtp25819770-79]: delete "segments_4"
[junit4] 2> 35277 T79 C37 oasu.LoggingInfoStream.message [IFD][qtp25819770-79]: 5 msec to checkpoint
[junit4] 2> 35277 T79 C37 oasu.LoggingInfoStream.message [IW][qtp25819770-79]: commit: done
[junit4] 2> 35278 T79 C37 oasu.LoggingInfoStream.message [DW][qtp25819770-79]: anyChanges? numDocsInRam=0 deletes=false hasTickets:false pendingChangesInFullFlush: false
[junit4] 2> 35278 T79 C37 oasu.LoggingInfoStream.message [IW][qtp25819770-79]: nrtIsCurrent: infoVersion matches: false; DW changes: false; BD changes: false
[junit4] 2> 35278 T79 C37 oasu.LoggingInfoStream.message [IW][qtp25819770-79]: flush at getReader
[junit4] 2> 35278 T79 C37 oasu.LoggingInfoStream.message [DW][qtp25819770-79]: qtp25819770-79 startFullFlush
[junit4] 2> 35279 T79 C37 oasu.LoggingInfoStream.message [DW][qtp25819770-79]: anyChanges? numDocsInRam=0 deletes=false hasTickets:false pendingChangesInFullFlush: false
[junit4] 2> 35279 T79 C37 oasu.LoggingInfoStream.message [IW][qtp25819770-79]: apply all deletes during flush
[junit4] 2> 35279 T79 C37 oasu.LoggingInfoStream.message [BD][qtp25819770-79]: applyDeletes: no deletes; skipping
[junit4] 2> 35279 T79 C37 oasu.LoggingInfoStream.message [BD][qtp25819770-79]: prune sis=org.apache.lucene.index.SegmentInfos@13a9d21 minGen=17 packetCount=0
[junit4] 2> 35280 T79 C37 oasu.LoggingInfoStream.message [IW][qtp25819770-79]: return reader version=11 reader=StandardDirectoryReader(segments_5:11:nrt _2(5.0):C1)
[junit4] 2> 35280 T79 C37 oasu.LoggingInfoStream.message [DW][qtp25819770-79]: qtp25819770-79 finishFullFlush success=true
[junit4] 2> 35281 T79 C37 oasu.LoggingInfoStream.message [IW][qtp25819770-79]: getReader took 3 msec
[junit4] 2> 35281 T79 C37 oass.SolrIndexSearcher.<init> Opening Searcher@1b6222 main
[junit4] 2> 35281 T81 oasc.QuerySenderListener.newSearcher QuerySenderListener sending requests to Searcher@1b6222 main{StandardDirectoryReader(segments_5:11:nrt _2(5.0):C1)}
[junit4] 2> 35282 T81 oasc.QuerySenderListener.newSearcher QuerySenderListener done.
[junit4] 2> 35281 T79 C37 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4] 2> 35290 T81 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@1b6222 main{StandardDirectoryReader(segments_5:11:nrt _2(5.0):C1)}
[junit4] 2> 35291 T81 oasu.LoggingInfoStream.message [IFD][searcherExecutor-19-thread-1]: delete pending file _1_Lucene41_0.pos
[junit4] 2> 35291 T81 oasu.LoggingInfoStream.message [IFD][searcherExecutor-19-thread-1]: delete "_1_Lucene41_0.pos"
[junit4] 2> 35291 T81 oasu.LoggingInfoStream.message [IFD][searcherExecutor-19-thread-1]: delete pending file _1_Lucene41_0.doc
[junit4] 2> 35291 T81 oasu.LoggingInfoStream.message [IFD][searcherExecutor-19-thread-1]: delete "_1_Lucene41_0.doc"
[junit4] 2> 35291 T81 oasu.LoggingInfoStream.message [IFD][searcherExecutor-19-thread-1]: delete pending file _1.fdt
[junit4] 2> 35291 T81 oasu.LoggingInfoStream.message [IFD][searcherExecutor-19-thread-1]: delete "_1.fdt"
[junit4] 2> 35291 T81 oasu.LoggingInfoStream.message [IFD][searcherExecutor-19-thread-1]: delete pending file _1_Lucene41_0.tim
[junit4] 2> 35292 T81 oasu.LoggingInfoStream.message [IFD][searcherExecutor-19-thread-1]: delete "_1_Lucene41_0.tim"
[junit4] 2> 35292 T81 oasu.LoggingInfoStream.message [IFD][searcherExecutor-19-thread-1]: delete pending file _1.nvd
[junit4] 2> 35292 T81 oasu.LoggingInfoStream.message [IFD][searcherExecutor-19-thread-1]: delete "_1.nvd"
[junit4] 2> ASYNC NEW_CORE C38 name=collection1 org.apache.solr.core.SolrCore@670355
[junit4] 2> 35292 T79 C38 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={waitSearcher=true&commit=true&wt=javabin&version=2&softCommit=false} {commit=} 0 33
[junit4] 2> 35296 T77 C38 oasc.SolrCore.execute [collection1] webapp=/solr path=/select params={fl=id,price_f,name,_version_&q=*:*&wt=javabin&version=2} hits=1 status=0 QTime=1
[junit4] 2> 35300 T78 C38 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[unique (1445606933498167296)]} 0 1
[junit4] 2> 35303 T76 C38 oasu.DirectUpdateHandler2.commit start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4] 2> 35304 T76 C38 oasu.LoggingInfoStream.message [IW][qtp25819770-76]: commit: start
[junit4] 2> 35304 T76 C38 oasu.LoggingInfoStream.message [IW][qtp25819770-76]: commit: enter lock
[junit4] 2> 35304 T76 C38 oasu.LoggingInfoStream.message [IW][qtp25819770-76]: commit: now prepare
[junit4] 2> 35304 T76 C38 oasu.LoggingInfoStream.message [IW][qtp25819770-76]: prepareCommit: flush
[junit4] 2> 35305 T76 C38 oasu.LoggingInfoStream.message [IW][qtp25819770-76]: index before flush _2(5.0):C1
[junit4] 2> 35305 T76 C38 oasu.LoggingInfoStream.message [DW][qtp25819770-76]: qtp25819770-76 startFullFlush
[junit4] 2> 35305 T76 C38 oasu.LoggingInfoStream.message [DW][qtp25819770-76]: anyChanges? numDocsInRam=1 deletes=true hasTickets:false pendingChangesInFullFlush: false
[junit4] 2> 35305 T76 C38 oasu.LoggingInfoStream.message [DWFC][qtp25819770-76]: addFlushableState DocumentsWriterPerThread [pendingDeletes=gen=0, segment=_3, aborting=false, numDocsInRAM=1, deleteQueue=DWDQ: [ generation: 10 ]]
[junit4] 2> 35306 T76 C38 oasu.LoggingInfoStream.message [DWPT][qtp25819770-76]: flush postings as segment _3 numDocs=1
[junit4] 2> 35307 T76 C38 oasu.LoggingInfoStream.message [DWPT][qtp25819770-76]: new segment has 0 deleted docs
[junit4] 2> 35307 T76 C38 oasu.LoggingInfoStream.message [DWPT][qtp25819770-76]: new segment has no vectors; norms; no docValues; prox; freqs
[junit4] 2> 35307 T76 C38 oasu.LoggingInfoStream.message [DWPT][qtp25819770-76]: flushedFiles=[_3.fdx, _3.nvd, _3_Lucene41_0.pos, _3_Lucene41_0.doc, _3_Lucene41_0.tip, _3.fnm, _3.nvm, _3_Lucene41_0.tim, _3.fdt]
[junit4] 2> 35308 T76 C38 oasu.LoggingInfoStream.message [DWPT][qtp25819770-76]: flushed codec=Lucene45
[junit4] 2> 35308 T76 C38 oasu.LoggingInfoStream.message [DWPT][qtp25819770-76]: flushed: segment=_3 ramUsed=0.079 MB newFlushedSize(includes docstores)=0.001 MB docs/MB=942.117
[junit4] 2> 35308 T76 C38 oasu.LoggingInfoStream.message [DW][qtp25819770-76]: publishFlushedSegment seg-private deletes=null
[junit4] 2> 35309 T76 C38 oasu.LoggingInfoStream.message [IW][qtp25819770-76]: publishFlushedSegment
[junit4] 2> 35309 T76 C38 oasu.LoggingInfoStream.message [BD][qtp25819770-76]: push deletes 1 deleted terms (unique count=1) bytesUsed=1024 delGen=19 packetCount=1 totBytesUsed=1024
[junit4] 2> 35309 T76 C38 oasu.LoggingInfoStream.message [IW][qtp25819770-76]: publish sets newSegment delGen=20 seg=_3(5.0):C1
[junit4] 2> 35309 T76 C38 oasu.LoggingInfoStream.message [IFD][qtp25819770-76]: now checkpoint "_2(5.0):C1 _3(5.0):C1" [2 segments ; isCommit = false]
[junit4] 2> 35310 T76 C38 oasu.LoggingInfoStream.message [IFD][qtp25819770-76]: 0 msec to checkpoint
[junit4] 2> 35310 T76 C38 oasu.LoggingInfoStream.message [IW][qtp25819770-76]: apply all deletes during flush
[junit4] 2> 35310 T76 C38 oasu.LoggingInfoStream.message [BD][qtp25819770-76]: applyDeletes: infos=[_2(5.0):C1, _3(5.0):C1] packetCount=1
[junit4] 2> 35311 T76 C38 oasu.LoggingInfoStream.message [BD][qtp25819770-76]: seg=_2(5.0):C1 segGen=17 coalesced deletes=[CoalescedDeletes(termSets=1,queries=0)] newDelCount=1 100% deleted
[junit4] 2> 35311 T76 C38 oasu.LoggingInfoStream.message [BD][qtp25819770-76]: applyDeletes took 1 msec
[junit4] 2> 35311 T76 C38 oasu.LoggingInfoStream.message [IFD][qtp25819770-76]: now checkpoint "_2(5.0):C1/1 _3(5.0):C1" [2 segments ; isCommit = false]
[junit4] 2> 35312 T76 C38 oasu.LoggingInfoStream.message [IFD][qtp25819770-76]: 0 msec to checkpoint
[junit4] 2> 35312 T76 C38 oasu.LoggingInfoStream.message [IW][qtp25819770-76]: drop 100% deleted segments: _2(5.0):C1/1
[junit4] 2> 35312 T76 C38 oasu.LoggingInfoStream.message [IFD][qtp25819770-76]: now checkpoint "_3(5.0):C1" [1 segments ; isCommit = false]
[junit4] 2> 35312 T76 C38 oasu.LoggingInfoStream.message [IFD][qtp25819770-76]: 0 msec to checkpoint
[junit4] 2> 35313 T76 C38 oasu.LoggingInfoStream.message [BD][qtp25819770-76]: prune sis=org.apache.lucene.index.SegmentInfos@13a9d21 minGen=21 packetCount=1
[junit4] 2> 35313 T76 C38 oasu.LoggingInfoStream.message [BD][qtp25819770-76]: pruneDeletes: prune 1 packets; 0 packets remain
[junit4] 2> 35313 T76 C38 oasu.LoggingInfoStream.message [DW][qtp25819770-76]: qtp25819770-76 finishFullFlush success=true
[junit4] 2> 35314 T76 C38 oasu.LoggingInfoStream.message [TMP][qtp25819770-76]: findMerges: 1 segments
[junit4] 2> 35314 T76 C38 oasu.LoggingInfoStream.message [TMP][qtp25819770-76]: seg=_3(5.0):C1 size=0.001 MB [floored]
[junit4] 2> 35314 T76 C38 oasu.LoggingInfoStream.message [TMP][qtp25819770-76]: allowedSegmentCount=1 vs count=1 (eligible count=1) tooBigCount=0
[junit4] 2> 35315 T76 C38 oasu.LoggingInfoStream.message [CMS][qtp25819770-76]: now merge
[junit4] 2> 35315 T76 C38 oasu.LoggingInfoStream.message [CMS][qtp25819770-76]: index: _3(5.0):C1
[junit4] 2> 35315 T76 C38 oasu.LoggingInfoStream.message [CMS][qtp25819770-76]: no more merges pending; now return
[junit4] 2> 35315 T76 C38 oasu.LoggingInfoStream.message [IW][qtp25819770-76]: startCommit(): start
[junit4] 2> 35316 T76 C38 oasu.LoggingInfoStream.message [IW][qtp25819770-76]: startCommit index=_3(5.0):C1 changeCount=19
[junit4] 2> 35316 T76 C38 oasu.LoggingInfoStream.message [IW][qtp25819770-76]: done all syncs: [_3.fdx, _3.nvd, _3_Lucene41_0.doc, _3_Lucene41_0.pos, _3_Lucene41_0.tip, _3.si, _3.fdt, _3_Lucene41_0.tim, _3.nvm, _3.fnm]
[junit4] 2> 35316 T76 C38 oasu.LoggingInfoStream.message [IW][qtp25819770-76]: commit: pendingCommit != null
[junit4] 2> 35316 T76 C38 oasu.LoggingInfoStream.message [IW][qtp25819770-76]: commit: wrote segments file "segments_6"
[junit4] 2> 35317 T76 C38 oasu.LoggingInfoStream.message [IFD][qtp25819770-76]: now checkpoint "_3(5.0):C1" [1 segments ; isCommit = true]
[junit4] 2> 35317 T76 C38 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=2
[junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@186207d lockFactory=org.apache.lucene.store.NativeFSLockFactory@101ac3),segFN=segments_5,generation=5}
[junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@186207d lockFactory=org.apache.lucene.store.NativeFSLockFactory@101ac3),segFN=segments_6,generation=6}
[junit4] 2> 35317 T76 C38 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 6
[junit4] 2> 35317 T76 C38 oasu.LoggingInfoStream.message [IFD][qtp25819770-76]: deleteCommits: now decRef commit "segments_5"
[junit4] 2> 35318 T76 C38 oasu.LoggingInfoStream.message [IFD][qtp25819770-76]: delete "_2.si"
[junit4] 2> 35318 T76 C38 oasu.LoggingInfoStream.message [IFD][qtp25819770-76]: delete "_2_Lucene41_0.pos"
[junit4] 2> 35318 T76 C38 oasu.LoggingInfoStream.message [IFD][qtp25819770-76]: unable to remove file "_2_Lucene41_0.pos": java.io.IOException: MockDirectoryWrapper: file "_2_Lucene41_0.pos" is still open: cannot delete; Will re-try later.
[junit4] 2> 35318 T76 C38 oasu.LoggingInfoStream.message [IFD][qtp25819770-76]: delete "_2_Lucene41_0.tim"
[junit4] 2> 35319 T76 C38 oasu.LoggingInfoStream.message [IFD][qtp25819770-76]: unable to remove file "_2_Lucene41_0.tim": java.io.IOException: MockDirectoryWrapper: file "_2_Lucene41_0.tim" is still open: cannot delete; Will re-try later.
[junit4] 2> 35319 T76 C38 oasu.LoggingInfoStream.message [IFD][qtp25819770-76]: delete "_2.nvm"
[junit4] 2> 35319 T76 C38 oasu.LoggingInfoStream.message [IFD][qtp25819770-76]: delete "_2.nvd"
[junit4] 2> 35319 T76 C38 oasu.LoggingInfoStream.message [IFD][qtp25819770-76]: unable to remove file "_2.nvd": java.io.IOException: MockDirectoryWrapper: file "_2.nvd" is still open: cannot delete; Will re-try later.
[junit4] 2> 35320 T76 C38 oasu.LoggingInfoStream.message [IFD][qtp25819770-76]: delete "_2.fdt"
[junit4] 2> 35320 T76 C38 oasu.LoggingInfoStream.message [IFD][qtp25819770-76]: unable to remove file "_2.fdt": java.io.IOException: MockDirectoryWrapper: file "_2.fdt" is still open: cannot delete; Will re-try later.
[junit4] 2> 35320 T76 C38 oasu.LoggingInfoStream.message [IFD][qtp25819770-76]: delete "_2_Lucene41_0.doc"
[junit4] 2> 35320 T76 C38 oasu.LoggingInf
[...truncated too long message...]
.http.protocol.HttpRequestExecutor.doReceiveResponse(HttpRequestExecutor.java:300)
[junit4] > at org.apache.http.protocol.HttpRequestExecutor.execute(HttpRequestExecutor.java:127)
[junit4] > at org.apache.http.impl.client.DefaultRequestDirector.tryExecute(DefaultRequestDirector.java:717)
[junit4] > at org.apache.http.impl.client.DefaultRequestDirector.execute(DefaultRequestDirector.java:522)
[junit4] > at org.apache.http.impl.client.AbstractHttpClient.execute(AbstractHttpClient.java:906)
[junit4] > at org.apache.http.impl.client.AbstractHttpClient.execute(AbstractHttpClient.java:805)
[junit4] > at org.apache.http.impl.client.AbstractHttpClient.execute(AbstractHttpClient.java:784)
[junit4] > at org.apache.solr.client.solrj.impl.HttpSolrServer.request(HttpSolrServer.java:365)
[junit4] > ... 45 more
[junit4] 2> 241956 T70 oasc.CoreContainer.shutdown Shutting down CoreContainer instance=20669492
[junit4] 2> 241957 T70 oasc.SolrCore.close [collection1] CLOSING SolrCore org.apache.solr.core.SolrCore@670355
[junit4] 2> 241972 T70 oasu.DirectUpdateHandler2.close closing DirectUpdateHandler2{commits=69,autocommit maxTime=15000ms,autocommits=1,soft autocommits=3,optimizes=2,rollbacks=0,expungeDeletes=0,docsPending=0,adds=0,deletesById=0,deletesByQuery=0,errors=1,cumulative_adds=345,cumulative_deletesById=5,cumulative_deletesByQuery=37,cumulative_errors=1}
[junit4] 2> 241972 T70 oasu.SolrCoreState.decrefSolrCoreState Closing SolrCoreState
[junit4] 2> 241972 T70 oasu.DefaultSolrCoreState.closeIndexWriter SolrCoreState ref count has reached 0 - closing IndexWriter
[junit4] 2> 241973 T70 oasu.DefaultSolrCoreState.closeIndexWriter closing IndexWriter with IndexWriterCloser
[junit4] 2> 241974 T70 C51 oasu.LoggingInfoStream.message [IW][SUITE-SolrExampleJettyTest-seed#[6EEA9062DF94C2A1]-worker]: now flush at close waitForMerges=true
[junit4] 2> 241974 T70 C51 oasu.LoggingInfoStream.message [IW][SUITE-SolrExampleJettyTest-seed#[6EEA9062DF94C2A1]-worker]: start flush: applyAllDeletes=true
[junit4] 2> 241975 T70 C51 oasu.LoggingInfoStream.message [IW][SUITE-SolrExampleJettyTest-seed#[6EEA9062DF94C2A1]-worker]: index before flush
[junit4] 2> 241975 T70 C51 oasu.LoggingInfoStream.message [DW][SUITE-SolrExampleJettyTest-seed#[6EEA9062DF94C2A1]-worker]: SUITE-SolrExampleJettyTest-seed#[6EEA9062DF94C2A1]-worker startFullFlush
[junit4] 2> 241976 T70 C51 oasu.LoggingInfoStream.message [DW][SUITE-SolrExampleJettyTest-seed#[6EEA9062DF94C2A1]-worker]: anyChanges? numDocsInRam=0 deletes=false hasTickets:false pendingChangesInFullFlush: false
[junit4] 2> 241976 T70 C51 oasu.LoggingInfoStream.message [DW][SUITE-SolrExampleJettyTest-seed#[6EEA9062DF94C2A1]-worker]: SUITE-SolrExampleJettyTest-seed#[6EEA9062DF94C2A1]-worker finishFullFlush success=true
[junit4] 2> 241977 T70 C51 oasu.LoggingInfoStream.message [IW][SUITE-SolrExampleJettyTest-seed#[6EEA9062DF94C2A1]-worker]: apply all deletes during flush
[junit4] 2> 241977 T70 C51 oasu.LoggingInfoStream.message [BD][SUITE-SolrExampleJettyTest-seed#[6EEA9062DF94C2A1]-worker]: prune sis=org.apache.lucene.index.SegmentInfos@13a9d21 minGen=9223372036854775807 packetCount=0
[junit4] 2> 241978 T70 C51 oasu.LoggingInfoStream.message [CMS][SUITE-SolrExampleJettyTest-seed#[6EEA9062DF94C2A1]-worker]: now merge
[junit4] 2> 241978 T70 C51 oasu.LoggingInfoStream.message [CMS][SUITE-SolrExampleJettyTest-seed#[6EEA9062DF94C2A1]-worker]: index:
[junit4] 2> 241979 T70 C51 oasu.LoggingInfoStream.message [CMS][SUITE-SolrExampleJettyTest-seed#[6EEA9062DF94C2A1]-worker]: no more merges pending; now return
[junit4] 2> 241979 T70 C51 oasu.LoggingInfoStream.message [IW][SUITE-SolrExampleJettyTest-seed#[6EEA9062DF94C2A1]-worker]: waitForMerges
[junit4] 2> 241980 T70 C51 oasu.LoggingInfoStream.message [IW][SUITE-SolrExampleJettyTest-seed#[6EEA9062DF94C2A1]-worker]: waitForMerges done
[junit4] 2> 241980 T70 C51 oasu.LoggingInfoStream.message [IW][SUITE-SolrExampleJettyTest-seed#[6EEA9062DF94C2A1]-worker]: now call final commit()
[junit4] 2> 241980 T70 C51 oasu.LoggingInfoStream.message [IW][SUITE-SolrExampleJettyTest-seed#[6EEA9062DF94C2A1]-worker]: commit: start
[junit4] 2> 241981 T70 C51 oasu.LoggingInfoStream.message [IW][SUITE-SolrExampleJettyTest-seed#[6EEA9062DF94C2A1]-worker]: commit: enter lock
[junit4] 2> 241981 T70 C51 oasu.LoggingInfoStream.message [IW][SUITE-SolrExampleJettyTest-seed#[6EEA9062DF94C2A1]-worker]: commit: now prepare
[junit4] 2> 241981 T70 C51 oasu.LoggingInfoStream.message [IW][SUITE-SolrExampleJettyTest-seed#[6EEA9062DF94C2A1]-worker]: prepareCommit: flush
[junit4] 2> 241982 T70 C51 oasu.LoggingInfoStream.message [IW][SUITE-SolrExampleJettyTest-seed#[6EEA9062DF94C2A1]-worker]: index before flush
[junit4] 2> 241982 T70 C51 oasu.LoggingInfoStream.message [DW][SUITE-SolrExampleJettyTest-seed#[6EEA9062DF94C2A1]-worker]: SUITE-SolrExampleJettyTest-seed#[6EEA9062DF94C2A1]-worker startFullFlush
[junit4] 2> 241982 T70 C51 oasu.LoggingInfoStream.message [DW][SUITE-SolrExampleJettyTest-seed#[6EEA9062DF94C2A1]-worker]: anyChanges? numDocsInRam=0 deletes=false hasTickets:false pendingChangesInFullFlush: false
[junit4] 2> 241982 T70 C51 oasu.LoggingInfoStream.message [IW][SUITE-SolrExampleJettyTest-seed#[6EEA9062DF94C2A1]-worker]: apply all deletes during flush
[junit4] 2> 241983 T70 C51 oasu.LoggingInfoStream.message [BD][SUITE-SolrExampleJettyTest-seed#[6EEA9062DF94C2A1]-worker]: prune sis=org.apache.lucene.index.SegmentInfos@13a9d21 minGen=9223372036854775807 packetCount=0
[junit4] 2> 241983 T70 C51 oasu.LoggingInfoStream.message [DW][SUITE-SolrExampleJettyTest-seed#[6EEA9062DF94C2A1]-worker]: SUITE-SolrExampleJettyTest-seed#[6EEA9062DF94C2A1]-worker finishFullFlush success=true
[junit4] 2> 241983 T70 C51 oasu.LoggingInfoStream.message [IW][SUITE-SolrExampleJettyTest-seed#[6EEA9062DF94C2A1]-worker]: startCommit(): start
[junit4] 2> 241983 T70 C51 oasu.LoggingInfoStream.message [IW][SUITE-SolrExampleJettyTest-seed#[6EEA9062DF94C2A1]-worker]: skip startCommit(): no changes pending
[junit4] 2> 241984 T70 C51 oasu.LoggingInfoStream.message [IW][SUITE-SolrExampleJettyTest-seed#[6EEA9062DF94C2A1]-worker]: commit: pendingCommit == null; skip
[junit4] 2> 241984 T70 C51 oasu.LoggingInfoStream.message [IW][SUITE-SolrExampleJettyTest-seed#[6EEA9062DF94C2A1]-worker]: commit: done
[junit4] 2> 241984 T70 C51 oasu.LoggingInfoStream.message [IW][SUITE-SolrExampleJettyTest-seed#[6EEA9062DF94C2A1]-worker]: at close:
[junit4] 2> 241985 T70 oasc.SolrCore.closeSearcher [collection1] Closing main searcher on request.
[junit4] 2> 241985 T70 oasc.CachingDirectoryFactory.close Closing MockDirectoryFactory - 2 directories currently being tracked
[junit4] 2> 241985 T70 oasc.CachingDirectoryFactory.closeCacheValue looking to close /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-solrj/test/J1/solrtest-SolrExampleJettyTest-1378638202911 [CachedDir<<refCount=0;path=/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-solrj/test/J1/solrtest-SolrExampleJettyTest-1378638202911;done=false>>]
[junit4] 2> 241985 T70 oasc.CachingDirectoryFactory.close Closing directory: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-solrj/test/J1/solrtest-SolrExampleJettyTest-1378638202911
[junit4] 2> 241986 T70 oasc.CachingDirectoryFactory.closeCacheValue looking to close /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-solrj/test/J1/solrtest-SolrExampleJettyTest-1378638202911/index [CachedDir<<refCount=0;path=/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-solrj/test/J1/solrtest-SolrExampleJettyTest-1378638202911/index;done=false>>]
[junit4] 2> 241986 T70 oasc.CachingDirectoryFactory.close Closing directory: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-solrj/test/J1/solrtest-SolrExampleJettyTest-1378638202911/index
[junit4] 2> 241986 T70 oejsh.ContextHandler.doStop stopped o.e.j.s.ServletContextHandler{/solr,null}
[junit4] 2> 242038 T70 oas.SolrTestCaseJ4.deleteCore ###deleteCore
[junit4] 2> NOTE: test params are: codec=Lucene45: {}, docValues:{}, sim=RandomSimilarityProvider(queryNorm=false,coord=yes): {}, locale=lv, timezone=Australia/Queensland
[junit4] 2> NOTE: Linux 3.2.0-52-generic i386/Oracle Corporation 1.8.0-ea (32-bit)/cpus=8,threads=1,free=23191048,total=64880640
[junit4] 2> NOTE: All tests run in this JVM: [SolrExampleBinaryTest, SolrExampleStreamingTest, SolrExampleJettyTest]
[junit4] Completed on J1 in 207.97s, 27 tests, 1 error <<< FAILURES!
[...truncated 34 lines...]
BUILD FAILED
/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/build.xml:396: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/build.xml:376: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/build.xml:39: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build.xml:202: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/common-build.xml:455: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/lucene/common-build.xml:1230: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/lucene/common-build.xml:873: There were test failures: 46 suites, 272 tests, 1 error
Total time: 42 minutes 18 seconds
Build step 'Invoke Ant' marked build as failure
Description set: Java: 32bit/jdk1.8.0-ea-b102 -server -XX:+UseConcMarkSweepGC
Archiving artifacts
Recording test results
Email was triggered for: Failure
Sending email for trigger: Failure