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 2015/04/18 23:17:07 UTC
[JENKINS] Lucene-Solr-Tests-5.x-Java7 - Build # 2971 - Still
Failing
Build: https://builds.apache.org/job/Lucene-Solr-Tests-5.x-Java7/2971/
3 tests failed.
REGRESSION: org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest.test
Error Message:
There were too many update fails (30 > 20) - we expect it can happen, but shouldn't easily
Stack Trace:
java.lang.AssertionError: There were too many update fails (30 > 20) - we expect it can happen, but shouldn't easily
at __randomizedtesting.SeedInfo.seed([96710D3423572C68:1E2532EE8DAB4190]:0)
at org.junit.Assert.fail(Assert.java:93)
at org.junit.Assert.assertTrue(Assert.java:43)
at org.junit.Assert.assertFalse(Assert.java:68)
at org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest.test(ChaosMonkeyNothingIsSafeTest.java:230)
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:1627)
at com.carrotsearch.randomizedtesting.RandomizedRunner$6.evaluate(RandomizedRunner.java:836)
at com.carrotsearch.randomizedtesting.RandomizedRunner$7.evaluate(RandomizedRunner.java:872)
at com.carrotsearch.randomizedtesting.RandomizedRunner$8.evaluate(RandomizedRunner.java:886)
at org.apache.solr.BaseDistributedSearchTestCase$ShardsRepeatRule$ShardsFixedStatement.callStatement(BaseDistributedSearchTestCase.java:960)
at org.apache.solr.BaseDistributedSearchTestCase$ShardsRepeatRule$ShardsStatement.evaluate(BaseDistributedSearchTestCase.java:935)
at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:57)
at org.apache.lucene.util.TestRuleSetupTeardownChained$1.evaluate(TestRuleSetupTeardownChained.java:50)
at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:46)
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:845)
at com.carrotsearch.randomizedtesting.RandomizedRunner$3.evaluate(RandomizedRunner.java:747)
at com.carrotsearch.randomizedtesting.RandomizedRunner$4.evaluate(RandomizedRunner.java:781)
at com.carrotsearch.randomizedtesting.RandomizedRunner$5.evaluate(RandomizedRunner.java:792)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:57)
at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:46)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at org.apache.lucene.util.TestRuleStoreClassName$1.evaluate(TestRuleStoreClassName.java:42)
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)
REGRESSION: org.apache.solr.handler.component.DistributedMLTComponentTest.test
Error Message:
Timeout occured while waiting response from server at: http://127.0.0.1:11827/dd/collection1
Stack Trace:
org.apache.solr.client.solrj.SolrServerException: Timeout occured while waiting response from server at: http://127.0.0.1:11827/dd/collection1
at __randomizedtesting.SeedInfo.seed([96710D3423572C68:1E2532EE8DAB4190]:0)
at org.apache.solr.client.solrj.impl.HttpSolrClient.executeMethod(HttpSolrClient.java:570)
at org.apache.solr.client.solrj.impl.HttpSolrClient.request(HttpSolrClient.java:235)
at org.apache.solr.client.solrj.impl.HttpSolrClient.request(HttpSolrClient.java:227)
at org.apache.solr.client.solrj.SolrRequest.process(SolrRequest.java:135)
at org.apache.solr.client.solrj.SolrClient.query(SolrClient.java:943)
at org.apache.solr.client.solrj.SolrClient.query(SolrClient.java:958)
at org.apache.solr.BaseDistributedSearchTestCase.queryServer(BaseDistributedSearchTestCase.java:558)
at org.apache.solr.BaseDistributedSearchTestCase.query(BaseDistributedSearchTestCase.java:606)
at org.apache.solr.BaseDistributedSearchTestCase.query(BaseDistributedSearchTestCase.java:588)
at org.apache.solr.BaseDistributedSearchTestCase.query(BaseDistributedSearchTestCase.java:567)
at org.apache.solr.handler.component.DistributedMLTComponentTest.test(DistributedMLTComponentTest.java:126)
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:1627)
at com.carrotsearch.randomizedtesting.RandomizedRunner$6.evaluate(RandomizedRunner.java:836)
at com.carrotsearch.randomizedtesting.RandomizedRunner$7.evaluate(RandomizedRunner.java:872)
at com.carrotsearch.randomizedtesting.RandomizedRunner$8.evaluate(RandomizedRunner.java:886)
at org.apache.solr.BaseDistributedSearchTestCase$ShardsRepeatRule$ShardsFixedStatement.callStatement(BaseDistributedSearchTestCase.java:960)
at org.apache.solr.BaseDistributedSearchTestCase$ShardsRepeatRule$ShardsStatement.evaluate(BaseDistributedSearchTestCase.java:935)
at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:57)
at org.apache.lucene.util.TestRuleSetupTeardownChained$1.evaluate(TestRuleSetupTeardownChained.java:50)
at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:46)
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:845)
at com.carrotsearch.randomizedtesting.RandomizedRunner$3.evaluate(RandomizedRunner.java:747)
at com.carrotsearch.randomizedtesting.RandomizedRunner$4.evaluate(RandomizedRunner.java:781)
at com.carrotsearch.randomizedtesting.RandomizedRunner$5.evaluate(RandomizedRunner.java:792)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:57)
at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:46)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at org.apache.lucene.util.TestRuleStoreClassName$1.evaluate(TestRuleStoreClassName.java:42)
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)
Caused by: java.net.SocketTimeoutException: Read timed out
at java.net.SocketInputStream.socketRead0(Native Method)
at java.net.SocketInputStream.read(SocketInputStream.java:152)
at java.net.SocketInputStream.read(SocketInputStream.java:122)
at org.apache.http.impl.io.AbstractSessionInputBuffer.fillBuffer(AbstractSessionInputBuffer.java:160)
at org.apache.http.impl.io.SocketInputBuffer.fillBuffer(SocketInputBuffer.java:84)
at org.apache.http.impl.io.AbstractSessionInputBuffer.readLine(AbstractSessionInputBuffer.java:273)
at org.apache.http.impl.conn.DefaultHttpResponseParser.parseHead(DefaultHttpResponseParser.java:140)
at org.apache.http.impl.conn.DefaultHttpResponseParser.parseHead(DefaultHttpResponseParser.java:57)
at org.apache.http.impl.io.AbstractMessageParser.parse(AbstractMessageParser.java:261)
at org.apache.http.impl.AbstractHttpClientConnection.receiveResponseHeader(AbstractHttpClientConnection.java:283)
at org.apache.http.impl.conn.DefaultClientConnection.receiveResponseHeader(DefaultClientConnection.java:251)
at org.apache.http.impl.conn.ManagedClientConnectionImpl.receiveResponseHeader(ManagedClientConnectionImpl.java:197)
at org.apache.http.protocol.HttpRequestExecutor.doReceiveResponse(HttpRequestExecutor.java:272)
at org.apache.http.protocol.HttpRequestExecutor.execute(HttpRequestExecutor.java:124)
at org.apache.http.impl.client.DefaultRequestDirector.tryExecute(DefaultRequestDirector.java:685)
at org.apache.http.impl.client.DefaultRequestDirector.execute(DefaultRequestDirector.java:487)
at org.apache.http.impl.client.AbstractHttpClient.doExecute(AbstractHttpClient.java:882)
at org.apache.http.impl.client.CloseableHttpClient.execute(CloseableHttpClient.java:82)
at org.apache.http.impl.client.CloseableHttpClient.execute(CloseableHttpClient.java:107)
at org.apache.http.impl.client.CloseableHttpClient.execute(CloseableHttpClient.java:55)
at org.apache.solr.client.solrj.impl.HttpSolrClient.executeMethod(HttpSolrClient.java:466)
... 51 more
REGRESSION: org.apache.solr.update.SoftAutoCommitTest.testSoftAndHardCommitMaxTimeRapidAdds
Error Message:
1: soft wasn't fast enough
Stack Trace:
java.lang.AssertionError: 1: soft wasn't fast enough
at __randomizedtesting.SeedInfo.seed([96710D3423572C68:CA64A30DC8D56D10]: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:1627)
at com.carrotsearch.randomizedtesting.RandomizedRunner$6.evaluate(RandomizedRunner.java:836)
at com.carrotsearch.randomizedtesting.RandomizedRunner$7.evaluate(RandomizedRunner.java:872)
at com.carrotsearch.randomizedtesting.RandomizedRunner$8.evaluate(RandomizedRunner.java:886)
at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:57)
at org.apache.lucene.util.TestRuleSetupTeardownChained$1.evaluate(TestRuleSetupTeardownChained.java:50)
at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:46)
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:845)
at com.carrotsearch.randomizedtesting.RandomizedRunner$3.evaluate(RandomizedRunner.java:747)
at com.carrotsearch.randomizedtesting.RandomizedRunner$4.evaluate(RandomizedRunner.java:781)
at com.carrotsearch.randomizedtesting.RandomizedRunner$5.evaluate(RandomizedRunner.java:792)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:57)
at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:46)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at org.apache.lucene.util.TestRuleStoreClassName$1.evaluate(TestRuleStoreClassName.java:42)
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 9267 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/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-5.x-Java7/solr/build/solr-core/test/J0/temp/solr.update.SoftAutoCommitTest 96710D3423572C68-001/init-core-data-001
[junit4] 2> 4631 T11 oas.SolrTestCaseJ4.buildSSLConfig Randomized ssl (false) and clientAuth (true)
[junit4] 2> 4808 T11 oas.SolrTestCaseJ4.initCore ####initCore
[junit4] 2> 5279 T11 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> 5288 T11 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> 5289 T11 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> 5290 T11 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> 6670 T11 oasc.SolrConfig.refreshRequestParams current version of requestparams : -1
[junit4] 2> 7014 T11 oasc.SolrConfig.<init> Using Lucene MatchVersion: 5.2.0
[junit4] 2> 7687 T11 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4] 2> 7760 T11 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> 7979 T11 oass.IndexSchema.readSchema [null] Schema name=test
[junit4] 2> 11848 T11 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4] 2> 12033 T11 oass.IndexSchema.readSchema default search field in schema is text
[junit4] 2> 12042 T11 oass.IndexSchema.readSchema unique key field: id
[junit4] 2> 13477 T11 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4] 2> 13520 T11 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4] 2> 13530 T11 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4] 2> 13542 T11 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4] 2> 13543 T11 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4] 2> 13544 T11 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4] 2> 13546 T11 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4] 2> 13547 T11 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4] 2> 13590 T11 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4] 2> 13591 T11 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> 13592 T11 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> 13785 T11 oasc.CoreContainer.<init> New CoreContainer 331608321
[junit4] 2> 13787 T11 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> 13788 T11 oasc.CoreContainer.load loading shared library: /usr/home/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-5.x-Java7/solr/core/src/test-files/solr/lib
[junit4] 2> 13790 T11 oasc.SolrResourceLoader.addToClassLoader WARN Can't find (or read) directory to add to classloader: lib (resolved as: /usr/home/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-5.x-Java7/solr/core/src/test-files/solr/lib).
[junit4] 2> 13917 T11 oashc.HttpShardHandlerFactory.init created with socketTimeout : 600000,connTimeout : 60000,maxConnectionsPerHost : 20,maxConnections : 10000,corePoolSize : 0,maximumPoolSize : 2147483647,maxThreadIdleTime : 5,sizeOfQueue : -1,fairnessPolicy : false,useRetries : false,
[junit4] 2> 14861 T11 oasu.UpdateShardHandler.<init> Creating UpdateShardHandler HTTP client with params: socketTimeout=30000&connTimeout=30000&retry=true
[junit4] 2> 14892 T11 oasl.LogWatcher.createWatcher SLF4J impl is org.slf4j.impl.Log4jLoggerFactory
[junit4] 2> 14910 T11 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
[junit4] 2> 14924 T11 oasc.CoreContainer.load Node Name: testNode
[junit4] 2> 15552 T11 oasc.CoreDescriptor.<init> CORE DESCRIPTOR: {collection=collection1, name=collection1, loadOnStartup=true, shard=shard1, schema=schema.xml, config=solrconfig.xml, absoluteInstDir=/usr/home/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-5.x-Java7/solr/core/src/test-files/solr/collection1/, instanceDir=collection1, transient=false, dataDir=/usr/home/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-5.x-Java7/solr/build/solr-core/test/J0/temp/solr.update.SoftAutoCommitTest 96710D3423572C68-001/init-core-data-001}
[junit4] 2> 15569 T12 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> 15572 T12 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> 15573 T12 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> 15574 T12 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> 15788 T12 oasc.SolrConfig.refreshRequestParams current version of requestparams : -1
[junit4] 2> 15842 T12 oasc.SolrConfig.<init> Using Lucene MatchVersion: 5.2.0
[junit4] 2> 15952 T12 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4] 2> 15953 T12 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> 16032 T12 oass.IndexSchema.readSchema [collection1] Schema name=test
[junit4] 2> 16583 T12 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4] 2> 16620 T12 oass.IndexSchema.readSchema default search field in schema is text
[junit4] 2> 16625 T12 oass.IndexSchema.readSchema unique key field: id
[junit4] 2> 16672 T12 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4] 2> 16682 T12 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4] 2> 16691 T12 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4] 2> 16693 T12 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4] 2> 16694 T12 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4] 2> 16695 T12 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4] 2> 16697 T12 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4] 2> 16698 T12 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4] 2> 16707 T12 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> 16718 T12 c:collection1 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4] 2> 16761 T12 c:collection1 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/J0/temp/solr.update.SoftAutoCommitTest 96710D3423572C68-001/init-core-data-001/
[junit4] 2> 16771 T12 c:collection1 oasc.JmxMonitoredMap.<init> No JMX servers found, not exposing Solr information with JMX.
[junit4] 2> 17010 T12 c:collection1 oasc.CachingDirectoryFactory.get return new directory for /usr/home/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-5.x-Java7/solr/build/solr-core/test/J0/temp/solr.update.SoftAutoCommitTest 96710D3423572C68-001/init-core-data-001
[junit4] 2> 17011 T12 c:collection1 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/J0/temp/solr.update.SoftAutoCommitTest 96710D3423572C68-001/init-core-data-001/index/
[junit4] 2> 17012 T12 c:collection1 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/J0/temp/solr.update.SoftAutoCommitTest 96710D3423572C68-001/init-core-data-001/index' doesn't exist. Creating new index...
[junit4] 2> 17044 T12 c:collection1 oasc.CachingDirectoryFactory.get return new directory for /usr/home/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-5.x-Java7/solr/build/solr-core/test/J0/temp/solr.update.SoftAutoCommitTest 96710D3423572C68-001/init-core-data-001/index
[junit4] 2> 17047 T12 c:collection1 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.LogDocMergePolicy: [LogDocMergePolicy: minMergeSize=1000, mergeFactor=45, maxMergeSize=9223372036854775807, maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=false, maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.0]
[junit4] 2> 17393 T12 c:collection1 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
[junit4] 2> commit{dir=MockDirectoryWrapper(RAMDirectory@427f722 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@5bd1db4f),segFN=segments_1,generation=1}
[junit4] 2> 17400 T12 c:collection1 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4] 2> 19980 T12 c:collection1 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "dedupe"
[junit4] 2> 20181 T12 c:collection1 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4] 2> 20190 T12 c:collection1 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "dedupe-allfields"
[junit4] 2> 20191 T12 c:collection1 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe-allfields"
[junit4] 2> 20191 T12 c:collection1 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "stored_sig"
[junit4] 2> 20192 T12 c:collection1 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4] 2> 20192 T12 c:collection1 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "uniq-fields"
[junit4] 2> 20251 T12 c:collection1 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "uniq-fields"
[junit4] 2> 20252 T12 c:collection1 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-explicit"
[junit4] 2> 20594 T12 c:collection1 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4] 2> 20596 T12 c:collection1 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4] 2> 20596 T12 c:collection1 oasc.SolrCore.loadUpdateProcessorChains no updateRequestProcessorChain defined as default, creating implicit default
[junit4] 2> 21150 T12 c:collection1 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4] 2> 21199 T12 c:collection1 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4] 2> 21203 T12 c:collection1 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4] 2> 21206 T12 c:collection1 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4] 2> 21596 T12 c:collection1 oasc.PluginBag.createPlugin requestHandler : 'lazy' created with startup=lazy
[junit4] 2> 21764 T12 c:collection1 oasc.RequestHandlers.initHandlersFromConfig Registered paths: /admin/threads,/replication,dismax,/debug/dump,/admin/properties,/schema,standard,/update/json,/update/json/docs,spellCheckWithWordbreak_Direct,/config,mltrh,/admin/logging,spellCheckCompRH,spellCheckCompRH_Direct,/admin/plugins,/get,/admin/file,/terms,/admin/luke,/admin/mbeans,lazy,/update,spellCheckCompRH1,/mlt,mock,defaults,/update/csv,tvrh,/admin/segments,/search-facet-invariants,spellCheckWithWordbreak,/admin/system,/search-facet-def,/admin/ping
[junit4] 2> 21777 T12 c:collection1 oasc.SolrCore.initDeprecatedSupport WARN solrconfig.xml uses deprecated <admin/gettableFiles>, Please update your config to use the ShowFileRequestHandler.
[junit4] 2> 21780 T12 c:collection1 oasc.SolrCore.initStatsCache Using default statsCache cache: org.apache.solr.search.stats.LocalStatsCache
[junit4] 2> 21965 T12 c:collection1 oasu.UpdateHandler.<init> Using UpdateLog implementation: org.apache.solr.update.UpdateLog
[junit4] 2> 21966 T12 c:collection1 oasu.UpdateLog.init Initializing UpdateLog: dataDir= defaultSyncLevel=FLUSH numRecordsToKeep=100 maxNumLogsToKeep=10
[junit4] 2> 22038 T12 c:collection1 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4] 2> 22039 T12 c:collection1 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4] 2> 22040 T12 c:collection1 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: maxMergeAtOnce=46, maxMergeAtOnceExplicit=14, maxMergedSegmentMB=41.9423828125, floorSegmentMB=0.90234375, forceMergeDeletesPctAllowed=21.715227634028462, segmentsPerTier=42.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.2565476620380965
[junit4] 2> 22076 T12 c:collection1 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=1
[junit4] 2> commit{dir=MockDirectoryWrapper(RAMDirectory@427f722 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@5bd1db4f),segFN=segments_1,generation=1}
[junit4] 2> 22077 T12 c:collection1 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4] 2> 22384 T12 c:collection1 oass.SolrIndexSearcher.<init> Opening Searcher@70a21e54[collection1] main
[junit4] 2> 22489 T12 c:collection1 oasr.RestManager.init Initializing RestManager with initArgs: {storageIO=org.apache.solr.rest.ManagedResourceStorage$InMemoryStorageIO}
[junit4] 2> 22686 T12 c:collection1 oasr.ManagedResourceStorage.load Reading _rest_managed.json using InMemoryStorage
[junit4] 2> 22687 T12 c:collection1 oasr.RestManager.init Initializing 0 registered ManagedResources
[junit4] 2> 22958 T12 c:collection1 oashc.SpellCheckComponent.inform Initializing spell checkers
[junit4] 2> 23709 T12 c:collection1 oass.DirectSolrSpellChecker.init init: {name=direct,classname=DirectSolrSpellChecker,field=lowerfilt,minQueryLength=3}
[junit4] 2> 24592 T12 c:collection1 oash.ReplicationHandler.inform Commits will be reserved for 10000
[junit4] 2> 24594 T13 c:collection1 oashc.SpellCheckComponent$SpellCheckerListener.newSearcher Loading spell index for spellchecker: default
[junit4] 2> 24598 T13 c:collection1 oashc.SpellCheckComponent$SpellCheckerListener.newSearcher Loading spell index for spellchecker: direct
[junit4] 2> 24599 T13 c:collection1 oashc.SpellCheckComponent$SpellCheckerListener.newSearcher Loading spell index for spellchecker: wordbreak
[junit4] 2> 24600 T13 c:collection1 oashc.SpellCheckComponent$SpellCheckerListener.newSearcher Loading spell index for spellchecker: multipleFields
[junit4] 2> 24604 T13 c:collection1 oashc.SpellCheckComponent$SpellCheckerListener.newSearcher Loading spell index for spellchecker: jarowinkler
[junit4] 2> 24607 T13 c:collection1 oashc.SpellCheckComponent$SpellCheckerListener.newSearcher Loading spell index for spellchecker: external
[junit4] 2> 24609 T13 c:collection1 oashc.SpellCheckComponent$SpellCheckerListener.newSearcher Loading spell index for spellchecker: freq
[junit4] 2> 24611 T13 c:collection1 oashc.SpellCheckComponent$SpellCheckerListener.newSearcher Loading spell index for spellchecker: fqcn
[junit4] 2> 24613 T12 c:collection1 oasc.CoreContainer.registerCore registering core: collection1
[junit4] 2> 24613 T13 c:collection1 oashc.SpellCheckComponent$SpellCheckerListener.newSearcher Loading spell index for spellchecker: perDict
[junit4] 2> 24629 T13 c:collection1 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@70a21e54[collection1] main{ExitableDirectoryReader(UninvertingDirectoryReader())}
[junit4] 2> 24650 T11 oas.SolrTestCaseJ4.initCore ####initCore end
[junit4] 2> 24724 T11 oas.SolrTestCaseJ4.setUp ###Starting testSoftAndHardCommitMaxTimeRapidAdds
[junit4] 2> 24725 T11 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> 24727 T11 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> 24728 T11 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> 24729 T11 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> 24909 T11 oasc.SolrConfig.refreshRequestParams current version of requestparams : -1
[junit4] 2> 24952 T11 oasc.SolrConfig.<init> Using Lucene MatchVersion: 5.2.0
[junit4] 2> 25080 T11 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4] 2> 25083 T11 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> 25185 T11 oass.IndexSchema.readSchema [collection1] Schema name=test
[junit4] 2> 26052 T11 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4] 2> 26101 T11 oass.IndexSchema.readSchema default search field in schema is text
[junit4] 2> 26106 T11 oass.IndexSchema.readSchema unique key field: id
[junit4] 2> 26159 T11 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4] 2> 26168 T11 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4] 2> 26179 T11 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4] 2> 26181 T11 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4] 2> 26182 T11 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4] 2> 26183 T11 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4] 2> 26184 T11 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4] 2> 26185 T11 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4] 2> 26186 T11 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> 26187 T11 c:collection1 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/J0/temp/solr.update.SoftAutoCommitTest 96710D3423572C68-001/init-core-data-001/
[junit4] 2> 26188 T11 c:collection1 oasc.JmxMonitoredMap.<init> No JMX servers found, not exposing Solr information with JMX.
[junit4] 2> 26189 T11 c:collection1 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/J0/temp/solr.update.SoftAutoCommitTest 96710D3423572C68-001/init-core-data-001/index/
[junit4] 2> 26195 T11 c:collection1 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "dedupe"
[junit4] 2> 26197 T11 c:collection1 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4] 2> 26198 T11 c:collection1 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "dedupe-allfields"
[junit4] 2> 26199 T11 c:collection1 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe-allfields"
[junit4] 2> 26200 T11 c:collection1 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "stored_sig"
[junit4] 2> 26201 T11 c:collection1 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4] 2> 26202 T11 c:collection1 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "uniq-fields"
[junit4] 2> 26203 T11 c:collection1 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "uniq-fields"
[junit4] 2> 26205 T11 c:collection1 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-explicit"
[junit4] 2> 26207 T11 c:collection1 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4] 2> 26208 T11 c:collection1 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4] 2> 26208 T11 c:collection1 oasc.SolrCore.loadUpdateProcessorChains no updateRequestProcessorChain defined as default, creating implicit default
[junit4] 2> 26244 T11 c:collection1 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4] 2> 26249 T11 c:collection1 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4] 2> 26254 T11 c:collection1 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4] 2> 26258 T11 c:collection1 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4] 2> 26266 T11 c:collection1 oasc.PluginBag.createPlugin requestHandler : 'lazy' created with startup=lazy
[junit4] 2> 26272 T11 c:collection1 oasc.RequestHandlers.initHandlersFromConfig Registered paths: /admin/threads,/replication,dismax,/debug/dump,/admin/properties,/schema,standard,/update/json,/update/json/docs,spellCheckWithWordbreak_Direct,/config,mltrh,/admin/logging,spellCheckCompRH,spellCheckCompRH_Direct,/admin/plugins,/get,/admin/file,/terms,/admin/luke,/admin/mbeans,lazy,/update,spellCheckCompRH1,/mlt,mock,defaults,/update/csv,tvrh,/admin/segments,/search-facet-invariants,spellCheckWithWordbreak,/admin/system,/search-facet-def,/admin/ping
[junit4] 2> 26277 T11 c:collection1 oasc.SolrCore.initDeprecatedSupport WARN solrconfig.xml uses deprecated <admin/gettableFiles>, Please update your config to use the ShowFileRequestHandler.
[junit4] 2> 26283 T11 c:collection1 oasc.SolrCore.initStatsCache Using default statsCache cache: org.apache.solr.search.stats.LocalStatsCache
[junit4] 2> 26295 T11 c:collection1 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4] 2> 26297 T11 c:collection1 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4] 2> 26298 T11 c:collection1 oass.SolrIndexSearcher.<init> Opening Searcher@597d9abe[collection1] main
[junit4] 2> 26300 T11 c:collection1 oasr.RestManager.init Initializing RestManager with initArgs: {storageIO=org.apache.solr.rest.ManagedResourceStorage$InMemoryStorageIO}
[junit4] 2> 26302 T11 c:collection1 oasr.ManagedResourceStorage.load Reading _rest_managed.json using InMemoryStorage
[junit4] 2> 26303 T11 c:collection1 oasr.RestManager.init Initializing 0 registered ManagedResources
[junit4] 2> 26304 T11 c:collection1 oashc.SpellCheckComponent.inform Initializing spell checkers
[junit4] 2> 26307 T11 c:collection1 oass.DirectSolrSpellChecker.init init: {name=direct,classname=DirectSolrSpellChecker,field=lowerfilt,minQueryLength=3}
[junit4] 2> 26330 T11 c:collection1 oash.ReplicationHandler.inform Commits will be reserved for 10000
[junit4] 2> 26332 T15 c:collection1 oashc.SpellCheckComponent$SpellCheckerListener.newSearcher Loading spell index for spellchecker: default
[junit4] 2> 26333 T11 c:collection1 oasu.DefaultSolrCoreState.newIndexWriter Creating new IndexWriter...
[junit4] 2> 26334 T11 c:collection1 oasu.DefaultSolrCoreState.newIndexWriter Waiting until IndexWriter is unused... core=collection1
[junit4] 2> 26334 T15 c:collection1 oashc.SpellCheckComponent$SpellCheckerListener.newSearcher Loading spell index for spellchecker: direct
[junit4] 2> 26335 T11 c:collection1 oasu.DefaultSolrCoreState.newIndexWriter Closing old IndexWriter... core=collection1
[junit4] 2> 26337 T15 c:collection1 oashc.SpellCheckComponent$SpellCheckerListener.newSearcher Loading spell index for spellchecker: wordbreak
[junit4] 2> 26339 T15 c:collection1 oashc.SpellCheckComponent$SpellCheckerListener.newSearcher Loading spell index for spellchecker: multipleFields
[junit4] 2> 26339 T11 c:collection1 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: maxMergeAtOnce=26, maxMergeAtOnceExplicit=28, maxMergedSegmentMB=98.6572265625, floorSegmentMB=0.421875, forceMergeDeletesPctAllowed=14.483422308151631, segmentsPerTier=50.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.1698424553270576
[junit4] 2> 26343 T15 c:collection1 oashc.SpellCheckComponent$SpellCheckerListener.newSearcher Loading spell index for spellchecker: jarowinkler
[junit4] 2> 26344 T11 c:collection1 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=1
[junit4] 2> commit{dir=MockDirectoryWrapper(RAMDirectory@427f722 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@5bd1db4f),segFN=segments_1,generation=1}
[junit4] 2> 26346 T15 c:collection1 oashc.SpellCheckComponent$SpellCheckerListener.newSearcher Loading spell index for spellchecker: external
[junit4] 2> 26347 T11 c:collection1 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4] 2> 26348 T15 c:collection1 oashc.SpellCheckComponent$SpellCheckerListener.newSearcher Loading spell index for spellchecker: freq
[junit4] 2> 26348 T11 c:collection1 oasu.DefaultSolrCoreState.newIndexWriter New IndexWriter is ready to be used.
[junit4] 2> 26350 T11 c:collection1 oasc.SolrCore.getSearcher WARN [collection1] PERFORMANCE WARNING: Overlapping onDeckSearchers=2
[junit4] 2> 26351 T15 c:collection1 oashc.SpellCheckComponent$SpellCheckerListener.newSearcher Loading spell index for spellchecker: fqcn
[junit4] 2> 26352 T11 c:collection1 oass.SolrIndexSearcher.<init> Opening Searcher@50530c6d[collection1] main
[junit4] 2> 26353 T15 c:collection1 oashc.SpellCheckComponent$SpellCheckerListener.newSearcher Loading spell index for spellchecker: perDict
[junit4] 2> 26354 T11 c:collection1 oasc.CoreContainer.registerCore replacing core: collection1
[junit4] 2> 26355 T15 c:collection1 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@597d9abe[collection1] main{ExitableDirectoryReader(UninvertingDirectoryReader())}
[junit4] 2> 26356 T11 c:collection1 oasc.SolrCore.close [collection1] CLOSING SolrCore org.apache.solr.core.SolrCore@60ee0b0e
[junit4] 2> 26356 T15 c:collection1 oashc.SpellCheckComponent$SpellCheckerListener.newSearcher Loading spell index for spellchecker: default
[junit4] 2> 26359 T11 c:collection1 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> 26360 T15 c:collection1 oashc.SpellCheckComponent$SpellCheckerListener.newSearcher Loading spell index for spellchecker: direct
[junit4] 2> 26361 T11 c:collection1 oasc.SolrCore.closeSearcher [collection1] Closing main searcher on request.
[junit4] 2> 26361 T15 c:collection1 oashc.SpellCheckComponent$SpellCheckerListener.newSearcher Loading spell index for spellchecker: wordbreak
[junit4] 2> 26363 T15 c:collection1 oashc.SpellCheckComponent$SpellCheckerListener.newSearcher Loading spell index for spellchecker: multipleFields
[junit4] 2> 26365 T15 c:collection1 oashc.SpellCheckComponent$SpellCheckerListener.newSearcher Loading spell index for spellchecker: jarowinkler
[junit4] 2> 26368 T15 c:collection1 oashc.SpellCheckComponent$SpellCheckerListener.newSearcher Loading spell index for spellchecker: external
[junit4] 2> 26370 T15 c:collection1 oashc.SpellCheckComponent$SpellCheckerListener.newSearcher Loading spell index for spellchecker: freq
[junit4] 2> 26372 T15 c:collection1 oashc.SpellCheckComponent$SpellCheckerListener.newSearcher Loading spell index for spellchecker: fqcn
[junit4] 2> 26375 T15 c:collection1 oashc.SpellCheckComponent$SpellCheckerListener.newSearcher Loading spell index for spellchecker: perDict
[junit4] 2> 26376 T15 c:collection1 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@50530c6d[collection1] main{ExitableDirectoryReader(UninvertingDirectoryReader())}
[junit4] 2> ASYNC NEW_CORE C0 name=collection1 org.apache.solr.core.SolrCore@dd62e57
[junit4] 2> 28511 T11 c:collection1 C0 oasup.LogUpdateProcessor.finish [collection1] webapp=null path=null params={} {add=[5000 (1498822003433406464)]} 0 2118
[junit4] 2> 28602 T11 c:collection1 C0 oasup.LogUpdateProcessor.finish [collection1] webapp=null path=null params={} {add=[5001 (1498822004581597184)]} 0 2
[junit4] 2> 28605 T11 c:collection1 C0 oasup.LogUpdateProcessor.finish [collection1] webapp=null path=null params={} {add=[5002 (1498822004585791488)]} 0 1
[junit4] 2> 28608 T11 c:collection1 C0 oasup.LogUpdateProcessor.finish [collection1] webapp=null path=null params={} {add=[5003 (1498822004588937216)]} 0 1
[junit4] 2> 28612 T11 c:collection1 C0 oasup.LogUpdateProcessor.finish [collection1] webapp=null path=null params={} {add=[5004 (1498822004592082944)]} 0 1
[junit4] 2> 29005 T17 c:collection1 oasu.DirectUpdateHandler2.commit start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=true,prepareCommit=false}
[junit4] 2> 29615 T11 c:collection1 oas.SolrTestCaseJ4.tearDown ###Ending testSoftAndHardCommitMaxTimeRapidAdds
[junit4] 2> 29695 T16 c:collection1 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=testSoftAndHardCommitMaxTimeRapidAdds -Dtests.seed=96710D3423572C68 -Dtests.multiplier=2 -Dtests.slow=true -Dtests.locale=tr_TR -Dtests.timezone=Canada/Eastern -Dtests.asserts=true -Dtests.file.encoding=US-ASCII
[junit4] FAILURE 5.11s J0 | SoftAutoCommitTest.testSoftAndHardCommitMaxTimeRapidAdds <<<
[junit4] > Throwable #1: java.lang.AssertionError: 1: soft wasn't fast enough
[junit4] > at __randomizedtesting.SeedInfo.seed([96710D3423572C68:CA64A30DC8D56D10]:0)
[junit4] > at org.apache.solr.update.SoftAutoCommitTest.testSoftAndHardCommitMaxTimeRapidAdds(SoftAutoCommitTest.java:316)
[junit4] > at java.lang.Thread.run(Thread.java:745)
[junit4] 2> 29778 T11 c:collection1 oas.SolrTestCaseJ4.setUp ###Starting testSoftAndHardCommitMaxTimeDelete
[junit4] 2> 29779 T11 c:collection1 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> 29781 T11 c:collection1 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> 29781 T11 c:collection1 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> 29782 T11 c:collection1 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> 29974 T11 c:collection1 oasc.SolrConfig.refreshRequestParams current version of requestparams : -1
[junit4] 2> 30015 T11 c:collection1 oasc.SolrConfig.<init> Using Lucene MatchVersion: 5.2.0
[junit4] 2> 30094 T11 c:collection1 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4] 2> 30096 T11 c:collection1 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> 30210 T11 c:collection1 oass.IndexSchema.readSchema [collection1] Schema name=test
[junit4] 2> 30214 T17 c:collection1 oass.SolrIndexSearcher.<init> Opening Searcher@3798d967[collection1] main
[junit4] 2> 30236 T17 c:collection1 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4] 2> 30236 T15 c:collection1 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@3798d967[collection1] main{ExitableDirectoryReader(UninvertingDirectoryReader(Uninverting(_0(5.2.0):C5)))}
[junit4] 2> 30238 T16 c:collection1 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=2
[junit4] 2> commit{dir=MockDirectoryWrapper(RAMDirectory@427f722 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@5bd1db4f),segFN=segments_1,generation=1}
[junit4] 2> commit{dir=MockDirectoryWrapper(RAMDirectory@427f722 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@5bd1db4f),segFN=segments_2,generation=2}
[junit4] 2> 30239 T16 c:collection1 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 2
[junit4] 2> 30240 T16 c:collection1 oasc.SolrCore.openNewSearcher SolrIndexSearcher has not changed - not re-opening: org.apache.solr.search.SolrIndexSearcher
[junit4] 2> 30241 T16 c:collection1 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4] 2> 30706 T11 c:collection1 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4] 2> 30742 T11 c:collection1 oass.IndexSchema.readSchema default search field in schema is text
[junit4] 2> 30747 T11 c:collection1 oass.IndexSchema.readSchema unique key field: id
[junit4] 2> 30786 T11 c:collection1 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4] 2> 30794 T11 c:collection1 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4] 2> 30801 T11 c:collection1 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4] 2> 30803 T11 c:collection1 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4] 2> 30803 T11 c:collection1 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4] 2> 30804 T11 c:collection1 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4] 2> 30805 T11 c:collection1 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4] 2> 30806 T11 c:collection1 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4] 2> 30807 T11 c:collection1 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> 30808 T11 c:collection1 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/J0/temp/solr.update.SoftAutoCommitTest 96710D3423572C68-001/init-core-data-001/
[junit4] 2> 30809 T11 c:collection1 oasc.JmxMonitoredMap.<init> No JMX servers found, not exposing Solr information with JMX.
[junit4] 2> 30810 T11 c:collection1 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/J0/temp/solr.update.SoftAutoCommitTest 96710D3423572C68-001/init-core-data-001/index/
[junit4] 2> 30822 T11 c:collection1 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "dedupe"
[junit4] 2> 30823 T11 c:collection1 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4] 2> 30824 T11 c:collection1 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "dedupe-allfields"
[junit4] 2> 30825 T11 c:collection1 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe-allfields"
[junit4] 2> 30826 T11 c:collection1 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "stored_sig"
[junit4] 2> 30827 T11 c:collection1 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4] 2> 30828 T11 c:collection1 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "uniq-fields"
[junit4] 2> 30829 T11 c:collection1 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "uniq-fields"
[junit4] 2> 30830 T11 c:collection1 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-explicit"
[junit4] 2> 30831 T11 c:collection1 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4] 2> 30833 T11 c:collection1 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4] 2> 30833 T11 c:collection1 oasc.SolrCore.loadUpdateProcessorChains no updateRequestProcessorChain defined as default, creating implicit default
[junit4] 2> 30862 T11 c:collection1 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4] 2> 30866 T11 c:collection1 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4] 2> 30869 T11 c:collection1 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4] 2> 30872 T11 c:collection1 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4] 2> 30877 T11 c:collection1 oasc.PluginBag.createPlugin requestHandler : 'lazy' created with startup=lazy
[junit4] 2> 30880 T11 c:collection1 oasc.RequestHandlers.initHandlersFromConfig Registered paths: /admin/threads,/replication,dismax,/debug/dump,/admin/properties,/schema,standard,/update/json,/update/json/docs,spellCheckWithWordbreak_Direct,/config,mltrh,/admin/logging,spellCheckCompRH,spellCheckCompRH_Direct,/admin/plugins,/get,/admin/file,/terms,/admin/luke,/admin/mbeans,lazy,/update,spellCheckCompRH1,/mlt,mock,defaults,/update/csv,tvrh,/admin/segments,/search-facet-invariants,spellCheckWithWordbreak,/admin/system,/search-facet-def,/admin/ping
[junit4] 2> 30883 T11 c:collection1 oasc.SolrCore.initDeprecatedSupport WARN solrconfig.xml uses deprecated <admin/gettableFiles>, Please update your config to use the ShowFileRequestHandler.
[junit4] 2> 30886 T11 c:collection1 oasc.SolrCore.initStatsCache Using default statsCache cache: org.apache.solr.search.stats.LocalStatsCache
[junit4] 2> 30888 T11 c:collection1 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4] 2> 30888 T11 c:collection1 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4] 2> 30891 T11 c:collection1 oass.SolrIndexSearcher.<init> Opening Searcher@1ebee38a[collection1] main
[junit4] 2> 30892 T11 c:collection1 oasr.RestManager.init Initializing RestManager with initArgs: {storageIO=org.apache.solr.rest.ManagedResourceStorage$InMemoryStorageIO}
[junit4] 2> 30893 T11 c:collection1 oasr.ManagedResourceStorage.load Reading _rest_managed.json using InMemoryStorage
[junit4] 2> 30893 T11 c:collection1 oasr.RestManager.init Initializing 0 registered ManagedResources
[junit4] 2> 30894 T11 c:collection1 oashc.SpellCheckComponent.inform Initializing spell checkers
[junit4] 2> 30898 T11 c:collection1 oass.DirectSolrSpellChecker.init init: {name=direct,classname=DirectSolrSpellChecker,field=lowerfilt,minQueryLength=3}
[junit4] 2> 30915 T11 c:collection1 oash.ReplicationHandler.inform Commits will be reserved for 10000
[junit4] 2> 30917 T18 c:collection1 oashc.SpellCheckComponent$SpellCheckerListener.newSearcher Loading spell index for spellchecker: default
[junit4] 2> 30917 T11 c:collection1 oasu.DefaultSolrCoreState.newIndexWriter Creating new IndexWriter...
[junit4] 2> 30918 T11 c:collection1 oasu.DefaultSolrCoreState.newIndexWriter Waiting until IndexWriter is unused... core=collection1
[junit4] 2> 30918 T18 c:collection1 oashc.SpellCheckComponent$SpellCheckerListener.newSearcher Loading spell index for spellchecker: direct
[junit4] 2> 30918 T11 c:collection1 oasu.DefaultSolrCoreState.newIndexWriter Closing old IndexWriter... core=collection1
[junit4] 2> 30919 T18 c:collection1 oashc.SpellCheckComponent$SpellCheckerListener.newSearcher Loading spell index for spellchecker: wordbreak
[junit4] 2> 30920 T18 c:collection1 oashc.SpellCheckComponent$SpellCheckerListener.newSearcher Loading spell index for spellchecker: multipleFields
[junit4] 2> 30921 T11 c:collection1 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.LogByteSizeMergePolicy: [LogByteSizeMergePolicy: minMergeSize=1677721, mergeFactor=31, maxMergeSize=2147483648, maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=true, maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=1.0]
[junit4] 2> 30921 T18 c:collection1 oashc.SpellCheckComponent$SpellCheckerListener.newSearcher Loading spell index for spellchecker: jarowinkler
[junit4] 2> 30924 T18 c:collection1 oashc.SpellCheckComponent$SpellCheckerListener.newSearcher Loading spell index for spellchecker: external
[junit4] 2> 30925 T18 c:collection1 oashc.SpellCheckComponent$SpellCheckerListener.newSearcher Loading spell index for spellchecker: freq
[junit4] 2> 30926 T18 c:collection1 oashc.SpellCheckComponent$SpellCheckerListener.newSearcher Loading spell index for spellchecker: fqcn
[junit4] 2> 30927 T11 c:collection1 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=1
[junit4] 2> commit{dir=MockDirectoryWrapper(RAMDirectory@427f722 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@5bd1db4f),segFN=segments_2,generation=2}
[junit4] 2> 30927 T18 c:collection1 oashc.SpellCheckComponent$SpellCheckerListener.newSearcher Loading spell index for spellchecker: perDict
[junit4] 2> 30928 T11 c:collection1 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 2
[junit4] 2> 30928 T18 c:collection1 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@1ebee38a[collection1] main{ExitableDirectoryReader(UninvertingDirectoryReader(Uninverting(_0(5.2.0):C5)))}
[junit4] 2> 30929 T11 c:collection1 oasu.DefaultSolrCoreState.newIndexWriter New IndexWriter is ready to be used.
[junit4] 2> 30938 T11 c:collection1 oass.SolrIndexSearcher.<init> Opening Searcher@3ad932b2[collection1] main
[junit4] 2> 30940 T11 c:collection1 oasc.CoreContainer.registerCore replacing core: collection1
[junit4] 2> 30940 T18 c:collection1 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@3ad932b2[collection1] main{ExitableDirectoryReader(UninvertingDirectoryReader(Uninverting(_0(5.2.0):C5)))}
[junit4] 2> 30941 T11 c:collection1 oasc.SolrCore.close [collection1] CLOSING SolrCore org.apache.solr.core.SolrCore@dd62e57
[junit4] 2> 30943 T11 c:collection1 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> 30944 T11 c:collection1 oasc.SolrCore.closeSearcher [collection1] Closing main searcher on request.
[junit4] 2> ASYNC NEW_CORE C1 name=collection1 org.apache.solr.core.SolrCore@74e0da2d
[junit4] 2> 30954 T11 c:collection1 C1 oasup.LogUpdateProcessor.finish [collection1] webapp=null path=null params={} {add=[529 (1498822007041556480)]} 0 7
[junit4] 2> 30957 T11 c:collection1 C1 oasu.DirectUpdateHandler2.commit start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4] 2> 31085 T11 c:collection1 C1 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=2
[junit4] 2> commit{dir=MockDirectoryWrapper(RAMDirectory@427f722 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@5bd1db4f),segFN=segments_2,generation=2}
[junit4] 2> commit{dir=MockDirectoryWrapper(RAMDirectory@427f722 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@5bd1db4f),segFN=segments_3,generation=3}
[junit4] 2> 31085 T11 c:collection1 C1 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 3
[junit4] 2> 31087 T11 c:collection1 C1 oass.SolrIndexSearcher.<init> Opening Searcher@7b7a739[collection1] main
[junit4] 2> 31088 T11 c:collection1 C1 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4] 2> 31088 T18 c:collection1 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@7b7a739[collection1] main{ExitableDirectoryReader(UninvertingDirectoryReader(Uninverting(_0(5.2.0):C5) Uninverting(_1(5.2.0):C1)))}
[junit4] 2> 31090 T11 c:collection1 C1 oasup.LogUpdateProcessor.finish [collection1] webapp=null path=null params={} {commit=} 0 133
[junit4] 2> 31097 T11 c:collection1 C1 oasup.LogUpdateProcessor.finish [collection1] webapp=null path=null params={} {delete=[529 (-1498822007196745728)]} 0 2
[junit4] 2> 31599 T20 c:collection1 oasu.DirectUpdateHandler2.commit start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=true,prepareCommit=false}
[junit4] 2> 31628 T20 c:collection1 oass.SolrIndexSearcher.<init> Opening Searcher@32e95912[collection1] main
[junit4] 2> 31630 T20 c:collection1 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4] 2> 31631 T18 c:collection1 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@32e95912[collection1] main{ExitableDirectoryReader(UninvertingDirectoryReader(Uninverting(_0(5.2.0):C5)))}
[junit4] 2> 31635 T11 c:collection1 C1 oasup.LogUpdateProcessor.finish [collection1] webapp=null path=null params={} {add=[550 (1498822007758782464)]} 0 4
[junit4] 2> 32136 T20 c:collection1 oasu.DirectUpdateHandler2.commit start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=true,prepareCommit=false}
[junit4] 2> 32156 T20 c:collection1 oass.SolrIndexSearcher.<init> Opening Searcher@4d590460[collection1] main
[junit4] 2> 32157 T20 c:collection1 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4] 2> 32158 T18 c:collection1 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@4d590460[collection1] main{ExitableDirectoryReader(UninvertingDirectoryReader(Uninverting(_0(5.2.0):C5) Uninverting(_2(5.2.0):C1)))}
[junit4] 2> 32299 T19 c:collection1 oasu.DirectUpdateHandler2.commit start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4] 2> 32302 T19 c:collection1 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=2
[junit4] 2> commit{dir=MockDirectoryWrapper(RAMDirectory@427f722 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@5bd1db4f),segFN=segments_3,generation=3}
[junit4] 2> commit{dir=MockDirectoryWrapper(RAMDirectory@427f722 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@5bd1db4f),segFN=segments_4,generation=4}
[junit4] 2> 32303 T19 c:collection1 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 4
[junit4] 2> 32304 T19 c:collection1 oasc.SolrCore.openNewSearcher SolrIndexSearcher has not changed - not re-opening: org.apache.solr.search.SolrIndexSearcher
[junit4] 2> 32305 T19 c:collection1 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4] 2> 34304 T11 c:collection1 oas.SolrTestCaseJ4.tearDown ###Ending testSoftAndHardCommitMaxTimeDelete
[junit4] 2> 34315 T11 c:collection1 oas.SolrTestCaseJ4.setUp ###Starting testSoftAndHardCommitMaxTimeMixedAdds
[junit4] 2> 34316 T11 c:collection1 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> 34318 T11 c:collection1 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> 34318 T11 c:collection1 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> 34319 T11 c:collection1 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> 34465 T11 c:collection1 oasc.SolrConfig.refreshRequestParams current version of requestparams : -1
[junit4] 2> 34508 T11 c:collection1 oasc.SolrConfig.<init> Using Lucene MatchVersion: 5.2.0
[junit4] 2> 34586 T11 c:collection1 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4] 2> 34587 T11 c:collection1 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> 34629 T11 c:collection1 oass.IndexSchema.readSchema [collection1] Schema name=test
[junit4] 2> 35054 T11 c:collection1 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4] 2> 35094 T11 c:collection1 oass.IndexSchema.readSchema default search field in schema is text
[junit4] 2> 35097 T11 c:collection1 oass.IndexSchema.readSchema unique key field: id
[junit4] 2> 35122 T11 c:collection1 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4] 2> 35127 T11 c:collection1 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4] 2> 35132 T11 c:collection1 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4] 2> 35133 T11 c:collection1 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4] 2> 35133 T11 c:collection1 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4] 2> 35134 T11 c:collection1 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4] 2> 35135 T11 c:collection1 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4] 2> 35135 T11 c:collection1 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4] 2> 35136 T11 c:collection1 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> 35136 T11 c:collection1 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/J0/temp/solr.update.SoftAutoCommitTest 96710D3423572C68-001/init-core-data-001/
[junit4] 2> 35137 T11 c:collection1 oasc.JmxMonitoredMap.<init> No JMX servers found, not exposing Solr information with JMX.
[junit4] 2> 35137 T11 c:collection1 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/J0/temp/solr.update.SoftAutoCommitTest 96710D3423572C68-001/init-core-data-001/index/
[junit4] 2> 35141 T11 c:collection1 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "dedupe"
[junit4] 2> 35141 T11 c:collection1 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4] 2> 35142 T11 c:collection1 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "dedupe-allfields"
[junit4] 2> 35142 T11 c:collection1 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe-allfields"
[junit4] 2> 35143 T11 c:collection1 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "stored_sig"
[junit4] 2> 35143 T11 c:collection1 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4] 2> 35144 T11 c:collection1 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "uniq-fields"
[junit4] 2> 35144 T11 c:collection1 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "uniq-fields"
[junit4] 2> 35145 T11 c:collection1 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-explicit"
[junit4] 2> 35145 T11 c:collection1 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4] 2> 35146 T11 c:collection1 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4] 2> 35147 T11 c:collection1 oasc.SolrCore.loadUpdateProcessorChains no updateRequestProcessorChain defined as default, creating implicit default
[junit4] 2> 35164 T11 c:collection1 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4] 2> 35166 T11 c:collection1 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4] 2> 35169 T11 c:collection1 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4] 2> 35171 T11 c:collection1 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4] 2> 35175 T11 c:collection1 oasc.PluginBag.createPlugin requestHandler : 'lazy' created with startup=lazy
[junit4] 2> 35177 T11 c:collection1 oasc.RequestHandlers.initHandlersFromConfig Registered paths: /admin/threads,/replication,dismax,/debug/dump,/admin/properties,/schema,standard,/update/json,/update/json/docs,spellCheckWithWordbreak_Direct,/config,mltrh,/admin/logging,spellCheckCompRH,spellCheckCompRH_Direct,/admin/plugins,/get,/admin/file,/terms,/admin/luke,/admin/mbeans,lazy,/update,spellCheckCompRH1,/mlt,mock,defaults,/update/csv,tvrh,/admin/segments,/search-facet-invariants,spellCheckWithWordbreak,/admin/system,/search-facet-def,/admin/ping
[junit4] 2> 35179 T11 c:collection1 oasc.SolrCore.initDeprecatedSupport WARN solrconfig.xml uses deprecated <admin/gettableFiles>, Please update your config to use the ShowFileRequestHandler.
[junit4] 2> 35180 T11 c:collection1 oasc.SolrCore.initStatsCache Using default statsCache cache: org.apache.solr.search.stats.LocalStatsCache
[junit4] 2> 35181 T11 c:collection1 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4] 2> 35181 T11 c:collection1 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4] 2> 35183 T11 c:collection1 oass.SolrIndexSearcher.<init> Opening Searcher@3d29accb[collection1] main
[junit4] 2> 35184 T11 c:collection1 oasr.RestManager.init Initializing RestManager with initArgs: {storageIO=org.apache.solr.rest.ManagedResourceStorage$InMemoryStorageIO}
[junit4] 2> 35184 T11 c:collection1 oasr.ManagedResourceStorage.load Reading _rest_managed.json using InMemoryStorage
[junit4] 2> 35185 T11 c:collection1 oasr.RestManager.init Initializing 0 registered ManagedResources
[junit4] 2> 35185 T11 c:collection1 oashc.SpellCheckComponent.inform Initializing spell checkers
[junit4] 2> 35188 T11 c:collection1 oass.DirectSolrSpellChecker.init init: {name=direct,classname=DirectSolrSpellChecker,field=lowerfilt,minQueryLength=3}
[junit4] 2> 35203 T11 c:collection1 oash.ReplicationHandler.inform Commits will be reserved for 10000
[junit4] 2> 35204 T21 c:collection1 oashc.SpellCheckComponent$SpellCheckerListener.newSearcher Loading spell index for spellchecker: default
[junit4] 2> 35204 T11 c:collection1 oasu.DefaultSolrCoreState.newIndexWriter Creating new IndexWriter...
[junit4] 2> 35205 T11 c:collection1 oasu.DefaultSolrCoreState.newIndexWriter Waiting until IndexWriter is unused... core=collection1
[junit4] 2> 35205 T11 c:collection1 oasu.DefaultSolrCoreState.newIndexWriter Closing old IndexWriter... core=collection1
[junit4] 2> 35205 T21 c:collection1 oashc.SpellCheckComponent$SpellCheckerListener.newSearcher Loading spell index for spellchecker: direct
[junit4] 2> 35206 T21 c:collection1 oashc.SpellCheckComponent$SpellCheckerListener.newSearcher Loading spell index for spellchecker: wordbreak
[junit4] 2> 35206 T21 c:collection1 oashc.SpellCheckComponent$SpellCheckerListener.newSearcher Loading spell index for spellchecker: multipleFields
[junit4] 2> 35206 T11 c:collection1 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.LogDocMergePolicy: [LogDocMergePolicy: minMergeSize=1000, mergeFactor=33, maxMergeSize=9223372036854775807, maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=true, maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.121147928434372]
[junit4] 2> 35207 T21 c:collection1 oashc.SpellCheckComponent$SpellCheckerListener.newSearcher Loading spell index for spellchecker: jarowinkler
[junit4] 2> 35208 T21 c:collection1 oashc.SpellCheckComponent$SpellCheckerListener.newSearcher Loading spell index for spellchecker: external
[junit4] 2> 35210 T21 c:collection1 oashc.SpellCheckComponent$SpellCheckerListener.newSearcher Loading spell index for spellchecker: freq
[junit4] 2> 35211 T21 c:collection1 oashc.SpellCheckComponent$SpellCheckerListener.newSearcher Loading spell index for spellchecker: fqcn
[junit4] 2> 35212 T21 c:collection1 oashc.SpellCheckComponent$SpellCheckerListener.newSearcher Loading spell index for spellchecker: perDict
[junit4] 2> 35212 T11 c:collection1 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=1
[junit4] 2> commit{dir=MockDirectoryWrapper(RAMDirectory@427f722 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@5bd1db4f),segFN=segments_4,generation=4}
[junit4] 2> 35212 T21 c:collection1 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@3d29accb[collection1] main{ExitableDirectoryReader(UninvertingDirectoryReader(Uninverting(_0(5.2.0):C5) Uninverting(_2(5.2.0):C1)))}
[junit4] 2> 35213 T11 c:collection1 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 4
[junit4] 2> 35214 T11 c:collection1 oasu.DefaultSolrCoreState.newIndexWriter New IndexWriter is ready to be used.
[junit4] 2> 35223 T11 c:collection1 oass.SolrIndexSearcher.<init> Opening Searcher@192b2fef[collection1] main
[junit4] 2> 35224 T11 c:collection1 oasc.CoreContainer.registerCore replacing core: collection1
[junit4] 2> 35224 T21 c:collection1 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@192b2fef[collection1] main{ExitableDirectoryReader(UninvertingDirectoryReader(Uninverting(_0(5.2.0):C5) Uninverting(_2(5.2.0):C1)))}
[junit4] 2> 35225 T11 c:collection1 oasc.SolrCore.close [collection1] CLOSING SolrCore org.apache.solr.core.SolrCore@74e0da2d
[junit4] 2> 35227 T11 c:collection1 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=633,transaction_logs_total_number=3}
[junit4] 2> 35227 T11 c:collection1 oasc.SolrCore.closeSearcher [collection1] Closing main searcher on request.
[junit4] 2> ASYNC NEW_CORE C2 name=collection1 org.apache.solr.core.SolrCore@78658dc1
[junit4] 2> 35233 T11 c:collection1 C2 oasup.LogUpdateProcessor.finish [collection1] webapp=null path=null params={} {add=[529 (1498822011531558912)]} 0 4
[junit4] 2> 35734 T23 c:collection1 oasu.DirectUpdateHandler2.commit start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=true,prepareCommit=false}
[junit4] 2> 35756 T23 c:collection1 oass.SolrIndexSearcher.<init> Opening Searcher@2cc7fc32[collection1] main
[junit4] 2> 35758 T23 c:collection1 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4] 2> 35758 T21 c:collection1 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@2cc7fc32[collection1] main{ExitableDirectoryReader(UninvertingDirectoryReader(Uninverting(_0(5.2.0):C5) Uninverting(_2(5.2.0):C1) Uninverting(_3(5.2.0):C1)))}
[junit4] 2> 35760 T11 c:collection1 C2 oasup.LogUpdateProcessor.finish [collection1] webapp=null path=null params={} {add=[530 (1498822012086255616)]} 0 2
[junit4] 2> 36260 T23 c:collection1 oasu.DirectUpdateHandler2.commit start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=true,prepareCommit=false}
[junit4] 2> 36274 T23 c:collection1 oass.SolrIndexSearcher.<init> Opening Searcher@2c37f70c[collection1] main
[junit4] 2> 36275 T23 c:collection1 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4] 2> 36275 T21 c:collection1 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@2c37f70c[collection1] main{ExitableDirectoryReader(UninvertingDirectoryReader(Uninverting(_0(5.2.0):C5) Uninverting(_2(5.2.0):C1) Uninverting(_3(5.2.0):C1) Uninverting(_4(5.2.0):C1)))}
[junit4] 2> 36434 T22 c:collection1 oasu.DirectUpdateHandler2.commit start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4] 2> 36438 T22 c:collection1 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=2
[junit4] 2> commit{dir=MockDirectoryWrapper(RAMDirectory@427f722 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@5bd1db4f),segFN=segments_4,generation=4}
[junit4] 2> commit{dir=MockDirectoryWrapper(RAMDirectory@427f722 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@5bd1db4f),segFN=segments_5,generation=5}
[junit4] 2> 36438 T22 c:collection1 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 5
[junit4] 2> 36439 T22 c:collection1 oasc.SolrCore.openNewSearcher SolrIndexSearcher has not changed - not re-opening: org.apache.solr.search.SolrIndexSearcher
[junit4] 2> 36440 T22 c:collection1 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4] 2> 39641 T11 c:collection1 oas.SolrTestCaseJ4.tearDown ###Ending testSoftAndHardCommitMaxTimeMixedAdds
[junit4] 2> 39643 T11 c:collection1 oas.SolrTestCaseJ4.deleteCore ###deleteCore
[junit4] 2> 39644 T11 c:collection1 oasc.CoreContainer.shutdown Shutting down CoreContainer instance=331608321
[junit4] 2> 39644 T11 c:collection1 oasc.SolrCore.close [collection1] CLOSING SolrCore org.apache.solr.core.SolrCore@78658dc1
[junit4] 2> 39645 T11 c:collection1 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=838,transaction_logs_total_number=4}
[junit4] 2> 39646 T11 c:collection1 oasu.SolrCoreState.decrefSolrCoreState Closing SolrCoreState
[junit4] 2> 39646 T11 c:collection1 oasu.DefaultSolrCoreState.closeIndexWriter SolrCoreState ref count has reached 0 - closing IndexWriter
[junit4] 2> 39647 T11 c:collection1 oasu.DefaultSolrCoreState.closeIndexWriter closing IndexWriter with IndexWriterCloser
[junit4] 2> 39648 T11 c:collection1 oasc.SolrCore.closeSearcher [collection1] Closing main searcher on request.
[junit4] 2> 39651 T11 c:collection1 oasc.CachingDirectoryFactory.close Closing MockDirectoryFactory - 2 directories currently being tracked
[junit4] 2> 39652 T11 c:collection1 oasc.CachingDirectoryFactory.closeCacheValue looking to close /usr/home/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-5.x-Java7/solr/build/solr-core/test/J0/temp/solr.update.SoftAutoCommitTest 96710D3423572C68-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/J0/temp/solr.update.SoftAutoCommitTest 96710D3423572C68-001/init-core-data-001/index;done=false>>]
[junit4] 2> 39652 T11 c:collection1 oasc.CachingDirectoryFactory.close Closing directory: /usr/home/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-5.x-Java7/solr/build/solr-core/test/J0/temp/solr.update.SoftAutoCommitTest 96710D3423572C68-001/init-core-data-001/index
[junit4] 2> 39653 T11 c:collection1 oasc.CachingDirectoryFactory.closeCacheValue looking to close /usr/home/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-5.x-Java7/solr/build/solr-core/test/J0/temp/solr.update.SoftAutoCommitTest 96710D3423572C68-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/J0/temp/solr.update.SoftAutoCommitTest 96710D3423572C68-001/init-core-data-001;done=false>>]
[junit4] 2> 39653 T11 c:collection1 oasc.CachingDirectoryFactory.close Closing directory: /usr/home/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-5.x-Java7/solr/build/solr-core/test/J0/temp/solr.update.SoftAutoCommitTest 96710D3423572C68-001/init-core-data-001
[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/J0/temp/solr.update.SoftAutoCommitTest 96710D3423572C68-001
[junit4] 2> NOTE: test params are: codec=Asserting(Lucene50): {timestamp=PostingsFormat(name=Asserting), _version_=PostingsFormat(name=Asserting), text=Lucene50(blocksize=128), subject=PostingsFormat(name=Memory doPackFST= true), intDefault=PostingsFormat(name=Asserting), id=PostingsFormat(name=Direct), multiDefault=PostingsFormat(name=Memory doPackFST= true), range_facet_l=PostingsFormat(name=Asserting)}, docValues:{timestamp=DocValuesFormat(name=Lucene50)}, sim=RandomSimilarityProvider(queryNorm=true,coord=crazy): {}, locale=tr_TR, timezone=Canada/Eastern
[junit4] 2> NOTE: FreeBSD 9.1-RELEASE-p3 amd64/Oracle Corporation 1.7.0_65 (64-bit)/cpus=16,threads=1,free=119182200,total=223346688
[junit4] 2> NOTE: All tests run in this JVM: [SoftAutoCommitTest]
[junit4] Completed [3/483] on J0 in 40.79s, 3 tests, 1 failure <<< FAILURES!
[...truncated 520 lines...]
[junit4] Suite: org.apache.solr.handler.component.DistributedMLTComponentTest
[junit4] 2> Creating dataDir: /usr/home/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-5.x-Java7/solr/build/solr-core/test/J3/temp/solr.handler.component.DistributedMLTComponentTest 96710D3423572C68-001/init-core-data-001
[junit4] 2> 625850 T5629 oas.SolrTestCaseJ4.buildSSLConfig Randomized ssl (false) and clientAuth (false)
[junit4] 2> 625850 T5629 oas.BaseDistributedSearchTestCase.initHostContext Setting hostContext system property: /dd/
[junit4] 2> 627359 T5629 oas.SolrTestCaseJ4.writeCoreProperties Writing core.properties file to /usr/home/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-5.x-Java7/solr/build/solr-core/test/J3/temp/solr.handler.component.DistributedMLTComponentTest 96710D3423572C68-001/tempDir-001/control/cores/collection1
[junit4] 2> 627363 T5629 oejs.Server.doStart jetty-8.1.10.v20130312
[junit4] 2> 627367 T5629 oejs.AbstractConnector.doStart Started SocketConnector@127.0.0.1:11808
[junit4] 2> 627367 T5629 oascse.JettySolrRunner$1.lifeCycleStarted Jetty properties: {coreRootDirectory=/usr/home/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-5.x-Java7/solr/build/solr-core/test/J3/temp/solr.handler.component.DistributedMLTComponentTest 96710D3423572C68-001/tempDir-001/control/cores, hostContext=/dd, hostPort=11808}
[junit4] 2> 627367 T5629 oass.SolrDispatchFilter.init SolrDispatchFilter.init()sun.misc.Launcher$AppClassLoader@57bd06bf
[junit4] 2> 627368 T5629 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/usr/home/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-5.x-Java7/solr/build/solr-core/tes
[...truncated too long message...]
":"http://127.0.0.1:65387/wzy/oa",
[junit4] 2> "state":"down",
[junit4] 2> "roles":null,
[junit4] 2> "shard":"shard1",
[junit4] 2> "operation":"state"} current state version: 15
[junit4] 2> 1292985 T6925 C:control_collection S:shard1 c:collection1 oasu.DirectUpdateHandler2.close closing DirectUpdateHandler2{commits=1,autocommits=0,soft autocommits=0,optimizes=0,rollbacks=0,expungeDeletes=0,docsPending=0,adds=0,deletesById=0,deletesByQuery=0,errors=0,cumulative_adds=286,cumulative_deletesById=148,cumulative_deletesByQuery=1,cumulative_errors=0,transaction_logs_total_size=33183,transaction_logs_total_number=1}
[junit4] 2> 1292985 T7039 N:127.0.0.1:65387_wzy%2Foa oasco.ReplicaMutator.updateState Update state numShards=null message={
[junit4] 2> "node_name":"127.0.0.1:65387_wzy%2Foa",
[junit4] 2> "collection":"collection1",
[junit4] 2> "core_node_name":"core_node2",
[junit4] 2> "core":"collection1",
[junit4] 2> "base_url":"http://127.0.0.1:65387/wzy/oa",
[junit4] 2> "state":"down",
[junit4] 2> "roles":null,
[junit4] 2> "shard":"shard1",
[junit4] 2> "operation":"state"}
[junit4] 2> 1292985 T6925 C:control_collection S:shard1 c:collection1 oasu.SolrCoreState.decrefSolrCoreState Closing SolrCoreState
[junit4] 2> 1292986 T6925 C:control_collection S:shard1 c:collection1 oasu.DefaultSolrCoreState.closeIndexWriter SolrCoreState ref count has reached 0 - closing IndexWriter
[junit4] 2> 1292986 T6925 C:control_collection S:shard1 c:collection1 oasu.DefaultSolrCoreState.closeIndexWriter closing IndexWriter with IndexWriterCloser
[junit4] 2> 1292988 T6925 C:control_collection S:shard1 c:collection1 oasc.SolrCore.closeSearcher [collection1] Closing main searcher on request.
[junit4] 2> 1293001 T7038 N:127.0.0.1:65387_wzy%2Foa oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 1)
[junit4] 2> 1293006 T6925 C:control_collection S:shard1 c:collection1 oasc.CachingDirectoryFactory.close Closing StandardDirectoryFactory - 2 directories currently being tracked
[junit4] 2> 1293006 T6925 C:control_collection S:shard1 c:collection1 oasc.CachingDirectoryFactory.closeCacheValue looking to close /usr/home/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-5.x-Java7/solr/build/solr-core/test/J3/temp/solr.cloud.ChaosMonkeyNothingIsSafeTest 96710D3423572C68-001/shard-2-001/cores/collection1/data [CachedDir<<refCount=0;path=/usr/home/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-5.x-Java7/solr/build/solr-core/test/J3/temp/solr.cloud.ChaosMonkeyNothingIsSafeTest 96710D3423572C68-001/shard-2-001/cores/collection1/data;done=false>>]
[junit4] 2> 1293007 T6925 C:control_collection S:shard1 c:collection1 oasc.CachingDirectoryFactory.close Closing directory: /usr/home/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-5.x-Java7/solr/build/solr-core/test/J3/temp/solr.cloud.ChaosMonkeyNothingIsSafeTest 96710D3423572C68-001/shard-2-001/cores/collection1/data
[junit4] 2> 1293007 T6925 C:control_collection S:shard1 c:collection1 oasc.CachingDirectoryFactory.closeCacheValue looking to close /usr/home/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-5.x-Java7/solr/build/solr-core/test/J3/temp/solr.cloud.ChaosMonkeyNothingIsSafeTest 96710D3423572C68-001/shard-2-001/cores/collection1/data/index [CachedDir<<refCount=0;path=/usr/home/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-5.x-Java7/solr/build/solr-core/test/J3/temp/solr.cloud.ChaosMonkeyNothingIsSafeTest 96710D3423572C68-001/shard-2-001/cores/collection1/data/index;done=false>>]
[junit4] 2> 1293007 T6925 C:control_collection S:shard1 c:collection1 oasc.CachingDirectoryFactory.close Closing directory: /usr/home/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-5.x-Java7/solr/build/solr-core/test/J3/temp/solr.cloud.ChaosMonkeyNothingIsSafeTest 96710D3423572C68-001/shard-2-001/cores/collection1/data/index
[junit4] 2> 1293008 T6925 C:control_collection S:shard1 c:collection1 oasc.Overseer.close Overseer (id=93676451008675848-127.0.0.1:65387_wzy%2Foa-n_0000000002) closing
[junit4] 2> 1293008 T7039 N:127.0.0.1:65387_wzy%2Foa oasc.Overseer$ClusterStateUpdater.run Overseer Loop exiting : 127.0.0.1:65387_wzy%2Foa
[junit4] 2> 1293010 T7038 N:127.0.0.1:65387_wzy%2Foa oascc.ZkStateReader$3.process WARN ZooKeeper watch triggered, but Solr cannot talk to ZK
[junit4] 2> 1293011 T6925 oejsh.ContextHandler.doStop stopped o.e.j.s.ServletContextHandler{/wzy/oa,null}
[junit4] 2> 1293215 T6925 C:control_collection S:shard1 c:collection1 oasc.ZkTestServer.send4LetterWord connecting to 127.0.0.1:65293 65293
[junit4] 2> 1293317 T7021 oasc.ZkTestServer.send4LetterWord connecting to 127.0.0.1:65293 65293
[junit4] 2> NOTE: reproduce with: ant test -Dtestcase=ChaosMonkeyNothingIsSafeTest -Dtests.method=test -Dtests.seed=96710D3423572C68 -Dtests.multiplier=2 -Dtests.slow=true -Dtests.locale=es_CR -Dtests.timezone=America/Cordoba -Dtests.asserts=true -Dtests.file.encoding=US-ASCII
[junit4] FAILURE 109s J3 | ChaosMonkeyNothingIsSafeTest.test <<<
[junit4] > Throwable #1: java.lang.AssertionError: There were too many update fails (30 > 20) - we expect it can happen, but shouldn't easily
[junit4] > at __randomizedtesting.SeedInfo.seed([96710D3423572C68:1E2532EE8DAB4190]:0)
[junit4] > at org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest.test(ChaosMonkeyNothingIsSafeTest.java:230)
[junit4] > at org.apache.solr.BaseDistributedSearchTestCase$ShardsRepeatRule$ShardsFixedStatement.callStatement(BaseDistributedSearchTestCase.java:960)
[junit4] > at org.apache.solr.BaseDistributedSearchTestCase$ShardsRepeatRule$ShardsStatement.evaluate(BaseDistributedSearchTestCase.java:935)
[junit4] > at java.lang.Thread.run(Thread.java:745)
[junit4] 2> 1293327 T6925 C:control_collection S:shard1 c:collection1 oas.SolrTestCaseJ4.deleteCore ###deleteCore
[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/J3/temp/solr.cloud.ChaosMonkeyNothingIsSafeTest 96710D3423572C68-001
[junit4] 2> 108714 T6924 ccr.ThreadLeakControl.checkThreadLeaks WARNING Will linger awaiting termination of 1 leaked thread(s).
[junit4] 2> NOTE: test params are: codec=CheapBastard, sim=RandomSimilarityProvider(queryNorm=false,coord=no): {}, locale=es_CR, timezone=America/Cordoba
[junit4] 2> NOTE: FreeBSD 9.1-RELEASE-p3 amd64/Oracle Corporation 1.7.0_65 (64-bit)/cpus=16,threads=1,free=144169576,total=310378496
[junit4] 2> NOTE: All tests run in this JVM: [TestStressUserVersions, ExternalCollectionsTest, DefaultValueUpdateProcessorTest, TestSchemaVersionResource, TestDefaultStatsCache, RequiredFieldsTest, DebugComponentTest, MBeansHandlerTest, IndexBasedSpellCheckerTest, IndexSchemaRuntimeFieldTest, CursorMarkTest, TestJmxMonitoredMap, TestMissingGroups, TestPivotHelperCode, TestNonDefinedSimilarityFactory, TestManagedSchemaFieldTypeResource, RollingRestartTest, CoreMergeIndexesAdminHandlerTest, TestSolrConfigHandlerCloud, CloudExitableDirectoryReaderTest, SSLMigrationTest, FileUtilsTest, CacheHeaderTest, TestJettySolrRunner, TestPhraseSuggestions, SimpleFacetsTest, SliceStateTest, SpatialHeatmapFacetsTest, TestValueSourceCache, ZkSolrClientTest, SynonymTokenizerTest, TestManagedResource, TestHighlightDedupGrouping, OverseerCollectionProcessorTest, CachingDirectoryFactoryTest, TestReload, TestDefaultSearchFieldResource, TestReplicationHandler, RequestHandlersTest, TestDefaultSimilarityFactory, DocValuesMultiTest, DistributedSpellCheckComponentTest, ParsingFieldUpdateProcessorsTest, DistributedMLTComponentTest, UUIDFieldTest, ConcurrentDeleteAndCreateCollectionTest, TestIntervalFaceting, HdfsCollectionsAPIDistributedZkTest, HdfsLockFactoryTest, DateRangeFieldTest, TestCollectionAPI, StandardRequestHandlerTest, TestBinaryResponseWriter, BadComponentTest, TermVectorComponentTest, ShardRoutingCustomTest, TestSerializedLuceneMatchVersion, LeaderFailoverAfterPartitionTest, ChaosMonkeyNothingIsSafeTest]
[junit4] Completed [246/483] on J3 in 109.03s, 1 test, 1 failure <<< FAILURES!
[...truncated 753 lines...]
BUILD FAILED
/usr/home/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-5.x-Java7/build.xml:536: The following error occurred while executing this line:
/usr/home/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-5.x-Java7/build.xml:484: 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:229: The following error occurred while executing this line:
/usr/home/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-5.x-Java7/solr/common-build.xml:511: The following error occurred while executing this line:
/usr/home/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-5.x-Java7/lucene/common-build.xml:1434: The following error occurred while executing this line:
/usr/home/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-5.x-Java7/lucene/common-build.xml:991: There were test failures: 483 suites, 1917 tests, 1 error, 2 failures, 65 ignored (24 assumptions)
Total time: 52 minutes 3 seconds
Build step 'Invoke Ant' marked build as failure
Archiving artifacts
Sending artifact delta relative to Lucene-Solr-Tests-5.x-Java7 #2966
Archived 5 artifacts
Archive block size is 32768
Received 0 blocks and 230536385 bytes
Compression is 0.0%
Took 45 sec
Recording test results
Email was triggered for: Failure
Sending email for trigger: Failure