You are viewing a plain text version of this content. The canonical link for it is here.
Posted to dev@lucene.apache.org by Apache Jenkins Server <je...@builds.apache.org> on 2013/08/06 08:45:02 UTC
[JENKINS] Lucene-Solr-NightlyTests-trunk - Build # 342 - Failure
Build: https://builds.apache.org/job/Lucene-Solr-NightlyTests-trunk/342/
2 tests failed.
REGRESSION: org.apache.solr.ConvertedLegacyTest.testABunchOfConvertedStuff
Error Message:
Exception during query
Stack Trace:
java.lang.RuntimeException: Exception during query
at __randomizedtesting.SeedInfo.seed([8B0C219DD4D6D423:D3F5FB3CF1DDEB0]:0)
at org.apache.solr.SolrTestCaseJ4.assertQ(SolrTestCaseJ4.java:635)
at org.apache.solr.SolrTestCaseJ4.assertQ(SolrTestCaseJ4.java:602)
at org.apache.solr.ConvertedLegacyTest.testABunchOfConvertedStuff(ConvertedLegacyTest.java:1122)
at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:57)
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
at java.lang.reflect.Method.invoke(Method.java:606)
at com.carrotsearch.randomizedtesting.RandomizedRunner.invoke(RandomizedRunner.java:1559)
at com.carrotsearch.randomizedtesting.RandomizedRunner.access$600(RandomizedRunner.java:79)
at com.carrotsearch.randomizedtesting.RandomizedRunner$6.evaluate(RandomizedRunner.java:737)
at com.carrotsearch.randomizedtesting.RandomizedRunner$7.evaluate(RandomizedRunner.java:773)
at com.carrotsearch.randomizedtesting.RandomizedRunner$8.evaluate(RandomizedRunner.java:787)
at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:53)
at org.apache.lucene.util.TestRuleSetupTeardownChained$1.evaluate(TestRuleSetupTeardownChained.java:50)
at org.apache.lucene.util.TestRuleFieldCacheSanity$1.evaluate(TestRuleFieldCacheSanity.java:51)
at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:46)
at com.carrotsearch.randomizedtesting.rules.SystemPropertiesInvariantRule$1.evaluate(SystemPropertiesInvariantRule.java:55)
at org.apache.lucene.util.TestRuleThreadAndTestName$1.evaluate(TestRuleThreadAndTestName.java:49)
at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:70)
at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:48)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:358)
at com.carrotsearch.randomizedtesting.ThreadLeakControl.forkTimeoutingTask(ThreadLeakControl.java:782)
at com.carrotsearch.randomizedtesting.ThreadLeakControl$3.evaluate(ThreadLeakControl.java:442)
at com.carrotsearch.randomizedtesting.RandomizedRunner.runSingleTest(RandomizedRunner.java:746)
at com.carrotsearch.randomizedtesting.RandomizedRunner$3.evaluate(RandomizedRunner.java:648)
at com.carrotsearch.randomizedtesting.RandomizedRunner$4.evaluate(RandomizedRunner.java:682)
at com.carrotsearch.randomizedtesting.RandomizedRunner$5.evaluate(RandomizedRunner.java:693)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:53)
at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:46)
at org.apache.lucene.util.TestRuleStoreClassName$1.evaluate(TestRuleStoreClassName.java:42)
at com.carrotsearch.randomizedtesting.rules.SystemPropertiesInvariantRule$1.evaluate(SystemPropertiesInvariantRule.java:55)
at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:39)
at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:39)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at org.apache.lucene.util.TestRuleAssertionsRequired$1.evaluate(TestRuleAssertionsRequired.java:43)
at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:48)
at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:70)
at org.apache.lucene.util.TestRuleIgnoreTestSuites$1.evaluate(TestRuleIgnoreTestSuites.java:55)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:358)
at java.lang.Thread.run(Thread.java:724)
Caused by: java.lang.RuntimeException: REQUEST FAILED: xpath=//float[.='2.9459102']
xml response was: <?xml version="1.0" encoding="UTF-8"?>
<response>
<lst name="responseHeader"><int name="status">0</int><int name="QTime">0</int></lst><result name="response" numFound="1" start="0" maxScore="2.609438"><doc><arr name="fname_s"><str>Yonik</str></arr><float name="score">2.609438</float></doc></result>
</response>
request was:fl=fname_s,score&start=0&q=id:44&qt=standard&rows=10
at org.apache.solr.SolrTestCaseJ4.assertQ(SolrTestCaseJ4.java:628)
... 42 more
REGRESSION: org.apache.solr.handler.TestReplicationHandler.doTestStressReplication
Error Message:
timed out waiting for collection1 startAt time to exceed: Tue Aug 06 08:30:05 MEST 2013
Stack Trace:
java.lang.AssertionError: timed out waiting for collection1 startAt time to exceed: Tue Aug 06 08:30:05 MEST 2013
at __randomizedtesting.SeedInfo.seed([8B0C219DD4D6D423:50A7215BD1FEBD90]:0)
at org.junit.Assert.fail(Assert.java:93)
at org.apache.solr.handler.TestReplicationHandler.watchCoreStartAt(TestReplicationHandler.java:1507)
at org.apache.solr.handler.TestReplicationHandler.doTestStressReplication(TestReplicationHandler.java:811)
at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:57)
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
at java.lang.reflect.Method.invoke(Method.java:606)
at com.carrotsearch.randomizedtesting.RandomizedRunner.invoke(RandomizedRunner.java:1559)
at com.carrotsearch.randomizedtesting.RandomizedRunner.access$600(RandomizedRunner.java:79)
at com.carrotsearch.randomizedtesting.RandomizedRunner$6.evaluate(RandomizedRunner.java:737)
at com.carrotsearch.randomizedtesting.RandomizedRunner$7.evaluate(RandomizedRunner.java:773)
at com.carrotsearch.randomizedtesting.RandomizedRunner$8.evaluate(RandomizedRunner.java:787)
at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:53)
at org.apache.lucene.util.TestRuleSetupTeardownChained$1.evaluate(TestRuleSetupTeardownChained.java:50)
at org.apache.lucene.util.TestRuleFieldCacheSanity$1.evaluate(TestRuleFieldCacheSanity.java:51)
at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:46)
at com.carrotsearch.randomizedtesting.rules.SystemPropertiesInvariantRule$1.evaluate(SystemPropertiesInvariantRule.java:55)
at org.apache.lucene.util.TestRuleThreadAndTestName$1.evaluate(TestRuleThreadAndTestName.java:49)
at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:70)
at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:48)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:358)
at com.carrotsearch.randomizedtesting.ThreadLeakControl.forkTimeoutingTask(ThreadLeakControl.java:782)
at com.carrotsearch.randomizedtesting.ThreadLeakControl$3.evaluate(ThreadLeakControl.java:442)
at com.carrotsearch.randomizedtesting.RandomizedRunner.runSingleTest(RandomizedRunner.java:746)
at com.carrotsearch.randomizedtesting.RandomizedRunner$3.evaluate(RandomizedRunner.java:648)
at com.carrotsearch.randomizedtesting.RandomizedRunner$4.evaluate(RandomizedRunner.java:682)
at com.carrotsearch.randomizedtesting.RandomizedRunner$5.evaluate(RandomizedRunner.java:693)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:53)
at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:46)
at org.apache.lucene.util.TestRuleStoreClassName$1.evaluate(TestRuleStoreClassName.java:42)
at com.carrotsearch.randomizedtesting.rules.SystemPropertiesInvariantRule$1.evaluate(SystemPropertiesInvariantRule.java:55)
at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:39)
at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:39)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at org.apache.lucene.util.TestRuleAssertionsRequired$1.evaluate(TestRuleAssertionsRequired.java:43)
at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:48)
at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:70)
at org.apache.lucene.util.TestRuleIgnoreTestSuites$1.evaluate(TestRuleIgnoreTestSuites.java:55)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:358)
at java.lang.Thread.run(Thread.java:724)
Build Log:
[...truncated 9846 lines...]
[junit4] Suite: org.apache.solr.ConvertedLegacyTest
[junit4] 2> 889928 T2584 oas.SolrTestCaseJ4.initCore ####initCore
[junit4] 2> Creating dataDir: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test/J1/./solrtest-ConvertedLegacyTest-1375769519891
[junit4] 2> 889930 T2584 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test-files/solr/collection1/'
[junit4] 2> 889931 T2584 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test-files/solr/collection1/lib/README' to classloader
[junit4] 2> 889931 T2584 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test-files/solr/collection1/lib/classes/' to classloader
[junit4] 2> 890050 T2584 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_50
[junit4] 2> 890123 T2584 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4] 2> 890124 T2584 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4] 2> 890135 T2584 oass.IndexSchema.readSchema [null] Schema name=test
[junit4] 2> 890712 T2584 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4] 2> 890725 T2584 oass.IndexSchema.readSchema default search field in schema is text
[junit4] 2> 890728 T2584 oass.IndexSchema.readSchema unique key field: id
[junit4] 2> 890739 T2584 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4] 2> 890743 T2584 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4] 2> 890747 T2584 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4] 2> 890748 T2584 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4] 2> 890748 T2584 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4] 2> 890749 T2584 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4] 2> 890749 T2584 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4] 2> 890749 T2584 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4] 2> 890750 T2584 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4] 2> 890750 T2584 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test-files/solr
[junit4] 2> 890750 T2584 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test-files/solr/'
[junit4] 2> 890763 T2584 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4] 2> 890763 T2584 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test-files/solr
[junit4] 2> 890764 T2584 oasc.SolrResourceLoader.<init> new SolrResourceLoader for deduced Solr Home: '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test-files/solr/'
[junit4] 2> 890830 T2584 oasc.CoreContainer.<init> New CoreContainer 187527062
[junit4] 2> 890831 T2584 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test-files/solr/]
[junit4] 2> 890832 T2584 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 0
[junit4] 2> 890832 T2584 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4] 2> 890833 T2584 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 0
[junit4] 2> 890833 T2584 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4] 2> 890833 T2584 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4] 2> 890833 T2584 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4] 2> 890834 T2584 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4] 2> 890834 T2584 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4] 2> 890834 T2584 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4] 2> 890835 T2584 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=0&connTimeout=0&retry=false
[junit4] 2> 890847 T2584 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
[junit4] 2> 890851 T2585 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test-files/solr/collection1
[junit4] 2> 890851 T2585 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test-files/solr/collection1/'
[junit4] 2> 890852 T2585 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test-files/solr/collection1/lib/README' to classloader
[junit4] 2> 890853 T2585 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test-files/solr/collection1/lib/classes/' to classloader
[junit4] 2> 890912 T2585 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_50
[junit4] 2> 890989 T2585 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4] 2> 890989 T2585 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4] 2> 890999 T2585 oass.IndexSchema.readSchema [collection1] Schema name=test
[junit4] 2> 891543 T2585 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4] 2> 891551 T2585 oass.IndexSchema.readSchema default search field in schema is text
[junit4] 2> 891554 T2585 oass.IndexSchema.readSchema unique key field: id
[junit4] 2> 891561 T2585 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4] 2> 891565 T2585 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4] 2> 891569 T2585 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4] 2> 891569 T2585 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4] 2> 891569 T2585 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4] 2> 891569 T2585 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4] 2> 891570 T2585 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4] 2> 891570 T2585 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4] 2> 891570 T2585 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4] 2> 891571 T2585 oasc.SolrCore.<init> [collection1] Opening new SolrCore at /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test-files/solr/collection1/, dataDir=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test/J1/./solrtest-ConvertedLegacyTest-1375769519891/
[junit4] 2> 891571 T2585 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@7fd0007e
[junit4] 2> 891572 T2585 oasc.CachingDirectoryFactory.get return new directory for /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test/J1/./solrtest-ConvertedLegacyTest-1375769519891
[junit4] 2> 891572 T2585 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test/J1/./solrtest-ConvertedLegacyTest-1375769519891/index/
[junit4] 2> 891572 T2585 oasc.SolrCore.initIndex WARN [collection1] Solr index directory '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test/J1/./solrtest-ConvertedLegacyTest-1375769519891/index' doesn't exist. Creating new index...
[junit4] 2> 891573 T2585 oasc.CachingDirectoryFactory.get return new directory for /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test/J1/./solrtest-ConvertedLegacyTest-1375769519891/index
[junit4] 2> 891594 T2585 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
[junit4] 2> commit{dir=RateLimitedDirectoryWrapper(MockDirWrapper(org.apache.lucene.store.RAMDirectory@63ee93a lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@d34cf76)),segFN=segments_1,generation=1}
[junit4] 2> 891594 T2585 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4] 2> 891594 T2585 oasc.SolrCore.initWriters created xml: solr.XMLResponseWriter
[junit4] 2> 891597 T2585 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4] 2> 891597 T2585 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe-allfields"
[junit4] 2> 891597 T2585 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4] 2> 891597 T2585 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "uniq-fields"
[junit4] 2> 891598 T2585 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4] 2> 891598 T2585 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4] 2> 891598 T2585 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4] 2> 891599 T2585 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4] 2> 891599 T2585 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4] 2> 891599 T2585 oasc.RequestHandlers.initHandlersFromConfig created dismax: solr.SearchHandler
[junit4] 2> 891600 T2585 oasc.RequestHandlers.initHandlersFromConfig created mock: org.apache.solr.core.MockQuerySenderListenerReqHandler
[junit4] 2> 891600 T2585 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4] 2> 891600 T2585 oasc.RequestHandlers.initHandlersFromConfig created defaults: solr.StandardRequestHandler
[junit4] 2> 891600 T2585 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.StandardRequestHandler
[junit4] 2> 891601 T2585 oasc.RequestHandlers.initHandlersFromConfig created lazy: solr.StandardRequestHandler
[junit4] 2> 891601 T2585 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4] 2> 891601 T2585 oasc.RequestHandlers.initHandlersFromConfig created /terms: org.apache.solr.handler.component.SearchHandler
[junit4] 2> 891602 T2585 oasc.RequestHandlers.initHandlersFromConfig created spellCheckCompRH: org.apache.solr.handler.component.SearchHandler
[junit4] 2> 891602 T2585 oasc.RequestHandlers.initHandlersFromConfig created spellCheckCompRH_Direct: org.apache.solr.handler.component.SearchHandler
[junit4] 2> 891602 T2585 oasc.RequestHandlers.initHandlersFromConfig created spellCheckWithWordbreak: org.apache.solr.handler.component.SearchHandler
[junit4] 2> 891603 T2585 oasc.RequestHandlers.initHandlersFromConfig created spellCheckWithWordbreak_Direct: org.apache.solr.handler.component.SearchHandler
[junit4] 2> 891603 T2585 oasc.RequestHandlers.initHandlersFromConfig created spellCheckCompRH1: org.apache.solr.handler.component.SearchHandler
[junit4] 2> 891603 T2585 oasc.RequestHandlers.initHandlersFromConfig created mltrh: org.apache.solr.handler.component.SearchHandler
[junit4] 2> 891604 T2585 oasc.RequestHandlers.initHandlersFromConfig created tvrh: org.apache.solr.handler.component.SearchHandler
[junit4] 2> 891604 T2585 oasc.RequestHandlers.initHandlersFromConfig created /mlt: solr.MoreLikeThisHandler
[junit4] 2> 891604 T2585 oasc.RequestHandlers.initHandlersFromConfig created /debug/dump: solr.DumpRequestHandler
[junit4] 2> 891615 T2585 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4] 2> 891616 T2585 oasc.SolrCore.initDeprecatedSupport WARN solrconfig.xml uses deprecated <admin/gettableFiles>, Please update your config to use the ShowFileRequestHandler.
[junit4] 2> 891617 T2585 oasc.SolrCore.initDeprecatedSupport WARN adding ShowFileRequestHandler with hidden files: [THROW.ERROR.ON.ADD.UPDATEPROCESSOR.JS, SOLRCONFIG-HIGHLIGHT.XML, SCHEMA-REQUIRED-FIELDS.XML, BAD-SCHEMA-DOCVALUES-NOT-REQUIRED-NO-DEFAULT.XML, SCHEMA-REPLICATION2.XML, TRIVIAL.UPDATEPROCESSOR1.JS, SCHEMA-MINIMAL.XML, BAD-SCHEMA-DUP-DYNAMICFIELD.XML, SOLRCONFIG-CACHING.XML, BAD-SOLRCONFIG-UNEXPECTED-SCHEMA-ATTRIBUTE.XML, SCHEMA-POSTINGSHIGHLIGHT.XML, REGEX-BOOST-PROCESSOR-TEST.TXT, SOLRCONFIG-REPEATER.XML, BAD-SCHEMA-CURRENCY-FT-BOGUS-CODE-IN-XML.XML, SOLRCONFIG-MERGEPOLICY.XML, BAD-SCHEMA-NONTEXT-ANALYZER.XML, CURRENCY.XML, SOLRCONFIG-TLOG.XML, SOLRCONFIG-MASTER.XML, SOLRCONFIG-COMPONENTS-NAME.XML, SOLRCONFIG-MERGEPOLICY-LEGACY.XML, BAD-SCHEMA-UNIQUEKEY-MULTIVALUED.XML, SCHEMA11.XML, SOLRCONFIG-BASIC.XML, DA_COMPOUNDDICTIONARY.TXT, MISSLEADING.EXTENSION.UPDATEPROCESSOR.JS.TXT, SCHEMA-COPYFIELD-TEST.XML, SOLRCONFIG-SLAVE.XML, ELEVATE.XML, TRIVIAL.UPDATEPROCESSOR0.JS, SCHEMA-SWEETSPOT.XML, BAD-SOLRCONFIG-BOGUS-SCRIPTENGINE-NAME.XML, SCHEMA-CHARFILTERS.XML, SCHEMA-IB.XML, BAD-SCHEMA-MISPLACED-ASTERISK-COPYFIELD-SOURCE-SHOULD-FAIL-TEST.XML, SOLRCONFIG-QUERYSENDER.XML, SOLRCONFIG-SNIPPET-PROCESSOR.XML, SCHEMA-REPLICATION1.XML, DA_UTF8.XML, BAD-SOLRCONFIG-MULTIPLE-INDEXCONFIGS.XML, BAD-SCHEMA-NON-GLOB-COPYFIELD-SOURCE-MATCHING-NOTHING-SHOULD-FAIL-TEST.XML, SCHEMA-TINY.XML, CONDITIONAL.UPDATEPROCESSOR.JS, SOLRCONFIG-DEFAULTS.XML, MISSING.FUNCTIONS.UPDATEPROCESSOR.JS, HYPHENATION.DTD, SOLRCONFIG-ENABLEPLUGIN.XML, BAD-SOLRCONFIG-SCHEMA-MUTABLE-BUT-NOT-MANAGED.XML, STEMDICT.TXT, SCHEMA-PHRASESUGGEST.XML, SCHEMA-ID-AND-VERSION-FIELDS-ONLY.XML, HUNSPELL-TEST.AFF, SCHEMA-ONE-FIELD-NO-DYNAMIC-FIELD-UNIQUE-KEY.XML, BAD-SCHEMA-CURRENCY-FT-OER-NORATES.XML, SCHEMA-SNIPPET-TYPE.XML, STOPTYPES-1.TXT, STOPWORDSWRONGENCODING.TXT, SCHEMA-NUMERIC.XML, SOLRCONFIG-TRANSFORMERS.XML, BAD-SCHEMA-NOT-INDEXED-BUT-TF.XML, SOLRCONFIG-SIMPLELOCK.XML, SCHEMA-DOCVALUES.XML, SOLRCONFIG-TLOG-MUTABLE-MANAGED-SCHEMA.XML, WDFTYPES.TXT, SOLRCONFIG-INFOSTREAM-LOGGING.XML, STOPTYPES-2.TXT, SCHEMA-REVERSED.XML, BAD-SCHEMA-BOGUS-ANALYSIS-PARAMETERS.XML, BAD-SCHEMA-CURRENCY-FT-MULTIVALUED.XML, SOLRCONFIG-SPELLCHECKCOMPONENT.XML, BAD-SCHEMA-CURRENCY-MULTIVALUED.XML, SCHEMA-DFR.XML, SOLRCONFIG-PHRASESUGGEST.XML, BAD-SCHEMA-NOT-INDEXED-BUT-POS.XML, KEEP-1.TXT, SCHEMA-SPATIAL.XML, OPEN-EXCHANGE-RATES.JSON, STOPWITHBOM.TXT, SOLRCONFIG-POSTINGSHIGHLIGHT.XML, SCHEMA-BINARYFIELD.XML, SOLRCONFIG-SPELLCHECKER.XML, SOLRCONFIG-WARMER.XML, SOLRCONFIG-UPDATE-PROCESSOR-CHAINS.XML, BAD-SCHEMA-OMIT-TF-BUT-NOT-POS.XML, BAD-SCHEMA-DUP-FIELDTYPE.XML, SCHEMA-XINCLUDE.XML, SOLRCONFIG-MASTER1.XML, BAD-SCHEMA-MULTIPLE-ASTERISK-COPYFIELD-SOURCE-SHOULD-FAIL-TEST.XML, SCHEMA-BEHAVIOR.XML, SYNONYMS.TXT, SOLRCONFIG-MINIMAL.XML, SCHEMA-DOCVALUESMULTI.XML, BAD-SCHEMA-UNSUPPORTED-DOCVALUES.XML, BAD-SCHEMA-CURRENCY-DYNAMIC-MULTIVALUED.XML, SCHEMA_CODEC.XML, SCHEMA-SNIPPET-TYPES.INCL, BAD-SCHEMA-SWEETSPOT-PARTIAL-HYPERBOLIC.XML, SOLRCONFIG-SOLR-749.XML, SCHEMA-EFF.XML, SOLRCONFIG-MASTER1-KEEPONEBACKUP.XML, STOP-2.TXT, SOLRCONFIG-FUNCTIONQUERY.XML, SOLRCONFIG-TERMINDEX.XML, SCHEMA-LMDIRICHLET.XML, SCHEMA-ONE-FIELD-NO-DYNAMIC-FIELD.XML, BAD-SCHEMA-SWEETSPOT-PARTIAL-NORMS.XML, SOLRCONFIG-ELEVATE.XML, BAD-SCHEMA-SWEETSPOT-PARTIAL-BASELINE.XML, STOPWORDS.TXT, SCHEMA-FOLDING.XML, BAD-SCHEMA-BOGUS-FIELD-PARAMETERS.XML, SCHEMA-STOP-KEEP.XML, FUZZYSUGGEST.TXT, BAD-SOLRCONFIG-MANAGED-SCHEMA-NAMED-SCHEMA.XML.XML, BAD-SCHEMA-NOT-INDEXED-BUT-NORMS.XML, SCHEMA-REST.XML, SOLRCONFIG-SOLCOREPROPERTIES.XML, SOLRCONFIG-PARSING-UPDATE-PROCESSOR-CHAINS.XML, SOLRCONFIG-TLOG-MANAGED-SCHEMA.XML, STOP-1.TXT, SOLRCONFIG-MASTER2.XML, SOLRCONFIG-MANAGED-SCHEMA.XML, SOLRCONFIG-MERGEPOLICY-DEFAULTS.XML, SCHEMA-SPELLCHECKER.XML, SOLRCONFIG-RESPONSE-LOG-COMPONENT.XML, BAD-SCHEMA-MISPLACED-ASTERISK-COPYFIELD-DEST-SHOULD-FAIL-TEST.XML, SOLRCONFIG-LAZYWRITER.XML, SCHEMA-LUCENEMATCHVERSION.XML, SCHEMA-CLASS-NAME-SHORTENING-ON-SERIALIZATION.XML, BAD-MP-SOLRCONFIG.XML, FRENCHARTICLES.TXT, SCHEMA15.XML, SOLRCONFIG-REQHANDLER.INCL, SCHEMASURROUND.XML, SOLRCONFIG-MASTER3.XML, BAD-SCHEMA-MULTIPLE-ASTERISK-COPYFIELD-DEST-SHOULD-FAIL-TEST.XML, HUNSPELL-TEST.DIC, SOLRCONFIG-XINCLUDE.XML, BAD-SCHEMA-CODEC-GLOBAL-VS-FT-MISMATCH.XML, SOLRCONFIG-SLAVE1.XML, SOLRCONFIG-DELPOLICY1.XML, SCHEMA-SIM.XML, SCHEMA-SNIPPET-FIELD.XML, SCHEMA-COLLATE.XML, STOP-SNOWBALL.TXT, BAD-SCHEMA-SIM-GLOBAL-VS-FT-MISMATCH.XML, PROTWORDS.TXT, SOLRCONFIG-ADD-SCHEMA-FIELDS-UPDATE-PROCESSOR-CHAINS.XML, SCHEMA-TRIE.XML, SOLRCONFIG_CODEC.XML, SCHEMA-SYNONYM-TOKENIZER.XML, BAD-SOLRCONFIG-INVALID-SCRIPTFILE.XML, JASUGGEST.TXT, SCHEMA-REST-LUCENE-MATCH-VERSION.XML, BAD-SOLRCONFIG-MULTIPLE-CFS.XML, SCHEMA-DOCVALUESFACETING.XML, SCHEMA-TFIDF.XML, SCHEMA-ADD-SCHEMA-FIELDS-UPDATE-PROCESSOR.XML, SOLRCONFIG-SCRIPT-UPDATEPROCESSOR.XML, SCHEMA-LMJELINEKMERCER.XML, PHRASESUGGEST.TXT, BAD-SOLRCONFIG-MISSING-SCRIPTFILE.XML, BAD-SCHEMA-UNIQUEKEY-USES-DEFAULT.XML, OLD_SYNONYMS.TXT, SOLRCONFIG-DELPOLICY2.XML, SOLRCONFIG-NATIVELOCK.XML, XSLT, BAD-SCHEMA-DUP-FIELD.XML, SOLRCONFIG-MUTABLE-MANAGED-SCHEMA.XML, SOLRCONFIG-NOCACHE.XML, BAD-SCHEMA-SWEETSPOT-BOTH-TF.XML, SCHEMA-BM25.XML, ADDFIELDS.UPDATEPROCESSOR.JS, SOLRCONFIG-QUERYSENDER-NOQUERY.XML, SOLRCONFIG-ALTDIRECTORY.XML, COMPOUNDDICTIONARY.TXT, SOLRCONFIG-INDEXCONFIG.XML, BAD-SCHEMA-CURRENCY-FT-BOGUS-DEFAULT-CODE.XML, SOLRCONFIG_PERF.XML, BAD-CURRENCY.XML, SCHEMA-NOT-REQUIRED-UNIQUE-KEY.XML, BAD-SCHEMA-ANALYZER-CLASS-AND-NESTED.XML, KEEP-2.TXT, BAD-SCHEMA-UNIQUEKEY-IS-COPYFIELD-DEST.XML, SCHEMA12.XML, MAPPING-ISOLATIN1ACCENT.TXT, BAD_SOLRCONFIG.XML, SOLRCONFIG.SNIPPET.RANDOMINDEXCONFIG.XML, BAD-SCHEMA-EXTERNAL-FILEFIELD.XML]
[junit4] 2> 891619 T2585 oass.SolrIndexSearcher.<init> Opening Searcher@4cf82224 main
[junit4] 2> 891620 T2585 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4] 2> 891620 T2585 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4] 2> 891621 T2585 oashc.SpellCheckComponent.inform Initializing spell checkers
[junit4] 2> 891626 T2585 oass.DirectSolrSpellChecker.init init: {name=direct,classname=DirectSolrSpellChecker,field=lowerfilt,minQueryLength=3}
[junit4] 2> 891664 T2586 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@4cf82224 main{StandardDirectoryReader(segments_1:1)}
[junit4] 2> 891673 T2585 oasc.CoreContainer.registerCore registering core: collection1
[junit4] 2> 891684 T2584 oas.SolrTestCaseJ4.initCore ####initCore end
[junit4] 2> 891687 T2584 oas.SolrTestCaseJ4.setUp ###Starting testABunchOfConvertedStuff
[junit4] 2> ASYNC NEW_CORE C312 name=collection1 org.apache.solr.core.SolrCore@6c363cbe
[junit4] 2> 891696 T2584 C312 oasu.DirectUpdateHandler2.commit start commit{,optimize=true,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4] 2> 891697 T2584 C312 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=1
[junit4] 2> commit{dir=RateLimitedDirectoryWrapper(MockDirWrapper(org.apache.lucene.store.RAMDirectory@63ee93a lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@d34cf76)),segFN=segments_1,generation=1}
[junit4] 2> 891698 T2584 C312 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4] 2> 891698 T2584 C312 oasu.DirectUpdateHandler2.commit No uncommitted changes. Skipping IW.commit.
[junit4] 2> 891698 T2584 C312 oass.SolrIndexSearcher.<init> Opening Searcher@cb04815 main
[junit4] 2> 891699 T2584 C312 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4] 2> 891700 T2586 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@cb04815 main{StandardDirectoryReader(segments_1:1:nrt)}
[junit4] 2> 891701 T2584 C312 oasup.LogUpdateProcessor.finish [collection1] webapp=null path=null params={} {optimize=} 0 5
[junit4] 2> 891714 T2584 C312 oasc.SolrCore.execute [collection1] webapp=null path=null params={start=0&q=qlkciyopsbgzyvkylsjhchghjrdf&qt=standard&rows=20&version=2.2&defType=lucenePlusSort} hits=0 status=0 QTime=1
[junit4] 2> 891721 T2584 C312 oasup.LogUpdateProcessor.finish [collection1] webapp=null path=null params={} {delete=[42 (-1442598901967224832)]} 0 1
[junit4] 2> 891728 T2584 C312 oasup.LogUpdateProcessor.finish [collection1] webapp=null path=null params={} {add=[42 (1442598901974564864)]} 0 1
[junit4] 2> 891734 T2584 C312 oasu.DirectUpdateHandler2.commit start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4] 2> 891757 T2584 C312 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=2
[junit4] 2> commit{dir=RateLimitedDirectoryWrapper(MockDirWrapper(org.apache.lucene.store.RAMDirectory@63ee93a lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@d34cf76)),segFN=segments_1,generation=1}
[junit4] 2> commit{dir=RateLimitedDirectoryWrapper(MockDirWrapper(org.apache.lucene.store.RAMDirectory@63ee93a lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@d34cf76)),segFN=segments_2,generation=2}
[junit4] 2> 891758 T2584 C312 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 2
[junit4] 2> 891759 T2584 C312 oass.SolrIndexSearcher.<init> Opening Searcher@32b55c6c main
[junit4] 2> 891760 T2584 C312 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4] 2> 891761 T2586 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@32b55c6c main{StandardDirectoryReader(segments_2:3:nrt _0(5.0):C1)}
[junit4] 2> 891762 T2584 C312 oasup.LogUpdateProcessor.finish [collection1] webapp=null path=null params={} {commit=} 0 28
[junit4] 2> 891767 T2584 C312 oasc.SolrCore.execute [collection1] webapp=null path=null params={start=0&q=id:42+AND+val_s:aa\;bb&qt=standard&rows=20&version=2.2&defType=lucenePlusSort} hits=1 status=0 QTime=4
[junit4] 2> 891769 T2584 C312 oasc.SolrCore.execute [collection1] webapp=null path=null params={start=0&q=id:42+AND+val_s:"aa;bb"&qt=standard&rows=20&version=2.2&defType=lucenePlusSort} hits=1 status=0 QTime=0
[junit4] 2> 891770 T2584 C312 oasc.SolrCore.execute [collection1] webapp=null path=null params={start=0&q=id:42+AND+val_s:"aa"&qt=standard&rows=20&version=2.2&defType=lucenePlusSort} hits=0 status=0 QTime=0
[junit4] 2> 891778 T2584 C312 oasup.LogUpdateProcessor.finish [collection1] webapp=null path=null params={} {delete=[42 (-1442598902026993664)]} 0 1
[junit4] 2> 891787 T2584 C312 oasup.LogUpdateProcessor.finish [collection1] webapp=null path=null params={} {add=[42 (1442598902034333696)]} 0 3
[junit4] 2> 891837 T2584 C312 oasup.LogUpdateProcessor.finish [collection1] webapp=null path=null params={} {add=[42 (1442598902045868032)]} 0 43
[junit4] 2> 891846 T2584 C312 oasu.DirectUpdateHandler2.commit start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4] 2> 891847 T2584 C312 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=2
[junit4] 2> commit{dir=RateLimitedDirectoryWrapper(MockDirWrapper(org.apache.lucene.store.RAMDirectory@63ee93a lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@d34cf76)),segFN=segments_2,generation=2}
[junit4] 2> commit{dir=RateLimitedDirectoryWrapper(MockDirWrapper(org.apache.lucene.store.RAMDirectory@63ee93a lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@d34cf76)),segFN=segments_3,generation=3}
[junit4] 2> 891848 T2584 C312 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 3
[junit4] 2> 891850 T2584 C312 oass.SolrIndexSearcher.<init> Opening Searcher@1dbffc8c main
[junit4] 2> 891851 T2584 C312 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4] 2> 891853 T2586 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@1dbffc8c main{StandardDirectoryReader(segments_3:7:nrt _1(5.0):C2/1)}
[junit4] 2> 891854 T2584 C312 oasup.LogUpdateProcessor.finish [collection1] webapp=null path=null params={} {commit=} 0 8
[junit4] 2> 891856 T2584 C312 oasc.SolrCore.execute [collection1] webapp=null path=null params={start=0&q=id:42&qt=standard&rows=20&version=2.2&defType=lucenePlusSort} hits=1 status=0 QTime=0
[junit4] 2> 891868 T2584 C312 oasup.LogUpdateProcessor.finish [collection1] webapp=null path=null params={} {add=[42 (1442598902121365504)]} 0 2
[junit4] 2> 891921 T2584 C312 oasup.LogUpdateProcessor.finish [collection1] webapp=null path=null params={} {add=[42 (1442598902132899840)]} 0 43
[junit4] 2> 891930 T2584 C312 oasu.DirectUpdateHandler2.commit start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4] 2> 891931 T2584 C312 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=2
[junit4] 2> commit{dir=RateLimitedDirectoryWrapper(MockDirWrapper(org.apache.lucene.store.RAMDirectory@63ee93a lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@d34cf76)),segFN=segments_3,generation=3}
[junit4] 2> commit{dir=RateLimitedDirectoryWrapper(MockDirWrapper(org.apache.lucene.store.RAMDirectory@63ee93a lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@d34cf76)),segFN=segments_4,generation=4}
[junit4] 2> 891932 T2584 C312 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 4
[junit4] 2> 891934 T2584 C312 oass.SolrIndexSearcher.<init> Opening Searcher@58930831 main
[junit4] 2> 891935 T2584 C312 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4] 2> 891937 T2586 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@58930831 main{StandardDirectoryReader(segments_4:11:nrt _2(5.0):C2/1)}
[junit4] 2> 891938 T2584 C312 oasup.LogUpdateProcessor.finish [collection1] webapp=null path=null params={} {commit=} 0 8
[junit4] 2> 891940 T2584 C312 oasc.SolrCore.execute [collection1] webapp=null path=null params={start=0&q=id:42&qt=standard&rows=20&version=2.2&defType=lucenePlusSort} hits=1 status=0 QTime=0
[junit4] 2> 891951 T2584 C312 oasup.LogUpdateProcessor.finish [collection1] webapp=null path=null params={} {delete=[42 (-1442598902208397312)]} 0 1
[junit4] 2> 891960 T2584 C312 oass.SolrIndexSearcher.<init> Opening Searcher@26e26fc2 realtime
[junit4] 2> 891961 T2584 C312 oasup.LogUpdateProcessor.finish [collection1] webapp=null path=null params={} {deleteByQuery=id:[100 TO 110] (-1442598902218883072)} 0 2
[junit4] 2> 891970 T2584 C312 oasup.LogUpdateProcessor.finish [collection1] webapp=null path=null params={} {add=[101 (1442598902228320256)]} 0 1
[junit4] 2> 891982 T2584 C312 oasup.LogUpdateProcessor.finish [collection1] webapp=null path=null params={} {add=[101 (1442598902238806016)]} 0 3
[junit4] 2> 891992 T2584 C312 oasup.LogUpdateProcessor.finish [collection1] webapp=null path=null params={} {add=[105 (1442598902251388928)]} 0 1
[junit4] 2> 892004 T2584 C312 oasup.LogUpdateProcessor.finish [collection1] webapp=null path=null params={} {add=[102 (1442598902260826112)]} 0 4
[junit4] 2> 892013 T2584 C312 oasup.LogUpdateProcessor.finish [collection1] webapp=null path=null params={} {add=[103 (1442598902274457600)]} 0 1
[junit4] 2> 892045 T2584 C312 oasup.LogUpdateProcessor.finish [collection1] webapp=null path=null params={} {add=[101 (1442598902283894784)]} 0 23
[junit4] 2> 892055 T2584 C312 oasu.DirectUpdateHandler2.commit start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4] 2> 892060 T2584 C312 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=2
[junit4] 2> commit{dir=RateLimitedDirectoryWrapper(MockDirWrapper(org.apache.lucene.store.RAMDirectory@63ee93a lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@d34cf76)),segFN=segments_4,generation=4}
[junit4] 2> commit{dir=RateLimitedDirectoryWrapper(MockDirWrapper(org.apache.lucene.store.RAMDirectory@63ee93a lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@d34cf76)),segFN=segments_5,generation=5}
[junit4] 2> 892060 T2584 C312 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 5
[junit4] 2> 892063 T2584 C312 oass.SolrIndexSearcher.<init> Opening Searcher@528c1084 main
[junit4] 2> 892064 T2584 C312 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4] 2> 892066 T2586 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@528c1084 main{StandardDirectoryReader(segments_5:21:nrt _4(5.0):C2 _5(5.0):C2)}
[junit4] 2> 892067 T2584 C312 oasup.LogUpdateProcessor.finish [collection1] webapp=null path=null params={} {commit=} 0 12
[junit4] 2> 892069 T2584 C312 oasc.SolrCore.execute [collection1] webapp=null path=null params={start=0&q=id:[100+TO+110]&qt=standard&rows=20&version=2.2&defType=lucenePlusSort} hits=4 status=0 QTime=0
[junit4] 2> 892080 T2584 C312 oasup.LogUpdateProcessor.finish [collection1] webapp=null path=null params={} {delete=[102 (-1442598902343663616)]} 0 1
[junit4] 2> 892089 T2584 C312 oasu.DirectUpdateHandler2.commit start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4] 2> 892090 T2584 C312 oasu.DirectUpdateHandler2.commit No uncommitted changes. Skipping IW.commit.
[junit4] 2> 892090 T2584 C312 oass.SolrIndexSearcher.<init> Opening Searcher@208e2fff main
[junit4] 2> 892091 T2584 C312 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4] 2> 892093 T2586 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@208e2fff main{StandardDirectoryReader(segments_5:22:nrt _4(5.0):C2/1 _5(5.0):C2)}
[junit4] 2> 892093 T2584 C312 oasup.LogUpdateProcessor.finish [collection1] webapp=null path=null params={} {commit=} 0 4
[junit4] 2> 892095 T2584 C312 oasc.SolrCore.execute [collection1] webapp=null path=null params={start=0&q=id:[100+TO+110]&qt=standard&rows=20&version=2.2&defType=lucenePlusSort} hits=3 status=0 QTime=0
[junit4] 2> 892107 T2584 C312 oass.SolrIndexSearcher.<init> Opening Searcher@29aad718 realtime
[junit4] 2> 892107 T2584 C312 oasup.LogUpdateProcessor.finish [collection1] webapp=null path=null params={} {deleteByQuery=id:105 (-1442598902370926592)} 0 2
[junit4] 2> 892117 T2584 C312 oasu.DirectUpdateHandler2.commit start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4] 2> 892117 T2584 C312 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=2
[junit4] 2> commit{dir=RateLimitedDirectoryWrapper(MockDirWrapper(org.apache.lucene.store.RAMDirectory@63ee93a lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@d34cf76)),segFN=segments_5,generation=5}
[junit4] 2> commit{dir=RateLimitedDirectoryWrapper(MockDirWrapper(org.apache.lucene.store.RAMDirectory@63ee93a lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@d34cf76)),segFN=segments_6,generation=6}
[junit4] 2> 892118 T2584 C312 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 6
[junit4] 2> 892119 T2584 C312 oass.SolrIndexSearcher.<init> Opening Searcher@6f30c2f0 main
[junit4] 2> 892120 T2584 C312 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4] 2> 892122 T2586 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@6f30c2f0 main{StandardDirectoryReader(segments_5:24:nrt _5(5.0):C2)}
[junit4] 2> 892122 T2584 C312 oasup.LogUpdateProcessor.finish [collection1] webapp=null path=null params={} {commit=} 0 6
[junit4] 2> 892124 T2584 C312 oasc.SolrCore.execute [collection1] webapp=null path=null params={start=0&q=id:[100+TO+110]&qt=standard&rows=20&version=2.2&defType=lucenePlusSort} hits=2 status=0 QTime=0
[junit4] 2> 892135 T2584 C312 oass.SolrIndexSearcher.<init> Opening Searcher@30e29d81 realtime
[junit4] 2> 892136 T2584 C312 oasup.LogUpdateProcessor.finish [collection1] webapp=null path=null params={} {deleteByQuery=id:[100 TO 110] (-1442598902400286720)} 0 3
[junit4] 2> 892145 T2584 C312 oasu.DirectUpdateHandler2.commit start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4] 2> 892146 T2584 C312 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=2
[junit4] 2> commit{dir=RateLimitedDirectoryWrapper(MockDirWrapper(org.apache.lucene.store.RAMDirectory@63ee93a lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@d34cf76)),segFN=segments_6,generation=6}
[junit4] 2> commit{dir=RateLimitedDirectoryWrapper(MockDirWrapper(org.apache.lucene.store.RAMDirectory@63ee93a lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@d34cf76)),segFN=segments_7,generation=7}
[junit4] 2> 892146 T2584 C312 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 7
[junit4] 2> ASYNC NEW_CORE C313 name=collection1 org.apache.solr.core.SolrCore@6c363cbe
[junit4] 2> 892152 T2584 C313 oass.SolrIndexSearcher.<init> Opening Searcher@60e77e1d main
[junit4] 2> 892153 T2584 C313 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4] 2> 892155 T2586 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@60e77e1d main{StandardDirectoryReader(segments_6:26:nrt)}
[junit4] 2> 892156 T2584 C313 oasup.LogUpdateProcessor.finish [collection1] webapp=null path=null params={} {commit=} 0 11
[junit4] 2> 892158 T2584 C313 oasc.SolrCore.execute [collection1] webapp=null path=null params={start=0&q=id:[100+TO+110]&qt=standard&rows=20&version=2.2&defType=lucenePlusSort} hits=0 status=0 QTime=0
[junit4] 2> 892168 T2584 C313 oasup.LogUpdateProcessor.finish [collection1] webapp=null path=null params={} {delete=[44 (-1442598902435938304)]} 0 1
[junit4] 2> 892178 T2584 C313 oasup.LogUpdateProcessor.finish [collection1] webapp=null path=null params={} {add=[44 (1442598902446424064)]} 0 1
[junit4] 2> 892230 T2584 C313 oasup.LogUpdateProcessor.finish [collection1] webapp=null path=null params={} {add=[44 (1442598902456909824)]} 0 43
[junit4] 2> 892240 T2584 C313 oasup.LogUpdateProcessor.finish [collection1] webapp=null path=null params={} {add=[44 (1442598902511435776)]} 0 1
[junit4] 2> 892249 T2584 C313 oasu.DirectUpdateHandler2.commit start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4] 2> 892272 T2584 C313 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=2
[junit4] 2> commit{dir=RateLimitedDirectoryWrapper(MockDirWrapper(org.apache.lucene.store.RAMDirectory@63ee93a lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@d34cf76)),segFN=segments_7,generation=7}
[junit4] 2> commit{dir=RateLimitedDirectoryWrapper(MockDirWrapper(org.apache.lucene.store.RAMDirectory@63ee93a lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@d34cf76)),segFN=segments_8,generation=8}
[junit4] 2> 892273 T2584 C313 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 8
[junit4] 2> 892276 T2584 C313 oass.SolrIndexSearcher.<init> Opening Searcher@e165a23 main
[junit4] 2> 892277 T2584 C313 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4] 2> 892279 T2586 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@e165a23 main{StandardDirectoryReader(segments_8:30:nrt _6(5.0):C2 _7(5.0):C1)}
[junit4] 2> 892279 T2584 C313 oasup.LogUpdateProcessor.finish [collection1] webapp=null path=null params={} {commit=} 0 30
[junit4] 2> 892281 T2584 C313 oasc.SolrCore.execute [collection1] webapp=null path=null params={start=0&q=val_s:[a+TO+z]&qt=standard&rows=20&version=2.2&defType=lucenePlusSort} hits=3 status=0 QTime=0
[junit4] 2> 892286 T2584 C313 oasc.SolrCore.execute [collection1] webapp=null path=null params={start=2&q=val_s:[a+TO+z]&qt=standard&rows=5} hits=3 status=0 QTime=0
[junit4] 2> 892291 T2584 C313 oasc.SolrCore.execute [collection1] webapp=null path=null params={start=3&q=val_s:[a+TO+z]&qt=standard&rows=5} hits=3 status=0 QTime=0
[junit4] 2> 892293 T2584 C313 oasc.SolrCore.execute [collection1] webapp=null path=null params={start=4&q=val_s:[a+TO+z]&qt=standard&rows=5} hits=3 status=0 QTime=0
[junit4] 2> 892296 T2584 C313 oasc.SolrCore.execute [collection1] webapp=null path=null params={start=25&q=val_s:[a+TO+z]&qt=standard&rows=5} hits=3 status=0 QTime=0
[junit4] 2> 892299 T2584 C313 oasc.SolrCore.execute [collection1] webapp=null path=null params={start=0&q=val_s:[a+TO+z]&qt=standard&rows=1} hits=3 status=0 QTime=0
[junit4] 2> 892303 T2584 C313 oasc.SolrCore.execute [collection1] webapp=null path=null params={start=0&q=val_s:[a+TO+z]&qt=standard&rows=2} hits=3 status=0 QTime=0
[junit4] 2> 892307 T2584 C313 oasc.SolrCore.execute [collection1] webapp=null path=null params={start=1&q=val_s:[a+TO+z]&qt=standard&rows=1} hits=3 status=0 QTime=0
[junit4] 2> 892311 T2584 C313 oasc.SolrCore.execute [collection1] webapp=null path=null params={start=3&q=val_s:[a+TO+z]&qt=standard&rows=1} hits=3 status=0 QTime=1
[junit4] 2> 892313 T2584 C313 oasc.SolrCore.execute [collection1] webapp=null path=null params={start=4&q=val_s:[a+TO+z]&qt=standard&rows=1} hits=3 status=0 QTime=0
[junit4] 2> 892316 T2584 C313 oasc.SolrCore.execute [collection1] webapp=null path=null params={start=1&q=val_s:[a+TO+z]&qt=standard&rows=0} hits=3 status=0 QTime=0
[junit4] 2> 892319 T2584 C313 oasc.SolrCore.execute [collection1] webapp=null path=null params={start=0&q=val_s:[a+TO+z]&qt=standard&rows=0} hits=3 status=0 QTime=1
[junit4] 2> 892322 T2584 C313 oasc.SolrCore.execute [collection1] webapp=null path=null params={start=0&q=val_s:[a+TO+z];val_s1+asc&qt=standard&rows=0&defType=lucenePlusSort} hits=3 status=0 QTime=1
[junit4] 2> 892325 T2584 C313 oasc.SolrCore.execute [collection1] webapp=null path=null params={start=0&q=val_s:[a+TO+z];val_s1+desc&qt=standard&rows=0&defType=lucenePlusSort} hits=3 status=0 QTime=1
[junit4] 2> 892328 T2584 C313 oasc.SolrCore.execute [collection1] webapp=null path=null params={start=0&q=val_s:[a+TO+b]&qt=standard&rows=20&version=2.2&defType=lucenePlusSort} hits=1 status=0 QTime=1
[junit4] 2> 892329 T2584 C313 oasc.SolrCore.execute [collection1] webapp=null path=null params={start=0&q=val_s:[a+TO+cat]&qt=standard&rows=20&version=2.2&defType=lucenePlusSort} hits=2 status=0 QTime=0
[junit4] 2> 892331 T2584 C313 oasc.SolrCore.execute [collection1] webapp=null path=null params={start=0&q=val_s:[a+TO+*]&qt=standard&rows=20&version=2.2&defType=lucenePlusSort} hits=3 status=0 QTime=0
[junit4] 2> 892333 T2584 C313 oasc.SolrCore.execute [collection1] webapp=null path=null params={start=0&q=val_s:[*+TO+z]&qt=standard&rows=20&version=2.2&defType=lucenePlusSort} hits=3 status=0 QTime=0
[junit4] 2> 892335 T2584 C313 oasc.SolrCore.execute [collection1] webapp=null path=null params={start=0&q=val_s:[*+TO+*]&qt=standard&rows=20&version=2.2&defType=lucenePlusSort} hits=3 status=0 QTime=0
[junit4] 2> 892337 T2584 C313 oasc.SolrCore.execute [collection1] webapp=null path=null params={start=0&q=val_s:[apple+TO+pear]&qt=standard&rows=20&version=2.2&defType=lucenePlusSort} hits=3 status=0 QTime=0
[junit4] 2> 892339 T2584 C313 oasc.SolrCore.execute [collection1] webapp=null path=null params={start=0&q=val_s:[bear+TO+boar]&qt=standard&rows=20&version=2.2&defType=lucenePlusSort} hits=0 status=0 QTime=0
[junit4] 2> 892341 T2584 C313 oasc.SolrCore.execute [collection1] webapp=null path=null params={start=0&q=val_s:[a+TO+a]&qt=standard&rows=20&version=2.2&defType=lucenePlusSort} hits=0 status=0 QTime=0
[junit4] 2> 892343 T2584 C313 oasc.SolrCore.execute [collection1] webapp=null path=null params={start=0&q=val_s:[apple+TO+apple]&qt=standard&rows=20&version=2.2&defType=lucenePlusSort} hits=1 status=0 QTime=0
[junit4] 2> 892345 T2584 C313 oasc.SolrCore.execute [collection1] webapp=null path=null params={start=0&q=val_s:{apple+TO+pear}&qt=standard&rows=20&version=2.2&defType=lucenePlusSort} hits=1 status=0 QTime=0
[junit4] 2> 892347 T2584 C313 oasc.SolrCore.execute [collection1] webapp=null path=null params={start=0&q=val_s:{a+TO+z}&qt=standard&rows=20&version=2.2&defType=lucenePlusSort} hits=3 status=0 QTime=0
[junit4] 2> 892349 T2584 C313 oasc.SolrCore.execute [collection1] webapp=null path=null params={start=0&q=val_s:{*+TO+*}&qt=standard&rows=20&version=2.2&defType=lucenePlusSort} hits=3 status=0 QTime=0
[junit4] 2> 892351 T2584 C313 oasc.SolrCore.execute [collection1] webapp=null path=null params={start=0&q=id:44+AND+val_s:[a+TO+z]&qt=standard&rows=20&version=2.2&defType=lucenePlusSort} hits=3 status=0 QTime=0
[junit4] 2> 892353 T2584 C313 oasc.SolrCore.execute [collection1] webapp=null path=null params={start=0&q=id:44+OR+val_s:[a+TO+z]&qt=standard&rows=20&version=2.2&defType=lucenePlusSort} hits=3 status=0 QTime=0
[junit4] 2> 892356 T2584 C313 oasc.SolrCore.execute [collection1] webapp=null path=null params={start=0&q=val_s:[a+TO+b]+OR+val_s:[b+TO+z]&qt=standard&rows=20&version=2.2&defType=lucenePlusSort} hits=3 status=0 QTime=1
[junit4] 2> 892358 T2584 C313 oasc.SolrCore.execute [collection1] webapp=null path=null params={start=0&q=%2Bval_s:[a+TO+b]+-val_s:[b+TO+z]&qt=standard&rows=20&version=2.2&defType=lucenePlusSort} hits=1 status=0 QTime=0
[junit4] 2> 892360 T2584 C313 oasc.SolrCore.execute [collection1] webapp=null path=null params={start=0&q=-val_s:[a+TO+b]+%2Bval_s:[b+TO+z]&qt=standard&rows=20&version=2.2&defType=lucenePlusSort} hits=2 status=0 QTime=0
[junit4] 2> 892362 T2584 C313 oasc.SolrCore.execute [collection1] webapp=null path=null params={start=0&q=val_s:[a+TO+c]+AND+val_s:[apple+TO+z]&qt=standard&rows=20&version=2.2&defType=lucenePlusSort} hits=2 status=0 QTime=0
[junit4] 2> 892365 T2584 C313 oasc.SolrCore.execute [collection1] webapp=null path=null params={start=0&q=val_s:[a+TO+c]+AND+val_s:[a+TO+apple]&qt=standard&rows=20&version=2.2&defType=lucenePlusSort} hits=1 status=0 QTime=1
[junit4] 2> 892367 T2584 C313 oasc.SolrCore.execute [collection1] webapp=null path=null params={start=0&q=id:44+AND+(val_s:[a+TO+c]+AND+val_s:[a+TO+apple])&qt=standard&rows=20&version=2.2&defType=lucenePlusSort} hits=1 status=0 QTime=0
[junit4] 2> 892370 T2584 C313 oasc.SolrCore.execute [collection1] webapp=null path=null params={start=0&q=(val_s:[apple+TO+apple]+OR+val_s:[a+TO+c])+AND+(val_s:[b+TO+c]+OR+val_s:[b+TO+b])&qt=standard&rows=20&version=2.2&defType=lucenePlusSort} hits=1 status=0 QTime=1
[junit4] 2> 892373 T2584 C313 oasc.SolrCore.execute [collection1] webapp=null path=null params={start=0&q=(val_s:[apple+TO+apple]+AND+val_s:[a+TO+c])+OR+(val_s:[p+TO+z]+AND+val_s:[a+TO+z])&qt=standard&rows=20&version=2.2&defType=lucenePlusSort} hits=2 status=0 QTime=0
[junit4] 2> 892389 T2584 C313 oasup.LogUpdateProcessor.finish [collection1] webapp=null path=null params={} {add=[44 (1442598902666625024)]} 0 3
[junit4] 2> 892399 T2584 C313 oasu.DirectUpdateHandler2.commit start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4] 2> 892422 T2584 C313 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=2
[junit4] 2> commit{dir=RateLimitedDirectoryWrapper(MockDirWrapper(org.apache.lucene.store.RAMDirectory@63ee93a lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@d34cf76)),segFN=segments_8,generation=8}
[junit4] 2> commit{dir=RateLimitedDirectoryWrapper(MockDirWrapper(org.apache.lucene.store.RAMDirectory@63ee93a lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@d34cf76)),segFN=segments_9,generation=9}
[junit4] 2> 892423 T2584 C313 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 9
[junit4] 2> 892425 T2584 C313 oass.SolrIndexSearcher.<init> Opening Searcher@719726fc main
[junit4] 2> 892426 T2584 C313 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4] 2> 892428 T2586 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@719726fc main{StandardDirectoryReader(segments_9:32:nrt _6(5.0):C2 _7(5.0):C1 _8(5.0):C1)}
[junit4] 2> 892429 T2584 C313 oasup.LogUpdateProcessor.finish [collection1] webapp=null path=null params={} {commit=} 0 30
[junit4] 2> 892432 T2584 C313 oasc.SolrCore.execute [collection1] webapp=null path=null params={start=0&q=val_s:[*+TO+*]+OR++val_s:[*+TO+*]&qt=standard&rows=20&version=2.2&defType=lucenePlusSort} hits=4 status=0 QTime=1
[junit4] 2> 892434 T2584 C313 oasc.SolrCore.execute [collection1] webapp=null path=null params={start=0&q=val_s:[*+TO+*]+AND++val_s:[*+TO+*]&qt=standard&rows=20&version=2.2&defType=lucenePlusSort} hits=4 status=0 QTime=0
[junit4] 2> 892436 T2584 C313 oasc.SolrCore.execute [collection1] webapp=null path=null params={start=0&q=val_s:[*+TO+*]&qt=standard&rows=20&version=2.2&defType=lucenePlusSort} hits=4 status=0 QTime=0
[junit4] 2> 892449 T2584 C313 oasup.LogUpdateProcessor.finish [collection1] webapp=null path=null params={} {add=[44 (1442598902729539584)]} 0 2
[junit4] 2> 892459 T2584 C313 oasu.DirectUpdateHandler2.commit start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4] 2> 892463 T2584 C313 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=2
[junit4] 2> commit{dir=RateLimitedDirectoryWrapper(MockDirWrapper(org.apache.lucene.store.RAMDirectory@63ee93a lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@d34cf76)),segFN=segments_9,generation=9}
[junit4] 2> commit{dir=RateLimitedDirectoryWrapper(MockDirWrapper(org.apache.lucene.store.RAMDirectory@63ee93a lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@d34cf76)),segFN=segments_a,generation=10}
[junit4] 2> 892463 T2584 C313 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 10
[junit4] 2> 892468 T2584 C313 oass.SolrIndexSearcher.<init> Opening Searcher@3d0b78e8 main
[junit4] 2> 892468 T2584 C313 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4] 2> 892470 T2586 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@3d0b78e8 main{StandardDirectoryReader(segments_a:36:nrt _9(5.0):C1)}
[junit4] 2> 892472 T2584 C313 oasup.LogUpdateProcessor.finish [collection1] webapp=null path=null params={} {commit=} 0 13
[junit4] 2> 892474 T2584 C313 oasc.SolrCore.execute [collection1] webapp=null path=null params={start=0&q=id:44+AND+red&qt=standard&rows=20&version=2.2&defType=lucenePlusSort} hits=1 status=0 QTime=0
[junit4] 2> 892478 T2584 C313 oasc.SolrCore.execute [collection1] webapp=null path=null params={start=0&q=id:44+AND+ride&qt=standard&rows=20&version=2.2&defType=lucenePlusSort} hits=1 status=0 QTime=1
[junit4] 2> 892480 T2584 C313 oasc.SolrCore.execute [collection1] webapp=null path=null params={start=0&q=id:44+AND+blue&qt=standard&rows=20&version=2.2&defType=lucenePlusSort} hits=0 status=0 QTime=0
[junit4] 2> 892491 T2584 C313 oasup.LogUpdateProcessor.finish [collection1] webapp=null path=null params={} {delete=[44 (-1442598902774628352)]} 0 1
[junit4] 2> 892502 T2584 C313 oasup.LogUpdateProcessor.finish [collection1] webapp=null path=null params={} {add=[44 (1442598902786162688)]} 0 1
[junit4] 2> 892516 T2584 C313 oasup.LogUpdateProcessor.finish [collection1] webapp=null path=null params={} {add=[44 (1442598902797697024)]} 0 4
[junit4] 2> 892526 T2584 C313 oasu.DirectUpdateHandler2.commit start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4] 2> 892527 T2584 C313 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=2
[junit4] 2> commit{dir=RateLimitedDirectoryWrapper(MockDirWrapper(org.apache.lucene.store.RAMDirectory@63ee93a lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@d34cf76)),segFN=segments_a,generation=10}
[junit4] 2> commit{dir=RateLimitedDirectoryWrapper(MockDirWrapper(org.apache.lucene.store.RAMDirectory@63ee93a lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@d34cf76)),segFN=segments_b,generation=11}
[junit4] 2> 892527 T2584 C313 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 11
[junit4] 2> 892530 T2584 C313 oass.SolrIndexSearcher.<init> Opening Searcher@84f26fe main
[junit4] 2> 892531 T2584 C313 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4] 2> 892533 T2586 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@84f26fe main{StandardDirectoryReader(segments_b:40:nrt _a(5.0):C2)}
[junit4] 2> 892533 T2584 C313 oasup.LogUpdateProcessor.finish [collection1] webapp=null path=null params={} {commit=} 0 7
[junit4] 2> 892540 T2584 C313 oasc.SolrCore.execute [collection1] webapp=null path=null params={start=0&q=id:44&qt=standard&rows=20&version=2.2&defType=lucenePlusSort} hits=2 status=0 QTime=0
[junit4] 2> 892543 T2584 C313 oasc.SolrCore.execute [collection1] webapp=null path=null params={start=0&q=id:44+AND+red&qt=standard&rows=20&version=2.2&defType=lucenePlusSort} hits=1 status=0 QTime=1
[junit4] 2> 892547 T2584 C313 oasc.SolrCore.execute [collection1] webapp=null path=null params={start=0&q=id:44+AND+wolf&qt=standard&rows=20&version=2.2&defType=lucenePlusSort} hits=1 status=0 QTime=1
[junit4] 2> 892550 T2584 C313 oasc.SolrCore.execute [collection1] webapp=null path=null params={start=0&q=%2Bid:44+red+wolf&qt=standard&rows=20&version=2.2&defType=lucenePlusSort} hits=2 status=0 QTime=0
[junit4] 2> 892562 T2584 C313 oasup.LogUpdateProcessor.finish [collection1] webapp=null path=null params={} {delete=[44 (-1442598902849077248)]} 0 1
[junit4] 2> 892572 T2584 C313 oasu.DirectUpdateHandler2.commit start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4] 2> 892572 T2584 C313 oasu.DirectUpdateHandler2.commit No uncommitted changes. Skipping IW.commit.
[junit4] 2> 892573 T2584 C313 oass.SolrIndexSearcher.<init> Opening Searcher@5f23feee main
[junit4] 2> 892574 T2584 C313 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4] 2> 892576 T2586 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@5f23feee main{StandardDirectoryReader(segments_b:42:nrt)}
[junit4] 2> 892577 T2584 C313 oasup.LogUpdateProcessor.finish [collection1] webapp=null path=null params={} {commit=} 0 5
[junit4] 2> 892584 T2584 C313 oasc.SolrCore.execute [collection1] webapp=null path=null params={start=0&q=id:44&qt=standard&rows=20&version=2.2&defType=lucenePlusSort} hits=0 status=0 QTime=1
[junit4] 2> 892595 T2584 C313 oasup.LogUpdateProcessor.finish [collection1] webapp=null path=null params={} {delete=[44 (-1442598902883680256)]} 0 2
[junit4] 2> 892606 T2584 C313 oasup.LogUpdateProcessor.finish [collection1] webapp=null path=null params={} {add=[44 (1442598902895214592)]} 0 1
[junit4] 2> 892616 T2584 C313 oasu.DirectUpdateHandler2.commit start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4] 2> 892619 T2584 C313 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=2
[junit4] 2> commit{dir=RateLimitedDirectoryWrapper(MockDirWrapper(org.apache.lucene.store.RAMDirectory@63ee93a lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@d34cf76)),segFN=segments_b,generation=11}
[junit4] 2> commit{dir=RateLimitedDirectoryWrapper(MockDirWrapper(org.apache.lucene.store.RAMDirectory@63ee93a lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@d34cf76)),segFN=segments_c,generation=12}
[junit4] 2> 892619 T2584 C313 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 12
[junit4] 2> 892621 T2584 C313 oass.SolrIndexSearcher.<init> Opening Searcher@9226883 main
[junit4] 2> 892623 T2584 C313 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4] 2> 892624 T2586 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@9226883 main{StandardDirectoryReader(segments_c:44:nrt _b(5.0):C1)}
[junit4] 2> 892625 T2584 C313 oasup.LogUpdateProcessor.finish [collection1] webapp=null path=null params={} {commit=} 0 10
[junit4] 2> 892632 T2584 C313 oasc.SolrCore.execute [collection1] webapp=null path=null params={start=0&q=id:44&qt=standard&rows=20&version=2.2&defType=lucenePlusSort} hits=1 status=0 QTime=0
[junit4] 2> 892643 T2584 C313 oasup.LogUpdateProcessor.finish [collection1] webapp=null path=null params={} {delete=[44 (-1442598902934011904)]} 0 1
[junit4] 2> 892654 T2584 C313 oasup.LogUpdateProcessor.finish [collection1] webapp=null path=null params={} {add=[44 (1442598902945546240)]} 0 1
[junit4] 2> 892664 T2584 C313 oasu.DirectUpdateHandler2.commit start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4] 2> 892687 T2584 C313 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=2
[junit4] 2> commit{dir=RateLimitedDirectoryWrapper(MockDirWrapper(org.apache.lucene.store.RAMDirectory@63ee93a lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@d34cf76)),segFN=segments_c,generation=12}
[junit4] 2> commit{dir=RateLimitedDirectoryWrapper(MockDirWrapper(org.apache.lucene.store.RAMDirectory@63ee93a lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@d34cf76)),segFN=segments_d,generation=13}
[junit4] 2> 892688 T2584 C313 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 13
[junit4] 2> 892690 T2584 C313 oass.SolrIndexSearcher.<init> Opening Searcher@5f019c3e main
[junit4] 2> 892692 T2584 C313 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4] 2> 892693 T2586 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@5f019c3e main{StandardDirectoryReader(segments_d:48:nrt _c(5.0):C1)}
[junit4] 2> 892694 T2584 C313 oasup.LogUpdateProcessor.finish [collection1] webapp=null path=null params={} {commit=} 0 30
[junit4] 2> 892702 T2584 C313 oasc.SolrCore.execute [collection1] webapp=null path=null params={start=0&q=sind:abc123&qt=standard&rows=20&version=2.2&defType=lucenePlusSort} hits=1 status=0 QTime=1
[junit4] 2> 892716 T2584 C313 oasup.LogUpdateProcessor.finish [collection1] webapp=null path=null params={} {delete=[44 (-1442598903010557952)]} 0 1
[junit4] 2> 892727 T2584 C313 oasup.LogUpdateProcessor.finish [collection1] webapp=null path=null params={} {delete=[44 (-1442598903023140864)]} 0 1
[junit4] 2> 892738 T2584 C313 oasup.LogUpdateProcessor.finish [collection1] webapp=null path=null params={} {add=[44 (1442598903033626624)]} 0 1
[junit4] 2> 892748 T2584 C313 oasu.DirectUpdateHandler2.commit start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4] 2> 892752 T2584 C313 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=2
[junit4] 2> commit{dir=RateLimitedDirectoryWrapper(MockDirWrapper(org.apache.lucene.store.RAMDirectory@63ee93a lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@d34cf76)),segFN=segments_d,generation=13}
[junit4] 2> commit{dir=RateLimitedDirectoryWrapper(MockDirWrapper(org.apache.lucene.store.RAMDirectory@63ee93a lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@d34cf76)),segFN=segments_e,generation=14}
[junit4] 2> 892752 T2584 C313 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 14
[junit4] 2> 892755 T2584 C313 oass.SolrIndexSearcher.<init> Opening Searcher@c806bc6 main
[junit4] 2> 892756 T2584 C313 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4] 2> 892758 T2586 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@c806bc6 main{StandardDirectoryReader(segments_e:52:nrt _d(5.0):C1)}
[junit4] 2> 892758 T2584 C313 oasup.LogUpdateProcessor.finish [collection1] webapp=null path=null params={} {commit=} 0 10
[junit4] 2> 892766 T2584 C313 oasc.SolrCore.execute [collection1] webapp=null path=null params={start=0&q=sindsto:abc123&qt=standard&rows=20&version=2.2&defType=lucenePlusSort} hits=1 status=0 QTime=1
[junit4] 2> 892777 T2584 C313 oasup.LogUpdateProcessor.finish [collection1] webapp=null path=null params={} {delete=[44 (-1442598903074521088)]} 0 1
[junit4] 2> 892797 T2584 C313 oasup.LogUpdateProcessor.finish [collection1] webapp=null path=null params={} {add=[44 (1442598903094444032)]} 0 10
[junit4] 2> 892807 T2584 C313 oasu.DirectUpdateHandler2.commit start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4] 2> 892831 T2584 C313 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=2
[junit4] 2> commit{dir=RateLimitedDirectoryWrapper(MockDirWrapper(org.apache.lucene.store.RAMDirectory@63ee93a lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@d34cf76)),segFN=segments_e,generation=14}
[junit4] 2> commit{dir=RateLimitedDirectoryWrapper(MockDirWrapper(org.apache.lucene.store.RAMDirectory@63ee93a lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@d34cf76)),segFN=segments_f,generation=15}
[junit4] 2> 892831 T2584 C313 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 15
[junit4] 2> 892834 T2584 C313 oass.SolrIndexSearcher.<init> Opening Searcher@6cc9ee3a main
[junit4] 2> 892835 T2584 C313 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4] 2> 892837 T2586 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@6cc9ee3a main{StandardDirectoryReader(segments_f:56:nrt _e(5.0):C1)}
[junit4] 2> 892837 T2584 C313 oasup.LogUpdateProcessor.finish [collection1] webapp=null path=null params={} {commit=} 0 30
[junit4] 2> 892845 T2584 C313 oasc.SolrCore.execute [collection1] webapp=null path=null params={start=0&q=id:44&qt=standard&rows=20&version=2.2&defType=lucenePlusSort} hits=1 status=0 QTime=1
[junit4] 2> 892849 T2584 C313 oasc.SolrCore.execute [collection1] webapp=null path=null params={start=0&q=title:yonik3&qt=standard&rows=20&version=2.2&defType=lucenePlusSort} hits=1 status=0 QTime=1
[junit4] 2> 892851 T2584 C313 oasc.SolrCore.execute [collection1] webapp=null path=null params={start=0&q=title:yonik4&qt=standard&rows=20&version=2.2&defType=lucenePlusSort} hits=1 status=0 QTime=0
[junit4] 2> 892853 T2584 C313 oasc.SolrCore.execute [collection1] webapp=null path=null params={start=0&q=title:yonik5&qt=standard&rows=20&version=2.2&defType=lucenePlusSort} hits=0 status=0 QTime=0
[junit4] 2> 892865 T2584 C313 oass.SolrIndexSearcher.<init> Opening Searcher@77cd80d5 realtime
[junit4] 2> 892866 T2584 C313 oasup.LogUpdateProcessor.finish [collection1] webapp=null path=null params={} {deleteByQuery=title:yonik4 (-1442598903165747200)} 0 3
[junit4] 2> 892876 T2584 C313 oasu.DirectUpdateHandler2.commit start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4] 2> 892877 T2584 C313 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=2
[junit4] 2> commit{dir=RateLimitedDirectoryWrapper(MockDirWrapper(org.apache.lucene.store.RAMDirectory@63ee93a lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@d34cf76)),segFN=segments_f,generation=15}
[junit4] 2> commit{dir=RateLimitedDirectoryWrapper(MockDirWrapper(org.apache.lucene.store.RAMDirectory@63ee93a lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@d34cf76)),segFN=segments_g,generation=16}
[junit4] 2> 892877 T2584 C313 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 16
[junit4] 2> 892878 T2584 C313 oass.SolrIndexSearcher.<init> Opening Searcher@594cb14d main
[junit4] 2> 892879 T2584 C313 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4] 2> 892881 T2586 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@594cb14d main{StandardDirectoryReader(segments_f:58:nrt)}
[junit4] 2> 892882 T2584 C313 oasup.LogUpdateProcessor.finish [collection1] webapp=null path=null params={} {commit=} 0 6
[junit4] 2> 892888 T2584 C313 oasc.SolrCore.execute [collection1] webapp=null path=null params={start=0&q=id:44&qt=standard&rows=20&version=2.2&defType=lucenePlusSort} hits=0 status=0 QTime=0
[junit4] 2> 892899 T2584 C313 oasup.LogUpdateProcessor.finish [collection1] webapp=null path=null params={} {delete=[44 (-1442598903202447360)]} 0 1
[junit4] 2> 892909 T2584 C313 oasu.DirectUpdateHandler2.commit start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4] 2> 892910 T2584 C313 oasu.DirectUpdateHandler2.commit No uncommitted changes. Skipping IW.commit.
[junit4] 2> 892910 T2584 C313 oass.SolrIndexSearcher.<init> Opening Searcher@37b66fe main
[junit4] 2> ASYNC NEW_CORE C314 name=collection1 org.apache.solr.core.SolrCore@6c363cbe
[junit4] 2> 892917 T2584 C314 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4] 2> 892918 T2586 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@37b66fe main{StandardDirectoryReader(segments_f:58:nrt)}
[junit4] 2> 892919 T2584 C314 oasup.LogUpdateProcessor.finish [collection1] webapp=null path=null params={} {commit=} 0 10
[junit4] 2> 892936 T2584 C314 oasup.LogUpdateProcessor.finish [collection1] webapp=null path=null params={} {add=[44 (1442598903240196096)]} 0 2
[junit4] 2> 892938 T2584 C314 oasc.SolrCore.execute [collection1] webapp=null path=null params={start=0&q=id:44&qt=standard&rows=20&version=2.2&defType=lucenePlusSort} hits=0 status=0 QTime=0
[junit4] 2> 892948 T2584 C314 oasu.DirectUpdateHandler2.commit start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4] 2> 892952 T2584 C314 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=2
[junit4] 2> commit{dir=RateLimitedDirectoryWrapper(MockDirWrapper(org.apache.lucene.store.RAMDirectory@63ee93a lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@d34cf76)),segFN=segments_g,generation=16}
[junit4] 2> commit{dir=RateLimitedDirectoryWrapper(MockDirWrapper(org.apache.lucene.store.RAMDirectory@63ee93a lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@d34cf76)),segFN=segments_h,generation=17}
[junit4] 2> 892952 T2584 C314 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 17
[junit4] 2> 892954 T2584 C314 oass.SolrIndexSearcher.<init> Opening Searcher@2229a060 main
[junit4] 2> 892955 T2584 C314 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4] 2> 892957 T2586 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@2229a060 main{StandardDirectoryReader(segments_h:60:nrt _f(5.0):C1)}
[junit4] 2> 892957 T2584 C314 oasup.LogUpdateProcessor.finish [collection1] webapp=null path=null params={} {commit=} 0 9
[junit4] 2> 892964 T2584 C314 oasc.SolrCore.execute [collection1] webapp=null path=null params={start=0&q=id:44&qt=standard&rows=20&version=2.2&defType=lucenePlusSort} hits=1 status=0 QTime=0
[junit4] 2> 892975 T2584 C314 oasup.LogUpdateProcessor.finish [collection1] webapp=null path=null params={} {delete=[44 (-1442598903282139136)]} 0 1
[junit4] 2> 892986 T2584 C314 oasup.LogUpdateProcessor.finish [collection1] webapp=null path=null params={} {add=[44 (1442598903293673472)]} 0 1
[junit4] 2> 892996 T2584 C314 oasu.DirectUpdateHandler2.commit start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4] 2> 893000 T2584 C314 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=2
[junit4] 2> commit{dir=RateLimitedDirectoryWrapper(MockDirWrapper(org.apache.lucene.store.RAMDirectory@63ee93a lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@d34cf76)),segFN=segments_h,generation=17}
[junit4] 2> commit{dir=RateLimitedDirectoryWrapper(MockDirWrapper(org.apache.lucene.store.RAMDirectory@63ee93a lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@d34cf76)),segFN=segments_i,generation=18}
[junit4] 2> 893000 T2584 C314 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 18
[junit4] 2> 893003 T2584 C314 oass.SolrIndexSearcher.<init> Opening Searcher@68c97416 main
[junit4] 2> 893004 T2584 C314 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4] 2> 893005 T2586 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@68c97416 main{StandardDirectoryReader(segments_i:64:nrt _g(5.0):C1)}
[junit4] 2> 893006 T2584 C314 oasup.LogUpdateProcessor.finish [collection1] webapp=null path=null params={} {commit=} 0 10
[junit4] 2> 893013 T2584 C314 oasc.SolrCore.execute [collection1] webapp=null path=null params={start=0&q=%2Bid:44+%2Bteststop:world&qt=standard&rows=20&version=2.2&defType=lucenePlusSort} hits=1 status=0 QTime=0
[junit4] 2> 893016 T2584 C314 oasc.SolrCore.execute [collection1] webapp=null path=null params={start=0&q=teststop:stopworda&qt=standard&rows=20&version=2.2&defType=lucenePlusSort} hits=0 status=0 QTime=1
[junit4] 2> 893027 T2584 C314 oasup.LogUpdateProcessor.finish [collection1] webapp=null path=null params={} {delete=[44 (-1442598903336665088)]} 0 1
[junit4] 2> 893038 T2584 C314 oasup.LogUpdateProcessor.finish [collection1] webapp=null path=null params={} {add=[44 (1442598903348199424)]} 0 1
[junit4] 2> 893048 T2584 C314 oasu.DirectUpdateHandler2.commit start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4] 2> 893052 T2584 C314 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=2
[junit4] 2> commit{dir=RateLimitedDirectoryWrapper(MockDirWrapper(org.apache.lucene.store.RAMDirectory@63ee93a lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@d34cf76)),segFN=segments_i,generation=18}
[junit4] 2> commit{dir=RateLimitedDirectoryWrapper(MockDirWrapper(org.apache.lucene.store.RAMDirectory@63ee93a lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@d34cf76)),segFN=segments_j,generation=19}
[junit4] 2> 893052 T2584 C314 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 19
[junit4] 2> 893055 T2584 C314 oass.SolrIndexSearcher.<init> Opening Searcher@59498e57 main
[junit4] 2> 893056 T2584 C314 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4] 2> 893057 T2586 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@59498e57 main{StandardDirectoryReader(segments_j:68:nrt _h(5.0):C1)}
[junit4] 2> 893058 T2584 C314 oasup.LogUpdateProcessor.finish [collection1] webapp=null path=null params={} {commit=} 0 10
[junit4] 2> 893065 T2584 C314 oasc.SolrCore.execute [collection1] webapp=null path=null params={start=0&q=%2Bid:44+%2Bstopfilt:world&qt=standard&rows=20&version=2.2&defType=lucenePlusSort} hits=1 status=0 QTime=0
[junit4] 2> 893068 T2584 C314 oasc.SolrCore.execute [collection1] webapp=null path=null params={start=0&q=stopfilt:"and"&qt=standard&rows=20&version=2.2&defType=lucenePlusSort} hits=0 status=0 QTime=1
[junit4] 2> 893070 T2584 C314 oasc.SolrCore.execute [collection1] webapp=null path=null params={start=0&q=stopfilt:"AND"&qt=standard&rows=20&version=2.2&defType=lucenePlusSort} hits=0 status=0 QTime=1
[junit4] 2> 893072 T2584 C314 oasc.SolrCore.execute [collection1] webapp=null path=null params={start=0&q=stopfilt:"AnD"&qt=standard&rows=20&version=2.2&defType=lucenePlusSort} hits=0 status=0 QTime=1
[junit4] 2> 893083 T2584 C314 oasup.LogUpdateProcessor.finish [collection1] webapp=null path=null params={} {delete=[44 (-1442598903395385344)]} 0 2
[junit4] 2> 893094 T2584 C314 oasup.LogUpdateProcessor.finish [collection1] webapp=null path=null params={} {add=[44 (1442598903406919680)]} 0 2
[junit4] 2> 893104 T2584 C314 oasu.DirectUpdateHandler2.commit start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4] 2> 893147 T2584 C314 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=2
[junit4] 2> commit{dir=RateLimitedDirectoryWrapper(MockDirWrapper(org.apache.lucene.store.RAMDirectory@63ee93a lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@d34cf76)),segFN=segments_j,generation=19}
[junit4] 2> commit{dir=RateLimitedDirectoryWrapper(MockDirWrapper(org.apache.lucene.store.RAMDirectory@63ee93a lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@d34cf76)),segFN=segments_k,generation=20}
[junit4] 2> 893147 T2584 C314 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 20
[junit4] 2> 893150 T2584 C314 oass.SolrIndexSearcher.<init> Opening Searcher@f1c7aa main
[junit4] 2> 893151 T2584 C314 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4] 2> 893152 T2586 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@f1c7aa main{StandardDirectoryReader(segments_k:72:nrt _i(5.0):C1)}
[junit4] 2> 893153 T2584 C314 oasup.LogUpdateProcessor.finish [collection1] webapp=null path=null params={} {commit=} 0 50
[junit4] 2> 893159 T2584 C314 oasc.SolrCore.execute [collection1] webapp=null path=null params={start=0&q=id:44&qt=standard&rows=20&version=2.2&defType=lucenePlusSort} hits=1 status=0 QTime=0
[junit4] 2> 893165 T2584 C314 oasc.SolrCore.execute [collection1] webapp=null path=null params={start=0&q=t_name:cat&qt=standard&rows=20&version=2.2&defType=lucenePlusSort} hits=1 status=0 QTime=1
[junit4] 2> 893176 T2584 C314 oass.SolrIndexSearcher.<init> Opening Searcher@671bb16f realtime
[junit4] 2> 893177 T2584 C314 oasup.LogUpdateProcessor.finish [collection1] webapp=null path=null params={} {deleteByQuery=t_name:cat (-1442598903491854336)} 0 3
[junit4] 2> 893187 T2584 C314 oasu.DirectUpdateHandler2.commit start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4] 2> 893187 T2584 C314 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=2
[junit4] 2> commit{dir=RateLimitedDirectoryWrapper(MockDirWrapper(org.apache.lucene.store.RAMDirectory@63ee93a lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@d34cf76)),segFN=segments_k,generation=20}
[junit4] 2> commit{dir=RateLimitedDirectoryWrapper(MockDirWrapper(org.apache.lucene.store.RAMDirectory@63ee93a lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@d34cf76)),segFN=segments_l,generation=21}
[junit4] 2> 893188 T2584 C314 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 21
[junit4] 2> 893189 T2584 C314 oass.SolrIndexSearcher.<init> Opening Searcher@7fa1b391 main
[junit4] 2> 893190 T2584 C314 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4] 2> 893191 T2586 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@7fa1b391 main{StandardDirectoryReader(segments_k:74:nrt)}
[junit4] 2> 893192 T2584 C314 oasup.LogUpdateProcessor.finish [collection1] webapp=null path=null params={} {commit=} 0 6
[junit4] 2> 893199 T2584 C314 oasc.SolrCore.execute [collection1] webapp=null path=null params={start=0&q=t_name:cat&qt=standard&rows=20&version=2.2&defType=lucenePlusSort} hits=0 status=0 QTime=1
[junit4] 2> 893210 T2584 C314 oasup.LogUpdateProcessor.finish [collection1] webapp=null path=null params={} {add=[44 (1442598903527505920)]} 0 2
[junit4] 2> 893221 T2584 C314 oasu.DirectUpdateHandler2.commit start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4] 2> 893224 T2584 C314 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=2
[junit4] 2> commit{dir=RateLimitedDirectoryWrapper(MockDirWrapper(org.apache.lucene.store.RAMDirectory@63ee93a lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@d34cf76)),segFN=segments_l,generation=21}
[junit4] 2> commit{dir=RateLimitedDirectoryWrapper(MockDirWrapper(org.apache.lucene.store.RAMDirectory@63ee93a lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@d34cf76)),segFN=segments_m,generation=22}
[junit4] 2> 893225 T2584 C314 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 22
[junit4] 2> 893227 T2584 C314 oass.SolrIndexSearcher.<init> Opening Searcher@2054cd9a main
[junit4] 2> 893228 T2584 C314 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4] 2> 893229 T2586 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@2054cd9a main{StandardDirectoryReader(segments_m:76:nrt _j(5.0):C1)}
[junit4] 2> 893230 T2584 C314 oasup.LogUpdateProcessor.finish [collection1] webapp=null path=null params={} {commit=} 0 9
[junit4] 2> 893236 T2584 C314 oasc.SolrCore.execute [collection1] webapp=null path=null params={start=0&q=id:44&qt=standard&rows=20&version=2.2&defType=lucenePlusSort} hits=1 status=0 QTime=0
[junit4] 2> 893248 T2584 C314 oasup.LogUpdateProcessor.finish [collection1] webapp=null path=null params={} {delete=[44 (-1442598903568400384)]} 0 1
[junit4] 2> 893259 T2584 C314 oasup.LogUpdateProcessor.finish [collection1] webapp=null path=null params={} {add=[44 (1442598903579934720)]} 0 1
[junit4] 2> 893290 T2584 C314 oasup.LogUpdateProcessor.finish [collection1] webapp=null path=null params={} {add=[44 (1442598903590420480)]} 0 22
[junit4] 2> 893301 T2584 C314 oasup.LogUpdateProcessor.finish [collection1] webapp=null path=null params={} {add=[44 (1442598903623974912)]} 0 1
[junit4] 2> 893312 T2584 C314 oasup.LogUpdateProcessor.finish [collection1] webapp=null path=null params={} {add=[44 (1442598903633412096)]} 0 3
[junit4] 2> 893322 T2584 C314 oasup.LogUpdateProcessor.finish [collection1] webapp=null path=null params={} {add=[44 (1442598903645995008)]} 0 1
[junit4] 2> 893373 T2584 C314 oasup.LogUpdateProcessor.finish [collection1] webapp=null path=null params={} {add=[44 (1442598903655432192)]} 0 43
[junit4] 2> 893383 T2584 C314 oasup.LogUpdateProcessor.finish [collection1] webapp=null path=null params={} {add=[44 (1442598903709958144)]} 0 1
[junit4] 2> 893395 T2584 C314 oasup.LogUpdateProcessor.finish [collection1] webapp=null path=null params={} {add=[44 (1442598903719395328)]} 0 4
[junit4] 2> 893404 T2584 C314 oasup.LogUpdateProcessor.finish [collection1] webapp=null path=null params={} {add=[44 (1442598903731978240)]} 0 1
[junit4] 2> 893435 T2584 C314 oasup.LogUpdateProcessor.finish [collection1] webapp=null path=null params={} {add=[44 (1442598903742464000)]} 0 22
[junit4] 2> 893445 T2584 C314 oasu.DirectUpdateHandler2.commit start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4] 2> 893447 T2584 C314 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=2
[junit4] 2> commit{dir=RateLimitedDirectoryWrapper(MockDirWrapper(org.apache.lucene.store.RAMDirectory@63ee93a lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@d34cf76)),segFN=segments_m,generation=22}
[junit4] 2> commit{dir=RateLimitedDirectoryWrapper(MockDirWrapper(org.apache.lucene.store.RAMDirectory@63ee93a lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@d34cf76)),segFN=segments_n,generation=23}
[junit4] 2> 893447 T2584 C314 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 23
[junit4] 2> 893454 T2584 C314 oass.SolrIndexSearcher.<init> Opening Searcher@2448f551 main
[junit4] 2> 893455 T2584 C314 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4] 2> 893457 T2586 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@2448f551 main{StandardDirectoryReader(segments_n:88:nrt _k(5.0):C2 _l(5.0):C2 _m(5.0):C2 _n(5.0):C2 _o(5.0):C2)}
[junit4] 2> 893457 T2584 C314 oasup.LogUpdateProcessor.finish [collection1] webapp=null path=null params={} {commit=} 0 12
[junit4] 2> 893463 T2584 C314 oasc.SolrCore.execute [collection1] webapp=null path=null params={start=0&q=id:44&qt=standard&rows=20&version=2.2&defType=lucenePlusSort} hits=10 status=0 QTime=0
[junit4] 2> 893466 T2584 C314 oasc.SolrCore.execute [collection1] webapp=null path=null params={start=0&q=num_i1:2147483647&qt=standard&rows=20&version=2.2&defType=lucenePlusSort} hits=1 status=0 QTime=0
[junit4] 2> 893470 T2584 C314 oasc.SolrCore.execute [collection1] webapp=null path=null params={start=0&q=num_i1:"-2147483648"&qt=standard&rows=20&version=2.2&defType=lucenePlusSort} hits=1 status=0 QTime=1
[junit4] 2> 893473 T2584 C314 oasc.SolrCore.execute [collection1] webapp=null path=null params={start=0&q=id:44;num_i1+asc;&qt=standard&rows=20&version=2.2&defType=lucenePlusSort} hits=10 status=0 QTime=0
[junit4] 2> 893478 T2584 C314 oasc.SolrCore.execute [collection1] webapp=null path=null params={start=0&q=id:44;num_i1+desc;&qt=standard&rows=20&version=2.2&defType=lucenePlusSort} hits=10 status=0 QTime=1
[junit4] 2> 893482 T2584 C314 oasc.SolrCore.execute [collection1] webapp=null path=null params={start=0&q=num_i1:[0+TO+9]&qt=standard&rows=20&ver
[...truncated too long message...]
path=/replication params={command=indexversion&_trace=assertVersions&wt=javabin&qt=/replication&version=2} status=0 QTime=0
[junit4] 2> 2020032 T4515 C1231 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={command=indexversion&_trace=assertVersions&wt=javabin&qt=/replication&version=2} status=0 QTime=0
[junit4] 2> 2020032 T3674 oas.SolrTestCaseJ4.tearDown ###Ending testEmptyCommits
[junit4] 2> 2020033 T3674 oasc.CoreContainer.shutdown Shutting down CoreContainer instance=1885450487
[junit4] 2> 2020034 T3674 oasc.SolrCore.close [collection1] CLOSING SolrCore org.apache.solr.core.SolrCore@2816752d
[junit4] 2> 2020035 T3674 oasu.DirectUpdateHandler2.close closing DirectUpdateHandler2{commits=5,autocommits=0,soft autocommits=0,optimizes=0,rollbacks=0,expungeDeletes=0,docsPending=0,adds=0,deletesById=0,deletesByQuery=0,errors=0,cumulative_adds=4,cumulative_deletesById=0,cumulative_deletesByQuery=0,cumulative_errors=0}
[junit4] 2> 2020035 T3674 oasu.SolrCoreState.decrefSolrCoreState Closing SolrCoreState
[junit4] 2> 2020036 T3674 oasu.DefaultSolrCoreState.closeIndexWriter SolrCoreState ref count has reached 0 - closing IndexWriter
[junit4] 2> 2020036 T3674 oasu.DefaultSolrCoreState.closeIndexWriter closing IndexWriter with IndexWriterCloser
[junit4] 2> 2020037 T3674 oasc.SolrCore.closeSearcher [collection1] Closing main searcher on request.
[junit4] 2> 2020038 T3674 oasc.CachingDirectoryFactory.close Closing MockDirectoryFactory - 2 directories currently being tracked
[junit4] 2> 2020038 T3674 oasc.CachingDirectoryFactory.closeCacheValue looking to close /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test/J0/./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1375770649264/master/collection1/data [CachedDir<<refCount=0;path=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test/J0/./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1375770649264/master/collection1/data;done=false>>]
[junit4] 2> 2020039 T3674 oasc.CachingDirectoryFactory.close Closing directory: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test/J0/./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1375770649264/master/collection1/data
[junit4] 2> 2020039 T3674 oasc.CachingDirectoryFactory.closeCacheValue looking to close /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test/J0/./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1375770649264/master/collection1/data/index [CachedDir<<refCount=0;path=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test/J0/./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1375770649264/master/collection1/data/index;done=false>>]
[junit4] 2> 2020040 T3674 oasc.CachingDirectoryFactory.close Closing directory: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test/J0/./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1375770649264/master/collection1/data/index
[junit4] 2> 2020040 T3674 oejsh.ContextHandler.doStop stopped o.e.j.s.ServletContextHandler{/solr,null}
[junit4] 2> 2020092 T3674 oasc.CoreContainer.shutdown Shutting down CoreContainer instance=364679128
[junit4] 2> 2020093 T3674 oasc.SolrCore.close [collection1] CLOSING SolrCore org.apache.solr.core.SolrCore@785bec1
[junit4] 2> 2020093 T3674 oasu.DirectUpdateHandler2.close closing DirectUpdateHandler2{commits=0,autocommits=0,soft autocommits=0,optimizes=0,rollbacks=0,expungeDeletes=0,docsPending=0,adds=0,deletesById=0,deletesByQuery=0,errors=0,cumulative_adds=0,cumulative_deletesById=0,cumulative_deletesByQuery=0,cumulative_errors=0}
[junit4] 2> 2020094 T3674 oasu.SolrCoreState.decrefSolrCoreState Closing SolrCoreState
[junit4] 2> 2020094 T3674 oasu.DefaultSolrCoreState.closeIndexWriter SolrCoreState ref count has reached 0 - closing IndexWriter
[junit4] 2> 2020094 T3674 oasu.DefaultSolrCoreState.closeIndexWriter closing IndexWriter with IndexWriterCloser
[junit4] 2> 2020095 T3674 oasc.SolrCore.closeSearcher [collection1] Closing main searcher on request.
[junit4] 2> 2020096 T3674 oasc.CachingDirectoryFactory.close Closing MockDirectoryFactory - 2 directories currently being tracked
[junit4] 2> 2020096 T3674 oasc.CachingDirectoryFactory.closeCacheValue looking to close /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test/J0/./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1375770649638/slave/collection1/data [CachedDir<<refCount=0;path=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test/J0/./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1375770649638/slave/collection1/data;done=false>>]
[junit4] 2> 2020096 T3674 oasc.CachingDirectoryFactory.close Closing directory: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test/J0/./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1375770649638/slave/collection1/data
[junit4] 2> 2020097 T3674 oasc.CachingDirectoryFactory.closeCacheValue looking to close /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test/J0/./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1375770649638/slave/collection1/data/index [CachedDir<<refCount=0;path=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test/J0/./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1375770649638/slave/collection1/data/index;done=false>>]
[junit4] 2> 2020097 T3674 oasc.CachingDirectoryFactory.close Closing directory: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test/J0/./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1375770649638/slave/collection1/data/index
[junit4] 2> 2020098 T3674 oejsh.ContextHandler.doStop stopped o.e.j.s.ServletContextHandler{/solr,null}
[junit4] 2> 2020161 T3674 oas.SolrTestCaseJ4.deleteCore ###deleteCore
[junit4] 2> NOTE: test params are: codec=Lucene42: {newname=PostingsFormat(name=Direct), id=PostingsFormat(name=Direct), name=PostingsFormat(name=Direct)}, docValues:{}, sim=DefaultSimilarity, locale=mt, timezone=MET
[junit4] 2> NOTE: FreeBSD 9.1-RELEASE-p3 amd64/Oracle Corporation 1.7.0_25 (64-bit)/cpus=16,threads=1,free=152748008,total=390332416
[junit4] 2> NOTE: All tests run in this JVM: [RegexBoostProcessorTest, MoreLikeThisHandlerTest, TestWriterPerf, LegacyHTMLStripCharFilterTest, TestExtendedDismaxParser, TestSolrXml, UUIDFieldTest, AlternateDirectoryTest, TestFunctionQuery, ShardRoutingTest, IndexReaderFactoryTest, TestSolrIndexConfig, DistributedQueryElevationComponentTest, ClusterStateUpdateTest, TestLMDirichletSimilarityFactory, SolrIndexSplitterTest, BadComponentTest, TestFastLRUCache, SoftAutoCommitTest, LukeRequestHandlerTest, TestPluginEnable, TestSerializedLuceneMatchVersion, SyncSliceTest, QueryParsingTest, TestMaxScoreQueryParser, SolrTestCaseJ4Test, TestFastWriter, TestSolrQueryParser, AliasIntegrationTest, TestRemoteStreaming, PluginInfoTest, SpatialFilterTest, PolyFieldTest, TestGroupingSearch, TestDynamicFieldResource, TestSchemaNameResource, LoggingHandlerTest, RecoveryZkTest, JsonLoaderTest, TestSolrQueryParserDefaultOperatorResource, SearchHandlerTest, InfoHandlerTest, TermsComponentTest, SuggesterFSTTest, TestSolrCoreProperties, PreAnalyzedFieldTest, TestCharFilters, TestPHPSerializedResponseWriter, WordBreakSolrSpellCheckerTest, TermVectorComponentTest, TestQueryUtils, BasicFunctionalityTest, TestSolrDeletionPolicy2, TestFuzzyAnalyzedSuggestions, SimpleFacetsTest, SynonymTokenizerTest, TestFieldTypeCollectionResource, FastVectorHighlighterTest, BinaryUpdateRequestHandlerTest, TestPseudoReturnFields, TestLRUCache, StatelessScriptUpdateProcessorFactoryTest, FieldMutatingUpdateProcessorTest, PrimitiveFieldTypeTest, TestDefaultSearchFieldResource, PrimUtilsTest, DistributedTermsComponentTest, AnalysisAfterCoreReloadTest, CoreAdminHandlerTest, ShowFileRequestHandlerTest, TestCloudManagedSchemaAddField, DistributedSpellCheckComponentTest, TestStressVersions, TestSurroundQueryParser, LeaderElectionTest, SolrInfoMBeanTest, TestSort, BasicDistributedZkTest, OverseerTest, FullSolrCloudDistribCmdsTest, TestReplicationHandler]
[junit4] Completed on J0 in 681.57s, 14 tests, 1 failure <<< FAILURES!
[...truncated 474 lines...]
BUILD FAILED
/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-trunk/build.xml:396: The following error occurred while executing this line:
/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-trunk/build.xml:369: The following error occurred while executing this line:
/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-trunk/build.xml:39: The following error occurred while executing this line:
/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build.xml:181: The following error occurred while executing this line:
/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/common-build.xml:449: The following error occurred while executing this line:
/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-trunk/lucene/common-build.xml:1230: The following error occurred while executing this line:
/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-trunk/lucene/common-build.xml:873: There were test failures: 318 suites, 1342 tests, 1 error, 1 failure, 32 ignored (4 assumptions)
Total time: 104 minutes 51 seconds
Build step 'Invoke Ant' marked build as failure
Archiving artifacts
Recording test results
Email was triggered for: Failure
Sending email for trigger: Failure
Re: [JENKINS] Lucene-Solr-NightlyTests-trunk - Build # 343 - Still
Failing
Posted by Chris Hostetter <ho...@fucit.org>.
I can reproduce this -- it's probably related to the MP randomization i
put in ... looks like it's doing exact numeric comparisons based on term
stats. I'll take a look later today...
ant test -Dtestcase=SpellCheckCollatorTest -Dtests.method=testEstimatedHitCounts -Dtests.seed=16B4D8F74E59EE10 -Dtests.multiplier=2 -Dtests.nightly=true -Dtests.slow=true -Dtests.locale=nl -Dtests.timezone=America/Dawson -Dtests.file.encoding=US-ASCII
: Date: Wed, 7 Aug 2013 14:01:01 +0000 (UTC)
: From: Apache Jenkins Server <je...@builds.apache.org>
: Reply-To: dev@lucene.apache.org
: To: dev@lucene.apache.org
: Subject: [JENKINS] Lucene-Solr-NightlyTests-trunk - Build # 343 - Still
: Failing
:
: Build: https://builds.apache.org/job/Lucene-Solr-NightlyTests-trunk/343/
:
: 1 tests failed.
: REGRESSION: org.apache.solr.spelling.SpellCheckCollatorTest.testEstimatedHitCounts
:
: Error Message:
: Exception during query
:
: Stack Trace:
: java.lang.RuntimeException: Exception during query
: at __randomizedtesting.SeedInfo.seed([16B4D8F74E59EE10:270F66C2EB66FEC0]:0)
: at org.apache.solr.SolrTestCaseJ4.assertQ(SolrTestCaseJ4.java:635)
: at org.apache.solr.SolrTestCaseJ4.assertQ(SolrTestCaseJ4.java:602)
: at org.apache.solr.spelling.SpellCheckCollatorTest.testEstimatedHitCounts(SpellCheckCollatorTest.java:469)
: at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
: at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:57)
: at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
: at java.lang.reflect.Method.invoke(Method.java:606)
: at com.carrotsearch.randomizedtesting.RandomizedRunner.invoke(RandomizedRunner.java:1559)
: at com.carrotsearch.randomizedtesting.RandomizedRunner.access$600(RandomizedRunner.java:79)
: at com.carrotsearch.randomizedtesting.RandomizedRunner$6.evaluate(RandomizedRunner.java:737)
: at com.carrotsearch.randomizedtesting.RandomizedRunner$7.evaluate(RandomizedRunner.java:773)
: at com.carrotsearch.randomizedtesting.RandomizedRunner$8.evaluate(RandomizedRunner.java:787)
: at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:53)
: at org.apache.lucene.util.TestRuleSetupTeardownChained$1.evaluate(TestRuleSetupTeardownChained.java:50)
: at org.apache.lucene.util.TestRuleFieldCacheSanity$1.evaluate(TestRuleFieldCacheSanity.java:51)
: at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:46)
: at com.carrotsearch.randomizedtesting.rules.SystemPropertiesInvariantRule$1.evaluate(SystemPropertiesInvariantRule.java:55)
: at org.apache.lucene.util.TestRuleThreadAndTestName$1.evaluate(TestRuleThreadAndTestName.java:49)
: at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:70)
: at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:48)
: at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
: at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:358)
: at com.carrotsearch.randomizedtesting.ThreadLeakControl.forkTimeoutingTask(ThreadLeakControl.java:782)
: at com.carrotsearch.randomizedtesting.ThreadLeakControl$3.evaluate(ThreadLeakControl.java:442)
: at com.carrotsearch.randomizedtesting.RandomizedRunner.runSingleTest(RandomizedRunner.java:746)
: at com.carrotsearch.randomizedtesting.RandomizedRunner$3.evaluate(RandomizedRunner.java:648)
: at com.carrotsearch.randomizedtesting.RandomizedRunner$4.evaluate(RandomizedRunner.java:682)
: at com.carrotsearch.randomizedtesting.RandomizedRunner$5.evaluate(RandomizedRunner.java:693)
: at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
: at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:53)
: at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:46)
: at org.apache.lucene.util.TestRuleStoreClassName$1.evaluate(TestRuleStoreClassName.java:42)
: at com.carrotsearch.randomizedtesting.rules.SystemPropertiesInvariantRule$1.evaluate(SystemPropertiesInvariantRule.java:55)
: at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:39)
: at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:39)
: at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
: at org.apache.lucene.util.TestRuleAssertionsRequired$1.evaluate(TestRuleAssertionsRequired.java:43)
: at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:48)
: at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:70)
: at org.apache.lucene.util.TestRuleIgnoreTestSuites$1.evaluate(TestRuleIgnoreTestSuites.java:55)
: at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
: at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:358)
: at java.lang.Thread.run(Thread.java:724)
: Caused by: java.lang.RuntimeException: REQUEST FAILED: xpath=//lst[@name='spellcheck']/lst[@name='suggestions']/lst[@name='collation']/int[@name='hits']=4
: xml response was: <?xml version="1.0" encoding="UTF-8"?>
: <response>
: <lst name="responseHeader"><int name="status">0</int><int name="QTime">8</int></lst><result name="response" numFound="0" start="0"></result><lst name="spellcheck"><lst name="suggestions"><lst name="metnoia"><int name="numFound">1</int><int name="startOffset">9</int><int name="endOffset">16</int><arr name="suggestion"><str>metanoia</str></arr></lst><lst name="collation"><str name="collationQuery">teststop:metanoia</str><int name="hits">17</int><lst name="misspellingsAndCorrections"><str name="metnoia">metanoia</str></lst></lst></lst></lst>
: </response>
:
: request was:spellcheck=true&spellcheck.collateExtendedResults=true&q=teststop:metnoia&spellcheck.maxCollations=1&spellcheck.maxCollationTries=1&spellcheck.dictionary=direct&spellcheck.collateMaxCollectDocs=3&spellcheck.count=1&qt=spellCheckCompRH&spellcheck.collate=true
: at org.apache.solr.SolrTestCaseJ4.assertQ(SolrTestCaseJ4.java:628)
: ... 42 more
:
:
:
:
: Build Log:
: [...truncated 9902 lines...]
: [junit4] Suite: org.apache.solr.spelling.SpellCheckCollatorTest
: [junit4] 2> 2399675 T4045 oas.SolrTestCaseJ4.initCore ####initCore
: [junit4] 2> Creating dataDir: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test/J1/./solrtest-SpellCheckCollatorTest-1375883796067
: [junit4] 2> 2399676 T4045 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test-files/solr/collection1/'
: [junit4] 2> 2399677 T4045 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test-files/solr/collection1/lib/classes/' to classloader
: [junit4] 2> 2399677 T4045 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test-files/solr/collection1/lib/README' to classloader
: [junit4] 2> 2399765 T4045 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_50
: [junit4] 2> 2399808 T4045 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig-spellcheckcomponent.xml
: [junit4] 2> 2399809 T4045 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
: [junit4] 2> 2399817 T4045 oass.IndexSchema.readSchema [null] Schema name=test
: [junit4] 2> 2400228 T4045 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
: [junit4] 2> 2400236 T4045 oass.IndexSchema.readSchema default search field in schema is text
: [junit4] 2> 2400238 T4045 oass.IndexSchema.readSchema unique key field: id
: [junit4] 2> 2400244 T4045 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
: [junit4] 2> 2400247 T4045 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
: [junit4] 2> 2400250 T4045 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
: [junit4] 2> 2400251 T4045 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
: [junit4] 2> 2400251 T4045 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
: [junit4] 2> 2400251 T4045 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
: [junit4] 2> 2400251 T4045 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
: [junit4] 2> 2400251 T4045 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
: [junit4] 2> 2400252 T4045 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
: [junit4] 2> 2400252 T4045 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test-files/solr
: [junit4] 2> 2400252 T4045 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test-files/solr/'
: [junit4] 2> 2400261 T4045 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
: [junit4] 2> 2400262 T4045 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test-files/solr
: [junit4] 2> 2400262 T4045 oasc.SolrResourceLoader.<init> new SolrResourceLoader for deduced Solr Home: '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test-files/solr/'
: [junit4] 2> 2400320 T4045 oasc.CoreContainer.<init> New CoreContainer 1414615201
: [junit4] 2> 2400321 T4045 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test-files/solr/]
: [junit4] 2> 2400322 T4045 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 0
: [junit4] 2> 2400322 T4045 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
: [junit4] 2> 2400322 T4045 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 0
: [junit4] 2> 2400323 T4045 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
: [junit4] 2> 2400323 T4045 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
: [junit4] 2> 2400323 T4045 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
: [junit4] 2> 2400323 T4045 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
: [junit4] 2> 2400323 T4045 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
: [junit4] 2> 2400324 T4045 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
: [junit4] 2> 2400324 T4045 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=0&connTimeout=0&retry=false
: [junit4] 2> 2400340 T4045 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
: [junit4] 2> 2400347 T4046 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test-files/solr/collection1
: [junit4] 2> 2400347 T4046 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test-files/solr/collection1/'
: [junit4] 2> 2400348 T4046 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test-files/solr/collection1/lib/classes/' to classloader
: [junit4] 2> 2400348 T4046 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test-files/solr/collection1/lib/README' to classloader
: [junit4] 2> 2400390 T4046 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_50
: [junit4] 2> 2400429 T4046 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig-spellcheckcomponent.xml
: [junit4] 2> 2400430 T4046 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
: [junit4] 2> 2400436 T4046 oass.IndexSchema.readSchema [collection1] Schema name=test
: [junit4] 2> 2400922 T4046 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
: [junit4] 2> 2400931 T4046 oass.IndexSchema.readSchema default search field in schema is text
: [junit4] 2> 2400935 T4046 oass.IndexSchema.readSchema unique key field: id
: [junit4] 2> 2400942 T4046 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
: [junit4] 2> 2400946 T4046 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
: [junit4] 2> 2400950 T4046 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
: [junit4] 2> 2400950 T4046 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
: [junit4] 2> 2400950 T4046 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
: [junit4] 2> 2400951 T4046 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
: [junit4] 2> 2400951 T4046 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
: [junit4] 2> 2400951 T4046 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
: [junit4] 2> 2400952 T4046 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
: [junit4] 2> 2400952 T4046 oasc.SolrCore.<init> [collection1] Opening new SolrCore at /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test-files/solr/collection1/, dataDir=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test/J1/./solrtest-SpellCheckCollatorTest-1375883796067/
: [junit4] 2> 2400952 T4046 oasc.SolrCore.<init> JMX monitoring not detected for core: collection1
: [junit4] 2> 2400953 T4046 oasc.CachingDirectoryFactory.get return new directory for /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test/J1/./solrtest-SpellCheckCollatorTest-1375883796067
: [junit4] 2> 2400953 T4046 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test/J1/./solrtest-SpellCheckCollatorTest-1375883796067/index/
: [junit4] 2> 2400953 T4046 oasc.SolrCore.initIndex WARN [collection1] Solr index directory '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test/J1/./solrtest-SpellCheckCollatorTest-1375883796067/index' doesn't exist. Creating new index...
: [junit4] 2> 2400954 T4046 oasc.CachingDirectoryFactory.get return new directory for /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test/J1/./solrtest-SpellCheckCollatorTest-1375883796067/index
: [junit4] 2> 2400955 T4046 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
: [junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@7714200f lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@5a4c3855),segFN=segments_1,generation=1}
: [junit4] 2> 2400955 T4046 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
: [junit4] 2> 2400956 T4046 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
: [junit4] 2> 2400956 T4046 oasc.RequestHandlers.initHandlersFromConfig created spellCheckCompRH: org.apache.solr.handler.component.SearchHandler
: [junit4] 2> 2400957 T4046 oasc.RequestHandlers.initHandlersFromConfig created spellCheckCompRH1: org.apache.solr.handler.component.SearchHandler
: [junit4] 2> 2400957 T4046 oasc.RequestHandlers.initHandlersFromConfig created spellCheckWithWordbreak: org.apache.solr.handler.component.SearchHandler
: [junit4] 2> 2400960 T4046 oass.SolrIndexSearcher.<init> Opening Searcher@318e8f99 main
: [junit4] 2> 2400961 T4046 oasu.CommitTracker.<init> Hard AutoCommit: disabled
: [junit4] 2> 2400961 T4046 oasu.CommitTracker.<init> Soft AutoCommit: disabled
: [junit4] 2> 2400961 T4046 oashc.SpellCheckComponent.inform Initializing spell checkers
: [junit4] 2> 2400969 T4046 oashc.SpellCheckComponent.inform Registering newSearcher listener for spellchecker: default
: [junit4] 2> 2400982 T4046 oashc.SpellCheckComponent.inform Registering newSearcher listener for spellchecker: default_teststop
: [junit4] 2> 2400983 T4046 oass.DirectSolrSpellChecker.init init: {name=direct,classname=solr.DirectSolrSpellChecker,minQueryLength=3,maxQueryFrequency=100.0,field=teststop}
: [junit4] 2> 2400983 T4046 oass.DirectSolrSpellChecker.init init: {name=direct_lowerfilt,classname=solr.DirectSolrSpellChecker,minQueryLength=3,maxQueryFrequency=100.0,field=lowerfilt}
: [junit4] 2> 2400991 T4046 oashc.SpellCheckComponent.inform Registering newSearcher listener for spellchecker: threshold
: [junit4] 2> 2400991 T4046 oass.DirectSolrSpellChecker.init init: {name=threshold_direct,classname=solr.DirectSolrSpellChecker,field=lowerfilt,spellcheckIndexDir=spellcheckerThreshold,buildOnCommit=true,thresholdTokenFrequency=0.29}
: [junit4] 2> 2400992 T4046 oashc.SpellCheckComponent.inform Registering newSearcher listener for spellchecker: threshold_direct
: [junit4] 2> 2400999 T4046 oashc.SpellCheckComponent.inform Registering newSearcher listener for spellchecker: multipleFields
: [junit4] 2> 2401034 T4046 oashc.SpellCheckComponent.inform Registering newSearcher listener for spellchecker: freq
: [junit4] 2> 2401041 T4046 oashc.SpellCheckComponent.inform Registering newSearcher listener for spellchecker: fqcn
: [junit4] 2> 2401042 T4047 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@318e8f99 main{StandardDirectoryReader(segments_1:1)}
: [junit4] 2> 2401042 T4046 oasc.CoreContainer.registerCore registering core: collection1
: [junit4] 2> 2401055 T4045 oas.SolrTestCaseJ4.initCore ####initCore end
: [junit4] 2> ASYNC NEW_CORE C21367 name=collection1 org.apache.solr.core.SolrCore@32af94b0
: [junit4] 2> 2401064 T4045 C21367 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=1
: [junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@7714200f lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@5a4c3855),segFN=segments_1,generation=1}
: [junit4] 2> 2401064 T4045 C21367 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
: [junit4] 2> 2401065 T4045 C21367 oasup.LogUpdateProcessor.finish [collection1] webapp=null path=null params={} {add=[0]} 0 2
: [junit4] 2> 2401083 T4045 C21367 oasup.LogUpdateProcessor.finish [collection1] webapp=null path=null params={} {add=[1]} 0 0
: [junit4] 2> 2401090 T4045 C21367 oasup.LogUpdateProcessor.finish [collection1] webapp=null path=null params={} {add=[2]} 0 1
: [junit4] 2> 2401096 T4045 C21367 oasup.LogUpdateProcessor.finish [collection1] webapp=null path=null params={} {add=[3]} 0 1
: [junit4] 2> 2401104 T4045 C21367 oasup.LogUpdateProcessor.finish [collection1] webapp=null path=null params={} {add=[4]} 0 3
: [junit4] 2> 2401111 T4045 C21367 oasup.LogUpdateProcessor.finish [collection1] webapp=null path=null params={} {add=[5]} 0 1
: [junit4] 2> 2401116 T4045 C21367 oasup.LogUpdateProcessor.finish [collection1] webapp=null path=null params={} {add=[6]} 0 0
: [junit4] 2> 2401122 T4045 C21367 oasup.LogUpdateProcessor.finish [collection1] webapp=null path=null params={} {add=[7]} 0 0
: [junit4] 2> 2401128 T4045 C21367 oasup.LogUpdateProcessor.finish [collection1] webapp=null path=null params={} {add=[8]} 0 0
: [junit4] 2> 2401154 T4045 C21367 oasup.LogUpdateProcessor.finish [collection1] webapp=null path=null params={} {add=[9]} 0 20
: [junit4] 2> 2401160 T4045 C21367 oasup.LogUpdateProcessor.finish [collection1] webapp=null path=null params={} {add=[10]} 0 1
: [junit4] 2> 2401166 T4045 C21367 oasup.LogUpdateProcessor.finish [collection1] webapp=null path=null params={} {add=[11]} 0 1
: [junit4] 2> 2401171 T4045 C21367 oasup.LogUpdateProcessor.finish [collection1] webapp=null path=null params={} {add=[12]} 0 0
: [junit4] 2> 2401177 T4045 C21367 oasup.LogUpdateProcessor.finish [collection1] webapp=null path=null params={} {add=[13]} 0 0
: [junit4] 2> 2401211 T4045 C21367 oasup.LogUpdateProcessor.finish [collection1] webapp=null path=null params={} {add=[14]} 0 28
: [junit4] 2> 2401218 T4045 C21367 oasup.LogUpdateProcessor.finish [collection1] webapp=null path=null params={} {add=[15]} 0 1
: [junit4] 2> 2401223 T4045 C21367 oasup.LogUpdateProcessor.finish [collection1] webapp=null path=null params={} {add=[16]} 0 0
: [junit4] 2> 2401229 T4045 C21367 oasu.DirectUpdateHandler2.commit start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
: [junit4] 2> 2401254 T4045 C21367 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=2
: [junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@7714200f lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@5a4c3855),segFN=segments_1,generation=1}
: [junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@7714200f lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@5a4c3855),segFN=segments_2,generation=2}
: [junit4] 2> 2401254 T4045 C21367 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 2
: [junit4] 2> 2401259 T4045 C21367 oass.SolrIndexSearcher.<init> Opening Searcher@60a8d965 main
: [junit4] 2> 2401259 T4045 C21367 oasu.DirectUpdateHandler2.commit end_commit_flush
: [junit4] 2> 2401259 T4047 oashc.SpellCheckComponent$SpellCheckerListener.buildSpellIndex Building spell index for spell checker: default
: [junit4] 2> 2401346 T4047 oashc.SpellCheckComponent$SpellCheckerListener.buildSpellIndex Building spell index for spell checker: default_teststop
: [junit4] 2> 2401408 T4047 oashc.SpellCheckComponent$SpellCheckerListener.buildSpellIndex Building spell index for spell checker: threshold
: [junit4] 2> 2401421 T4047 oashc.SpellCheckComponent$SpellCheckerListener.buildSpellIndex Building spell index for spell checker: threshold_direct
: [junit4] 2> 2401422 T4047 oashc.SpellCheckComponent$SpellCheckerListener.buildSpellIndex Building spell index for spell checker: multipleFields
: [junit4] 2> 2401490 T4047 oashc.SpellCheckComponent$SpellCheckerListener.buildSpellIndex Building spell index for spell checker: freq
: [junit4] 2> 2401560 T4047 oashc.SpellCheckComponent$SpellCheckerListener.buildSpellIndex Building spell index for spell checker: fqcn
: [junit4] 2> 2401628 T4047 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@60a8d965 main{StandardDirectoryReader(segments_2:9:nrt _0(5.0):c5 _1(5.0):c5 _2(5.0):c5 _3(5.0):c2)}
: [junit4] 2> ASYNC NEW_CORE C21368 name=collection1 org.apache.solr.core.SolrCore@32af94b0
: [junit4] 2> 2401628 T4045 C21368 oasup.LogUpdateProcessor.finish [collection1] webapp=null path=null params={} {commit=} 0 399
: [junit4] 2> 2401640 T4045 oas.SolrTestCaseJ4.setUp ###Starting testExtendedCollate
: [junit4] 2> 2401733 T4045 oas.SolrTestCaseJ4.tearDown ###Ending testExtendedCollate
: [junit4] 2> 2401739 T4045 oas.SolrTestCaseJ4.setUp ###Starting testCollateWithFilter
: [junit4] 2> 2401825 T4045 oas.SolrTestCaseJ4.tearDown ###Ending testCollateWithFilter
: [junit4] 2> 2401832 T4045 oas.SolrTestCaseJ4.setUp ###Starting testContextSensitiveCollate
: [junit4] 2> 2401866 T4045 C21368 oasc.SolrCore.execute [collection1] webapp=null path=null params={spellcheck=true&indent=true&spellcheck.maxResultsForSuggest=0&spellcheck.collateExtendedResults=true&spellcheck.extendedResults=true&spellcheck.maxCollations=1&spellcheck.maxCollationTries=10&spellcheck.collate=true&q=teststop:(flew+AND+form+AND+heathrow)&spellcheck.dictionary=direct&spellcheck.count=10&qt=spellCheckCompRH&spellcheck.build=true&spellcheck.alternativeTermCount=5} hits=0 status=0 QTime=34
: [junit4] 2> 2401899 T4045 C21368 oasc.SolrCore.execute [collection1] webapp=null path=null params={spellcheck=true&indent=true&spellcheck.maxResultsForSuggest=1&spellcheck.collateExtendedResults=true&spellcheck.extendedResults=true&spellcheck.maxCollationTries=10&spellcheck.maxCollations=1&spellcheck.collate=true&q=teststop:(june+AND+customs)&spellcheck.dictionary=direct&spellcheck.count=10&qt=spellCheckCompRH&spellcheck.alternativeTermCount=5} hits=1 status=0 QTime=19
: [junit4] 2> 2401999 T4045 C21368 oasc.SolrCore.execute [collection1] webapp=null path=null params={spellcheck=true&indent=true&spellcheck.maxResultsForSuggest=0&spellcheck.collateExtendedResults=true&spellcheck.extendedResults=true&spellcheck.maxCollations=1&spellcheck.maxCollationTries=10&spellcheck.collate=true&q=teststop:(flew+AND+form+AND+heathrow)&spellcheck.dictionary=default_teststop&spellcheck.count=10&qt=spellCheckCompRH&spellcheck.build=true&spellcheck.alternativeTermCount=5} hits=0 status=0 QTime=90
: [junit4] 2> 2402017 T4045 C21368 oasc.SolrCore.execute [collection1] webapp=null path=null params={spellcheck=true&indent=true&spellcheck.maxResultsForSuggest=1&spellcheck.collateExtendedResults=true&spellcheck.extendedResults=true&spellcheck.maxCollationTries=10&spellcheck.maxCollations=1&spellcheck.collate=true&q=teststop:(june+AND+customs)&spellcheck.dictionary=default_teststop&spellcheck.count=10&qt=spellCheckCompRH&spellcheck.alternativeTermCount=5} hits=1 status=0 QTime=5
: [junit4] 2> 2402027 T4045 oas.SolrTestCaseJ4.tearDown ###Ending testContextSensitiveCollate
: [junit4] 2> 2402035 T4045 oas.SolrTestCaseJ4.setUp ###Starting testCollateWithMultipleRequestHandlers
: [junit4] 2> 2402108 T4045 oas.SolrTestCaseJ4.tearDown ###Ending testCollateWithMultipleRequestHandlers
: [junit4] 2> 2402115 T4045 oas.SolrTestCaseJ4.setUp ###Starting testCollationWithHypens
: [junit4] 2> 2402260 T4045 oas.SolrTestCaseJ4.tearDown ###Ending testCollationWithHypens
: [junit4] 2> 2402267 T4045 oas.SolrTestCaseJ4.setUp ###Starting testCollateWithGrouping
: [junit4] 2> 2402336 T4045 oas.SolrTestCaseJ4.tearDown ###Ending testCollateWithGrouping
: [junit4] 2> 2402344 T4045 oas.SolrTestCaseJ4.setUp ###Starting testCollateWithOverride
: [junit4] 2> 2402446 T4045 C21368 oasc.SolrCore.execute [collection1] webapp=null path=null params={mm=1&spellcheck=true&q=partisian+politcal+mashine&spellcheck.maxCollations=10&spellcheck.maxCollationTries=10&qf=teststop&spellcheck.dictionary=direct&spellcheck.count=10&qt=spellCheckCompRH&spellcheck.collate=true&defType=edismax} hits=0 status=0 QTime=102
: [junit4] 2> 2402493 T4045 C21368 oasc.SolrCore.execute [collection1] webapp=null path=null params={mm=1&spellcheck=true&spellcheck.collateParam.mm=100%25&q=partisian+politcal+mashine&spellcheck.maxCollations=10&spellcheck.maxCollationTries=10&qf=teststop&spellcheck.dictionary=direct&spellcheck.count=10&qt=spellCheckCompRH&spellcheck.collate=true&defType=edismax} hits=0 status=0 QTime=40
: [junit4] 2> 2402496 T4045 oas.SolrTestCaseJ4.tearDown ###Ending testCollateWithOverride
: [junit4] 2> 2402502 T4045 oas.SolrTestCaseJ4.setUp ###Starting testEstimatedHitCounts
: [junit4] 2> 2402512 T4045 C21368 oasc.SolrCore.execute [collection1] webapp=null path=null params={spellcheck=true&spellcheck.collateExtendedResults=true&q=teststop:metnoia&spellcheck.maxCollations=1&spellcheck.maxCollationTries=1&spellcheck.dictionary=direct&spellcheck.count=1&qt=spellCheckCompRH&spellcheck.collate=true} hits=0 status=0 QTime=10
: [junit4] 2> 2402526 T4045 C21368 oasc.SolrCore.execute [collection1] webapp=null path=null params={spellcheck=true&spellcheck.collateExtendedResults=true&q=teststop:metnoia&spellcheck.maxCollations=1&spellcheck.maxCollationTries=1&spellcheck.dictionary=direct&spellcheck.collateMaxCollectDocs=1&spellcheck.count=1&qt=spellCheckCompRH&spellcheck.collate=true} hits=0 status=0 QTime=11
: [junit4] 2> 2402538 T4045 C21368 oasc.SolrCore.execute [collection1] webapp=null path=null params={spellcheck=true&spellcheck.collateExtendedResults=true&q=teststop:metnoia&spellcheck.maxCollations=1&spellcheck.maxCollationTries=1&spellcheck.dictionary=direct&spellcheck.collateMaxCollectDocs=3&spellcheck.count=1&qt=spellCheckCompRH&spellcheck.collate=true} hits=0 status=0 QTime=8
: [junit4] 2> 2402542 T4045 oas.SolrTestCaseJ4.assertQ ERROR REQUEST FAILED: xpath=//lst[@name='spellcheck']/lst[@name='suggestions']/lst[@name='collation']/int[@name='hits']=4
: [junit4] 2> xml response was: <?xml version="1.0" encoding="UTF-8"?>
: [junit4] 2> <response>
: [junit4] 2> <lst name="responseHeader"><int name="status">0</int><int name="QTime">8</int></lst><result name="response" numFound="0" start="0"></result><lst name="spellcheck"><lst name="suggestions"><lst name="metnoia"><int name="numFound">1</int><int name="startOffset">9</int><int name="endOffset">16</int><arr name="suggestion"><str>metanoia</str></arr></lst><lst name="collation"><str name="collationQuery">teststop:metanoia</str><int name="hits">17</int><lst name="misspellingsAndCorrections"><str name="metnoia">metanoia</str></lst></lst></lst></lst>
: [junit4] 2> </response>
: [junit4] 2>
: [junit4] 2> request was:spellcheck=true&spellcheck.collateExtendedResults=true&q=teststop:metnoia&spellcheck.maxCollations=1&spellcheck.maxCollationTries=1&spellcheck.dictionary=direct&spellcheck.collateMaxCollectDocs=3&spellcheck.count=1&qt=spellCheckCompRH&spellcheck.collate=true
: [junit4] 2> 2402544 T4045 oasc.SolrException.log ERROR REQUEST FAILED: spellcheck=true&spellcheck.collateExtendedResults=true&q=teststop:metnoia&spellcheck.maxCollations=1&spellcheck.maxCollationTries=1&spellcheck.dictionary=direct&spellcheck.collateMaxCollectDocs=3&spellcheck.count=1&qt=spellCheckCompRH&spellcheck.collate=true:java.lang.RuntimeException: REQUEST FAILED: xpath=//lst[@name='spellcheck']/lst[@name='suggestions']/lst[@name='collation']/int[@name='hits']=4
: [junit4] 2> xml response was: <?xml version="1.0" encoding="UTF-8"?>
: [junit4] 2> <response>
: [junit4] 2> <lst name="responseHeader"><int name="status">0</int><int name="QTime">8</int></lst><result name="response" numFound="0" start="0"></result><lst name="spellcheck"><lst name="suggestions"><lst name="metnoia"><int name="numFound">1</int><int name="startOffset">9</int><int name="endOffset">16</int><arr name="suggestion"><str>metanoia</str></arr></lst><lst name="collation"><str name="collationQuery">teststop:metanoia</str><int name="hits">17</int><lst name="misspellingsAndCorrections"><str name="metnoia">metanoia</str></lst></lst></lst></lst>
: [junit4] 2> </response>
: [junit4] 2>
: [junit4] 2> request was:spellcheck=true&spellcheck.collateExtendedResults=true&q=teststop:metnoia&spellcheck.maxCollations=1&spellcheck.maxCollationTries=1&spellcheck.dictionary=direct&spellcheck.collateMaxCollectDocs=3&spellcheck.count=1&qt=spellCheckCompRH&spellcheck.collate=true
: [junit4] 2> at org.apache.solr.SolrTestCaseJ4.assertQ(SolrTestCaseJ4.java:628)
: [junit4] 2> at org.apache.solr.SolrTestCaseJ4.assertQ(SolrTestCaseJ4.java:602)
: [junit4] 2> at org.apache.solr.spelling.SpellCheckCollatorTest.testEstimatedHitCounts(SpellCheckCollatorTest.java:469)
: [junit4] 2> at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
: [junit4] 2> at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:57)
: [junit4] 2> at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
: [junit4] 2> at java.lang.reflect.Method.invoke(Method.java:606)
: [junit4] 2> at com.carrotsearch.randomizedtesting.RandomizedRunner.invoke(RandomizedRunner.java:1559)
: [junit4] 2> at com.carrotsearch.randomizedtesting.RandomizedRunner.access$600(RandomizedRunner.java:79)
: [junit4] 2> at com.carrotsearch.randomizedtesting.RandomizedRunner$6.evaluate(RandomizedRunner.java:737)
: [junit4] 2> at com.carrotsearch.randomizedtesting.RandomizedRunner$7.evaluate(RandomizedRunner.java:773)
: [junit4] 2> at com.carrotsearch.randomizedtesting.RandomizedRunner$8.evaluate(RandomizedRunner.java:787)
: [junit4] 2> at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:53)
: [junit4] 2> at org.apache.lucene.util.TestRuleSetupTeardownChained$1.evaluate(TestRuleSetupTeardownChained.java:50)
: [junit4] 2> at org.apache.lucene.util.TestRuleFieldCacheSanity$1.evaluate(TestRuleFieldCacheSanity.java:51)
: [junit4] 2> at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:46)
: [junit4] 2> at com.carrotsearch.randomizedtesting.rules.SystemPropertiesInvariantRule$1.evaluate(SystemPropertiesInvariantRule.java:55)
: [junit4] 2> at org.apache.lucene.util.TestRuleThreadAndTestName$1.evaluate(TestRuleThreadAndTestName.java:49)
: [junit4] 2> at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:70)
: [junit4] 2> at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:48)
: [junit4] 2> at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
: [junit4] 2> at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:358)
: [junit4] 2> at com.carrotsearch.randomizedtesting.ThreadLeakControl.forkTimeoutingTask(ThreadLeakControl.java:782)
: [junit4] 2> at com.carrotsearch.randomizedtesting.ThreadLeakControl$3.evaluate(ThreadLeakControl.java:442)
: [junit4] 2> at com.carrotsearch.randomizedtesting.RandomizedRunner.runSingleTest(RandomizedRunner.java:746)
: [junit4] 2> at com.carrotsearch.randomizedtesting.RandomizedRunner$3.evaluate(RandomizedRunner.java:648)
: [junit4] 2> at com.carrotsearch.randomizedtesting.RandomizedRunner$4.evaluate(RandomizedRunner.java:682)
: [junit4] 2> at com.carrotsearch.randomizedtesting.RandomizedRunner$5.evaluate(RandomizedRunner.java:693)
: [junit4] 2> at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
: [junit4] 2> at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:53)
: [junit4] 2> at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:46)
: [junit4] 2> at org.apache.lucene.util.TestRuleStoreClassName$1.evaluate(TestRuleStoreClassName.java:42)
: [junit4] 2> at com.carrotsearch.randomizedtesting.rules.SystemPropertiesInvariantRule$1.evaluate(SystemPropertiesInvariantRule.java:55)
: [junit4] 2> at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:39)
: [junit4] 2> at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:39)
: [junit4] 2> at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
: [junit4] 2> at org.apache.lucene.util.TestRuleAssertionsRequired$1.evaluate(TestRuleAssertionsRequired.java:43)
: [junit4] 2> at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:48)
: [junit4] 2> at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:70)
: [junit4] 2> at org.apache.lucene.util.TestRuleIgnoreTestSuites$1.evaluate(TestRuleIgnoreTestSuites.java:55)
: [junit4] 2> at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
: [junit4] 2> at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:358)
: [junit4] 2> at java.lang.Thread.run(Thread.java:724)
: [junit4] 2>
: [junit4] 2> 2402546 T4045 oas.SolrTestCaseJ4.tearDown ###Ending testEstimatedHitCounts
: [junit4] 2> NOTE: download the large Jenkins line-docs file by running 'ant get-jenkins-line-docs' in the lucene directory.
: [junit4] 2> NOTE: reproduce with: ant test -Dtestcase=SpellCheckCollatorTest -Dtests.method=testEstimatedHitCounts -Dtests.seed=16B4D8F74E59EE10 -Dtests.multiplier=2 -Dtests.nightly=true -Dtests.slow=true -Dtests.linedocsfile=/home/hudson/lucene-data/enwiki.random.lines.txt -Dtests.locale=nl -Dtests.timezone=America/Dawson -Dtests.file.encoding=US-ASCII
: [junit4] ERROR 0.06s J1 | SpellCheckCollatorTest.testEstimatedHitCounts <<<
: [junit4] > Throwable #1: java.lang.RuntimeException: Exception during query
: [junit4] > at __randomizedtesting.SeedInfo.seed([16B4D8F74E59EE10:270F66C2EB66FEC0]:0)
: [junit4] > at org.apache.solr.SolrTestCaseJ4.assertQ(SolrTestCaseJ4.java:635)
: [junit4] > at org.apache.solr.SolrTestCaseJ4.assertQ(SolrTestCaseJ4.java:602)
: [junit4] > at org.apache.solr.spelling.SpellCheckCollatorTest.testEstimatedHitCounts(SpellCheckCollatorTest.java:469)
: [junit4] > at java.lang.Thread.run(Thread.java:724)
: [junit4] > Caused by: java.lang.RuntimeException: REQUEST FAILED: xpath=//lst[@name='spellcheck']/lst[@name='suggestions']/lst[@name='collation']/int[@name='hits']=4
: [junit4] > xml response was: <?xml version="1.0" encoding="UTF-8"?>
: [junit4] > <response>
: [junit4] > <lst name="responseHeader"><int name="status">0</int><int name="QTime">8</int></lst><result name="response" numFound="0" start="0"></result><lst name="spellcheck"><lst name="suggestions"><lst name="metnoia"><int name="numFound">1</int><int name="startOffset">9</int><int name="endOffset">16</int><arr name="suggestion"><str>metanoia</str></arr></lst><lst name="collation"><str name="collationQuery">teststop:metanoia</str><int name="hits">17</int><lst name="misspellingsAndCorrections"><str name="metnoia">metanoia</str></lst></lst></lst></lst>
: [junit4] > </response>
: [junit4] > request was:spellcheck=true&spellcheck.collateExtendedResults=true&q=teststop:metnoia&spellcheck.maxCollations=1&spellcheck.maxCollationTries=1&spellcheck.dictionary=direct&spellcheck.collateMaxCollectDocs=3&spellcheck.count=1&qt=spellCheckCompRH&spellcheck.collate=true
: [junit4] > at org.apache.solr.SolrTestCaseJ4.assertQ(SolrTestCaseJ4.java:628)
: [junit4] > ... 42 more
: [junit4] 2> 2402558 T4045 oas.SolrTestCaseJ4.deleteCore ###deleteCore
: [junit4] 2> 2402559 T4045 oasc.CoreContainer.shutdown Shutting down CoreContainer instance=1414615201
: [junit4] 2> 2402559 T4045 oasc.SolrCore.close [collection1] CLOSING SolrCore org.apache.solr.core.SolrCore@32af94b0
: [junit4] 2> 2402559 T4045 oasu.DirectUpdateHandler2.close closing DirectUpdateHandler2{commits=1,autocommits=0,soft autocommits=0,optimizes=0,rollbacks=0,expungeDeletes=0,docsPending=0,adds=0,deletesById=0,deletesByQuery=0,errors=0,cumulative_adds=17,cumulative_deletesById=0,cumulative_deletesByQuery=0,cumulative_errors=0}
: [junit4] 2> 2402560 T4045 oasu.SolrCoreState.decrefSolrCoreState Closing SolrCoreState
: [junit4] 2> 2402560 T4045 oasu.DefaultSolrCoreState.closeIndexWriter SolrCoreState ref count has reached 0 - closing IndexWriter
: [junit4] 2> 2402560 T4045 oasu.DefaultSolrCoreState.closeIndexWriter closing IndexWriter with IndexWriterCloser
: [junit4] 2> 2402561 T4045 oasc.SolrCore.closeSearcher [collection1] Closing main searcher on request.
: [junit4] 2> 2402561 T4045 oasc.CachingDirectoryFactory.close Closing MockDirectoryFactory - 2 directories currently being tracked
: [junit4] 2> 2402562 T4045 oasc.CachingDirectoryFactory.closeCacheValue looking to close /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test/J1/./solrtest-SpellCheckCollatorTest-1375883796067/index [CachedDir<<refCount=0;path=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test/J1/./solrtest-SpellCheckCollatorTest-1375883796067/index;done=false>>]
: [junit4] 2> 2402562 T4045 oasc.CachingDirectoryFactory.close Closing directory: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test/J1/./solrtest-SpellCheckCollatorTest-1375883796067/index
: [junit4] 2> 2402562 T4045 oasc.CachingDirectoryFactory.closeCacheValue looking to close /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test/J1/./solrtest-SpellCheckCollatorTest-1375883796067 [CachedDir<<refCount=0;path=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test/J1/./solrtest-SpellCheckCollatorTest-1375883796067;done=false>>]
: [junit4] 2> 2402563 T4045 oasc.CachingDirectoryFactory.close Closing directory: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test/J1/./solrtest-SpellCheckCollatorTest-1375883796067
: [junit4] 2> NOTE: test params are: codec=Lucene42: {range_facet_l=MockVariableIntBlock(baseBlockSize=72), lowerfilt1=Pulsing41(freqCutoff=12 minBlockSize=73 maxBlockSize=149), lowerfilt=PostingsFormat(name=Lucene41VarGapFixedInterval), teststop=PostingsFormat(name=Lucene41VarGapFixedInterval), end4=Pulsing41(freqCutoff=12 minBlockSize=73 maxBlockSize=149), end3=PostingsFormat(name=Lucene41VarGapFixedInterval), lowerfilt1and2=PostingsFormat(name=Lucene41VarGapFixedInterval), start1=Pulsing41(freqCutoff=12 minBlockSize=73 maxBlockSize=149), end2=PostingsFormat(name=Lucene41WithOrds), end1=MockVariableIntBlock(baseBlockSize=72), intDefault=MockVariableIntBlock(baseBlockSize=72), id=PostingsFormat(name=Lucene41WithOrds), timestamp=MockVariableIntBlock(baseBlockSize=72), range_facet_sl=Pulsing41(freqCutoff=12 minBlockSize=73 maxBlockSize=149), range_facet_si=PostingsFormat(name=Lucene41VarGapFixedInterval), start4=MockVariableIntBlock(baseBlockSize=72), start2=PostingsFormat(name=L
ucene41VarGapFixedInterval), start3=PostingsFormat(name=Lucene41WithOrds), word=MockVariableIntBlock(baseBlockSize=72), gram2=PostingsFormat(name=Lucene41WithOrds), gram1=MockVariableIntBlock(baseBlockSize=72), multiDefault=PostingsFormat(name=Lucene41VarGapFixedInterval), gram4=Pulsing41(freqCutoff=12 minBlockSize=73 maxBlockSize=149), gram3=PostingsFormat(name=Lucene41VarGapFixedInterval)}, docValues:{timestamp=DocValuesFormat(name=Asserting)}, sim=RandomSimilarityProvider(queryNorm=false,coord=yes): {}, locale=nl, timezone=America/Dawson
: [junit4] 2> NOTE: FreeBSD 9.1-RELEASE-p3 amd64/Oracle Corporation 1.7.0_25 (64-bit)/cpus=16,threads=1,free=281063024,total=534052864
: [junit4] 2> NOTE: All tests run in this JVM: [IndexBasedSpellCheckerTest, CoreAdminCreateDiscoverTest, CoreContainerCoreInitFailuresTest, TestQueryTypes, ResourceLoaderTest, TestReload, UUIDFieldTest, TestCopyFieldCollectionResource, TestCSVLoader, SuggesterTSTTest, TestBinaryField, TestPhraseSuggestions, SuggesterWFSTTest, ConvertedLegacyTest, TestSweetSpotSimilarityFactory, HdfsUnloadDistributedZkTest, HighlighterTest, ChaosMonkeySafeLeaderTest, CurrencyFieldXmlFileTest, SimplePostToolTest, DistanceFunctionTest, TestFiltering, TestDFRSimilarityFactory, JSONWriterTest, BasicZkTest, TestUtils, HdfsBasicDistributedZk2Test, TestOmitPositions, TestCloudManagedSchema, SliceStateTest, PrimUtilsTest, OpenCloseCoreStressTest, PathHierarchyTokenizerFactoryTest, TestDefaultSimilarityFactory, AlternateDirectoryTest, DebugComponentTest, SolrRequestParserTest, LeaderElectionIntegrationTest, HighlighterConfigTest, TestFastWriter, PreAnalyzedFieldTest, TestRecoveryHdfs, HdfsCollectionsAPIDi
stributedZkTest, TestCoreDiscovery, BadIndexSchemaTest, TestCodecSupport, TestIndexSearcher, TestSolrDeletionPolicy2, TestJmxIntegration, TestZkChroot, DirectUpdateHandlerTest, FullSolrCloudDistribCmdsTest, StatsComponentTest, XsltUpdateRequestHandlerTest, CircularListTest, RequestHandlersTest, HardAutoCommitTest, TestMultiCoreConfBootstrap, TestUpdate, UniqFieldsUpdateProcessorFactoryTest, HdfsRecoveryZkTest, NoCacheHeaderTest, ShardSplitTest, TestRandomMergePolicy, BasicDistributedZk2Test, TestStressReorder, TestFuzzyAnalyzedSuggestions, TestAtomicUpdateErrorCases, DirectSolrSpellCheckerTest, TestSolr4Spatial, TestClassNameShortening, SolrCmdDistributorTest, DisMaxRequestHandlerTest, DefaultValueUpdateProcessorTest, ClusterStateTest, TestRandomFaceting, AutoCommitTest, TestDistributedGrouping, TestFaceting, TestRecovery, TestHashPartitioner, TermVectorComponentDistributedTest, TestJoin, SpellCheckComponentTest, PeerSyncTest, TestLazyCores, SoftAutoCommitTest, CurrencyFieldOpenExch
angeTest, SpellCheckCollatorTest]
: [junit4] Completed on J1 in 2.93s, 8 tests, 1 error <<< FAILURES!
:
: [...truncated 386 lines...]
: BUILD FAILED
: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-trunk/build.xml:396: The following error occurred while executing this line:
: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-trunk/build.xml:369: The following error occurred while executing this line:
: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-trunk/build.xml:39: The following error occurred while executing this line:
: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build.xml:181: The following error occurred while executing this line:
: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/common-build.xml:449: The following error occurred while executing this line:
: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-trunk/lucene/common-build.xml:1230: The following error occurred while executing this line:
: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-trunk/lucene/common-build.xml:873: There were test failures: 317 suites, 1343 tests, 1 error, 32 ignored (4 assumptions)
:
: Total time: 102 minutes 23 seconds
: Build step 'Invoke Ant' marked build as failure
: Archiving artifacts
: Recording test results
: Email was triggered for: Failure
: Sending email for trigger: Failure
:
:
:
-Hoss
[JENKINS] Lucene-Solr-NightlyTests-trunk - Build # 343 - Still
Failing
Posted by Apache Jenkins Server <je...@builds.apache.org>.
Build: https://builds.apache.org/job/Lucene-Solr-NightlyTests-trunk/343/
1 tests failed.
REGRESSION: org.apache.solr.spelling.SpellCheckCollatorTest.testEstimatedHitCounts
Error Message:
Exception during query
Stack Trace:
java.lang.RuntimeException: Exception during query
at __randomizedtesting.SeedInfo.seed([16B4D8F74E59EE10:270F66C2EB66FEC0]:0)
at org.apache.solr.SolrTestCaseJ4.assertQ(SolrTestCaseJ4.java:635)
at org.apache.solr.SolrTestCaseJ4.assertQ(SolrTestCaseJ4.java:602)
at org.apache.solr.spelling.SpellCheckCollatorTest.testEstimatedHitCounts(SpellCheckCollatorTest.java:469)
at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:57)
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
at java.lang.reflect.Method.invoke(Method.java:606)
at com.carrotsearch.randomizedtesting.RandomizedRunner.invoke(RandomizedRunner.java:1559)
at com.carrotsearch.randomizedtesting.RandomizedRunner.access$600(RandomizedRunner.java:79)
at com.carrotsearch.randomizedtesting.RandomizedRunner$6.evaluate(RandomizedRunner.java:737)
at com.carrotsearch.randomizedtesting.RandomizedRunner$7.evaluate(RandomizedRunner.java:773)
at com.carrotsearch.randomizedtesting.RandomizedRunner$8.evaluate(RandomizedRunner.java:787)
at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:53)
at org.apache.lucene.util.TestRuleSetupTeardownChained$1.evaluate(TestRuleSetupTeardownChained.java:50)
at org.apache.lucene.util.TestRuleFieldCacheSanity$1.evaluate(TestRuleFieldCacheSanity.java:51)
at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:46)
at com.carrotsearch.randomizedtesting.rules.SystemPropertiesInvariantRule$1.evaluate(SystemPropertiesInvariantRule.java:55)
at org.apache.lucene.util.TestRuleThreadAndTestName$1.evaluate(TestRuleThreadAndTestName.java:49)
at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:70)
at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:48)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:358)
at com.carrotsearch.randomizedtesting.ThreadLeakControl.forkTimeoutingTask(ThreadLeakControl.java:782)
at com.carrotsearch.randomizedtesting.ThreadLeakControl$3.evaluate(ThreadLeakControl.java:442)
at com.carrotsearch.randomizedtesting.RandomizedRunner.runSingleTest(RandomizedRunner.java:746)
at com.carrotsearch.randomizedtesting.RandomizedRunner$3.evaluate(RandomizedRunner.java:648)
at com.carrotsearch.randomizedtesting.RandomizedRunner$4.evaluate(RandomizedRunner.java:682)
at com.carrotsearch.randomizedtesting.RandomizedRunner$5.evaluate(RandomizedRunner.java:693)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:53)
at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:46)
at org.apache.lucene.util.TestRuleStoreClassName$1.evaluate(TestRuleStoreClassName.java:42)
at com.carrotsearch.randomizedtesting.rules.SystemPropertiesInvariantRule$1.evaluate(SystemPropertiesInvariantRule.java:55)
at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:39)
at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:39)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at org.apache.lucene.util.TestRuleAssertionsRequired$1.evaluate(TestRuleAssertionsRequired.java:43)
at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:48)
at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:70)
at org.apache.lucene.util.TestRuleIgnoreTestSuites$1.evaluate(TestRuleIgnoreTestSuites.java:55)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:358)
at java.lang.Thread.run(Thread.java:724)
Caused by: java.lang.RuntimeException: REQUEST FAILED: xpath=//lst[@name='spellcheck']/lst[@name='suggestions']/lst[@name='collation']/int[@name='hits']=4
xml response was: <?xml version="1.0" encoding="UTF-8"?>
<response>
<lst name="responseHeader"><int name="status">0</int><int name="QTime">8</int></lst><result name="response" numFound="0" start="0"></result><lst name="spellcheck"><lst name="suggestions"><lst name="metnoia"><int name="numFound">1</int><int name="startOffset">9</int><int name="endOffset">16</int><arr name="suggestion"><str>metanoia</str></arr></lst><lst name="collation"><str name="collationQuery">teststop:metanoia</str><int name="hits">17</int><lst name="misspellingsAndCorrections"><str name="metnoia">metanoia</str></lst></lst></lst></lst>
</response>
request was:spellcheck=true&spellcheck.collateExtendedResults=true&q=teststop:metnoia&spellcheck.maxCollations=1&spellcheck.maxCollationTries=1&spellcheck.dictionary=direct&spellcheck.collateMaxCollectDocs=3&spellcheck.count=1&qt=spellCheckCompRH&spellcheck.collate=true
at org.apache.solr.SolrTestCaseJ4.assertQ(SolrTestCaseJ4.java:628)
... 42 more
Build Log:
[...truncated 9902 lines...]
[junit4] Suite: org.apache.solr.spelling.SpellCheckCollatorTest
[junit4] 2> 2399675 T4045 oas.SolrTestCaseJ4.initCore ####initCore
[junit4] 2> Creating dataDir: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test/J1/./solrtest-SpellCheckCollatorTest-1375883796067
[junit4] 2> 2399676 T4045 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test-files/solr/collection1/'
[junit4] 2> 2399677 T4045 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test-files/solr/collection1/lib/classes/' to classloader
[junit4] 2> 2399677 T4045 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test-files/solr/collection1/lib/README' to classloader
[junit4] 2> 2399765 T4045 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_50
[junit4] 2> 2399808 T4045 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig-spellcheckcomponent.xml
[junit4] 2> 2399809 T4045 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4] 2> 2399817 T4045 oass.IndexSchema.readSchema [null] Schema name=test
[junit4] 2> 2400228 T4045 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4] 2> 2400236 T4045 oass.IndexSchema.readSchema default search field in schema is text
[junit4] 2> 2400238 T4045 oass.IndexSchema.readSchema unique key field: id
[junit4] 2> 2400244 T4045 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4] 2> 2400247 T4045 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4] 2> 2400250 T4045 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4] 2> 2400251 T4045 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4] 2> 2400251 T4045 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4] 2> 2400251 T4045 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4] 2> 2400251 T4045 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4] 2> 2400251 T4045 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4] 2> 2400252 T4045 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4] 2> 2400252 T4045 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test-files/solr
[junit4] 2> 2400252 T4045 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test-files/solr/'
[junit4] 2> 2400261 T4045 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4] 2> 2400262 T4045 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test-files/solr
[junit4] 2> 2400262 T4045 oasc.SolrResourceLoader.<init> new SolrResourceLoader for deduced Solr Home: '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test-files/solr/'
[junit4] 2> 2400320 T4045 oasc.CoreContainer.<init> New CoreContainer 1414615201
[junit4] 2> 2400321 T4045 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test-files/solr/]
[junit4] 2> 2400322 T4045 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 0
[junit4] 2> 2400322 T4045 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4] 2> 2400322 T4045 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 0
[junit4] 2> 2400323 T4045 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4] 2> 2400323 T4045 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4] 2> 2400323 T4045 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4] 2> 2400323 T4045 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4] 2> 2400323 T4045 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4] 2> 2400324 T4045 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4] 2> 2400324 T4045 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=0&connTimeout=0&retry=false
[junit4] 2> 2400340 T4045 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
[junit4] 2> 2400347 T4046 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test-files/solr/collection1
[junit4] 2> 2400347 T4046 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test-files/solr/collection1/'
[junit4] 2> 2400348 T4046 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test-files/solr/collection1/lib/classes/' to classloader
[junit4] 2> 2400348 T4046 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test-files/solr/collection1/lib/README' to classloader
[junit4] 2> 2400390 T4046 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_50
[junit4] 2> 2400429 T4046 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig-spellcheckcomponent.xml
[junit4] 2> 2400430 T4046 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4] 2> 2400436 T4046 oass.IndexSchema.readSchema [collection1] Schema name=test
[junit4] 2> 2400922 T4046 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4] 2> 2400931 T4046 oass.IndexSchema.readSchema default search field in schema is text
[junit4] 2> 2400935 T4046 oass.IndexSchema.readSchema unique key field: id
[junit4] 2> 2400942 T4046 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4] 2> 2400946 T4046 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4] 2> 2400950 T4046 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4] 2> 2400950 T4046 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4] 2> 2400950 T4046 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4] 2> 2400951 T4046 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4] 2> 2400951 T4046 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4] 2> 2400951 T4046 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4] 2> 2400952 T4046 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4] 2> 2400952 T4046 oasc.SolrCore.<init> [collection1] Opening new SolrCore at /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test-files/solr/collection1/, dataDir=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test/J1/./solrtest-SpellCheckCollatorTest-1375883796067/
[junit4] 2> 2400952 T4046 oasc.SolrCore.<init> JMX monitoring not detected for core: collection1
[junit4] 2> 2400953 T4046 oasc.CachingDirectoryFactory.get return new directory for /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test/J1/./solrtest-SpellCheckCollatorTest-1375883796067
[junit4] 2> 2400953 T4046 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test/J1/./solrtest-SpellCheckCollatorTest-1375883796067/index/
[junit4] 2> 2400953 T4046 oasc.SolrCore.initIndex WARN [collection1] Solr index directory '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test/J1/./solrtest-SpellCheckCollatorTest-1375883796067/index' doesn't exist. Creating new index...
[junit4] 2> 2400954 T4046 oasc.CachingDirectoryFactory.get return new directory for /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test/J1/./solrtest-SpellCheckCollatorTest-1375883796067/index
[junit4] 2> 2400955 T4046 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
[junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@7714200f lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@5a4c3855),segFN=segments_1,generation=1}
[junit4] 2> 2400955 T4046 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4] 2> 2400956 T4046 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4] 2> 2400956 T4046 oasc.RequestHandlers.initHandlersFromConfig created spellCheckCompRH: org.apache.solr.handler.component.SearchHandler
[junit4] 2> 2400957 T4046 oasc.RequestHandlers.initHandlersFromConfig created spellCheckCompRH1: org.apache.solr.handler.component.SearchHandler
[junit4] 2> 2400957 T4046 oasc.RequestHandlers.initHandlersFromConfig created spellCheckWithWordbreak: org.apache.solr.handler.component.SearchHandler
[junit4] 2> 2400960 T4046 oass.SolrIndexSearcher.<init> Opening Searcher@318e8f99 main
[junit4] 2> 2400961 T4046 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4] 2> 2400961 T4046 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4] 2> 2400961 T4046 oashc.SpellCheckComponent.inform Initializing spell checkers
[junit4] 2> 2400969 T4046 oashc.SpellCheckComponent.inform Registering newSearcher listener for spellchecker: default
[junit4] 2> 2400982 T4046 oashc.SpellCheckComponent.inform Registering newSearcher listener for spellchecker: default_teststop
[junit4] 2> 2400983 T4046 oass.DirectSolrSpellChecker.init init: {name=direct,classname=solr.DirectSolrSpellChecker,minQueryLength=3,maxQueryFrequency=100.0,field=teststop}
[junit4] 2> 2400983 T4046 oass.DirectSolrSpellChecker.init init: {name=direct_lowerfilt,classname=solr.DirectSolrSpellChecker,minQueryLength=3,maxQueryFrequency=100.0,field=lowerfilt}
[junit4] 2> 2400991 T4046 oashc.SpellCheckComponent.inform Registering newSearcher listener for spellchecker: threshold
[junit4] 2> 2400991 T4046 oass.DirectSolrSpellChecker.init init: {name=threshold_direct,classname=solr.DirectSolrSpellChecker,field=lowerfilt,spellcheckIndexDir=spellcheckerThreshold,buildOnCommit=true,thresholdTokenFrequency=0.29}
[junit4] 2> 2400992 T4046 oashc.SpellCheckComponent.inform Registering newSearcher listener for spellchecker: threshold_direct
[junit4] 2> 2400999 T4046 oashc.SpellCheckComponent.inform Registering newSearcher listener for spellchecker: multipleFields
[junit4] 2> 2401034 T4046 oashc.SpellCheckComponent.inform Registering newSearcher listener for spellchecker: freq
[junit4] 2> 2401041 T4046 oashc.SpellCheckComponent.inform Registering newSearcher listener for spellchecker: fqcn
[junit4] 2> 2401042 T4047 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@318e8f99 main{StandardDirectoryReader(segments_1:1)}
[junit4] 2> 2401042 T4046 oasc.CoreContainer.registerCore registering core: collection1
[junit4] 2> 2401055 T4045 oas.SolrTestCaseJ4.initCore ####initCore end
[junit4] 2> ASYNC NEW_CORE C21367 name=collection1 org.apache.solr.core.SolrCore@32af94b0
[junit4] 2> 2401064 T4045 C21367 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=1
[junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@7714200f lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@5a4c3855),segFN=segments_1,generation=1}
[junit4] 2> 2401064 T4045 C21367 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4] 2> 2401065 T4045 C21367 oasup.LogUpdateProcessor.finish [collection1] webapp=null path=null params={} {add=[0]} 0 2
[junit4] 2> 2401083 T4045 C21367 oasup.LogUpdateProcessor.finish [collection1] webapp=null path=null params={} {add=[1]} 0 0
[junit4] 2> 2401090 T4045 C21367 oasup.LogUpdateProcessor.finish [collection1] webapp=null path=null params={} {add=[2]} 0 1
[junit4] 2> 2401096 T4045 C21367 oasup.LogUpdateProcessor.finish [collection1] webapp=null path=null params={} {add=[3]} 0 1
[junit4] 2> 2401104 T4045 C21367 oasup.LogUpdateProcessor.finish [collection1] webapp=null path=null params={} {add=[4]} 0 3
[junit4] 2> 2401111 T4045 C21367 oasup.LogUpdateProcessor.finish [collection1] webapp=null path=null params={} {add=[5]} 0 1
[junit4] 2> 2401116 T4045 C21367 oasup.LogUpdateProcessor.finish [collection1] webapp=null path=null params={} {add=[6]} 0 0
[junit4] 2> 2401122 T4045 C21367 oasup.LogUpdateProcessor.finish [collection1] webapp=null path=null params={} {add=[7]} 0 0
[junit4] 2> 2401128 T4045 C21367 oasup.LogUpdateProcessor.finish [collection1] webapp=null path=null params={} {add=[8]} 0 0
[junit4] 2> 2401154 T4045 C21367 oasup.LogUpdateProcessor.finish [collection1] webapp=null path=null params={} {add=[9]} 0 20
[junit4] 2> 2401160 T4045 C21367 oasup.LogUpdateProcessor.finish [collection1] webapp=null path=null params={} {add=[10]} 0 1
[junit4] 2> 2401166 T4045 C21367 oasup.LogUpdateProcessor.finish [collection1] webapp=null path=null params={} {add=[11]} 0 1
[junit4] 2> 2401171 T4045 C21367 oasup.LogUpdateProcessor.finish [collection1] webapp=null path=null params={} {add=[12]} 0 0
[junit4] 2> 2401177 T4045 C21367 oasup.LogUpdateProcessor.finish [collection1] webapp=null path=null params={} {add=[13]} 0 0
[junit4] 2> 2401211 T4045 C21367 oasup.LogUpdateProcessor.finish [collection1] webapp=null path=null params={} {add=[14]} 0 28
[junit4] 2> 2401218 T4045 C21367 oasup.LogUpdateProcessor.finish [collection1] webapp=null path=null params={} {add=[15]} 0 1
[junit4] 2> 2401223 T4045 C21367 oasup.LogUpdateProcessor.finish [collection1] webapp=null path=null params={} {add=[16]} 0 0
[junit4] 2> 2401229 T4045 C21367 oasu.DirectUpdateHandler2.commit start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4] 2> 2401254 T4045 C21367 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=2
[junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@7714200f lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@5a4c3855),segFN=segments_1,generation=1}
[junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@7714200f lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@5a4c3855),segFN=segments_2,generation=2}
[junit4] 2> 2401254 T4045 C21367 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 2
[junit4] 2> 2401259 T4045 C21367 oass.SolrIndexSearcher.<init> Opening Searcher@60a8d965 main
[junit4] 2> 2401259 T4045 C21367 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4] 2> 2401259 T4047 oashc.SpellCheckComponent$SpellCheckerListener.buildSpellIndex Building spell index for spell checker: default
[junit4] 2> 2401346 T4047 oashc.SpellCheckComponent$SpellCheckerListener.buildSpellIndex Building spell index for spell checker: default_teststop
[junit4] 2> 2401408 T4047 oashc.SpellCheckComponent$SpellCheckerListener.buildSpellIndex Building spell index for spell checker: threshold
[junit4] 2> 2401421 T4047 oashc.SpellCheckComponent$SpellCheckerListener.buildSpellIndex Building spell index for spell checker: threshold_direct
[junit4] 2> 2401422 T4047 oashc.SpellCheckComponent$SpellCheckerListener.buildSpellIndex Building spell index for spell checker: multipleFields
[junit4] 2> 2401490 T4047 oashc.SpellCheckComponent$SpellCheckerListener.buildSpellIndex Building spell index for spell checker: freq
[junit4] 2> 2401560 T4047 oashc.SpellCheckComponent$SpellCheckerListener.buildSpellIndex Building spell index for spell checker: fqcn
[junit4] 2> 2401628 T4047 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@60a8d965 main{StandardDirectoryReader(segments_2:9:nrt _0(5.0):c5 _1(5.0):c5 _2(5.0):c5 _3(5.0):c2)}
[junit4] 2> ASYNC NEW_CORE C21368 name=collection1 org.apache.solr.core.SolrCore@32af94b0
[junit4] 2> 2401628 T4045 C21368 oasup.LogUpdateProcessor.finish [collection1] webapp=null path=null params={} {commit=} 0 399
[junit4] 2> 2401640 T4045 oas.SolrTestCaseJ4.setUp ###Starting testExtendedCollate
[junit4] 2> 2401733 T4045 oas.SolrTestCaseJ4.tearDown ###Ending testExtendedCollate
[junit4] 2> 2401739 T4045 oas.SolrTestCaseJ4.setUp ###Starting testCollateWithFilter
[junit4] 2> 2401825 T4045 oas.SolrTestCaseJ4.tearDown ###Ending testCollateWithFilter
[junit4] 2> 2401832 T4045 oas.SolrTestCaseJ4.setUp ###Starting testContextSensitiveCollate
[junit4] 2> 2401866 T4045 C21368 oasc.SolrCore.execute [collection1] webapp=null path=null params={spellcheck=true&indent=true&spellcheck.maxResultsForSuggest=0&spellcheck.collateExtendedResults=true&spellcheck.extendedResults=true&spellcheck.maxCollations=1&spellcheck.maxCollationTries=10&spellcheck.collate=true&q=teststop:(flew+AND+form+AND+heathrow)&spellcheck.dictionary=direct&spellcheck.count=10&qt=spellCheckCompRH&spellcheck.build=true&spellcheck.alternativeTermCount=5} hits=0 status=0 QTime=34
[junit4] 2> 2401899 T4045 C21368 oasc.SolrCore.execute [collection1] webapp=null path=null params={spellcheck=true&indent=true&spellcheck.maxResultsForSuggest=1&spellcheck.collateExtendedResults=true&spellcheck.extendedResults=true&spellcheck.maxCollationTries=10&spellcheck.maxCollations=1&spellcheck.collate=true&q=teststop:(june+AND+customs)&spellcheck.dictionary=direct&spellcheck.count=10&qt=spellCheckCompRH&spellcheck.alternativeTermCount=5} hits=1 status=0 QTime=19
[junit4] 2> 2401999 T4045 C21368 oasc.SolrCore.execute [collection1] webapp=null path=null params={spellcheck=true&indent=true&spellcheck.maxResultsForSuggest=0&spellcheck.collateExtendedResults=true&spellcheck.extendedResults=true&spellcheck.maxCollations=1&spellcheck.maxCollationTries=10&spellcheck.collate=true&q=teststop:(flew+AND+form+AND+heathrow)&spellcheck.dictionary=default_teststop&spellcheck.count=10&qt=spellCheckCompRH&spellcheck.build=true&spellcheck.alternativeTermCount=5} hits=0 status=0 QTime=90
[junit4] 2> 2402017 T4045 C21368 oasc.SolrCore.execute [collection1] webapp=null path=null params={spellcheck=true&indent=true&spellcheck.maxResultsForSuggest=1&spellcheck.collateExtendedResults=true&spellcheck.extendedResults=true&spellcheck.maxCollationTries=10&spellcheck.maxCollations=1&spellcheck.collate=true&q=teststop:(june+AND+customs)&spellcheck.dictionary=default_teststop&spellcheck.count=10&qt=spellCheckCompRH&spellcheck.alternativeTermCount=5} hits=1 status=0 QTime=5
[junit4] 2> 2402027 T4045 oas.SolrTestCaseJ4.tearDown ###Ending testContextSensitiveCollate
[junit4] 2> 2402035 T4045 oas.SolrTestCaseJ4.setUp ###Starting testCollateWithMultipleRequestHandlers
[junit4] 2> 2402108 T4045 oas.SolrTestCaseJ4.tearDown ###Ending testCollateWithMultipleRequestHandlers
[junit4] 2> 2402115 T4045 oas.SolrTestCaseJ4.setUp ###Starting testCollationWithHypens
[junit4] 2> 2402260 T4045 oas.SolrTestCaseJ4.tearDown ###Ending testCollationWithHypens
[junit4] 2> 2402267 T4045 oas.SolrTestCaseJ4.setUp ###Starting testCollateWithGrouping
[junit4] 2> 2402336 T4045 oas.SolrTestCaseJ4.tearDown ###Ending testCollateWithGrouping
[junit4] 2> 2402344 T4045 oas.SolrTestCaseJ4.setUp ###Starting testCollateWithOverride
[junit4] 2> 2402446 T4045 C21368 oasc.SolrCore.execute [collection1] webapp=null path=null params={mm=1&spellcheck=true&q=partisian+politcal+mashine&spellcheck.maxCollations=10&spellcheck.maxCollationTries=10&qf=teststop&spellcheck.dictionary=direct&spellcheck.count=10&qt=spellCheckCompRH&spellcheck.collate=true&defType=edismax} hits=0 status=0 QTime=102
[junit4] 2> 2402493 T4045 C21368 oasc.SolrCore.execute [collection1] webapp=null path=null params={mm=1&spellcheck=true&spellcheck.collateParam.mm=100%25&q=partisian+politcal+mashine&spellcheck.maxCollations=10&spellcheck.maxCollationTries=10&qf=teststop&spellcheck.dictionary=direct&spellcheck.count=10&qt=spellCheckCompRH&spellcheck.collate=true&defType=edismax} hits=0 status=0 QTime=40
[junit4] 2> 2402496 T4045 oas.SolrTestCaseJ4.tearDown ###Ending testCollateWithOverride
[junit4] 2> 2402502 T4045 oas.SolrTestCaseJ4.setUp ###Starting testEstimatedHitCounts
[junit4] 2> 2402512 T4045 C21368 oasc.SolrCore.execute [collection1] webapp=null path=null params={spellcheck=true&spellcheck.collateExtendedResults=true&q=teststop:metnoia&spellcheck.maxCollations=1&spellcheck.maxCollationTries=1&spellcheck.dictionary=direct&spellcheck.count=1&qt=spellCheckCompRH&spellcheck.collate=true} hits=0 status=0 QTime=10
[junit4] 2> 2402526 T4045 C21368 oasc.SolrCore.execute [collection1] webapp=null path=null params={spellcheck=true&spellcheck.collateExtendedResults=true&q=teststop:metnoia&spellcheck.maxCollations=1&spellcheck.maxCollationTries=1&spellcheck.dictionary=direct&spellcheck.collateMaxCollectDocs=1&spellcheck.count=1&qt=spellCheckCompRH&spellcheck.collate=true} hits=0 status=0 QTime=11
[junit4] 2> 2402538 T4045 C21368 oasc.SolrCore.execute [collection1] webapp=null path=null params={spellcheck=true&spellcheck.collateExtendedResults=true&q=teststop:metnoia&spellcheck.maxCollations=1&spellcheck.maxCollationTries=1&spellcheck.dictionary=direct&spellcheck.collateMaxCollectDocs=3&spellcheck.count=1&qt=spellCheckCompRH&spellcheck.collate=true} hits=0 status=0 QTime=8
[junit4] 2> 2402542 T4045 oas.SolrTestCaseJ4.assertQ ERROR REQUEST FAILED: xpath=//lst[@name='spellcheck']/lst[@name='suggestions']/lst[@name='collation']/int[@name='hits']=4
[junit4] 2> xml response was: <?xml version="1.0" encoding="UTF-8"?>
[junit4] 2> <response>
[junit4] 2> <lst name="responseHeader"><int name="status">0</int><int name="QTime">8</int></lst><result name="response" numFound="0" start="0"></result><lst name="spellcheck"><lst name="suggestions"><lst name="metnoia"><int name="numFound">1</int><int name="startOffset">9</int><int name="endOffset">16</int><arr name="suggestion"><str>metanoia</str></arr></lst><lst name="collation"><str name="collationQuery">teststop:metanoia</str><int name="hits">17</int><lst name="misspellingsAndCorrections"><str name="metnoia">metanoia</str></lst></lst></lst></lst>
[junit4] 2> </response>
[junit4] 2>
[junit4] 2> request was:spellcheck=true&spellcheck.collateExtendedResults=true&q=teststop:metnoia&spellcheck.maxCollations=1&spellcheck.maxCollationTries=1&spellcheck.dictionary=direct&spellcheck.collateMaxCollectDocs=3&spellcheck.count=1&qt=spellCheckCompRH&spellcheck.collate=true
[junit4] 2> 2402544 T4045 oasc.SolrException.log ERROR REQUEST FAILED: spellcheck=true&spellcheck.collateExtendedResults=true&q=teststop:metnoia&spellcheck.maxCollations=1&spellcheck.maxCollationTries=1&spellcheck.dictionary=direct&spellcheck.collateMaxCollectDocs=3&spellcheck.count=1&qt=spellCheckCompRH&spellcheck.collate=true:java.lang.RuntimeException: REQUEST FAILED: xpath=//lst[@name='spellcheck']/lst[@name='suggestions']/lst[@name='collation']/int[@name='hits']=4
[junit4] 2> xml response was: <?xml version="1.0" encoding="UTF-8"?>
[junit4] 2> <response>
[junit4] 2> <lst name="responseHeader"><int name="status">0</int><int name="QTime">8</int></lst><result name="response" numFound="0" start="0"></result><lst name="spellcheck"><lst name="suggestions"><lst name="metnoia"><int name="numFound">1</int><int name="startOffset">9</int><int name="endOffset">16</int><arr name="suggestion"><str>metanoia</str></arr></lst><lst name="collation"><str name="collationQuery">teststop:metanoia</str><int name="hits">17</int><lst name="misspellingsAndCorrections"><str name="metnoia">metanoia</str></lst></lst></lst></lst>
[junit4] 2> </response>
[junit4] 2>
[junit4] 2> request was:spellcheck=true&spellcheck.collateExtendedResults=true&q=teststop:metnoia&spellcheck.maxCollations=1&spellcheck.maxCollationTries=1&spellcheck.dictionary=direct&spellcheck.collateMaxCollectDocs=3&spellcheck.count=1&qt=spellCheckCompRH&spellcheck.collate=true
[junit4] 2> at org.apache.solr.SolrTestCaseJ4.assertQ(SolrTestCaseJ4.java:628)
[junit4] 2> at org.apache.solr.SolrTestCaseJ4.assertQ(SolrTestCaseJ4.java:602)
[junit4] 2> at org.apache.solr.spelling.SpellCheckCollatorTest.testEstimatedHitCounts(SpellCheckCollatorTest.java:469)
[junit4] 2> at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
[junit4] 2> at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:57)
[junit4] 2> at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
[junit4] 2> at java.lang.reflect.Method.invoke(Method.java:606)
[junit4] 2> at com.carrotsearch.randomizedtesting.RandomizedRunner.invoke(RandomizedRunner.java:1559)
[junit4] 2> at com.carrotsearch.randomizedtesting.RandomizedRunner.access$600(RandomizedRunner.java:79)
[junit4] 2> at com.carrotsearch.randomizedtesting.RandomizedRunner$6.evaluate(RandomizedRunner.java:737)
[junit4] 2> at com.carrotsearch.randomizedtesting.RandomizedRunner$7.evaluate(RandomizedRunner.java:773)
[junit4] 2> at com.carrotsearch.randomizedtesting.RandomizedRunner$8.evaluate(RandomizedRunner.java:787)
[junit4] 2> at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:53)
[junit4] 2> at org.apache.lucene.util.TestRuleSetupTeardownChained$1.evaluate(TestRuleSetupTeardownChained.java:50)
[junit4] 2> at org.apache.lucene.util.TestRuleFieldCacheSanity$1.evaluate(TestRuleFieldCacheSanity.java:51)
[junit4] 2> at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:46)
[junit4] 2> at com.carrotsearch.randomizedtesting.rules.SystemPropertiesInvariantRule$1.evaluate(SystemPropertiesInvariantRule.java:55)
[junit4] 2> at org.apache.lucene.util.TestRuleThreadAndTestName$1.evaluate(TestRuleThreadAndTestName.java:49)
[junit4] 2> at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:70)
[junit4] 2> at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:48)
[junit4] 2> at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
[junit4] 2> at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:358)
[junit4] 2> at com.carrotsearch.randomizedtesting.ThreadLeakControl.forkTimeoutingTask(ThreadLeakControl.java:782)
[junit4] 2> at com.carrotsearch.randomizedtesting.ThreadLeakControl$3.evaluate(ThreadLeakControl.java:442)
[junit4] 2> at com.carrotsearch.randomizedtesting.RandomizedRunner.runSingleTest(RandomizedRunner.java:746)
[junit4] 2> at com.carrotsearch.randomizedtesting.RandomizedRunner$3.evaluate(RandomizedRunner.java:648)
[junit4] 2> at com.carrotsearch.randomizedtesting.RandomizedRunner$4.evaluate(RandomizedRunner.java:682)
[junit4] 2> at com.carrotsearch.randomizedtesting.RandomizedRunner$5.evaluate(RandomizedRunner.java:693)
[junit4] 2> at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
[junit4] 2> at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:53)
[junit4] 2> at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:46)
[junit4] 2> at org.apache.lucene.util.TestRuleStoreClassName$1.evaluate(TestRuleStoreClassName.java:42)
[junit4] 2> at com.carrotsearch.randomizedtesting.rules.SystemPropertiesInvariantRule$1.evaluate(SystemPropertiesInvariantRule.java:55)
[junit4] 2> at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:39)
[junit4] 2> at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:39)
[junit4] 2> at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
[junit4] 2> at org.apache.lucene.util.TestRuleAssertionsRequired$1.evaluate(TestRuleAssertionsRequired.java:43)
[junit4] 2> at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:48)
[junit4] 2> at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:70)
[junit4] 2> at org.apache.lucene.util.TestRuleIgnoreTestSuites$1.evaluate(TestRuleIgnoreTestSuites.java:55)
[junit4] 2> at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
[junit4] 2> at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:358)
[junit4] 2> at java.lang.Thread.run(Thread.java:724)
[junit4] 2>
[junit4] 2> 2402546 T4045 oas.SolrTestCaseJ4.tearDown ###Ending testEstimatedHitCounts
[junit4] 2> NOTE: download the large Jenkins line-docs file by running 'ant get-jenkins-line-docs' in the lucene directory.
[junit4] 2> NOTE: reproduce with: ant test -Dtestcase=SpellCheckCollatorTest -Dtests.method=testEstimatedHitCounts -Dtests.seed=16B4D8F74E59EE10 -Dtests.multiplier=2 -Dtests.nightly=true -Dtests.slow=true -Dtests.linedocsfile=/home/hudson/lucene-data/enwiki.random.lines.txt -Dtests.locale=nl -Dtests.timezone=America/Dawson -Dtests.file.encoding=US-ASCII
[junit4] ERROR 0.06s J1 | SpellCheckCollatorTest.testEstimatedHitCounts <<<
[junit4] > Throwable #1: java.lang.RuntimeException: Exception during query
[junit4] > at __randomizedtesting.SeedInfo.seed([16B4D8F74E59EE10:270F66C2EB66FEC0]:0)
[junit4] > at org.apache.solr.SolrTestCaseJ4.assertQ(SolrTestCaseJ4.java:635)
[junit4] > at org.apache.solr.SolrTestCaseJ4.assertQ(SolrTestCaseJ4.java:602)
[junit4] > at org.apache.solr.spelling.SpellCheckCollatorTest.testEstimatedHitCounts(SpellCheckCollatorTest.java:469)
[junit4] > at java.lang.Thread.run(Thread.java:724)
[junit4] > Caused by: java.lang.RuntimeException: REQUEST FAILED: xpath=//lst[@name='spellcheck']/lst[@name='suggestions']/lst[@name='collation']/int[@name='hits']=4
[junit4] > xml response was: <?xml version="1.0" encoding="UTF-8"?>
[junit4] > <response>
[junit4] > <lst name="responseHeader"><int name="status">0</int><int name="QTime">8</int></lst><result name="response" numFound="0" start="0"></result><lst name="spellcheck"><lst name="suggestions"><lst name="metnoia"><int name="numFound">1</int><int name="startOffset">9</int><int name="endOffset">16</int><arr name="suggestion"><str>metanoia</str></arr></lst><lst name="collation"><str name="collationQuery">teststop:metanoia</str><int name="hits">17</int><lst name="misspellingsAndCorrections"><str name="metnoia">metanoia</str></lst></lst></lst></lst>
[junit4] > </response>
[junit4] > request was:spellcheck=true&spellcheck.collateExtendedResults=true&q=teststop:metnoia&spellcheck.maxCollations=1&spellcheck.maxCollationTries=1&spellcheck.dictionary=direct&spellcheck.collateMaxCollectDocs=3&spellcheck.count=1&qt=spellCheckCompRH&spellcheck.collate=true
[junit4] > at org.apache.solr.SolrTestCaseJ4.assertQ(SolrTestCaseJ4.java:628)
[junit4] > ... 42 more
[junit4] 2> 2402558 T4045 oas.SolrTestCaseJ4.deleteCore ###deleteCore
[junit4] 2> 2402559 T4045 oasc.CoreContainer.shutdown Shutting down CoreContainer instance=1414615201
[junit4] 2> 2402559 T4045 oasc.SolrCore.close [collection1] CLOSING SolrCore org.apache.solr.core.SolrCore@32af94b0
[junit4] 2> 2402559 T4045 oasu.DirectUpdateHandler2.close closing DirectUpdateHandler2{commits=1,autocommits=0,soft autocommits=0,optimizes=0,rollbacks=0,expungeDeletes=0,docsPending=0,adds=0,deletesById=0,deletesByQuery=0,errors=0,cumulative_adds=17,cumulative_deletesById=0,cumulative_deletesByQuery=0,cumulative_errors=0}
[junit4] 2> 2402560 T4045 oasu.SolrCoreState.decrefSolrCoreState Closing SolrCoreState
[junit4] 2> 2402560 T4045 oasu.DefaultSolrCoreState.closeIndexWriter SolrCoreState ref count has reached 0 - closing IndexWriter
[junit4] 2> 2402560 T4045 oasu.DefaultSolrCoreState.closeIndexWriter closing IndexWriter with IndexWriterCloser
[junit4] 2> 2402561 T4045 oasc.SolrCore.closeSearcher [collection1] Closing main searcher on request.
[junit4] 2> 2402561 T4045 oasc.CachingDirectoryFactory.close Closing MockDirectoryFactory - 2 directories currently being tracked
[junit4] 2> 2402562 T4045 oasc.CachingDirectoryFactory.closeCacheValue looking to close /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test/J1/./solrtest-SpellCheckCollatorTest-1375883796067/index [CachedDir<<refCount=0;path=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test/J1/./solrtest-SpellCheckCollatorTest-1375883796067/index;done=false>>]
[junit4] 2> 2402562 T4045 oasc.CachingDirectoryFactory.close Closing directory: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test/J1/./solrtest-SpellCheckCollatorTest-1375883796067/index
[junit4] 2> 2402562 T4045 oasc.CachingDirectoryFactory.closeCacheValue looking to close /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test/J1/./solrtest-SpellCheckCollatorTest-1375883796067 [CachedDir<<refCount=0;path=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test/J1/./solrtest-SpellCheckCollatorTest-1375883796067;done=false>>]
[junit4] 2> 2402563 T4045 oasc.CachingDirectoryFactory.close Closing directory: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test/J1/./solrtest-SpellCheckCollatorTest-1375883796067
[junit4] 2> NOTE: test params are: codec=Lucene42: {range_facet_l=MockVariableIntBlock(baseBlockSize=72), lowerfilt1=Pulsing41(freqCutoff=12 minBlockSize=73 maxBlockSize=149), lowerfilt=PostingsFormat(name=Lucene41VarGapFixedInterval), teststop=PostingsFormat(name=Lucene41VarGapFixedInterval), end4=Pulsing41(freqCutoff=12 minBlockSize=73 maxBlockSize=149), end3=PostingsFormat(name=Lucene41VarGapFixedInterval), lowerfilt1and2=PostingsFormat(name=Lucene41VarGapFixedInterval), start1=Pulsing41(freqCutoff=12 minBlockSize=73 maxBlockSize=149), end2=PostingsFormat(name=Lucene41WithOrds), end1=MockVariableIntBlock(baseBlockSize=72), intDefault=MockVariableIntBlock(baseBlockSize=72), id=PostingsFormat(name=Lucene41WithOrds), timestamp=MockVariableIntBlock(baseBlockSize=72), range_facet_sl=Pulsing41(freqCutoff=12 minBlockSize=73 maxBlockSize=149), range_facet_si=PostingsFormat(name=Lucene41VarGapFixedInterval), start4=MockVariableIntBlock(baseBlockSize=72), start2=PostingsFormat(name=Lucene41VarGapFixedInterval), start3=PostingsFormat(name=Lucene41WithOrds), word=MockVariableIntBlock(baseBlockSize=72), gram2=PostingsFormat(name=Lucene41WithOrds), gram1=MockVariableIntBlock(baseBlockSize=72), multiDefault=PostingsFormat(name=Lucene41VarGapFixedInterval), gram4=Pulsing41(freqCutoff=12 minBlockSize=73 maxBlockSize=149), gram3=PostingsFormat(name=Lucene41VarGapFixedInterval)}, docValues:{timestamp=DocValuesFormat(name=Asserting)}, sim=RandomSimilarityProvider(queryNorm=false,coord=yes): {}, locale=nl, timezone=America/Dawson
[junit4] 2> NOTE: FreeBSD 9.1-RELEASE-p3 amd64/Oracle Corporation 1.7.0_25 (64-bit)/cpus=16,threads=1,free=281063024,total=534052864
[junit4] 2> NOTE: All tests run in this JVM: [IndexBasedSpellCheckerTest, CoreAdminCreateDiscoverTest, CoreContainerCoreInitFailuresTest, TestQueryTypes, ResourceLoaderTest, TestReload, UUIDFieldTest, TestCopyFieldCollectionResource, TestCSVLoader, SuggesterTSTTest, TestBinaryField, TestPhraseSuggestions, SuggesterWFSTTest, ConvertedLegacyTest, TestSweetSpotSimilarityFactory, HdfsUnloadDistributedZkTest, HighlighterTest, ChaosMonkeySafeLeaderTest, CurrencyFieldXmlFileTest, SimplePostToolTest, DistanceFunctionTest, TestFiltering, TestDFRSimilarityFactory, JSONWriterTest, BasicZkTest, TestUtils, HdfsBasicDistributedZk2Test, TestOmitPositions, TestCloudManagedSchema, SliceStateTest, PrimUtilsTest, OpenCloseCoreStressTest, PathHierarchyTokenizerFactoryTest, TestDefaultSimilarityFactory, AlternateDirectoryTest, DebugComponentTest, SolrRequestParserTest, LeaderElectionIntegrationTest, HighlighterConfigTest, TestFastWriter, PreAnalyzedFieldTest, TestRecoveryHdfs, HdfsCollectionsAPIDistributedZkTest, TestCoreDiscovery, BadIndexSchemaTest, TestCodecSupport, TestIndexSearcher, TestSolrDeletionPolicy2, TestJmxIntegration, TestZkChroot, DirectUpdateHandlerTest, FullSolrCloudDistribCmdsTest, StatsComponentTest, XsltUpdateRequestHandlerTest, CircularListTest, RequestHandlersTest, HardAutoCommitTest, TestMultiCoreConfBootstrap, TestUpdate, UniqFieldsUpdateProcessorFactoryTest, HdfsRecoveryZkTest, NoCacheHeaderTest, ShardSplitTest, TestRandomMergePolicy, BasicDistributedZk2Test, TestStressReorder, TestFuzzyAnalyzedSuggestions, TestAtomicUpdateErrorCases, DirectSolrSpellCheckerTest, TestSolr4Spatial, TestClassNameShortening, SolrCmdDistributorTest, DisMaxRequestHandlerTest, DefaultValueUpdateProcessorTest, ClusterStateTest, TestRandomFaceting, AutoCommitTest, TestDistributedGrouping, TestFaceting, TestRecovery, TestHashPartitioner, TermVectorComponentDistributedTest, TestJoin, SpellCheckComponentTest, PeerSyncTest, TestLazyCores, SoftAutoCommitTest, CurrencyFieldOpenExchangeTest, SpellCheckCollatorTest]
[junit4] Completed on J1 in 2.93s, 8 tests, 1 error <<< FAILURES!
[...truncated 386 lines...]
BUILD FAILED
/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-trunk/build.xml:396: The following error occurred while executing this line:
/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-trunk/build.xml:369: The following error occurred while executing this line:
/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-trunk/build.xml:39: The following error occurred while executing this line:
/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build.xml:181: The following error occurred while executing this line:
/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/common-build.xml:449: The following error occurred while executing this line:
/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-trunk/lucene/common-build.xml:1230: The following error occurred while executing this line:
/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-trunk/lucene/common-build.xml:873: There were test failures: 317 suites, 1343 tests, 1 error, 32 ignored (4 assumptions)
Total time: 102 minutes 23 seconds
Build step 'Invoke Ant' marked build as failure
Archiving artifacts
Recording test results
Email was triggered for: Failure
Sending email for trigger: Failure