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/05/02 13:48:56 UTC
[JENKINS] Lucene-Solr-Tests-trunk-Java7 - Build # 4693 - Failure
Build: https://builds.apache.org/job/Lucene-Solr-Tests-trunk-Java7/4693/
1 tests failed.
REGRESSION: org.apache.solr.update.SoftAutoCommitTest.testSoftAndHardCommitMaxTimeRapidAdds
Error Message:
2: soft wasn't fast enough
Stack Trace:
java.lang.AssertionError: 2: soft wasn't fast enough
at __randomizedtesting.SeedInfo.seed([C17ACE2B3DC4F930:9D6F6012D646B848]: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.testSoftAndHardCommitMaxTimeRapidAdds(SoftAutoCommitTest.java:316)
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.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: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:360)
at com.carrotsearch.randomizedtesting.ThreadLeakControl.forkTimeoutingTask(ThreadLeakControl.java:793)
at com.carrotsearch.randomizedtesting.ThreadLeakControl$3.evaluate(ThreadLeakControl.java:453)
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:43)
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:360)
at java.lang.Thread.run(Thread.java:724)
Build Log:
[...truncated 10726 lines...]
[junit4] Suite: org.apache.solr.update.SoftAutoCommitTest
[junit4] 2> log4j:WARN No such property [conversionPattern] in org.apache.solr.util.SolrLogLayout.
[junit4] 2> Creating dataDir: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J0/./solr.update.SoftAutoCommitTest-C17ACE2B3DC4F930-001/init-core-data-001
[junit4] 2> 2515 T11 oas.SolrTestCaseJ4.buildSSLConfig Randomized ssl (false) and clientAuth (true)
[junit4] 2> 2656 T11 oas.SolrTestCaseJ4.initCore ####initCore
[junit4] 2> 2798 T11 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/core/src/test-files/solr/collection1/'
[junit4] 2> 2806 T11 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/core/src/test-files/solr/collection1/lib/README' to classloader
[junit4] 2> 2807 T11 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/core/src/test-files/solr/collection1/lib/.svn/' to classloader
[junit4] 2> 2808 T11 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/core/src/test-files/solr/collection1/lib/classes/' to classloader
[junit4] 2> 4126 T11 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_5_0
[junit4] 2> 4552 T11 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4] 2> 4579 T11 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4] 2> 4719 T11 oass.IndexSchema.readSchema [null] Schema name=test
[junit4] 2> 6558 T11 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4] 2> 6629 T11 oass.IndexSchema.readSchema default search field in schema is text
[junit4] 2> 6635 T11 oass.IndexSchema.readSchema unique key field: id
[junit4] 2> 7744 T11 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4] 2> 7766 T11 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4] 2> 7773 T11 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4] 2> 7797 T11 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4] 2> 7798 T11 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4] 2> 7799 T11 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4] 2> 7800 T11 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4] 2> 7801 T11 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4] 2> 7814 T11 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4] 2> 7815 T11 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/core/src/test-files/solr
[junit4] 2> 7816 T11 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/core/src/test-files/solr/'
[junit4] 2> 8056 T11 oasc.CoreContainer.<init> New CoreContainer 717690625
[junit4] 2> 8063 T11 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/core/src/test-files/solr/]
[junit4] 2> 8162 T11 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 0
[junit4] 2> 8163 T11 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: null
[junit4] 2> 8179 T11 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 0
[junit4] 2> 8180 T11 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4] 2> 8182 T11 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4] 2> 8183 T11 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4] 2> 8184 T11 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4] 2> 8185 T11 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4] 2> 8186 T11 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4] 2> 9042 T11 oasl.LogWatcher.createWatcher SLF4J impl is org.slf4j.impl.Log4jLoggerFactory
[junit4] 2> 9048 T11 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
[junit4] 2> 9056 T11 oasc.CoreContainer.load Host Name:
[junit4] 2> 9570 T12 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/core/src/test-files/solr/collection1/'
[junit4] 2> 9574 T12 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/core/src/test-files/solr/collection1/lib/README' to classloader
[junit4] 2> 9575 T12 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/core/src/test-files/solr/collection1/lib/.svn/' to classloader
[junit4] 2> 9577 T12 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/core/src/test-files/solr/collection1/lib/classes/' to classloader
[junit4] 2> 9899 T12 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_5_0
[junit4] 2> 10045 T12 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4] 2> 10047 T12 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4] 2> 10154 T12 oass.IndexSchema.readSchema [collection1] Schema name=test
[junit4] 2> 10790 T12 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4] 2> 10811 T12 oass.IndexSchema.readSchema default search field in schema is text
[junit4] 2> 10815 T12 oass.IndexSchema.readSchema unique key field: id
[junit4] 2> 10861 T12 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4] 2> 10868 T12 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4] 2> 10874 T12 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4] 2> 10875 T12 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4] 2> 10876 T12 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4] 2> 10877 T12 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4] 2> 10878 T12 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4] 2> 10879 T12 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4] 2> 10883 T12 oasc.CoreContainer.create Creating SolrCore 'collection1' using configuration from instancedir /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/core/src/test-files/solr/collection1/
[junit4] 2> 11011 T12 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4] 2> 11057 T12 oasc.SolrCore.<init> [collection1] Opening new SolrCore at /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/core/src/test-files/solr/collection1/, dataDir=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J0/./solr.update.SoftAutoCommitTest-C17ACE2B3DC4F930-001/init-core-data-001/
[junit4] 2> 11065 T12 oasc.JmxMonitoredMap.<init> No JMX servers found, not exposing Solr information with JMX.
[junit4] 2> 11207 T12 oasc.CachingDirectoryFactory.get return new directory for /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J0/./solr.update.SoftAutoCommitTest-C17ACE2B3DC4F930-001/init-core-data-001
[junit4] 2> 11209 T12 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J0/./solr.update.SoftAutoCommitTest-C17ACE2B3DC4F930-001/init-core-data-001/index/
[junit4] 2> 11210 T12 oasc.SolrCore.initIndex WARN [collection1] Solr index directory '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J0/./solr.update.SoftAutoCommitTest-C17ACE2B3DC4F930-001/init-core-data-001/index' doesn't exist. Creating new index...
[junit4] 2> 11230 T12 oasc.CachingDirectoryFactory.get return new directory for /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J0/./solr.update.SoftAutoCommitTest-C17ACE2B3DC4F930-001/init-core-data-001/index
[junit4] 2> 11232 T12 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: maxMergeAtOnce=29, maxMergeAtOnceExplicit=27, maxMergedSegmentMB=44.1083984375, floorSegmentMB=0.2109375, forceMergeDeletesPctAllowed=12.203476784114914, segmentsPerTier=13.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.7977350703196885
[junit4] 2> 11488 T12 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
[junit4] 2> commit{dir=RateLimitedDirectoryWrapper(MockDirectoryWrapper(RAMDirectory@66d24521 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@4ea4453)),segFN=segments_1,generation=1}
[junit4] 2> 11493 T12 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4] 2> 11558 T12 oasc.SolrCore.initWriters created xml: solr.XMLResponseWriter
[junit4] 2> 12740 T12 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "dedupe"
[junit4] 2> 12909 T12 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4] 2> 12911 T12 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "dedupe-allfields"
[junit4] 2> 12912 T12 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe-allfields"
[junit4] 2> 12913 T12 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "stored_sig"
[junit4] 2> 12914 T12 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4] 2> 12915 T12 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "uniq-fields"
[junit4] 2> 12959 T12 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "uniq-fields"
[junit4] 2> 12960 T12 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-explicit"
[junit4] 2> 13178 T12 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4] 2> 13179 T12 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4] 2> 13179 T12 oasc.SolrCore.loadUpdateProcessorChains no updateRequestProcessorChain defined as default, creating implicit default
[junit4] 2> 13197 T12 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4] 2> 13203 T12 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4] 2> 13251 T12 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4] 2> 13289 T12 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4] 2> 13405 T12 oasc.RequestHandlers.initHandlersFromConfig created dismax: solr.SearchHandler
[junit4] 2> 13407 T12 oasc.RequestHandlers.initHandlersFromConfig created mock: org.apache.solr.core.MockQuerySenderListenerReqHandler
[junit4] 2> 13414 T12 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4] 2> 13469 T12 oasc.RequestHandlers.initHandlersFromConfig created /admin/file: solr.admin.ShowFileRequestHandler
[junit4] 2> 13503 T12 oasc.RequestHandlers.initHandlersFromConfig created /admin/fileedit: solr.admin.EditFileRequestHandler
[junit4] 2> 13504 T12 oasc.RequestHandlers.initHandlersFromConfig created defaults: solr.StandardRequestHandler
[junit4] 2> 13504 T12 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.StandardRequestHandler
[junit4] 2> 13505 T12 oasc.RequestHandlers.initHandlersFromConfig created lazy: solr.StandardRequestHandler
[junit4] 2> 13540 T12 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4] 2> 13541 T12 oasc.RequestHandlers.initHandlersFromConfig created /terms: org.apache.solr.handler.component.SearchHandler
[junit4] 2> 13542 T12 oasc.RequestHandlers.initHandlersFromConfig created spellCheckCompRH: org.apache.solr.handler.component.SearchHandler
[junit4] 2> 13542 T12 oasc.RequestHandlers.initHandlersFromConfig created spellCheckCompRH_Direct: org.apache.solr.handler.component.SearchHandler
[junit4] 2> 13543 T12 oasc.RequestHandlers.initHandlersFromConfig created spellCheckWithWordbreak: org.apache.solr.handler.component.SearchHandler
[junit4] 2> 13543 T12 oasc.RequestHandlers.initHandlersFromConfig created spellCheckWithWordbreak_Direct: org.apache.solr.handler.component.SearchHandler
[junit4] 2> 13544 T12 oasc.RequestHandlers.initHandlersFromConfig created spellCheckCompRH1: org.apache.solr.handler.component.SearchHandler
[junit4] 2> 13545 T12 oasc.RequestHandlers.initHandlersFromConfig created mltrh: org.apache.solr.handler.component.SearchHandler
[junit4] 2> 13545 T12 oasc.RequestHandlers.initHandlersFromConfig created tvrh: org.apache.solr.handler.component.SearchHandler
[junit4] 2> 13577 T12 oasc.RequestHandlers.initHandlersFromConfig created /mlt: solr.MoreLikeThisHandler
[junit4] 2> 13615 T12 oasc.RequestHandlers.initHandlersFromConfig created /debug/dump: solr.DumpRequestHandler
[junit4] 2> 13768 T12 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4] 2> 13804 T12 oasc.SolrCore.initDeprecatedSupport WARN solrconfig.xml uses deprecated <admin/gettableFiles>, Please update your config to use the ShowFileRequestHandler.
[junit4] 2> 13940 T12 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4] 2> 13941 T12 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4] 2> 13943 T12 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: maxMergeAtOnce=47, maxMergeAtOnceExplicit=43, maxMergedSegmentMB=72.4609375, floorSegmentMB=2.18359375, forceMergeDeletesPctAllowed=10.20115932009782, segmentsPerTier=42.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.6510653684093802
[junit4] 2> 13952 T12 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=1
[junit4] 2> commit{dir=RateLimitedDirectoryWrapper(MockDirectoryWrapper(RAMDirectory@66d24521 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@4ea4453)),segFN=segments_1,generation=1}
[junit4] 2> 13953 T12 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4] 2> 14055 T12 oass.SolrIndexSearcher.<init> Opening Searcher@68e6e750[collection1] main
[junit4] 2> 14137 T12 oasr.RestManager.init Initializing RestManager with initArgs: {storageIO=org.apache.solr.rest.ManagedResourceStorage$InMemoryStorageIO}
[junit4] 2> 14262 T12 oasr.ManagedResourceStorage.load Reading _rest_managed.json using InMemoryStorage
[junit4] 2> 14262 T12 oasr.ManagedResource.reloadFromStorage WARN No stored data found for /rest/managed
[junit4] 2> 14263 T12 oasr.ManagedResource.notifyObserversDuringInit WARN No registered observers for /rest/managed
[junit4] 2> 14263 T12 oasr.RestManager.init Initializing 0 registered ManagedResources
[junit4] 2> 14264 T12 oashc.SpellCheckComponent.inform Initializing spell checkers
[junit4] 2> 14544 T12 oass.DirectSolrSpellChecker.init init: {name=direct,classname=DirectSolrSpellChecker,field=lowerfilt,minQueryLength=3}
[junit4] 2> 15040 T13 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@68e6e750[collection1] main{StandardDirectoryReader(segments_1:1:nrt)}
[junit4] 2> 15044 T12 oasc.CoreContainer.registerCore registering core: collection1
[junit4] 2> 15066 T11 oas.SolrTestCaseJ4.initCore ####initCore end
[junit4] 2> 15111 T11 oas.SolrTestCaseJ4.setUp ###Starting testSoftAndHardCommitMaxTimeRapidAdds
[junit4] 2> 15111 T11 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/core/src/test-files/solr/collection1/'
[junit4] 2> 15113 T11 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/core/src/test-files/solr/collection1/lib/README' to classloader
[junit4] 2> 15114 T11 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/core/src/test-files/solr/collection1/lib/.svn/' to classloader
[junit4] 2> 15115 T11 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/core/src/test-files/solr/collection1/lib/classes/' to classloader
[junit4] 2> 15275 T11 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_5_0
[junit4] 2> 15370 T11 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4] 2> 15371 T11 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4] 2> 15428 T11 oass.IndexSchema.readSchema [collection1] Schema name=test
[junit4] 2> 16001 T11 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4] 2> 16019 T11 oass.IndexSchema.readSchema default search field in schema is text
[junit4] 2> 16022 T11 oass.IndexSchema.readSchema unique key field: id
[junit4] 2> 16058 T11 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4] 2> 16065 T11 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4] 2> 16072 T11 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4] 2> 16073 T11 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4] 2> 16074 T11 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4] 2> 16075 T11 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4] 2> 16075 T11 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4] 2> 16076 T11 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4] 2> 16077 T11 oasc.CoreContainer.reload Reloading SolrCore 'collection1' using configuration from instancedir /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/core/src/test-files/solr/collection1/
[junit4] 2> 16078 T11 oasc.SolrCore.<init> [collection1] Opening new SolrCore at /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/core/src/test-files/solr/collection1/, dataDir=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J0/./solr.update.SoftAutoCommitTest-C17ACE2B3DC4F930-001/init-core-data-001/
[junit4] 2> 16078 T11 oasc.JmxMonitoredMap.<init> No JMX servers found, not exposing Solr information with JMX.
[junit4] 2> 16079 T11 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J0/./solr.update.SoftAutoCommitTest-C17ACE2B3DC4F930-001/init-core-data-001/index/
[junit4] 2> 16080 T11 oasc.SolrCore.initWriters created xml: solr.XMLResponseWriter
[junit4] 2> 16082 T11 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "dedupe"
[junit4] 2> 16083 T11 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4] 2> 16083 T11 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "dedupe-allfields"
[junit4] 2> 16084 T11 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe-allfields"
[junit4] 2> 16084 T11 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "stored_sig"
[junit4] 2> 16085 T11 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4] 2> 16086 T11 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "uniq-fields"
[junit4] 2> 16086 T11 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "uniq-fields"
[junit4] 2> 16087 T11 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-explicit"
[junit4] 2> 16088 T11 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4] 2> 16089 T11 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4] 2> 16089 T11 oasc.SolrCore.loadUpdateProcessorChains no updateRequestProcessorChain defined as default, creating implicit default
[junit4] 2> 16090 T11 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4] 2> 16090 T11 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4] 2> 16091 T11 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4] 2> 16092 T11 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4] 2> 16092 T11 oasc.RequestHandlers.initHandlersFromConfig created dismax: solr.SearchHandler
[junit4] 2> 16093 T11 oasc.RequestHandlers.initHandlersFromConfig created mock: org.apache.solr.core.MockQuerySenderListenerReqHandler
[junit4] 2> 16094 T11 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4] 2> 16094 T11 oasc.RequestHandlers.initHandlersFromConfig created /admin/file: solr.admin.ShowFileRequestHandler
[junit4] 2> 16095 T11 oasc.RequestHandlers.initHandlersFromConfig created /admin/fileedit: solr.admin.EditFileRequestHandler
[junit4] 2> 16095 T11 oasc.RequestHandlers.initHandlersFromConfig created defaults: solr.StandardRequestHandler
[junit4] 2> 16096 T11 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.StandardRequestHandler
[junit4] 2> 16097 T11 oasc.RequestHandlers.initHandlersFromConfig created lazy: solr.StandardRequestHandler
[junit4] 2> 16097 T11 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4] 2> 16098 T11 oasc.RequestHandlers.initHandlersFromConfig created /terms: org.apache.solr.handler.component.SearchHandler
[junit4] 2> 16098 T11 oasc.RequestHandlers.initHandlersFromConfig created spellCheckCompRH: org.apache.solr.handler.component.SearchHandler
[junit4] 2> 16099 T11 oasc.RequestHandlers.initHandlersFromConfig created spellCheckCompRH_Direct: org.apache.solr.handler.component.SearchHandler
[junit4] 2> 16100 T11 oasc.RequestHandlers.initHandlersFromConfig created spellCheckWithWordbreak: org.apache.solr.handler.component.SearchHandler
[junit4] 2> 16100 T11 oasc.RequestHandlers.initHandlersFromConfig created spellCheckWithWordbreak_Direct: org.apache.solr.handler.component.SearchHandler
[junit4] 2> 16101 T11 oasc.RequestHandlers.initHandlersFromConfig created spellCheckCompRH1: org.apache.solr.handler.component.SearchHandler
[junit4] 2> 16102 T11 oasc.RequestHandlers.initHandlersFromConfig created mltrh: org.apache.solr.handler.component.SearchHandler
[junit4] 2> 16103 T11 oasc.RequestHandlers.initHandlersFromConfig created tvrh: org.apache.solr.handler.component.SearchHandler
[junit4] 2> 16103 T11 oasc.RequestHandlers.initHandlersFromConfig created /mlt: solr.MoreLikeThisHandler
[junit4] 2> 16104 T11 oasc.RequestHandlers.initHandlersFromConfig created /debug/dump: solr.DumpRequestHandler
[junit4] 2> 16119 T11 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4] 2> 16122 T11 oasc.SolrCore.initDeprecatedSupport WARN solrconfig.xml uses deprecated <admin/gettableFiles>, Please update your config to use the ShowFileRequestHandler.
[junit4] 2> 16129 T11 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4] 2> 16130 T11 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4] 2> 16131 T11 oass.SolrIndexSearcher.<init> Opening Searcher@49968124[collection1] main
[junit4] 2> 16132 T11 oasr.RestManager.init Initializing RestManager with initArgs: {storageIO=org.apache.solr.rest.ManagedResourceStorage$InMemoryStorageIO}
[junit4] 2> 16132 T11 oasr.ManagedResourceStorage.load Reading _rest_managed.json using InMemoryStorage
[junit4] 2> 16133 T11 oasr.ManagedResource.reloadFromStorage WARN No stored data found for /rest/managed
[junit4] 2> 16134 T11 oasr.ManagedResource.notifyObserversDuringInit WARN No registered observers for /rest/managed
[junit4] 2> 16134 T11 oasr.RestManager.init Initializing 0 registered ManagedResources
[junit4] 2> 16135 T11 oashc.SpellCheckComponent.inform Initializing spell checkers
[junit4] 2> 16138 T11 oass.DirectSolrSpellChecker.init init: {name=direct,classname=DirectSolrSpellChecker,field=lowerfilt,minQueryLength=3}
[junit4] 2> 16158 T11 oasu.DefaultSolrCoreState.newIndexWriter Creating new IndexWriter...
[junit4] 2> 16158 T15 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@49968124[collection1] main{StandardDirectoryReader(segments_1:1:nrt)}
[junit4] 2> 16159 T11 oasu.DefaultSolrCoreState.newIndexWriter Waiting until IndexWriter is unused... core=collection1
[junit4] 2> 16160 T11 oasu.DefaultSolrCoreState.newIndexWriter Closing old IndexWriter... core=collection1
[junit4] 2> 16163 T11 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.LogByteSizeMergePolicy: [LogByteSizeMergePolicy: minMergeSize=1677721, mergeFactor=30, maxMergeSize=2147483648, maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=true, maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.4979091124492163]
[junit4] 2> 16165 T11 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=1
[junit4] 2> commit{dir=RateLimitedDirectoryWrapper(MockDirectoryWrapper(RAMDirectory@66d24521 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@4ea4453)),segFN=segments_1,generation=1}
[junit4] 2> 16166 T11 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4] 2> 16167 T11 oasu.DefaultSolrCoreState.newIndexWriter New IndexWriter is ready to be used.
[junit4] 2> 16168 T11 oass.SolrIndexSearcher.<init> Opening Searcher@44939656[collection1] main
[junit4] 2> 16175 T11 oasc.CoreContainer.registerCore replacing core: collection1
[junit4] 2> 16176 T11 oasc.SolrCore.close [collection1] CLOSING SolrCore org.apache.solr.core.SolrCore@3deb4583
[junit4] 2> 16177 T11 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> 16178 T11 oasc.SolrCore.closeSearcher [collection1] Closing main searcher on request.
[junit4] 2> 16202 T15 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@44939656[collection1] main{StandardDirectoryReader(segments_1:1:nrt)}
[junit4] 2> ASYNC NEW_CORE C0 name=collection1 org.apache.solr.core.SolrCore@66b4c2e4
[junit4] 2> 17334 T11 C0 oasup.LogUpdateProcessor.finish [collection1] webapp=null path=null params={} {add=[5000 (1466988275083247616)]} 0 1135
[junit4] 2> 17441 T11 C0 oasup.LogUpdateProcessor.finish [collection1] webapp=null path=null params={} {add=[5001 (1466988275728121856)]} 0 3
[junit4] 2> 17457 T11 C0 oasup.LogUpdateProcessor.finish [collection1] webapp=null path=null params={} {add=[5002 (1466988275735461888)]} 0 12
[junit4] 2> 17464 T11 C0 oasup.LogUpdateProcessor.finish [collection1] webapp=null path=null params={} {add=[5003 (1466988275752239104)]} 0 3
[junit4] 2> 17470 T11 C0 oasup.LogUpdateProcessor.finish [collection1] webapp=null path=null params={} {add=[5004 (1466988275759579136)]} 0 2
[junit4] 2> 17820 T17 oasu.DirectUpdateHandler2.commit start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=true,prepareCommit=false}
[junit4] 2> 18520 T16 oasu.DirectUpdateHandler2.commit start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4] 2> 18597 T17 oass.SolrIndexSearcher.<init> Opening Searcher@3ef0642[collection1] main
[junit4] 2> 18605 T17 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4] 2> 18605 T15 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@3ef0642[collection1] main{StandardDirectoryReader(segments_1:3:nrt _0(5.0):c5)}
[junit4] 2> 18607 T16 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=2
[junit4] 2> commit{dir=RateLimitedDirectoryWrapper(MockDirectoryWrapper(RAMDirectory@66d24521 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@4ea4453)),segFN=segments_1,generation=1}
[junit4] 2> commit{dir=RateLimitedDirectoryWrapper(MockDirectoryWrapper(RAMDirectory@66d24521 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@4ea4453)),segFN=segments_2,generation=2}
[junit4] 2> 18607 T16 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 2
[junit4] 2> 18608 T16 oasc.SolrCore.openNewSearcher SolrIndexSearcher has not changed - not re-opening: org.apache.solr.search.SolrIndexSearcher
[junit4] 2> 18610 T16 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4] 2> 18823 T11 oas.SolrTestCaseJ4.tearDown ###Ending testSoftAndHardCommitMaxTimeRapidAdds
[junit4] 2> NOTE: reproduce with: ant test -Dtestcase=SoftAutoCommitTest -Dtests.method=testSoftAndHardCommitMaxTimeRapidAdds -Dtests.seed=C17ACE2B3DC4F930 -Dtests.multiplier=3 -Dtests.slow=true -Dtests.locale=es_BO -Dtests.timezone=IET -Dtests.file.encoding=US-ASCII
[junit4] FAILURE 3.83s J0 | SoftAutoCommitTest.testSoftAndHardCommitMaxTimeRapidAdds <<<
[junit4] > Throwable #1: java.lang.AssertionError: 2: soft wasn't fast enough
[junit4] > at __randomizedtesting.SeedInfo.seed([C17ACE2B3DC4F930:9D6F6012D646B848]:0)
[junit4] > at org.apache.solr.update.SoftAutoCommitTest.testSoftAndHardCommitMaxTimeRapidAdds(SoftAutoCommitTest.java:316)
[junit4] > at java.lang.Thread.run(Thread.java:724)
[junit4] 2> 18915 T11 oas.SolrTestCaseJ4.setUp ###Starting testSoftAndHardCommitMaxTimeMixedAdds
[junit4] 2> 18916 T11 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/core/src/test-files/solr/collection1/'
[junit4] 2> 18918 T11 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/core/src/test-files/solr/collection1/lib/README' to classloader
[junit4] 2> 18918 T11 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/core/src/test-files/solr/collection1/lib/.svn/' to classloader
[junit4] 2> 18919 T11 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/core/src/test-files/solr/collection1/lib/classes/' to classloader
[junit4] 2> 19107 T11 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_5_0
[junit4] 2> 19211 T11 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4] 2> 19212 T11 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4] 2> 19262 T11 oass.IndexSchema.readSchema [collection1] Schema name=test
[junit4] 2> 19900 T11 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4] 2> 19916 T11 oass.IndexSchema.readSchema default search field in schema is text
[junit4] 2> 19930 T11 oass.IndexSchema.readSchema unique key field: id
[junit4] 2> 19955 T11 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4] 2> 19962 T11 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4] 2> 19967 T11 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4] 2> 19968 T11 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4] 2> 19969 T11 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4] 2> 19969 T11 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4] 2> 19970 T11 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4] 2> 19971 T11 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4] 2> 19971 T11 oasc.CoreContainer.reload Reloading SolrCore 'collection1' using configuration from instancedir /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/core/src/test-files/solr/collection1/
[junit4] 2> 19972 T11 oasc.SolrCore.<init> [collection1] Opening new SolrCore at /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/core/src/test-files/solr/collection1/, dataDir=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J0/./solr.update.SoftAutoCommitTest-C17ACE2B3DC4F930-001/init-core-data-001/
[junit4] 2> 19973 T11 oasc.JmxMonitoredMap.<init> No JMX servers found, not exposing Solr information with JMX.
[junit4] 2> 19973 T11 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J0/./solr.update.SoftAutoCommitTest-C17ACE2B3DC4F930-001/init-core-data-001/index/
[junit4] 2> 19974 T11 oasc.SolrCore.initWriters created xml: solr.XMLResponseWriter
[junit4] 2> 19976 T11 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "dedupe"
[junit4] 2> 19977 T11 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4] 2> 19977 T11 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "dedupe-allfields"
[junit4] 2> 19978 T11 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe-allfields"
[junit4] 2> 19978 T11 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "stored_sig"
[junit4] 2> 19979 T11 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4] 2> 19980 T11 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "uniq-fields"
[junit4] 2> 19981 T11 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "uniq-fields"
[junit4] 2> 19981 T11 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-explicit"
[junit4] 2> 19982 T11 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4] 2> 19983 T11 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4] 2> 19983 T11 oasc.SolrCore.loadUpdateProcessorChains no updateRequestProcessorChain defined as default, creating implicit default
[junit4] 2> 19984 T11 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4] 2> 19984 T11 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4] 2> 19985 T11 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4] 2> 19986 T11 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4] 2> 19986 T11 oasc.RequestHandlers.initHandlersFromConfig created dismax: solr.SearchHandler
[junit4] 2> 19987 T11 oasc.RequestHandlers.initHandlersFromConfig created mock: org.apache.solr.core.MockQuerySenderListenerReqHandler
[junit4] 2> 19987 T11 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4] 2> 19988 T11 oasc.RequestHandlers.initHandlersFromConfig created /admin/file: solr.admin.ShowFileRequestHandler
[junit4] 2> 19988 T11 oasc.RequestHandlers.initHandlersFromConfig created /admin/fileedit: solr.admin.EditFileRequestHandler
[junit4] 2> 19989 T11 oasc.RequestHandlers.initHandlersFromConfig created defaults: solr.StandardRequestHandler
[junit4] 2> 19989 T11 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.StandardRequestHandler
[junit4] 2> 19990 T11 oasc.RequestHandlers.initHandlersFromConfig created lazy: solr.StandardRequestHandler
[junit4] 2> 19990 T11 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4] 2> 19991 T11 oasc.RequestHandlers.initHandlersFromConfig created /terms: org.apache.solr.handler.component.SearchHandler
[junit4] 2> 19992 T11 oasc.RequestHandlers.initHandlersFromConfig created spellCheckCompRH: org.apache.solr.handler.component.SearchHandler
[junit4] 2> 19992 T11 oasc.RequestHandlers.initHandlersFromConfig created spellCheckCompRH_Direct: org.apache.solr.handler.component.SearchHandler
[junit4] 2> 19993 T11 oasc.RequestHandlers.initHandlersFromConfig created spellCheckWithWordbreak: org.apache.solr.handler.component.SearchHandler
[junit4] 2> 19993 T11 oasc.RequestHandlers.initHandlersFromConfig created spellCheckWithWordbreak_Direct: org.apache.solr.handler.component.SearchHandler
[junit4] 2> 19994 T11 oasc.RequestHandlers.initHandlersFromConfig created spellCheckCompRH1: org.apache.solr.handler.component.SearchHandler
[junit4] 2> 19994 T11 oasc.RequestHandlers.initHandlersFromConfig created mltrh: org.apache.solr.handler.component.SearchHandler
[junit4] 2> 19995 T11 oasc.RequestHandlers.initHandlersFromConfig created tvrh: org.apache.solr.handler.component.SearchHandler
[junit4] 2> 19995 T11 oasc.RequestHandlers.initHandlersFromConfig created /mlt: solr.MoreLikeThisHandler
[junit4] 2> 19996 T11 oasc.RequestHandlers.initHandlersFromConfig created /debug/dump: solr.DumpRequestHandler
[junit4] 2> 20018 T11 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4] 2> 20021 T11 oasc.SolrCore.initDeprecatedSupport WARN solrconfig.xml uses deprecated <admin/gettableFiles>, Please update your config to use the ShowFileRequestHandler.
[junit4] 2> 20024 T11 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4] 2> 20025 T11 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4] 2> 20026 T11 oass.SolrIndexSearcher.<init> Opening Searcher@6e6621f2[collection1] main
[junit4] 2> 20027 T11 oasr.RestManager.init Initializing RestManager with initArgs: {storageIO=org.apache.solr.rest.ManagedResourceStorage$InMemoryStorageIO}
[junit4] 2> 20027 T11 oasr.ManagedResourceStorage.load Reading _rest_managed.json using InMemoryStorage
[junit4] 2> 20028 T11 oasr.ManagedResource.reloadFromStorage WARN No stored data found for /rest/managed
[junit4] 2> 20028 T11 oasr.ManagedResource.notifyObserversDuringInit WARN No registered observers for /rest/managed
[junit4] 2> 20029 T11 oasr.RestManager.init Initializing 0 registered ManagedResources
[junit4] 2> 20029 T11 oashc.SpellCheckComponent.inform Initializing spell checkers
[junit4] 2> 20033 T11 oass.DirectSolrSpellChecker.init init: {name=direct,classname=DirectSolrSpellChecker,field=lowerfilt,minQueryLength=3}
[junit4] 2> 20050 T11 oasu.DefaultSolrCoreState.newIndexWriter Creating new IndexWriter...
[junit4] 2> 20050 T18 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@6e6621f2[collection1] main{StandardDirectoryReader(segments_2:3:nrt _0(5.0):c5)}
[junit4] 2> 20051 T11 oasu.DefaultSolrCoreState.newIndexWriter Waiting until IndexWriter is unused... core=collection1
[junit4] 2> 20052 T11 oasu.DefaultSolrCoreState.newIndexWriter Closing old IndexWriter... core=collection1
[junit4] 2> 20053 T11 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.LogDocMergePolicy: [LogDocMergePolicy: minMergeSize=1000, mergeFactor=44, maxMergeSize=9223372036854775807, maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=true, maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=1.0]
[junit4] 2> 20056 T11 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=1
[junit4] 2> commit{dir=RateLimitedDirectoryWrapper(MockDirectoryWrapper(RAMDirectory@66d24521 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@4ea4453)),segFN=segments_2,generation=2}
[junit4] 2> 20057 T11 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 2
[junit4] 2> 20057 T11 oasu.DefaultSolrCoreState.newIndexWriter New IndexWriter is ready to be used.
[junit4] 2> 20061 T11 oass.SolrIndexSearcher.<init> Opening Searcher@24fc81b4[collection1] main
[junit4] 2> 20062 T11 oasc.CoreContainer.registerCore replacing core: collection1
[junit4] 2> 20062 T18 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@24fc81b4[collection1] main{StandardDirectoryReader(segments_2:3:nrt _0(5.0):c5)}
[junit4] 2> 20062 T11 oasc.SolrCore.close [collection1] CLOSING SolrCore org.apache.solr.core.SolrCore@66b4c2e4
[junit4] 2> 20064 T11 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=5,cumulative_deletesById=0,cumulative_deletesByQuery=0,cumulative_errors=0,transaction_logs_total_size=339,transaction_logs_total_number=1}
[junit4] 2> 20064 T11 oasc.SolrCore.closeSearcher [collection1] Closing main searcher on request.
[junit4] 2> ASYNC NEW_CORE C1 name=collection1 org.apache.solr.core.SolrCore@5eb29f87
[junit4] 2> 20070 T11 C1 oasup.LogUpdateProcessor.finish [collection1] webapp=null path=null params={} {add=[529 (1466988278483779584)]} 0 4
[junit4] 2> 20571 T20 oasu.DirectUpdateHandler2.commit start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=true,prepareCommit=false}
[junit4] 2> 20703 T20 oass.SolrIndexSearcher.<init> Opening Searcher@78d6df62[collection1] main
[junit4] 2> 20704 T20 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4] 2> 20704 T18 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@78d6df62[collection1] main{StandardDirectoryReader(segments_2:5:nrt _0(5.0):c5 _1(5.0):c1)}
[junit4] 2> 20707 T11 C1 oasup.LogUpdateProcessor.finish [collection1] webapp=null path=null params={} {add=[530 (1466988279153819648)]} 0 3
[junit4] 2> 21208 T20 oasu.DirectUpdateHandler2.commit start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=true,prepareCommit=false}
[junit4] 2> 21217 T20 oass.SolrIndexSearcher.<init> Opening Searcher@106db9f5[collection1] main
[junit4] 2> 21218 T20 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4] 2> 21218 T18 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@106db9f5[collection1] main{StandardDirectoryReader(segments_2:7:nrt _0(5.0):c5 _1(5.0):c1 _2(5.0):c1)}
[junit4] 2> 21271 T19 oasu.DirectUpdateHandler2.commit start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4] 2> 21272 T19 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=2
[junit4] 2> commit{dir=RateLimitedDirectoryWrapper(MockDirectoryWrapper(RAMDirectory@66d24521 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@4ea4453)),segFN=segments_2,generation=2}
[junit4] 2> commit{dir=RateLimitedDirectoryWrapper(MockDirectoryWrapper(RAMDirectory@66d24521 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@4ea4453)),segFN=segments_3,generation=3}
[junit4] 2> 21273 T19 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 3
[junit4] 2> 21274 T19 oasc.SolrCore.openNewSearcher SolrIndexSearcher has not changed - not re-opening: org.apache.solr.search.SolrIndexSearcher
[junit4] 2> 21274 T19 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4] 2> 24476 T11 oas.SolrTestCaseJ4.tearDown ###Ending testSoftAndHardCommitMaxTimeMixedAdds
[junit4] 2> 24671 T11 oas.SolrTestCaseJ4.setUp ###Starting testSoftAndHardCommitMaxTimeDelete
[junit4] 2> 24671 T11 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/core/src/test-files/solr/collection1/'
[junit4] 2> 24673 T11 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/core/src/test-files/solr/collection1/lib/README' to classloader
[junit4] 2> 24673 T11 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/core/src/test-files/solr/collection1/lib/.svn/' to classloader
[junit4] 2> 24674 T11 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/core/src/test-files/solr/collection1/lib/classes/' to classloader
[junit4] 2> 24824 T11 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_5_0
[junit4] 2> 24918 T11 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4] 2> 24919 T11 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4] 2> 24960 T11 oass.IndexSchema.readSchema [collection1] Schema name=test
[junit4] 2> 25519 T11 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4] 2> 25536 T11 oass.IndexSchema.readSchema default search field in schema is text
[junit4] 2> 25540 T11 oass.IndexSchema.readSchema unique key field: id
[junit4] 2> 25563 T11 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4] 2> 25572 T11 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4] 2> 25578 T11 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4] 2> 25579 T11 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4] 2> 25579 T11 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4] 2> 25580 T11 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4] 2> 25581 T11 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4] 2> 25581 T11 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4] 2> 25582 T11 oasc.CoreContainer.reload Reloading SolrCore 'collection1' using configuration from instancedir /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/core/src/test-files/solr/collection1/
[junit4] 2> 25582 T11 oasc.SolrCore.<init> [collection1] Opening new SolrCore at /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/core/src/test-files/solr/collection1/, dataDir=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J0/./solr.update.SoftAutoCommitTest-C17ACE2B3DC4F930-001/init-core-data-001/
[junit4] 2> 25583 T11 oasc.JmxMonitoredMap.<init> No JMX servers found, not exposing Solr information with JMX.
[junit4] 2> 25583 T11 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J0/./solr.update.SoftAutoCommitTest-C17ACE2B3DC4F930-001/init-core-data-001/index/
[junit4] 2> 25584 T11 oasc.SolrCore.initWriters created xml: solr.XMLResponseWriter
[junit4] 2> 25586 T11 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "dedupe"
[junit4] 2> 25587 T11 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4] 2> 25587 T11 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "dedupe-allfields"
[junit4] 2> 25588 T11 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe-allfields"
[junit4] 2> 25588 T11 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "stored_sig"
[junit4] 2> 25589 T11 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4] 2> 25589 T11 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "uniq-fields"
[junit4] 2> 25590 T11 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "uniq-fields"
[junit4] 2> 25590 T11 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-explicit"
[junit4] 2> 25591 T11 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4] 2> 25592 T11 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4] 2> 25592 T11 oasc.SolrCore.loadUpdateProcessorChains no updateRequestProcessorChain defined as default, creating implicit default
[junit4] 2> 25593 T11 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4] 2> 25593 T11 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4] 2> 25594 T11 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4] 2> 25594 T11 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4] 2> 25595 T11 oasc.RequestHandlers.initHandlersFromConfig created dismax: solr.SearchHandler
[junit4] 2> 25595 T11 oasc.RequestHandlers.initHandlersFromConfig created mock: org.apache.solr.core.MockQuerySenderListenerReqHandler
[junit4] 2> 25596 T11 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4] 2> 25596 T11 oasc.RequestHandlers.initHandlersFromConfig created /admin/file: solr.admin.ShowFileRequestHandler
[junit4] 2> 25597 T11 oasc.RequestHandlers.initHandlersFromConfig created /admin/fileedit: solr.admin.EditFileRequestHandler
[junit4] 2> 25598 T11 oasc.RequestHandlers.initHandlersFromConfig created defaults: solr.StandardRequestHandler
[junit4] 2> 25598 T11 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.StandardRequestHandler
[junit4] 2> 25598 T11 oasc.RequestHandlers.initHandlersFromConfig created lazy: solr.StandardRequestHandler
[junit4] 2> 25599 T11 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4] 2> 25600 T11 oasc.RequestHandlers.initHandlersFromConfig created /terms: org.apache.solr.handler.component.SearchHandler
[junit4] 2> 25600 T11 oasc.RequestHandlers.initHandlersFromConfig created spellCheckCompRH: org.apache.solr.handler.component.SearchHandler
[junit4] 2> 25601 T11 oasc.RequestHandlers.initHandlersFromConfig created spellCheckCompRH_Direct: org.apache.solr.handler.component.SearchHandler
[junit4] 2> 25601 T11 oasc.RequestHandlers.initHandlersFromConfig created spellCheckWithWordbreak: org.apache.solr.handler.component.SearchHandler
[junit4] 2> 25602 T11 oasc.RequestHandlers.initHandlersFromConfig created spellCheckWithWordbreak_Direct: org.apache.solr.handler.component.SearchHandler
[junit4] 2> 25602 T11 oasc.RequestHandlers.initHandlersFromConfig created spellCheckCompRH1: org.apache.solr.handler.component.SearchHandler
[junit4] 2> 25603 T11 oasc.RequestHandlers.initHandlersFromConfig created mltrh: org.apache.solr.handler.component.SearchHandler
[junit4] 2> 25603 T11 oasc.RequestHandlers.initHandlersFromConfig created tvrh: org.apache.solr.handler.component.SearchHandler
[junit4] 2> 25604 T11 oasc.RequestHandlers.initHandlersFromConfig created /mlt: solr.MoreLikeThisHandler
[junit4] 2> 25604 T11 oasc.RequestHandlers.initHandlersFromConfig created /debug/dump: solr.DumpRequestHandler
[junit4] 2> 25624 T11 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4] 2> 25627 T11 oasc.SolrCore.initDeprecatedSupport WARN solrconfig.xml uses deprecated <admin/gettableFiles>, Please update your config to use the ShowFileRequestHandler.
[junit4] 2> 25630 T11 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4] 2> 25630 T11 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4] 2> 25631 T11 oass.SolrIndexSearcher.<init> Opening Searcher@46ffcd87[collection1] main
[junit4] 2> 25632 T11 oasr.RestManager.init Initializing RestManager with initArgs: {storageIO=org.apache.solr.rest.ManagedResourceStorage$InMemoryStorageIO}
[junit4] 2> 25633 T11 oasr.ManagedResourceStorage.load Reading _rest_managed.json using InMemoryStorage
[junit4] 2> 25633 T11 oasr.ManagedResource.reloadFromStorage WARN No stored data found for /rest/managed
[junit4] 2> 25634 T11 oasr.ManagedResource.notifyObserversDuringInit WARN No registered observers for /rest/managed
[junit4] 2> 25634 T11 oasr.RestManager.init Initializing 0 registered ManagedResources
[junit4] 2> 25635 T11 oashc.SpellCheckComponent.inform Initializing spell checkers
[junit4] 2> 25638 T11 oass.DirectSolrSpellChecker.init init: {name=direct,classname=DirectSolrSpellChecker,field=lowerfilt,minQueryLength=3}
[junit4] 2> 25653 T11 oasu.DefaultSolrCoreState.newIndexWriter Creating new IndexWriter...
[junit4] 2> 25653 T21 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@46ffcd87[collection1] main{StandardDirectoryReader(segments_3:7:nrt _0(5.0):c5 _1(5.0):c1 _2(5.0):c1)}
[junit4] 2> 25654 T11 oasu.DefaultSolrCoreState.newIndexWriter Waiting until IndexWriter is unused... core=collection1
[junit4] 2> 25655 T11 oasu.DefaultSolrCoreState.newIndexWriter Closing old IndexWriter... core=collection1
[junit4] 2> 25656 T11 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: maxMergeAtOnce=46, maxMergeAtOnceExplicit=38, maxMergedSegmentMB=96.0751953125, floorSegmentMB=1.5087890625, forceMergeDeletesPctAllowed=13.080225435974786, segmentsPerTier=30.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.0
[junit4] 2> 25662 T11 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=1
[junit4] 2> commit{dir=RateLimitedDirectoryWrapper(MockDirectoryWrapper(RAMDirectory@66d24521 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@4ea4453)),segFN=segments_3,generation=3}
[junit4] 2> 25662 T11 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 3
[junit4] 2> 25663 T11 oasu.DefaultSolrCoreState.newIndexWriter New IndexWriter is ready to be used.
[junit4] 2> 25671 T11 oass.SolrIndexSearcher.<init> Opening Searcher@31d0f86e[collection1] main
[junit4] 2> 25672 T11 oasc.CoreContainer.registerCore replacing core: collection1
[junit4] 2> 25672 T21 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@31d0f86e[collection1] main{StandardDirectoryReader(segments_3:7:nrt _0(5.0):c5 _1(5.0):c1 _2(5.0):c1)}
[junit4] 2> 25673 T11 oasc.SolrCore.close [collection1] CLOSING SolrCore org.apache.solr.core.SolrCore@5eb29f87
[junit4] 2> 25674 T11 oasu.DirectUpdateHandler2.close closing DirectUpdateHandler2{commits=3,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=0,cumulative_deletesByQuery=0,cumulative_errors=0,transaction_logs_total_size=544,transaction_logs_total_number=2}
[junit4] 2> 25675 T11 oasc.SolrCore.closeSearcher [collection1] Closing main searcher on request.
[junit4] 2> ASYNC NEW_CORE C2 name=collection1 org.apache.solr.core.SolrCore@752e9f4
[junit4] 2> 25681 T11 C2 oasup.LogUpdateProcessor.finish [collection1] webapp=null path=null params={} {add=[529 (1466988284367339520)]} 0 5
[junit4] 2> 25684 T11 C2 oasu.DirectUpdateHandler2.commit start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4] 2> ASYNC NEW_CORE C3 name=collection1 org.apache.solr.core.SolrCore@752e9f4
[junit4] 2> 25766 T11 C3 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=2
[junit4] 2> commit{dir=RateLimitedDirectoryWrapper(MockDirectoryWrapper(RAMDirectory@66d24521 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@4ea4453)),segFN=segments_3,generation=3}
[junit4] 2> commit{dir=RateLimitedDirectoryWrapper(MockDirectoryWrapper(RAMDirectory@66d24521 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@4ea4453)),segFN=segments_4,generation=4}
[junit4] 2> 25767 T11 C3 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 4
[junit4] 2> 25771 T11 C3 oass.SolrIndexSearcher.<init> Opening Searcher@21fc554b[collection1] main
[junit4] 2> 25772 T11 C3 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4] 2> 25772 T21 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@21fc554b[collection1] main{StandardDirectoryReader(segments_4:11:nrt _0(5.0):c5 _2(5.0):c1 _3(5.0):c1)}
[junit4] 2> 25773 T11 C3 oasup.LogUpdateProcessor.finish [collection1] webapp=null path=null params={} {commit=} 0 89
[junit4] 2> 25780 T11 C3 oasup.LogUpdateProcessor.finish [collection1] webapp=null path=null params={} {delete=[529 (-1466988284473245696)]} 0 3
[junit4] 2> 26282 T23 oasu.DirectUpdateHandler2.commit start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=true,prepareCommit=false}
[junit4] 2> 26289 T23 oass.SolrIndexSearcher.<init> Opening Searcher@67095e4[collection1] main
[junit4] 2> 26289 T23 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4] 2> 26290 T21 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@67095e4[collection1] main{StandardDirectoryReader(segments_4:13:nrt _0(5.0):c5 _2(5.0):c1)}
[junit4] 2> 26292 T11 C3 oasup.LogUpdateProcessor.finish [collection1] webapp=null path=null params={} {add=[550 (1466988285010116608)]} 0 2
[junit4] 2> 26793 T23 oasu.DirectUpdateHandler2.commit start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=true,prepareCommit=false}
[junit4] 2> 26805 T23 oass.SolrIndexSearcher.<init> Opening Searcher@72c58d7f[collection1] main
[junit4] 2> 26806 T23 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4] 2> 26806 T21 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@72c58d7f[collection1] main{StandardDirectoryReader(segments_4:15:nrt _0(5.0):c5 _2(5.0):c1 _4(5.0):c1)}
[junit4] 2> 26982 T22 oasu.DirectUpdateHandler2.commit start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4] 2> 26984 T22 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=2
[junit4] 2> commit{dir=RateLimitedDirectoryWrapper(MockDirectoryWrapper(RAMDirectory@66d24521 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@4ea4453)),segFN=segments_4,generation=4}
[junit4] 2> commit{dir=RateLimitedDirectoryWrapper(MockDirectoryWrapper(RAMDirectory@66d24521 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@4ea4453)),segFN=segments_5,generation=5}
[junit4] 2> 26985 T22 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 5
[junit4] 2> 26986 T22 oasc.SolrCore.openNewSearcher SolrIndexSearcher has not changed - not re-opening: org.apache.solr.search.SolrIndexSearcher
[junit4] 2> 26987 T22 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4] 2> 28987 T11 oas.SolrTestCaseJ4.tearDown ###Ending testSoftAndHardCommitMaxTimeDelete
[junit4] 2> 28993 T11 oas.SolrTestCaseJ4.deleteCore ###deleteCore
[junit4] 2> 28993 T11 oasc.CoreContainer.shutdown Shutting down CoreContainer instance=717690625
[junit4] 2> 28994 T11 oasc.SolrCore.close [collection1] CLOSING SolrCore org.apache.solr.core.SolrCore@752e9f4
[junit4] 2> 28995 T11 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=838,transaction_logs_total_number=4}
[junit4] 2> 28996 T11 oasu.SolrCoreState.decrefSolrCoreState Closing SolrCoreState
[junit4] 2> 28997 T11 oasu.DefaultSolrCoreState.closeIndexWriter SolrCoreState ref count has reached 0 - closing IndexWriter
[junit4] 2> 28998 T11 oasu.DefaultSolrCoreState.closeIndexWriter closing IndexWriter with IndexWriterCloser
[junit4] 2> 28999 T11 oasc.SolrCore.closeSearcher [collection1] Closing main searcher on request.
[junit4] 2> 29001 T11 oasc.CachingDirectoryFactory.close Closing MockDirectoryFactory - 2 directories currently being tracked
[junit4] 2> 29002 T11 oasc.CachingDirectoryFactory.closeCacheValue looking to close /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J0/./solr.update.SoftAutoCommitTest-C17ACE2B3DC4F930-001/init-core-data-001 [CachedDir<<refCount=0;path=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J0/./solr.update.SoftAutoCommitTest-C17ACE2B3DC4F930-001/init-core-data-001;done=false>>]
[junit4] 2> 29003 T11 oasc.CachingDirectoryFactory.close Closing directory: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J0/./solr.update.SoftAutoCommitTest-C17ACE2B3DC4F930-001/init-core-data-001
[junit4] 2> 29004 T11 oasc.CachingDirectoryFactory.closeCacheValue looking to close /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J0/./solr.update.SoftAutoCommitTest-C17ACE2B3DC4F930-001/init-core-data-001/index [CachedDir<<refCount=0;path=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J0/./solr.update.SoftAutoCommitTest-C17ACE2B3DC4F930-001/init-core-data-001/index;done=false>>]
[junit4] 2> 29004 T11 oasc.CachingDirectoryFactory.close Closing directory: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J0/./solr.update.SoftAutoCommitTest-C17ACE2B3DC4F930-001/init-core-data-001/index
[junit4] 2> NOTE: leaving temporary files on disk at: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J0/./solr.update.SoftAutoCommitTest-C17ACE2B3DC4F930-001
[junit4] 2> NOTE: test params are: codec=FastCompressingStoredFields(storedFieldsFormat=CompressingStoredFieldsFormat(compressionMode=FAST, chunkSize=158), termVectorsFormat=CompressingTermVectorsFormat(compressionMode=FAST, chunkSize=158)), sim=DefaultSimilarity, locale=es_BO, timezone=IET
[junit4] 2> NOTE: FreeBSD 9.1-RELEASE-p3 amd64/Oracle Corporation 1.7.0_25 (64-bit)/cpus=16,threads=1,free=163146880,total=186646528
[junit4] 2> NOTE: All tests run in this JVM: [SoftAutoCommitTest]
[junit4] Completed on J0 in 29.72s, 3 tests, 1 failure <<< FAILURES!
[...truncated 1241 lines...]
BUILD FAILED
/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/build.xml:467: The following error occurred while executing this line:
/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/build.xml:447: The following error occurred while executing this line:
/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/build.xml:45: The following error occurred while executing this line:
/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/extra-targets.xml:37: The following error occurred while executing this line:
/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build.xml:189: The following error occurred while executing this line:
/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/common-build.xml:496: The following error occurred while executing this line:
/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/lucene/common-build.xml:1296: The following error occurred while executing this line:
/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/lucene/common-build.xml:920: There were test failures: 398 suites, 1669 tests, 1 failure, 37 ignored (16 assumptions)
Total time: 76 minutes 50 seconds
Build step 'Invoke Ant' marked build as failure
Archiving artifacts
Recording test results
Email was triggered for: Failure
Sending email for trigger: Failure
[JENKINS] Lucene-Solr-Tests-trunk-Java7 - Build # 4694 - Still
Failing
Posted by Apache Jenkins Server <je...@builds.apache.org>.
Build: https://builds.apache.org/job/Lucene-Solr-Tests-trunk-Java7/4694/
No tests ran.
Build Log:
[...truncated 11915 lines...]
FATAL: hudson.remoting.RequestAbortedException: hudson.remoting.Channel$OrderlyShutdown: java.util.concurrent.TimeoutException: Ping started on 1399251548302 hasn't completed at 1399251788303
[junit4] HEARTBEAT J0 PID(42108@lucene.zones.apache.org): 2014-05-05T01:01:32, stalled for 3967s at: SSLMigrationTest.testDistribSearch
[junit4] HEARTBEAT J0 PID(42108@lucene.zones.apache.org): 2014-05-05T01:02:32, stalled for 4027s at: SSLMigrationTest.testDistribSearch
hudson.remoting.RequestAbortedException: hudson.remoting.RequestAbortedException: hudson.remoting.Channel$OrderlyShutdown: java.util.concurrent.TimeoutException: Ping started on 1399251548302 hasn't completed at 1399251788303
at hudson.remoting.RequestAbortedException.wrapForRethrow(RequestAbortedException.java:41)
at hudson.remoting.RequestAbortedException.wrapForRethrow(RequestAbortedException.java:34)
at hudson.remoting.Request.call(Request.java:174)
at hudson.remoting.Channel.call(Channel.java:739)
at hudson.remoting.RemoteInvocationHandler.invoke(RemoteInvocationHandler.java:168)
at com.sun.proxy.$Proxy55.join(Unknown Source)
at hudson.Launcher$RemoteLauncher$ProcImpl.join(Launcher.java:951)
at hudson.Launcher$ProcStarter.join(Launcher.java:362)
at hudson.tasks.Ant.perform(Ant.java:217)
at hudson.tasks.BuildStepMonitor$1.perform(BuildStepMonitor.java:20)
at hudson.model.AbstractBuild$AbstractBuildExecution.perform(AbstractBuild.java:745)
at hudson.model.Build$BuildExecution.build(Build.java:198)
at hudson.model.Build$BuildExecution.doRun(Build.java:159)
at hudson.model.AbstractBuild$AbstractBuildExecution.run(AbstractBuild.java:518)
at hudson.model.Run.execute(Run.java:1706)
at hudson.model.FreeStyleBuild.run(FreeStyleBuild.java:43)
at hudson.model.ResourceController.execute(ResourceController.java:88)
at hudson.model.Executor.run(Executor.java:231)
Caused by: hudson.remoting.RequestAbortedException: hudson.remoting.Channel$OrderlyShutdown: java.util.concurrent.TimeoutException: Ping started on 1399251548302 hasn't completed at 1399251788303
at hudson.remoting.Request.abort(Request.java:299)
at hudson.remoting.Channel.terminate(Channel.java:802)
at hudson.remoting.Channel$CloseCommand.execute(Channel.java:951)
at hudson.remoting.Channel$2.handle(Channel.java:475)
at hudson.remoting.SynchronousCommandTransport$ReaderThread.run(SynchronousCommandTransport.java:60)
Caused by: hudson.remoting.Channel$OrderlyShutdown: java.util.concurrent.TimeoutException: Ping started on 1399251548302 hasn't completed at 1399251788303
... 3 more
Caused by: Command close created at
at hudson.remoting.Command.<init>(Command.java:56)
at hudson.remoting.Channel$CloseCommand.<init>(Channel.java:945)
at hudson.remoting.Channel$CloseCommand.<init>(Channel.java:943)
at hudson.remoting.Channel.close(Channel.java:1026)
at hudson.slaves.ChannelPinger$1.onDead(ChannelPinger.java:110)
at hudson.remoting.PingThread.ping(PingThread.java:120)
at hudson.remoting.PingThread.run(PingThread.java:81)
Caused by: java.util.concurrent.TimeoutException: Ping started on 1399251548302 hasn't completed at 1399251788303
... 2 more