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 2014/11/23 02:32:40 UTC
[JENKINS] Lucene-Solr-Tests-5.x-Java7 - Build # 2225 - Failure
Build: https://builds.apache.org/job/Lucene-Solr-Tests-5.x-Java7/2225/
1 tests failed.
REGRESSION: org.apache.solr.update.SoftAutoCommitTest.testSoftAndHardCommitMaxTimeMixedAdds
Error Message:
soft529 wasn't fast enough
Stack Trace:
java.lang.AssertionError: soft529 wasn't fast enough
at __randomizedtesting.SeedInfo.seed([391FB952BB027BFD:68CB40D20A714B5A]:0)
at org.junit.Assert.fail(Assert.java:93)
at org.junit.Assert.assertTrue(Assert.java:43)
at org.junit.Assert.assertNotNull(Assert.java:526)
at org.apache.solr.update.SoftAutoCommitTest.testSoftAndHardCommitMaxTimeMixedAdds(SoftAutoCommitTest.java:111)
at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:57)
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
at java.lang.reflect.Method.invoke(Method.java:606)
at com.carrotsearch.randomizedtesting.RandomizedRunner.invoke(RandomizedRunner.java:1618)
at com.carrotsearch.randomizedtesting.RandomizedRunner$6.evaluate(RandomizedRunner.java:827)
at com.carrotsearch.randomizedtesting.RandomizedRunner$7.evaluate(RandomizedRunner.java:863)
at com.carrotsearch.randomizedtesting.RandomizedRunner$8.evaluate(RandomizedRunner.java:877)
at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:53)
at org.apache.lucene.util.TestRuleSetupTeardownChained$1.evaluate(TestRuleSetupTeardownChained.java:50)
at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:46)
at com.carrotsearch.randomizedtesting.rules.SystemPropertiesInvariantRule$1.evaluate(SystemPropertiesInvariantRule.java:55)
at org.apache.lucene.util.TestRuleThreadAndTestName$1.evaluate(TestRuleThreadAndTestName.java:49)
at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:65)
at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:48)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:365)
at com.carrotsearch.randomizedtesting.ThreadLeakControl.forkTimeoutingTask(ThreadLeakControl.java:798)
at com.carrotsearch.randomizedtesting.ThreadLeakControl$3.evaluate(ThreadLeakControl.java:458)
at com.carrotsearch.randomizedtesting.RandomizedRunner.runSingleTest(RandomizedRunner.java:836)
at com.carrotsearch.randomizedtesting.RandomizedRunner$3.evaluate(RandomizedRunner.java:738)
at com.carrotsearch.randomizedtesting.RandomizedRunner$4.evaluate(RandomizedRunner.java:772)
at com.carrotsearch.randomizedtesting.RandomizedRunner$5.evaluate(RandomizedRunner.java:783)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:53)
at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:46)
at org.apache.lucene.util.TestRuleStoreClassName$1.evaluate(TestRuleStoreClassName.java:42)
at com.carrotsearch.randomizedtesting.rules.SystemPropertiesInvariantRule$1.evaluate(SystemPropertiesInvariantRule.java:55)
at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:39)
at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:39)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at org.apache.lucene.util.TestRuleAssertionsRequired$1.evaluate(TestRuleAssertionsRequired.java:54)
at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:48)
at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:65)
at org.apache.lucene.util.TestRuleIgnoreTestSuites$1.evaluate(TestRuleIgnoreTestSuites.java:55)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:365)
at java.lang.Thread.run(Thread.java:745)
Build Log:
[...truncated 10831 lines...]
[junit4] Suite: org.apache.solr.update.SoftAutoCommitTest
[junit4] 2> Creating dataDir: /usr/home/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-5.x-Java7/solr/build/solr-core/test/J2/temp/solr.update.SoftAutoCommitTest-391FB952BB027BFD-001/init-core-data-001
[junit4] 2> 21645 T18 oas.SolrTestCaseJ4.buildSSLConfig Randomized ssl (false) and clientAuth (false)
[junit4] 2> 21648 T18 oas.SolrTestCaseJ4.initCore ####initCore
[junit4] 2> 21649 T18 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/usr/home/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-5.x-Java7/solr/core/src/test-files/solr/collection1/'
[junit4] 2> 21651 T18 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-5.x-Java7/solr/core/src/test-files/solr/collection1/lib/classes/' to classloader
[junit4] 2> 21652 T18 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-5.x-Java7/solr/core/src/test-files/solr/collection1/lib/README' to classloader
[junit4] 2> 21653 T18 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-5.x-Java7/solr/core/src/test-files/solr/collection1/lib/.svn/' to classloader
[junit4] 2> 21946 T18 oasc.SolrConfig.<init> Using Lucene MatchVersion: 5.0.0
[junit4] 2> 22065 T18 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4] 2> 22067 T18 oass.IndexSchema.readSchema Reading Solr Schema from /usr/home/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-5.x-Java7/solr/core/src/test-files/solr/collection1/conf/schema.xml
[junit4] 2> 22146 T18 oass.IndexSchema.readSchema [null] Schema name=test
[junit4] 2> 24403 T18 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4] 2> 24429 T18 oass.IndexSchema.readSchema default search field in schema is text
[junit4] 2> 24432 T18 oass.IndexSchema.readSchema unique key field: id
[junit4] 2> 25793 T18 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4] 2> 25835 T18 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4] 2> 25840 T18 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4] 2> 25871 T18 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4] 2> 25871 T18 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4] 2> 25872 T18 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4] 2> 25873 T18 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4] 2> 25873 T18 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4] 2> 25874 T18 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4] 2> 25875 T18 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: /usr/home/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-5.x-Java7/solr/core/src/test-files/solr
[junit4] 2> 25875 T18 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/usr/home/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-5.x-Java7/solr/core/src/test-files/solr/'
[junit4] 2> 26023 T18 oasc.CoreContainer.<init> New CoreContainer 716910764
[junit4] 2> 26023 T18 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=/usr/home/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-5.x-Java7/solr/core/src/test-files/solr/]
[junit4] 2> 26025 T18 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 0
[junit4] 2> 26025 T18 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: null
[junit4] 2> 26026 T18 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 0
[junit4] 2> 26026 T18 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4] 2> 26027 T18 oashc.HttpShardHandlerFactory.getParameter Setting maxConnections to: 10000
[junit4] 2> 26027 T18 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4] 2> 26028 T18 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4] 2> 26028 T18 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4] 2> 26029 T18 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4] 2> 26029 T18 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4] 2> 26030 T18 oasu.UpdateShardHandler.<init> Creating UpdateShardHandler HTTP client with params: socketTimeout=30000&connTimeout=30000&retry=false
[junit4] 2> 26031 T18 oasl.LogWatcher.createWatcher SLF4J impl is org.slf4j.impl.Log4jLoggerFactory
[junit4] 2> 26031 T18 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
[junit4] 2> 26032 T18 oasc.CoreContainer.load Host Name:
[junit4] 2> 26037 T19 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/usr/home/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-5.x-Java7/solr/core/src/test-files/solr/collection1/'
[junit4] 2> 26039 T19 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-5.x-Java7/solr/core/src/test-files/solr/collection1/lib/classes/' to classloader
[junit4] 2> 26040 T19 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-5.x-Java7/solr/core/src/test-files/solr/collection1/lib/README' to classloader
[junit4] 2> 26041 T19 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-5.x-Java7/solr/core/src/test-files/solr/collection1/lib/.svn/' to classloader
[junit4] 2> 26144 T19 oasc.SolrConfig.<init> Using Lucene MatchVersion: 5.0.0
[junit4] 2> 26216 T19 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4] 2> 26218 T19 oass.IndexSchema.readSchema Reading Solr Schema from /usr/home/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-5.x-Java7/solr/core/src/test-files/solr/collection1/conf/schema.xml
[junit4] 2> 26279 T19 oass.IndexSchema.readSchema [collection1] Schema name=test
[junit4] 2> 26697 T19 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4] 2> 26717 T19 oass.IndexSchema.readSchema default search field in schema is text
[junit4] 2> 26720 T19 oass.IndexSchema.readSchema unique key field: id
[junit4] 2> 26746 T19 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4] 2> 26752 T19 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4] 2> 26757 T19 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4] 2> 26757 T19 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4] 2> 26758 T19 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4] 2> 26758 T19 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4] 2> 26759 T19 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4] 2> 26760 T19 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4] 2> 26760 T19 oasc.CoreContainer.create Creating SolrCore 'collection1' using configuration from instancedir /usr/home/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-5.x-Java7/solr/core/src/test-files/solr/collection1/
[junit4] 2> 26761 T19 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4] 2> 26761 T19 oasc.SolrCore.<init> [collection1] Opening new SolrCore at /usr/home/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-5.x-Java7/solr/core/src/test-files/solr/collection1/, dataDir=/usr/home/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-5.x-Java7/solr/build/solr-core/test/J2/temp/solr.update.SoftAutoCommitTest-391FB952BB027BFD-001/init-core-data-001/
[junit4] 2> 26769 T19 oasc.JmxMonitoredMap.<init> No JMX servers found, not exposing Solr information with JMX.
[junit4] 2> 26794 T19 oasc.CachingDirectoryFactory.get return new directory for /usr/home/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-5.x-Java7/solr/build/solr-core/test/J2/temp/solr.update.SoftAutoCommitTest-391FB952BB027BFD-001/init-core-data-001
[junit4] 2> 26795 T19 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=/usr/home/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-5.x-Java7/solr/build/solr-core/test/J2/temp/solr.update.SoftAutoCommitTest-391FB952BB027BFD-001/init-core-data-001/index/
[junit4] 2> 26795 T19 oasc.SolrCore.initIndex WARN [collection1] Solr index directory '/usr/home/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-5.x-Java7/solr/build/solr-core/test/J2/temp/solr.update.SoftAutoCommitTest-391FB952BB027BFD-001/init-core-data-001/index' doesn't exist. Creating new index...
[junit4] 2> 26795 T19 oasc.CachingDirectoryFactory.get return new directory for /usr/home/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-5.x-Java7/solr/build/solr-core/test/J2/temp/solr.update.SoftAutoCommitTest-391FB952BB027BFD-001/init-core-data-001/index
[junit4] 2> 26796 T19 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.LogDocMergePolicy: [LogDocMergePolicy: minMergeSize=1000, mergeFactor=47, maxMergeSize=9223372036854775807, maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=false, maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.0]
[junit4] 2> 26798 T19 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
[junit4] 2> commit{dir=RateLimitedDirectoryWrapper(MockDirectoryWrapper(RAMDirectory@899c9fd lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@289c0574)),segFN=segments_1,generation=1}
[junit4] 2> 26798 T19 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4] 2> 26894 T19 oasc.SolrCore.initWriters created xml: solr.XMLResponseWriter
[junit4] 2> 27184 T19 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "dedupe"
[junit4] 2> 27328 T19 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4] 2> 27329 T19 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "dedupe-allfields"
[junit4] 2> 27330 T19 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe-allfields"
[junit4] 2> 27330 T19 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "stored_sig"
[junit4] 2> 27330 T19 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4] 2> 27331 T19 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "uniq-fields"
[junit4] 2> 27381 T19 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "uniq-fields"
[junit4] 2> 27381 T19 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-explicit"
[junit4] 2> 27716 T19 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4] 2> 27717 T19 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4] 2> 27718 T19 oasc.SolrCore.loadUpdateProcessorChains no updateRequestProcessorChain defined as default, creating implicit default
[junit4] 2> 27719 T19 oasc.RequestHandlers.initHandlersFromConfig created /update/json/docs: org.apache.solr.handler.UpdateRequestHandler
[junit4] 2> 27719 T19 oasc.RequestHandlers.initHandlersFromConfig created /update/json: org.apache.solr.handler.UpdateRequestHandler
[junit4] 2> 27720 T19 oasc.RequestHandlers.initHandlersFromConfig created /update/csv: org.apache.solr.handler.UpdateRequestHandler
[junit4] 2> 27721 T19 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4] 2> 27721 T19 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4] 2> 27793 T19 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4] 2> 27794 T19 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4] 2> 27795 T19 oasc.RequestHandlers.initHandlersFromConfig created dismax: solr.SearchHandler
[junit4] 2> 27797 T19 oasc.RequestHandlers.initHandlersFromConfig created mock: org.apache.solr.core.MockQuerySenderListenerReqHandler
[junit4] 2> 27798 T19 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4] 2> 27877 T19 oasc.RequestHandlers.initHandlersFromConfig created /admin/file: solr.admin.ShowFileRequestHandler
[junit4] 2> 27978 T19 oasc.RequestHandlers.initHandlersFromConfig created /admin/fileedit: solr.admin.EditFileRequestHandler
[junit4] 2> 27979 T19 oasc.RequestHandlers.initHandlersFromConfig created defaults: solr.StandardRequestHandler
[junit4] 2> 27980 T19 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.StandardRequestHandler
[junit4] 2> 27980 T19 oasc.RequestHandlers.initHandlersFromConfig created lazy: solr.StandardRequestHandler
[junit4] 2> 27981 T19 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4] 2> 27982 T19 oasc.RequestHandlers.initHandlersFromConfig created /terms: org.apache.solr.handler.component.SearchHandler
[junit4] 2> 27982 T19 oasc.RequestHandlers.initHandlersFromConfig created spellCheckCompRH: org.apache.solr.handler.component.SearchHandler
[junit4] 2> 27983 T19 oasc.RequestHandlers.initHandlersFromConfig created spellCheckCompRH_Direct: org.apache.solr.handler.component.SearchHandler
[junit4] 2> 27984 T19 oasc.RequestHandlers.initHandlersFromConfig created spellCheckWithWordbreak: org.apache.solr.handler.component.SearchHandler
[junit4] 2> 27984 T19 oasc.RequestHandlers.initHandlersFromConfig created spellCheckWithWordbreak_Direct: org.apache.solr.handler.component.SearchHandler
[junit4] 2> 27985 T19 oasc.RequestHandlers.initHandlersFromConfig created spellCheckCompRH1: org.apache.solr.handler.component.SearchHandler
[junit4] 2> 27986 T19 oasc.RequestHandlers.initHandlersFromConfig created mltrh: org.apache.solr.handler.component.SearchHandler
[junit4] 2> 27986 T19 oasc.RequestHandlers.initHandlersFromConfig created tvrh: org.apache.solr.handler.component.SearchHandler
[junit4] 2> 28048 T19 oasc.RequestHandlers.initHandlersFromConfig created /mlt: solr.MoreLikeThisHandler
[junit4] 2> 28105 T19 oasc.RequestHandlers.initHandlersFromConfig created /debug/dump: solr.DumpRequestHandler
[junit4] 2> 28133 T19 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4] 2> 28136 T19 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4] 2> 28138 T19 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4] 2> 28140 T19 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4] 2> 28149 T19 oasc.SolrCore.initDeprecatedSupport WARN solrconfig.xml uses deprecated <admin/gettableFiles>, Please update your config to use the ShowFileRequestHandler.
[junit4] 2> 28153 T19 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4] 2> 28153 T19 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4] 2> 28154 T19 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: maxMergeAtOnce=20, maxMergeAtOnceExplicit=49, maxMergedSegmentMB=55.517578125, floorSegmentMB=1.1640625, forceMergeDeletesPctAllowed=8.847220166709654, segmentsPerTier=41.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.10074572997716569
[junit4] 2> 28155 T19 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=1
[junit4] 2> commit{dir=RateLimitedDirectoryWrapper(MockDirectoryWrapper(RAMDirectory@899c9fd lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@289c0574)),segFN=segments_1,generation=1}
[junit4] 2> 28155 T19 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4] 2> 28156 T19 oass.SolrIndexSearcher.<init> Opening Searcher@5aaf2690[collection1] main
[junit4] 2> 28157 T19 oasr.RestManager.init Initializing RestManager with initArgs: {storageIO=org.apache.solr.rest.ManagedResourceStorage$InMemoryStorageIO}
[junit4] 2> 28157 T19 oasr.ManagedResourceStorage.load Reading _rest_managed.json using InMemoryStorage
[junit4] 2> 28158 T19 oasr.ManagedResource.reloadFromStorage WARN No stored data found for /rest/managed
[junit4] 2> 28158 T19 oasr.ManagedResourceStorage$JsonStorage.store Saved JSON object to path _rest_managed.json using InMemoryStorage
[junit4] 2> 28159 T19 oasr.RestManager.init Initializing 0 registered ManagedResources
[junit4] 2> 28159 T19 oashc.SpellCheckComponent.inform Initializing spell checkers
[junit4] 2> 28597 T19 oass.DirectSolrSpellChecker.init init: {name=direct,classname=DirectSolrSpellChecker,field=lowerfilt,minQueryLength=3}
[junit4] 2> 29064 T20 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@5aaf2690[collection1] main{ExitableDirectoryReader(UninvertingDirectoryReader())}
[junit4] 2> 29065 T19 oasc.CoreContainer.registerCore registering core: collection1
[junit4] 2> 29092 T18 oas.SolrTestCaseJ4.initCore ####initCore end
[junit4] 2> 29101 T18 oas.SolrTestCaseJ4.setUp ###Starting testSoftAndHardCommitMaxTimeMixedAdds
[junit4] 2> 29102 T18 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/usr/home/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-5.x-Java7/solr/core/src/test-files/solr/collection1/'
[junit4] 2> 29104 T18 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-5.x-Java7/solr/core/src/test-files/solr/collection1/lib/classes/' to classloader
[junit4] 2> 29105 T18 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-5.x-Java7/solr/core/src/test-files/solr/collection1/lib/README' to classloader
[junit4] 2> 29106 T18 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-5.x-Java7/solr/core/src/test-files/solr/collection1/lib/.svn/' to classloader
[junit4] 2> 29306 T18 oasc.SolrConfig.<init> Using Lucene MatchVersion: 5.0.0
[junit4] 2> 29391 T18 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4] 2> 29392 T18 oass.IndexSchema.readSchema Reading Solr Schema from /usr/home/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-5.x-Java7/solr/core/src/test-files/solr/collection1/conf/schema.xml
[junit4] 2> 29451 T18 oass.IndexSchema.readSchema [collection1] Schema name=test
[junit4] 2> 29908 T18 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4] 2> 29925 T18 oass.IndexSchema.readSchema default search field in schema is text
[junit4] 2> 29929 T18 oass.IndexSchema.readSchema unique key field: id
[junit4] 2> 29956 T18 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4] 2> 29962 T18 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4] 2> 29968 T18 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4] 2> 29969 T18 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4] 2> 29970 T18 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4] 2> 29971 T18 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4] 2> 29972 T18 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4] 2> 29972 T18 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4] 2> 29973 T18 oasc.CoreContainer.reload Reloading SolrCore 'collection1' using configuration from instancedir /usr/home/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-5.x-Java7/solr/core/src/test-files/solr/collection1/
[junit4] 2> 29973 T18 oasc.SolrCore.<init> [collection1] Opening new SolrCore at /usr/home/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-5.x-Java7/solr/core/src/test-files/solr/collection1/, dataDir=/usr/home/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-5.x-Java7/solr/build/solr-core/test/J2/temp/solr.update.SoftAutoCommitTest-391FB952BB027BFD-001/init-core-data-001/
[junit4] 2> 29974 T18 oasc.JmxMonitoredMap.<init> No JMX servers found, not exposing Solr information with JMX.
[junit4] 2> 29975 T18 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=/usr/home/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-5.x-Java7/solr/build/solr-core/test/J2/temp/solr.update.SoftAutoCommitTest-391FB952BB027BFD-001/init-core-data-001/index/
[junit4] 2> 29975 T18 oasc.SolrCore.initWriters created xml: solr.XMLResponseWriter
[junit4] 2> 29978 T18 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "dedupe"
[junit4] 2> 29979 T18 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4] 2> 29979 T18 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "dedupe-allfields"
[junit4] 2> 29980 T18 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe-allfields"
[junit4] 2> 29980 T18 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "stored_sig"
[junit4] 2> 29981 T18 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4] 2> 29982 T18 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "uniq-fields"
[junit4] 2> 29982 T18 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "uniq-fields"
[junit4] 2> 29983 T18 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-explicit"
[junit4] 2> 29984 T18 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4] 2> 29984 T18 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4] 2> 29985 T18 oasc.SolrCore.loadUpdateProcessorChains no updateRequestProcessorChain defined as default, creating implicit default
[junit4] 2> 29986 T18 oasc.RequestHandlers.initHandlersFromConfig created /update/json/docs: org.apache.solr.handler.UpdateRequestHandler
[junit4] 2> 29986 T18 oasc.RequestHandlers.initHandlersFromConfig created /update/json: org.apache.solr.handler.UpdateRequestHandler
[junit4] 2> 29987 T18 oasc.RequestHandlers.initHandlersFromConfig created /update/csv: org.apache.solr.handler.UpdateRequestHandler
[junit4] 2> 29987 T18 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4] 2> 29988 T18 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4] 2> 29988 T18 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4] 2> 29989 T18 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4] 2> 29990 T18 oasc.RequestHandlers.initHandlersFromConfig created dismax: solr.SearchHandler
[junit4] 2> 29990 T18 oasc.RequestHandlers.initHandlersFromConfig created mock: org.apache.solr.core.MockQuerySenderListenerReqHandler
[junit4] 2> 29991 T18 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4] 2> 29992 T18 oasc.RequestHandlers.initHandlersFromConfig created /admin/file: solr.admin.ShowFileRequestHandler
[junit4] 2> 29992 T18 oasc.RequestHandlers.initHandlersFromConfig created /admin/fileedit: solr.admin.EditFileRequestHandler
[junit4] 2> 29993 T18 oasc.RequestHandlers.initHandlersFromConfig created defaults: solr.StandardRequestHandler
[junit4] 2> 29993 T18 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.StandardRequestHandler
[junit4] 2> 29994 T18 oasc.RequestHandlers.initHandlersFromConfig created lazy: solr.StandardRequestHandler
[junit4] 2> 29994 T18 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4] 2> 29995 T18 oasc.RequestHandlers.initHandlersFromConfig created /terms: org.apache.solr.handler.component.SearchHandler
[junit4] 2> 29995 T18 oasc.RequestHandlers.initHandlersFromConfig created spellCheckCompRH: org.apache.solr.handler.component.SearchHandler
[junit4] 2> 29996 T18 oasc.RequestHandlers.initHandlersFromConfig created spellCheckCompRH_Direct: org.apache.solr.handler.component.SearchHandler
[junit4] 2> 29997 T18 oasc.RequestHandlers.initHandlersFromConfig created spellCheckWithWordbreak: org.apache.solr.handler.component.SearchHandler
[junit4] 2> 29998 T18 oasc.RequestHandlers.initHandlersFromConfig created spellCheckWithWordbreak_Direct: org.apache.solr.handler.component.SearchHandler
[junit4] 2> 29998 T18 oasc.RequestHandlers.initHandlersFromConfig created spellCheckCompRH1: org.apache.solr.handler.component.SearchHandler
[junit4] 2> 29999 T18 oasc.RequestHandlers.initHandlersFromConfig created mltrh: org.apache.solr.handler.component.SearchHandler
[junit4] 2> 29999 T18 oasc.RequestHandlers.initHandlersFromConfig created tvrh: org.apache.solr.handler.component.SearchHandler
[junit4] 2> 30000 T18 oasc.RequestHandlers.initHandlersFromConfig created /mlt: solr.MoreLikeThisHandler
[junit4] 2> 30000 T18 oasc.RequestHandlers.initHandlersFromConfig created /debug/dump: solr.DumpRequestHandler
[junit4] 2> 30003 T18 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4] 2> 30005 T18 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4] 2> 30007 T18 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4] 2> 30010 T18 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4] 2> 30012 T18 oasc.SolrCore.initDeprecatedSupport WARN solrconfig.xml uses deprecated <admin/gettableFiles>, Please update your config to use the ShowFileRequestHandler.
[junit4] 2> 30022 T18 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4] 2> 30022 T18 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4] 2> 30023 T18 oass.SolrIndexSearcher.<init> Opening Searcher@27f4ca70[collection1] main
[junit4] 2> 30024 T18 oasr.RestManager.init Initializing RestManager with initArgs: {storageIO=org.apache.solr.rest.ManagedResourceStorage$InMemoryStorageIO}
[junit4] 2> 30024 T18 oasr.ManagedResourceStorage.load Reading _rest_managed.json using InMemoryStorage
[junit4] 2> 30025 T18 oasr.ManagedResource.reloadFromStorage WARN No stored data found for /rest/managed
[junit4] 2> 30025 T18 oasr.ManagedResourceStorage$JsonStorage.store Saved JSON object to path _rest_managed.json using InMemoryStorage
[junit4] 2> 30026 T18 oasr.RestManager.init Initializing 0 registered ManagedResources
[junit4] 2> 30026 T18 oashc.SpellCheckComponent.inform Initializing spell checkers
[junit4] 2> 30030 T18 oass.DirectSolrSpellChecker.init init: {name=direct,classname=DirectSolrSpellChecker,field=lowerfilt,minQueryLength=3}
[junit4] 2> 30047 T22 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@27f4ca70[collection1] main{ExitableDirectoryReader(UninvertingDirectoryReader())}
[junit4] 2> 30048 T18 oasu.DefaultSolrCoreState.newIndexWriter Creating new IndexWriter...
[junit4] 2> 30049 T18 oasu.DefaultSolrCoreState.newIndexWriter Waiting until IndexWriter is unused... core=collection1
[junit4] 2> 30049 T18 oasu.DefaultSolrCoreState.newIndexWriter Closing old IndexWriter... core=collection1
[junit4] 2> 30051 T18 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.AlcoholicMergePolicy: [AlcoholicMergePolicy: minMergeSize=0, mergeFactor=10, maxMergeSize=827463786, maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=true, maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.1]
[junit4] 2> 30052 T18 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=1
[junit4] 2> commit{dir=RateLimitedDirectoryWrapper(MockDirectoryWrapper(RAMDirectory@899c9fd lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@289c0574)),segFN=segments_1,generation=1}
[junit4] 2> 30052 T18 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4] 2> 30053 T18 oasu.DefaultSolrCoreState.newIndexWriter New IndexWriter is ready to be used.
[junit4] 2> 30054 T18 oass.SolrIndexSearcher.<init> Opening Searcher@1207457c[collection1] main
[junit4] 2> 30059 T18 oasc.CoreContainer.registerCore replacing core: collection1
[junit4] 2> 30060 T18 oasc.SolrCore.close [collection1] CLOSING SolrCore org.apache.solr.core.SolrCore@59052e
[junit4] 2> 30060 T18 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,transaction_logs_total_size=0,transaction_logs_total_number=0}
[junit4] 2> 30061 T18 oasc.SolrCore.closeSearcher [collection1] Closing main searcher on request.
[junit4] 2> 30068 T22 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@1207457c[collection1] main{ExitableDirectoryReader(UninvertingDirectoryReader())}
[junit4] 2> ASYNC NEW_CORE C0 name=collection1 org.apache.solr.core.SolrCore@6f931514
[junit4] 2> 31713 T18 C0 oasup.LogUpdateProcessor.finish [collection1] webapp=null path=null params={} {add=[529 (1485520490771513344)]} 0 1635
[junit4] 2> 32195 T24 oasu.DirectUpdateHandler2.commit start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=true,prepareCommit=false}
[junit4] 2> 32831 T18 oas.SolrTestCaseJ4.tearDown ###Ending testSoftAndHardCommitMaxTimeMixedAdds
[junit4] 2> 32895 T23 oasu.DirectUpdateHandler2.commit start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4] 2> NOTE: reproduce with: ant test -Dtestcase=SoftAutoCommitTest -Dtests.method=testSoftAndHardCommitMaxTimeMixedAdds -Dtests.seed=391FB952BB027BFD -Dtests.multiplier=2 -Dtests.slow=true -Dtests.locale=bg_BG -Dtests.timezone=Australia/Queensland -Dtests.asserts=true -Dtests.file.encoding=US-ASCII
[junit4] FAILURE 3.85s J2 | SoftAutoCommitTest.testSoftAndHardCommitMaxTimeMixedAdds <<<
[junit4] > Throwable #1: java.lang.AssertionError: soft529 wasn't fast enough
[junit4] > at __randomizedtesting.SeedInfo.seed([391FB952BB027BFD:68CB40D20A714B5A]:0)
[junit4] > at org.apache.solr.update.SoftAutoCommitTest.testSoftAndHardCommitMaxTimeMixedAdds(SoftAutoCommitTest.java:111)
[junit4] > at java.lang.Thread.run(Thread.java:745)
[junit4] 2> 32953 T18 oas.SolrTestCaseJ4.setUp ###Starting testSoftAndHardCommitMaxTimeDelete
[junit4] 2> 32954 T18 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/usr/home/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-5.x-Java7/solr/core/src/test-files/solr/collection1/'
[junit4] 2> 32956 T18 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-5.x-Java7/solr/core/src/test-files/solr/collection1/lib/classes/' to classloader
[junit4] 2> 32957 T18 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-5.x-Java7/solr/core/src/test-files/solr/collection1/lib/README' to classloader
[junit4] 2> 32958 T18 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-5.x-Java7/solr/core/src/test-files/solr/collection1/lib/.svn/' to classloader
[junit4] 2> 33212 T18 oasc.SolrConfig.<init> Using Lucene MatchVersion: 5.0.0
[junit4] 2> 33317 T18 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4] 2> 33319 T18 oass.IndexSchema.readSchema Reading Solr Schema from /usr/home/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-5.x-Java7/solr/core/src/test-files/solr/collection1/conf/schema.xml
[junit4] 2> 33504 T18 oass.IndexSchema.readSchema [collection1] Schema name=test
[junit4] 2> 33621 T24 oass.SolrIndexSearcher.<init> Opening Searcher@506dd498[collection1] main
[junit4] 2> 33627 T24 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4] 2> 33628 T22 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@506dd498[collection1] main{ExitableDirectoryReader(UninvertingDirectoryReader(Uninverting(_0(5.0.0):C1)))}
[junit4] 2> 33629 T23 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=2
[junit4] 2> commit{dir=RateLimitedDirectoryWrapper(MockDirectoryWrapper(RAMDirectory@899c9fd lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@289c0574)),segFN=segments_1,generation=1}
[junit4] 2> commit{dir=RateLimitedDirectoryWrapper(MockDirectoryWrapper(RAMDirectory@899c9fd lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@289c0574)),segFN=segments_2,generation=2}
[junit4] 2> 33630 T23 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 2
[junit4] 2> 33631 T23 oasc.SolrCore.openNewSearcher SolrIndexSearcher has not changed - not re-opening: org.apache.solr.search.SolrIndexSearcher
[junit4] 2> 33632 T23 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4] 2> 34109 T18 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4] 2> 34125 T18 oass.IndexSchema.readSchema default search field in schema is text
[junit4] 2> 34128 T18 oass.IndexSchema.readSchema unique key field: id
[junit4] 2> 34157 T18 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4] 2> 34182 T18 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4] 2> 34187 T18 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4] 2> 34188 T18 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4] 2> 34189 T18 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4] 2> 34189 T18 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4] 2> 34190 T18 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4] 2> 34190 T18 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4] 2> 34191 T18 oasc.CoreContainer.reload Reloading SolrCore 'collection1' using configuration from instancedir /usr/home/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-5.x-Java7/solr/core/src/test-files/solr/collection1/
[junit4] 2> 34191 T18 oasc.SolrCore.<init> [collection1] Opening new SolrCore at /usr/home/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-5.x-Java7/solr/core/src/test-files/solr/collection1/, dataDir=/usr/home/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-5.x-Java7/solr/build/solr-core/test/J2/temp/solr.update.SoftAutoCommitTest-391FB952BB027BFD-001/init-core-data-001/
[junit4] 2> 34192 T18 oasc.JmxMonitoredMap.<init> No JMX servers found, not exposing Solr information with JMX.
[junit4] 2> 34192 T18 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=/usr/home/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-5.x-Java7/solr/build/solr-core/test/J2/temp/solr.update.SoftAutoCommitTest-391FB952BB027BFD-001/init-core-data-001/index/
[junit4] 2> 34193 T18 oasc.SolrCore.initWriters created xml: solr.XMLResponseWriter
[junit4] 2> 34194 T18 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "dedupe"
[junit4] 2> 34195 T18 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4] 2> 34195 T18 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "dedupe-allfields"
[junit4] 2> 34196 T18 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe-allfields"
[junit4] 2> 34196 T18 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "stored_sig"
[junit4] 2> 34197 T18 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4] 2> 34198 T18 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "uniq-fields"
[junit4] 2> 34198 T18 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "uniq-fields"
[junit4] 2> 34199 T18 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-explicit"
[junit4] 2> 34200 T18 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4] 2> 34200 T18 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4] 2> 34201 T18 oasc.SolrCore.loadUpdateProcessorChains no updateRequestProcessorChain defined as default, creating implicit default
[junit4] 2> 34201 T18 oasc.RequestHandlers.initHandlersFromConfig created /update/json/docs: org.apache.solr.handler.UpdateRequestHandler
[junit4] 2> 34202 T18 oasc.RequestHandlers.initHandlersFromConfig created /update/json: org.apache.solr.handler.UpdateRequestHandler
[junit4] 2> 34202 T18 oasc.RequestHandlers.initHandlersFromConfig created /update/csv: org.apache.solr.handler.UpdateRequestHandler
[junit4] 2> 34203 T18 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4] 2> 34203 T18 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4] 2> 34203 T18 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4] 2> 34204 T18 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4] 2> 34204 T18 oasc.RequestHandlers.initHandlersFromConfig created dismax: solr.SearchHandler
[junit4] 2> 34205 T18 oasc.RequestHandlers.initHandlersFromConfig created mock: org.apache.solr.core.MockQuerySenderListenerReqHandler
[junit4] 2> 34205 T18 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4] 2> 34206 T18 oasc.RequestHandlers.initHandlersFromConfig created /admin/file: solr.admin.ShowFileRequestHandler
[junit4] 2> 34206 T18 oasc.RequestHandlers.initHandlersFromConfig created /admin/fileedit: solr.admin.EditFileRequestHandler
[junit4] 2> 34207 T18 oasc.RequestHandlers.initHandlersFromConfig created defaults: solr.StandardRequestHandler
[junit4] 2> 34207 T18 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.StandardRequestHandler
[junit4] 2> 34208 T18 oasc.RequestHandlers.initHandlersFromConfig created lazy: solr.StandardRequestHandler
[junit4] 2> 34208 T18 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4] 2> 34209 T18 oasc.RequestHandlers.initHandlersFromConfig created /terms: org.apache.solr.handler.component.SearchHandler
[junit4] 2> 34209 T18 oasc.RequestHandlers.initHandlersFromConfig created spellCheckCompRH: org.apache.solr.handler.component.SearchHandler
[junit4] 2> 34210 T18 oasc.RequestHandlers.initHandlersFromConfig created spellCheckCompRH_Direct: org.apache.solr.handler.component.SearchHandler
[junit4] 2> 34210 T18 oasc.RequestHandlers.initHandlersFromConfig created spellCheckWithWordbreak: org.apache.solr.handler.component.SearchHandler
[junit4] 2> 34211 T18 oasc.RequestHandlers.initHandlersFromConfig created spellCheckWithWordbreak_Direct: org.apache.solr.handler.component.SearchHandler
[junit4] 2> 34211 T18 oasc.RequestHandlers.initHandlersFromConfig created spellCheckCompRH1: org.apache.solr.handler.component.SearchHandler
[junit4] 2> 34212 T18 oasc.RequestHandlers.initHandlersFromConfig created mltrh: org.apache.solr.handler.component.SearchHandler
[junit4] 2> 34212 T18 oasc.RequestHandlers.initHandlersFromConfig created tvrh: org.apache.solr.handler.component.SearchHandler
[junit4] 2> 34212 T18 oasc.RequestHandlers.initHandlersFromConfig created /mlt: solr.MoreLikeThisHandler
[junit4] 2> 34213 T18 oasc.RequestHandlers.initHandlersFromConfig created /debug/dump: solr.DumpRequestHandler
[junit4] 2> 34234 T18 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4] 2> 34237 T18 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4] 2> 34239 T18 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4] 2> 34241 T18 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4] 2> 34242 T18 oasc.SolrCore.initDeprecatedSupport WARN solrconfig.xml uses deprecated <admin/gettableFiles>, Please update your config to use the ShowFileRequestHandler.
[junit4] 2> 34244 T18 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4] 2> 34245 T18 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4] 2> 34246 T18 oass.SolrIndexSearcher.<init> Opening Searcher@60f465a7[collection1] main
[junit4] 2> 34247 T18 oasr.RestManager.init Initializing RestManager with initArgs: {storageIO=org.apache.solr.rest.ManagedResourceStorage$InMemoryStorageIO}
[junit4] 2> 34248 T18 oasr.ManagedResourceStorage.load Reading _rest_managed.json using InMemoryStorage
[junit4] 2> 34248 T18 oasr.ManagedResource.reloadFromStorage WARN No stored data found for /rest/managed
[junit4] 2> 34249 T18 oasr.ManagedResourceStorage$JsonStorage.store Saved JSON object to path _rest_managed.json using InMemoryStorage
[junit4] 2> 34249 T18 oasr.RestManager.init Initializing 0 registered ManagedResources
[junit4] 2> 34249 T18 oashc.SpellCheckComponent.inform Initializing spell checkers
[junit4] 2> 34253 T18 oass.DirectSolrSpellChecker.init init: {name=direct,classname=DirectSolrSpellChecker,field=lowerfilt,minQueryLength=3}
[junit4] 2> 34272 T25 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@60f465a7[collection1] main{ExitableDirectoryReader(UninvertingDirectoryReader(Uninverting(_0(5.0.0):C1)))}
[junit4] 2> 34272 T18 oasu.DefaultSolrCoreState.newIndexWriter Creating new IndexWriter...
[junit4] 2> 34273 T18 oasu.DefaultSolrCoreState.newIndexWriter Waiting until IndexWriter is unused... core=collection1
[junit4] 2> 34273 T18 oasu.DefaultSolrCoreState.newIndexWriter Closing old IndexWriter... core=collection1
[junit4] 2> 34274 T18 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: maxMergeAtOnce=25, maxMergeAtOnceExplicit=21, maxMergedSegmentMB=70.4296875, floorSegmentMB=1.955078125, forceMergeDeletesPctAllowed=26.00754871424691, segmentsPerTier=46.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.0
[junit4] 2> 34278 T18 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=1
[junit4] 2> commit{dir=RateLimitedDirectoryWrapper(MockDirectoryWrapper(RAMDirectory@899c9fd lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@289c0574)),segFN=segments_2,generation=2}
[junit4] 2> 34278 T18 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 2
[junit4] 2> 34279 T18 oasu.DefaultSolrCoreState.newIndexWriter New IndexWriter is ready to be used.
[junit4] 2> 34284 T18 oass.SolrIndexSearcher.<init> Opening Searcher@73a734a0[collection1] main
[junit4] 2> 34285 T18 oasc.CoreContainer.registerCore replacing core: collection1
[junit4] 2> 34285 T25 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@73a734a0[collection1] main{ExitableDirectoryReader(UninvertingDirectoryReader(Uninverting(_0(5.0.0):C1)))}
[junit4] 2> 34286 T18 oasc.SolrCore.close [collection1] CLOSING SolrCore org.apache.solr.core.SolrCore@6f931514
[junit4] 2> 34287 T18 oasu.DirectUpdateHandler2.close closing DirectUpdateHandler2{commits=2,autocommit maxTime=1200ms,autocommits=1,soft autocommit maxTime=500ms,soft autocommits=1,optimizes=0,rollbacks=0,expungeDeletes=0,docsPending=0,adds=0,deletesById=0,deletesByQuery=0,errors=0,cumulative_adds=1,cumulative_deletesById=0,cumulative_deletesByQuery=0,cumulative_errors=0,transaction_logs_total_size=143,transaction_logs_total_number=1}
[junit4] 2> 34288 T18 oasc.SolrCore.closeSearcher [collection1] Closing main searcher on request.
[junit4] 2> ASYNC NEW_CORE C1 name=collection1 org.apache.solr.core.SolrCore@69470e44
[junit4] 2> 34293 T18 C1 oasup.LogUpdateProcessor.finish [collection1] webapp=null path=null params={} {add=[529 (1485520494444675072)]} 0 4
[junit4] 2> 34296 T18 C1 oasu.DirectUpdateHandler2.commit start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4] 2> 34441 T18 C1 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=2
[junit4] 2> commit{dir=RateLimitedDirectoryWrapper(MockDirectoryWrapper(RAMDirectory@899c9fd lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@289c0574)),segFN=segments_2,generation=2}
[junit4] 2> commit{dir=RateLimitedDirectoryWrapper(MockDirectoryWrapper(RAMDirectory@899c9fd lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@289c0574)),segFN=segments_3,generation=3}
[junit4] 2> 34441 T18 C1 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 3
[junit4] 2> 34499 T18 C1 oass.SolrIndexSearcher.<init> Opening Searcher@9674b2d[collection1] main
[junit4] 2> 34501 T18 C1 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4] 2> 34501 T25 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@9674b2d[collection1] main{ExitableDirectoryReader(UninvertingDirectoryReader(Uninverting(_1(5.0.0):C1)))}
[junit4] 2> 34503 T18 C1 oasup.LogUpdateProcessor.finish [collection1] webapp=null path=null params={} {commit=} 0 207
[junit4] 2> 34518 T18 C1 oasup.LogUpdateProcessor.finish [collection1] webapp=null path=null params={} {delete=[529 (-1485520494681653248)]} 0 3
[junit4] 2> 35020 T27 oasu.DirectUpdateHandler2.commit start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=true,prepareCommit=false}
[junit4] 2> 35029 T27 oass.SolrIndexSearcher.<init> Opening Searcher@4ec6871d[collection1] main
[junit4] 2> 35029 T27 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4] 2> 35030 T25 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@4ec6871d[collection1] main{ExitableDirectoryReader(UninvertingDirectoryReader())}
[junit4] 2> 35032 T18 C1 oasup.LogUpdateProcessor.finish [collection1] webapp=null path=null params={} {add=[550 (1485520495220621312)]} 0 2
[junit4] 2> 35532 T27 oasu.DirectUpdateHandler2.commit start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=true,prepareCommit=false}
[junit4] 2> 35547 T27 oass.SolrIndexSearcher.<init> Opening Searcher@19b3e4b8[collection1] main
[junit4] 2> 35548 T27 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4] 2> 35548 T25 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@19b3e4b8[collection1] main{ExitableDirectoryReader(UninvertingDirectoryReader(Uninverting(_2(5.0.0):C1)))}
[junit4] 2> 35720 T26 oasu.DirectUpdateHandler2.commit start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4] 2> 35721 T26 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=2
[junit4] 2> commit{dir=RateLimitedDirectoryWrapper(MockDirectoryWrapper(RAMDirectory@899c9fd lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@289c0574)),segFN=segments_3,generation=3}
[junit4] 2> commit{dir=RateLimitedDirectoryWrapper(MockDirectoryWrapper(RAMDirectory@899c9fd lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@289c0574)),segFN=segments_4,generation=4}
[junit4] 2> 35722 T26 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 4
[junit4] 2> 35723 T26 oasc.SolrCore.openNewSearcher SolrIndexSearcher has not changed - not re-opening: org.apache.solr.search.SolrIndexSearcher
[junit4] 2> 35723 T26 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4] 2> 37724 T18 oas.SolrTestCaseJ4.tearDown ###Ending testSoftAndHardCommitMaxTimeDelete
[junit4] 2> 37733 T18 oas.SolrTestCaseJ4.setUp ###Starting testSoftAndHardCommitMaxTimeRapidAdds
[junit4] 2> 37734 T18 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/usr/home/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-5.x-Java7/solr/core/src/test-files/solr/collection1/'
[junit4] 2> 37735 T18 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-5.x-Java7/solr/core/src/test-files/solr/collection1/lib/classes/' to classloader
[junit4] 2> 37736 T18 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-5.x-Java7/solr/core/src/test-files/solr/collection1/lib/README' to classloader
[junit4] 2> 37737 T18 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-5.x-Java7/solr/core/src/test-files/solr/collection1/lib/.svn/' to classloader
[junit4] 2> 37878 T18 oasc.SolrConfig.<init> Using Lucene MatchVersion: 5.0.0
[junit4] 2> 37940 T18 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4] 2> 37942 T18 oass.IndexSchema.readSchema Reading Solr Schema from /usr/home/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-5.x-Java7/solr/core/src/test-files/solr/collection1/conf/schema.xml
[junit4] 2> 37972 T18 oass.IndexSchema.readSchema [collection1] Schema name=test
[junit4] 2> 38321 T18 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4] 2> 38339 T18 oass.IndexSchema.readSchema default search field in schema is text
[junit4] 2> 38341 T18 oass.IndexSchema.readSchema unique key field: id
[junit4] 2> 38363 T18 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4] 2> 38368 T18 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4] 2> 38373 T18 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4] 2> 38374 T18 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4] 2> 38374 T18 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4] 2> 38375 T18 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4] 2> 38375 T18 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4] 2> 38376 T18 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4] 2> 38376 T18 oasc.CoreContainer.reload Reloading SolrCore 'collection1' using configuration from instancedir /usr/home/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-5.x-Java7/solr/core/src/test-files/solr/collection1/
[junit4] 2> 38377 T18 oasc.SolrCore.<init> [collection1] Opening new SolrCore at /usr/home/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-5.x-Java7/solr/core/src/test-files/solr/collection1/, dataDir=/usr/home/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-5.x-Java7/solr/build/solr-core/test/J2/temp/solr.update.SoftAutoCommitTest-391FB952BB027BFD-001/init-core-data-001/
[junit4] 2> 38377 T18 oasc.JmxMonitoredMap.<init> No JMX servers found, not exposing Solr information with JMX.
[junit4] 2> 38378 T18 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=/usr/home/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-5.x-Java7/solr/build/solr-core/test/J2/temp/solr.update.SoftAutoCommitTest-391FB952BB027BFD-001/init-core-data-001/index/
[junit4] 2> 38378 T18 oasc.SolrCore.initWriters created xml: solr.XMLResponseWriter
[junit4] 2> 38380 T18 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "dedupe"
[junit4] 2> 38380 T18 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4] 2> 38381 T18 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "dedupe-allfields"
[junit4] 2> 38381 T18 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe-allfields"
[junit4] 2> 38381 T18 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "stored_sig"
[junit4] 2> 38382 T18 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4] 2> 38382 T18 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "uniq-fields"
[junit4] 2> 38383 T18 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "uniq-fields"
[junit4] 2> 38383 T18 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-explicit"
[junit4] 2> 38384 T18 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4] 2> 38385 T18 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4] 2> 38385 T18 oasc.SolrCore.loadUpdateProcessorChains no updateRequestProcessorChain defined as default, creating implicit default
[junit4] 2> 38386 T18 oasc.RequestHandlers.initHandlersFromConfig created /update/json/docs: org.apache.solr.handler.UpdateRequestHandler
[junit4] 2> 38386 T18 oasc.RequestHandlers.initHandlersFromConfig created /update/json: org.apache.solr.handler.UpdateRequestHandler
[junit4] 2> 38387 T18 oasc.RequestHandlers.initHandlersFromConfig created /update/csv: org.apache.solr.handler.UpdateRequestHandler
[junit4] 2> 38387 T18 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4] 2> 38387 T18 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4] 2> 38388 T18 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4] 2> 38388 T18 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4] 2> 38389 T18 oasc.RequestHandlers.initHandlersFromConfig created dismax: solr.SearchHandler
[junit4] 2> 38389 T18 oasc.RequestHandlers.initHandlersFromConfig created mock: org.apache.solr.core.MockQuerySenderListenerReqHandler
[junit4] 2> 38390 T18 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4] 2> 38390 T18 oasc.RequestHandlers.initHandlersFromConfig created /admin/file: solr.admin.ShowFileRequestHandler
[junit4] 2> 38391 T18 oasc.RequestHandlers.initHandlersFromConfig created /admin/fileedit: solr.admin.EditFileRequestHandler
[junit4] 2> 38391 T18 oasc.RequestHandlers.initHandlersFromConfig created defaults: solr.StandardRequestHandler
[junit4] 2> 38392 T18 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.StandardRequestHandler
[junit4] 2> 38392 T18 oasc.RequestHandlers.initHandlersFromConfig created lazy: solr.StandardRequestHandler
[junit4] 2> 38392 T18 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4] 2> 38393 T18 oasc.RequestHandlers.initHandlersFromConfig created /terms: org.apache.solr.handler.component.SearchHandler
[junit4] 2> 38393 T18 oasc.RequestHandlers.initHandlersFromConfig created spellCheckCompRH: org.apache.solr.handler.component.SearchHandler
[junit4] 2> 38394 T18 oasc.RequestHandlers.initHandlersFromConfig created spellCheckCompRH_Direct: org.apache.solr.handler.component.SearchHandler
[junit4] 2> 38394 T18 oasc.RequestHandlers.initHandlersFromConfig created spellCheckWithWordbreak: org.apache.solr.handler.component.SearchHandler
[junit4] 2> 38395 T18 oasc.RequestHandlers.initHandlersFromConfig created spellCheckWithWordbreak_Direct: org.apache.solr.handler.component.SearchHandler
[junit4] 2> 38395 T18 oasc.RequestHandlers.initHandlersFromConfig created spellCheckCompRH1: org.apache.solr.handler.component.SearchHandler
[junit4] 2> 38396 T18 oasc.RequestHandlers.initHandlersFromConfig created mltrh: org.apache.solr.handler.component.SearchHandler
[junit4] 2> 38396 T18 oasc.RequestHandlers.initHandlersFromConfig created tvrh: org.apache.solr.handler.component.SearchHandler
[junit4] 2> 38396 T18 oasc.RequestHandlers.initHandlersFromConfig created /mlt: solr.MoreLikeThisHandler
[junit4] 2> 38397 T18 oasc.RequestHandlers.initHandlersFromConfig created /debug/dump: solr.DumpRequestHandler
[junit4] 2> 38418 T18 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4] 2> 38420 T18 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4] 2> 38422 T18 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4] 2> 38424 T18 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4] 2> 38431 T18 oasc.SolrCore.initDeprecatedSupport WARN solrconfig.xml uses deprecated <admin/gettableFiles>, Please update your config to use the ShowFileRequestHandler.
[junit4] 2> 38433 T18 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4] 2> 38433 T18 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4] 2> 38434 T18 oass.SolrIndexSearcher.<init> Opening Searcher@61c6408d[collection1] main
[junit4] 2> 38435 T18 oasr.RestManager.init Initializing RestManager with initArgs: {storageIO=org.apache.solr.rest.ManagedResourceStorage$InMemoryStorageIO}
[junit4] 2> 38435 T18 oasr.ManagedResourceStorage.load Reading _rest_managed.json using InMemoryStorage
[junit4] 2> 38436 T18 oasr.ManagedResource.reloadFromStorage WARN No stored data found for /rest/managed
[junit4] 2> 38436 T18 oasr.ManagedResourceStorage$JsonStorage.store Saved JSON object to path _rest_managed.json using InMemoryStorage
[junit4] 2> 38437 T18 oasr.RestManager.init Initializing 0 registered ManagedResources
[junit4] 2> 38437 T18 oashc.SpellCheckComponent.inform Initializing spell checkers
[junit4] 2> 38441 T18 oass.DirectSolrSpellChecker.init init: {name=direct,classname=DirectSolrSpellChecker,field=lowerfilt,minQueryLength=3}
[junit4] 2> 38457 T28 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@61c6408d[collection1] main{ExitableDirectoryReader(UninvertingDirectoryReader(Uninverting(_2(5.0.0):C1)))}
[junit4] 2> 38457 T18 oasu.DefaultSolrCoreState.newIndexWriter Creating new IndexWriter...
[junit4] 2> 38458 T18 oasu.DefaultSolrCoreState.newIndexWriter Waiting until IndexWriter is unused... core=collection1
[junit4] 2> 38458 T18 oasu.DefaultSolrCoreState.newIndexWriter Closing old IndexWriter... core=collection1
[junit4] 2> 38459 T18 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: maxMergeAtOnce=11, maxMergeAtOnceExplicit=33, maxMergedSegmentMB=51.568359375, floorSegmentMB=1.01171875, forceMergeDeletesPctAllowed=17.05224143726121, segmentsPerTier=21.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.4286795830693818
[junit4] 2> 38462 T18 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=1
[junit4] 2> commit{dir=RateLimitedDirectoryWrapper(MockDirectoryWrapper(RAMDirectory@899c9fd lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@289c0574)),segFN=segments_4,generation=4}
[junit4] 2> 38463 T18 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 4
[junit4] 2> 38463 T18 oasu.DefaultSolrCoreState.newIndexWriter New IndexWriter is ready to be used.
[junit4] 2> 38469 T18 oass.SolrIndexSearcher.<init> Opening Searcher@7c8e1724[collection1] main
[junit4] 2> 38470 T18 oasc.CoreContainer.registerCore replacing core: collection1
[junit4] 2> 38470 T28 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@7c8e1724[collection1] main{ExitableDirectoryReader(UninvertingDirectoryReader(Uninverting(_2(5.0.0):C1)))}
[junit4] 2> 38470 T18 oasc.SolrCore.close [collection1] CLOSING SolrCore org.apache.solr.core.SolrCore@69470e44
[junit4] 2> 38472 T18 oasu.DirectUpdateHandler2.close closing DirectUpdateHandler2{commits=4,autocommit maxTime=1200ms,autocommits=1,soft autocommit maxTime=500ms,soft autocommits=2,optimizes=0,rollbacks=0,expungeDeletes=0,docsPending=0,adds=0,deletesById=0,deletesByQuery=0,errors=0,cumulative_adds=2,cumulative_deletesById=1,cumulative_deletesByQuery=0,cumulative_errors=0,transaction_logs_total_size=437,transaction_logs_total_number=3}
[junit4] 2> 38473 T18 oasc.SolrCore.closeSearcher [collection1] Closing main searcher on request.
[junit4] 2> ASYNC NEW_CORE C2 name=collection1 org.apache.solr.core.SolrCore@46b8c77f
[junit4] 2> 38477 T18 C2 oasup.LogUpdateProcessor.finish [collection1] webapp=null path=null params={} {add=[5000 (1485520498831917056)]} 0 3
[junit4] 2> 38481 T18 C2 oasup.LogUpdateProcessor.finish [collection1] webapp=null path=null params={} {add=[5001 (1485520498838208512)]} 0 1
[junit4] 2> 38483 T18 C2 oasup.LogUpdateProcessor.finish [collection1] webapp=null path=null params={} {add=[5002 (1485520498841354240)]} 0 1
[junit4] 2> 38486 T18 C2 oasup.LogUpdateProcessor.finish [collection1] webapp=null path=null params={} {add=[5003 (1485520498843451392)]} 0 1
[junit4] 2> 38489 T18 C2 oasup.LogUpdateProcessor.finish [collection1] webapp=null path=null params={} {add=[5004 (1485520498846597120)]} 0 1
[junit4] 2> 38490 T18 oas.SolrTestCaseJ4.tearDown ###Ending testSoftAndHardCommitMaxTimeRapidAdds
[junit4] 2> 38493 T18 oas.SolrTestCaseJ4.deleteCore ###deleteCore
[junit4] 2> 38493 T18 oasc.CoreContainer.shutdown Shutting down CoreContainer instance=716910764
[junit4] 2> 38494 T18 oasc.SolrCore.close [collection1] CLOSING SolrCore org.apache.solr.core.SolrCore@46b8c77f
[junit4] 2> 38494 T18 oasu.DirectUpdateHandler2.close closing DirectUpdateHandler2{commits=0,autocommit maxTime=1200ms,autocommits=0,soft autocommit maxTime=500ms,soft autocommits=0,optimizes=0,rollbacks=0,expungeDeletes=0,docsPending=5,adds=5,deletesById=0,deletesByQuery=0,errors=0,cumulative_adds=5,cumulative_deletesById=0,cumulative_deletesByQuery=0,cumulative_errors=0,transaction_logs_total_size=437,transaction_logs_total_number=3}
[junit4] 2> 38495 T18 oasu.SolrCoreState.decrefSolrCoreState Closing SolrCoreState
[junit4] 2> 38496 T18 oasu.DefaultSolrCoreState.closeIndexWriter SolrCoreState ref count has reached 0 - closing IndexWriter
[junit4] 2> 38496 T18 oasu.DefaultSolrCoreState.closeIndexWriter closing IndexWriter with IndexWriterCloser
[junit4] 2> 38496 T18 C2 oasu.DirectUpdateHandler2.closeWriter Committing on IndexWriter close.
[junit4] 2> 38574 T18 C2 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=2
[junit4] 2> commit{dir=RateLimitedDirectoryWrapper(MockDirectoryWrapper(RAMDirectory@899c9fd lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@289c0574)),segFN=segments_4,generation=4}
[junit4] 2> commit{dir=RateLimitedDirectoryWrapper(MockDirectoryWrapper(RAMDirectory@899c9fd lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@289c0574)),segFN=segments_5,generation=5}
[junit4] 2> 38574 T18 C2 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 5
[junit4] 2> 38576 T18 oasc.SolrCore.closeSearcher [collection1] Closing main searcher on request.
[junit4] 2> 38577 T18 oasc.CachingDirectoryFactory.close Closing MockDirectoryFactory - 2 directories currently being tracked
[junit4] 2> 38578 T18 oasc.CachingDirectoryFactory.closeCacheValue looking to close /usr/home/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-5.x-Java7/solr/build/solr-core/test/J2/temp/solr.update.SoftAutoCommitTest-391FB952BB027BFD-001/init-core-data-001 [CachedDir<<refCount=0;path=/usr/home/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-5.x-Java7/solr/build/solr-core/test/J2/temp/solr.update.SoftAutoCommitTest-391FB952BB027BFD-001/init-core-data-001;done=false>>]
[junit4] 2> 38578 T18 oasc.CachingDirectoryFactory.close Closing directory: /usr/home/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-5.x-Java7/solr/build/solr-core/test/J2/temp/solr.update.SoftAutoCommitTest-391FB952BB027BFD-001/init-core-data-001
[junit4] 2> 38578 T18 oasc.CachingDirectoryFactory.closeCacheValue looking to close /usr/home/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-5.x-Java7/solr/build/solr-core/test/J2/temp/solr.update.SoftAutoCommitTest-391FB952BB027BFD-001/init-core-data-001/index [CachedDir<<refCount=0;path=/usr/home/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-5.x-Java7/solr/build/solr-core/test/J2/temp/solr.update.SoftAutoCommitTest-391FB952BB027BFD-001/init-core-data-001/index;done=false>>]
[junit4] 2> 38579 T18 oasc.CachingDirectoryFactory.close Closing directory: /usr/home/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-5.x-Java7/solr/build/solr-core/test/J2/temp/solr.update.SoftAutoCommitTest-391FB952BB027BFD-001/init-core-data-001/index
[junit4] 2> NOTE: leaving temporary files on disk at: /usr/home/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-5.x-Java7/solr/build/solr-core/test/J2/temp/solr.update.SoftAutoCommitTest-391FB952BB027BFD-001
[junit4] 2> NOTE: test params are: codec=Asserting(Lucene50): {subject=PostingsFormat(name=Asserting), multiDefault=PostingsFormat(name=Asserting), id=FST50, timestamp=PostingsFormat(name=Direct), intDefault=PostingsFormat(name=Direct), _version_=PostingsFormat(name=Direct), text=PostingsFormat(name=LuceneVarGapFixedInterval), range_facet_l=PostingsFormat(name=Direct)}, docValues:{timestamp=DocValuesFormat(name=Lucene50)}, sim=RandomSimilarityProvider(queryNorm=false,coord=crazy): {}, locale=bg_BG, timezone=Australia/Queensland
[junit4] 2> NOTE: FreeBSD 9.1-RELEASE-p3 amd64/Oracle Corporation 1.7.0_65 (64-bit)/cpus=16,threads=1,free=90904288,total=228589568
[junit4] 2> NOTE: All tests run in this JVM: [CursorMarkTest, TestUtils, SoftAutoCommitTest]
[junit4] Completed on J2 in 16.99s, 3 tests, 1 failure <<< FAILURES!
[...truncated 1429 lines...]
BUILD FAILED
/usr/home/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-5.x-Java7/build.xml:525: The following error occurred while executing this line:
/usr/home/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-5.x-Java7/build.xml:473: The following error occurred while executing this line:
/usr/home/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-5.x-Java7/build.xml:61: The following error occurred while executing this line:
/usr/home/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-5.x-Java7/extra-targets.xml:39: The following error occurred while executing this line:
/usr/home/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-5.x-Java7/solr/build.xml:189: The following error occurred while executing this line:
/usr/home/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-5.x-Java7/solr/common-build.xml:508: The following error occurred while executing this line:
/usr/home/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-5.x-Java7/lucene/common-build.xml:1359: The following error occurred while executing this line:
/usr/home/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-5.x-Java7/lucene/common-build.xml:966: There were test failures: 445 suites, 1819 tests, 1 failure, 58 ignored (22 assumptions)
Total time: 69 minutes 2 seconds
Build step 'Invoke Ant' marked build as failure
Archiving artifacts
Sending artifact delta relative to Lucene-Solr-Tests-5.x-Java7 #2224
Archived 5 artifacts
Archive block size is 32768
Received 0 blocks and 202427706 bytes
Compression is 0.0%
Took 39 sec
Recording test results
Email was triggered for: Failure
Sending email for trigger: Failure