Build: http://jenkins.thetaphi.de/job/Lucene-Solr-trunk-Linux/15658/
Java: 32bit/jdk-9-ea+95 -server -XX:+UseParallelGC -XX:-CompactStrings

2 tests failed.
FAILED:  org.apache.solr.cloud.CollectionsAPIDistributedZkTest.test

Error Message:
Error from server at http://127.0.0.1:43001/v_s/w/awholynewcollection_0: non ok 
status: 500, message:Server Error

Stack Trace:
org.apache.solr.client.solrj.impl.HttpSolrClient$RemoteSolrException: Error 
from server at http://127.0.0.1:43001/v_s/w/awholynewcollection_0: non ok 
status: 500, message:Server Error
        at 
__randomizedtesting.SeedInfo.seed([DB7C2B831BD4D005:53281459B528BDFD]:0)
        at 
org.apache.solr.client.solrj.impl.HttpSolrClient.executeMethod(HttpSolrClient.java:511)
        at 
org.apache.solr.client.solrj.impl.HttpSolrClient.request(HttpSolrClient.java:240)
        at 
org.apache.solr.client.solrj.impl.HttpSolrClient.request(HttpSolrClient.java:229)
        at 
org.apache.solr.client.solrj.SolrRequest.process(SolrRequest.java:150)
        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.cloud.AbstractFullDistribZkTestBase.waitForNon403or404or503(AbstractFullDistribZkTestBase.java:1773)
        at 
org.apache.solr.cloud.CollectionsAPIDistributedZkTest.testCollectionsAPI(CollectionsAPIDistributedZkTest.java:644)
        at 
org.apache.solr.cloud.CollectionsAPIDistributedZkTest.test(CollectionsAPIDistributedZkTest.java:160)
        at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
        at 
sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
        at 
sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
        at java.lang.reflect.Method.invoke(Method.java:520)
        at 
com.carrotsearch.randomizedtesting.RandomizedRunner.invoke(RandomizedRunner.java:1764)
        at 
com.carrotsearch.randomizedtesting.RandomizedRunner$8.evaluate(RandomizedRunner.java:871)
        at 
com.carrotsearch.randomizedtesting.RandomizedRunner$9.evaluate(RandomizedRunner.java:907)
        at 
com.carrotsearch.randomizedtesting.RandomizedRunner$10.evaluate(RandomizedRunner.java:921)
        at 
org.apache.solr.BaseDistributedSearchTestCase$ShardsRepeatRule$ShardsFixedStatement.callStatement(BaseDistributedSearchTestCase.java:965)
        at 
org.apache.solr.BaseDistributedSearchTestCase$ShardsRepeatRule$ShardsStatement.evaluate(BaseDistributedSearchTestCase.java:940)
        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:367)
        at 
com.carrotsearch.randomizedtesting.ThreadLeakControl.forkTimeoutingTask(ThreadLeakControl.java:809)
        at 
com.carrotsearch.randomizedtesting.ThreadLeakControl$3.evaluate(ThreadLeakControl.java:460)
        at 
com.carrotsearch.randomizedtesting.RandomizedRunner.runSingleTest(RandomizedRunner.java:880)
        at 
com.carrotsearch.randomizedtesting.RandomizedRunner$5.evaluate(RandomizedRunner.java:781)
        at 
com.carrotsearch.randomizedtesting.RandomizedRunner$6.evaluate(RandomizedRunner.java:816)
        at 
com.carrotsearch.randomizedtesting.RandomizedRunner$7.evaluate(RandomizedRunner.java:827)
        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:40)
        at 
com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:40)
        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:367)
        at java.lang.Thread.run(Thread.java:747)


FAILED:  
org.apache.solr.update.SoftAutoCommitTest.testSoftAndHardCommitMaxTimeRapidAdds

Error Message:
2: soft wasn't fast enough

Stack Trace:
java.lang.AssertionError: 2: soft wasn't fast enough
        at 
__randomizedtesting.SeedInfo.seed([DB7C2B831BD4D005:876985BAF056917D]: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:323)
        at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
        at 
sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
        at 
sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
        at java.lang.reflect.Method.invoke(Method.java:520)
        at 
com.carrotsearch.randomizedtesting.RandomizedRunner.invoke(RandomizedRunner.java:1764)
        at 
com.carrotsearch.randomizedtesting.RandomizedRunner$8.evaluate(RandomizedRunner.java:871)
        at 
com.carrotsearch.randomizedtesting.RandomizedRunner$9.evaluate(RandomizedRunner.java:907)
        at 
com.carrotsearch.randomizedtesting.RandomizedRunner$10.evaluate(RandomizedRunner.java:921)
        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:367)
        at 
com.carrotsearch.randomizedtesting.ThreadLeakControl.forkTimeoutingTask(ThreadLeakControl.java:809)
        at 
com.carrotsearch.randomizedtesting.ThreadLeakControl$3.evaluate(ThreadLeakControl.java:460)
        at 
com.carrotsearch.randomizedtesting.RandomizedRunner.runSingleTest(RandomizedRunner.java:880)
        at 
com.carrotsearch.randomizedtesting.RandomizedRunner$5.evaluate(RandomizedRunner.java:781)
        at 
com.carrotsearch.randomizedtesting.RandomizedRunner$6.evaluate(RandomizedRunner.java:816)
        at 
com.carrotsearch.randomizedtesting.RandomizedRunner$7.evaluate(RandomizedRunner.java:827)
        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:40)
        at 
com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:40)
        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:367)
        at java.lang.Thread.run(Thread.java:747)




Build Log:
[...truncated 9649 lines...]
   [junit4] Suite: org.apache.solr.update.SoftAutoCommitTest
   [junit4]   2> Creating dataDir: 
/home/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/temp/solr.update.SoftAutoCommitTest_DB7C2B831BD4D005-001/init-core-data-001
   [junit4]   2> 389869 INFO  
(SUITE-SoftAutoCommitTest-seed#[DB7C2B831BD4D005]-worker) [    ] 
o.a.s.SolrTestCaseJ4 Randomized ssl (false) and clientAuth (false)
   [junit4]   2> 389869 INFO  
(SUITE-SoftAutoCommitTest-seed#[DB7C2B831BD4D005]-worker) [    ] 
o.a.s.SolrTestCaseJ4 ####initCore
   [junit4]   2> 389869 INFO  
(SUITE-SoftAutoCommitTest-seed#[DB7C2B831BD4D005]-worker) [    ] 
o.a.s.c.SolrResourceLoader new SolrResourceLoader for directory: 
'/home/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/core/src/test-files/solr/collection1'
   [junit4]   2> 389870 INFO  
(SUITE-SoftAutoCommitTest-seed#[DB7C2B831BD4D005]-worker) [    ] 
o.a.s.c.SolrResourceLoader JNDI not configured for solr (NoInitialContextEx)
   [junit4]   2> 389870 INFO  
(SUITE-SoftAutoCommitTest-seed#[DB7C2B831BD4D005]-worker) [    ] 
o.a.s.c.SolrResourceLoader using system property solr.solr.home: 
/home/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/core/src/test-files/solr
   [junit4]   2> 389870 INFO  
(SUITE-SoftAutoCommitTest-seed#[DB7C2B831BD4D005]-worker) [    ] 
o.a.s.c.SolrResourceLoader Adding 
'file:/home/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/core/src/test-files/solr/collection1/lib/classes/'
 to classloader
   [junit4]   2> 389870 INFO  
(SUITE-SoftAutoCommitTest-seed#[DB7C2B831BD4D005]-worker) [    ] 
o.a.s.c.SolrResourceLoader Adding 
'file:/home/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/core/src/test-files/solr/collection1/lib/README'
 to classloader
   [junit4]   2> 389895 INFO  
(SUITE-SoftAutoCommitTest-seed#[DB7C2B831BD4D005]-worker) [    ] 
o.a.s.c.SolrConfig current version of requestparams : -1
   [junit4]   2> 389904 INFO  
(SUITE-SoftAutoCommitTest-seed#[DB7C2B831BD4D005]-worker) [    ] 
o.a.s.c.SolrConfig Using Lucene MatchVersion: 6.0.0
   [junit4]   2> 389919 INFO  
(SUITE-SoftAutoCommitTest-seed#[DB7C2B831BD4D005]-worker) [    ] 
o.a.s.c.SolrConfig Loaded SolrConfig: solrconfig.xml
   [junit4]   2> 389923 INFO  
(SUITE-SoftAutoCommitTest-seed#[DB7C2B831BD4D005]-worker) [    ] 
o.a.s.s.IndexSchema [null] Schema name=test
   [junit4]   2> 389972 INFO  
(SUITE-SoftAutoCommitTest-seed#[DB7C2B831BD4D005]-worker) [    ] 
o.a.s.s.OpenExchangeRatesOrgProvider Initialized with 
rates=open-exchange-rates.json, refreshInterval=1440.
   [junit4]   2> 389976 INFO  
(SUITE-SoftAutoCommitTest-seed#[DB7C2B831BD4D005]-worker) [    ] 
o.a.s.s.IndexSchema default search field in schema is text
   [junit4]   2> 389976 INFO  
(SUITE-SoftAutoCommitTest-seed#[DB7C2B831BD4D005]-worker) [    ] 
o.a.s.s.IndexSchema unique key field: id
   [junit4]   2> 389980 INFO  
(SUITE-SoftAutoCommitTest-seed#[DB7C2B831BD4D005]-worker) [    ] 
o.a.s.s.FileExchangeRateProvider Reloading exchange rates from file currency.xml
   [junit4]   2> 389982 INFO  
(SUITE-SoftAutoCommitTest-seed#[DB7C2B831BD4D005]-worker) [    ] 
o.a.s.s.FileExchangeRateProvider Reloading exchange rates from file currency.xml
   [junit4]   2> 389983 INFO  
(SUITE-SoftAutoCommitTest-seed#[DB7C2B831BD4D005]-worker) [    ] 
o.a.s.s.OpenExchangeRatesOrgProvider Reloading exchange rates from 
open-exchange-rates.json
   [junit4]   2> 389983 INFO  
(SUITE-SoftAutoCommitTest-seed#[DB7C2B831BD4D005]-worker) [    ] 
o.a.s.s.OpenExchangeRatesOrgProvider Reloading exchange rates from 
open-exchange-rates.json
   [junit4]   2> 389984 INFO  
(SUITE-SoftAutoCommitTest-seed#[DB7C2B831BD4D005]-worker) [    ] 
o.a.s.c.SolrResourceLoader JNDI not configured for solr (NoInitialContextEx)
   [junit4]   2> 389984 INFO  
(SUITE-SoftAutoCommitTest-seed#[DB7C2B831BD4D005]-worker) [    ] 
o.a.s.c.SolrResourceLoader using system property solr.solr.home: 
/home/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/core/src/test-files/solr
   [junit4]   2> 389984 INFO  
(SUITE-SoftAutoCommitTest-seed#[DB7C2B831BD4D005]-worker) [    ] 
o.a.s.c.SolrResourceLoader new SolrResourceLoader for directory: 
'/home/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/core/src/test-files/solr'
   [junit4]   2> 389984 INFO  
(SUITE-SoftAutoCommitTest-seed#[DB7C2B831BD4D005]-worker) [    ] 
o.a.s.c.SolrResourceLoader JNDI not configured for solr (NoInitialContextEx)
   [junit4]   2> 389984 INFO  
(SUITE-SoftAutoCommitTest-seed#[DB7C2B831BD4D005]-worker) [    ] 
o.a.s.c.SolrResourceLoader using system property solr.solr.home: 
/home/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/core/src/test-files/solr
   [junit4]   2> 389984 INFO  
(SUITE-SoftAutoCommitTest-seed#[DB7C2B831BD4D005]-worker) [    ] 
o.a.s.c.CoreContainer New CoreContainer 7312797
   [junit4]   2> 389984 INFO  
(SUITE-SoftAutoCommitTest-seed#[DB7C2B831BD4D005]-worker) [    ] 
o.a.s.c.CoreContainer Loading cores into CoreContainer 
[instanceDir=/home/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/core/src/test-files/solr]
   [junit4]   2> 389984 WARN  
(SUITE-SoftAutoCommitTest-seed#[DB7C2B831BD4D005]-worker) [    ] 
o.a.s.c.CoreContainer Couldn't add files from 
/home/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/core/src/test-files/solr/lib
 to classpath: 
/home/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/core/src/test-files/solr/lib
   [junit4]   2> 389984 INFO  
(SUITE-SoftAutoCommitTest-seed#[DB7C2B831BD4D005]-worker) [    ] 
o.a.s.h.c.HttpShardHandlerFactory created with socketTimeout : 
600000,connTimeout : 60000,maxConnectionsPerHost : 20,maxConnections : 
10000,corePoolSize : 0,maximumPoolSize : 2147483647,maxThreadIdleTime : 
5,sizeOfQueue : -1,fairnessPolicy : false,useRetries : false,
   [junit4]   2> 389990 INFO  
(SUITE-SoftAutoCommitTest-seed#[DB7C2B831BD4D005]-worker) [    ] 
o.a.s.u.UpdateShardHandler Creating UpdateShardHandler HTTP client with params: 
socketTimeout=30000&connTimeout=30000&retry=true
   [junit4]   2> 389990 INFO  
(SUITE-SoftAutoCommitTest-seed#[DB7C2B831BD4D005]-worker) [    ] 
o.a.s.l.LogWatcher SLF4J impl is org.slf4j.impl.Log4jLoggerFactory
   [junit4]   2> 389990 INFO  
(SUITE-SoftAutoCommitTest-seed#[DB7C2B831BD4D005]-worker) [    ] 
o.a.s.l.LogWatcher Registering Log Listener [Log4j 
(org.slf4j.impl.Log4jLoggerFactory)]
   [junit4]   2> 389990 INFO  
(SUITE-SoftAutoCommitTest-seed#[DB7C2B831BD4D005]-worker) [    ] 
o.a.s.c.CoreContainer Security conf doesn't exist. Skipping setup for 
authorization module.
   [junit4]   2> 389990 INFO  
(SUITE-SoftAutoCommitTest-seed#[DB7C2B831BD4D005]-worker) [    ] 
o.a.s.c.CoreContainer No authentication plugin used.
   [junit4]   2> 389991 INFO  
(SUITE-SoftAutoCommitTest-seed#[DB7C2B831BD4D005]-worker) [    ] 
o.a.s.c.CoreDescriptor Created CoreDescriptor: {name=collection1, 
config=solrconfig.xml, transient=false, schema=schema.xml, loadOnStartup=true, 
configSetProperties=configsetprops.json, collection=collection1, 
dataDir=/home/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/temp/solr.update.SoftAutoCommitTest_DB7C2B831BD4D005-001/init-core-data-001,
 shard=shard1}
   [junit4]   2> 389991 INFO  (coreLoadExecutor-1090-thread-1) [    ] 
o.a.s.c.SolrResourceLoader new SolrResourceLoader for directory: 
'/home/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/core/src/test-files/solr/collection1'
   [junit4]   2> 389992 INFO  (coreLoadExecutor-1090-thread-1) [    ] 
o.a.s.c.SolrResourceLoader JNDI not configured for solr (NoInitialContextEx)
   [junit4]   2> 389992 INFO  (coreLoadExecutor-1090-thread-1) [    ] 
o.a.s.c.SolrResourceLoader using system property solr.solr.home: 
/home/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/core/src/test-files/solr
   [junit4]   2> 389992 INFO  (coreLoadExecutor-1090-thread-1) [    ] 
o.a.s.c.SolrResourceLoader Adding 
'file:/home/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/core/src/test-files/solr/collection1/lib/classes/'
 to classloader
   [junit4]   2> 389992 INFO  (coreLoadExecutor-1090-thread-1) [    ] 
o.a.s.c.SolrResourceLoader Adding 
'file:/home/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/core/src/test-files/solr/collection1/lib/README'
 to classloader
   [junit4]   2> 390016 INFO  (coreLoadExecutor-1090-thread-1) [    ] 
o.a.s.c.SolrConfig current version of requestparams : -1
   [junit4]   2> 390021 INFO  (coreLoadExecutor-1090-thread-1) [    ] 
o.a.s.c.SolrConfig Using Lucene MatchVersion: 6.0.0
   [junit4]   2> 390033 INFO  (coreLoadExecutor-1090-thread-1) [    ] 
o.a.s.c.SolrConfig Loaded SolrConfig: solrconfig.xml
   [junit4]   2> 390037 INFO  (coreLoadExecutor-1090-thread-1) [    ] 
o.a.s.s.IndexSchema [collection1] Schema name=test
   [junit4]   2> 390088 INFO  (coreLoadExecutor-1090-thread-1) [    ] 
o.a.s.s.OpenExchangeRatesOrgProvider Initialized with 
rates=open-exchange-rates.json, refreshInterval=1440.
   [junit4]   2> 390093 INFO  (coreLoadExecutor-1090-thread-1) [    ] 
o.a.s.s.IndexSchema default search field in schema is text
   [junit4]   2> 390094 INFO  (coreLoadExecutor-1090-thread-1) [    ] 
o.a.s.s.IndexSchema unique key field: id
   [junit4]   2> 390097 INFO  (coreLoadExecutor-1090-thread-1) [    ] 
o.a.s.s.FileExchangeRateProvider Reloading exchange rates from file currency.xml
   [junit4]   2> 390098 INFO  (coreLoadExecutor-1090-thread-1) [    ] 
o.a.s.s.FileExchangeRateProvider Reloading exchange rates from file currency.xml
   [junit4]   2> 390099 INFO  (coreLoadExecutor-1090-thread-1) [    ] 
o.a.s.s.OpenExchangeRatesOrgProvider Reloading exchange rates from 
open-exchange-rates.json
   [junit4]   2> 390099 INFO  (coreLoadExecutor-1090-thread-1) [    ] 
o.a.s.s.OpenExchangeRatesOrgProvider Reloading exchange rates from 
open-exchange-rates.json
   [junit4]   2> 390101 INFO  (coreLoadExecutor-1090-thread-1) [    ] 
o.a.s.c.ConfigSetProperties Did not find ConfigSet properties, assuming default 
properties: Can't find resource 'configsetprops.json' in classpath or 
'/home/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/core/src/test-files/solr/collection1'
   [junit4]   2> 390101 INFO  (coreLoadExecutor-1090-thread-1) [    ] 
o.a.s.c.CoreContainer Creating SolrCore 'collection1' using configuration from 
instancedir 
/home/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/core/src/test-files/solr/collection1
   [junit4]   2> 390101 INFO  (coreLoadExecutor-1090-thread-1) [    ] 
o.a.s.c.SolrCore org.apache.solr.core.MockDirectoryFactory
   [junit4]   2> 390101 INFO  (coreLoadExecutor-1090-thread-1) [    ] 
o.a.s.c.SolrCore [[collection1] ] Opening new SolrCore at 
[/home/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/core/src/test-files/solr/collection1],
 
dataDir=[/home/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/temp/solr.update.SoftAutoCommitTest_DB7C2B831BD4D005-001/init-core-data-001/]
   [junit4]   2> 390101 INFO  (coreLoadExecutor-1090-thread-1) [    ] 
o.a.s.c.JmxMonitoredMap JMX monitoring is enabled. Adding Solr mbeans to JMX 
Server: com.sun.jmx.mbeanserver.JmxMBeanServer@bd6c92
   [junit4]   2> 390102 INFO  (coreLoadExecutor-1090-thread-1) [    ] 
o.a.s.c.CachingDirectoryFactory return new directory for 
/home/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/temp/solr.update.SoftAutoCommitTest_DB7C2B831BD4D005-001/init-core-data-001
   [junit4]   2> 390102 INFO  (coreLoadExecutor-1090-thread-1) [    ] 
o.a.s.c.SolrCore New index directory detected: old=null 
new=/home/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/temp/solr.update.SoftAutoCommitTest_DB7C2B831BD4D005-001/init-core-data-001/index/
   [junit4]   2> 390102 WARN  (coreLoadExecutor-1090-thread-1) [    ] 
o.a.s.c.SolrCore [collection1] Solr index directory 
'/home/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/temp/solr.update.SoftAutoCommitTest_DB7C2B831BD4D005-001/init-core-data-001/index'
 doesn't exist. Creating new index...
   [junit4]   2> 390102 INFO  (coreLoadExecutor-1090-thread-1) [    ] 
o.a.s.c.CachingDirectoryFactory return new directory for 
/home/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/temp/solr.update.SoftAutoCommitTest_DB7C2B831BD4D005-001/init-core-data-001/index
   [junit4]   2> 390102 INFO  (coreLoadExecutor-1090-thread-1) [    ] 
o.a.s.u.RandomMergePolicy RandomMergePolicy wrapping class 
org.apache.lucene.index.AlcoholicMergePolicy: [AlcoholicMergePolicy: 
minMergeSize=0, mergeFactor=10, maxMergeSize=989934577, 
maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=true, 
maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12, 
noCFSRatio=0.1]
   [junit4]   2> 390103 INFO  (coreLoadExecutor-1090-thread-1) [    ] 
o.a.s.c.SolrDeletionPolicy SolrDeletionPolicy.onCommit: commits: num=1
   [junit4]   2>        commit{dir=MockDirectoryWrapper(RAMDirectory@f4f966 
lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@e86492),segFN=segments_1,generation=1}
   [junit4]   2> 390103 INFO  (coreLoadExecutor-1090-thread-1) [    ] 
o.a.s.c.SolrDeletionPolicy newest commit generation = 1
   [junit4]   2> 390103 INFO  
(OldIndexDirectoryCleanupThreadForCore-collection1) [    ] o.a.s.c.SolrCore 
Looking for old index directories to cleanup for core collection1 in 
/home/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/temp/solr.update.SoftAutoCommitTest_DB7C2B831BD4D005-001/init-core-data-001/
   [junit4]   2> 390105 INFO  (coreLoadExecutor-1090-thread-1) [    ] 
o.a.s.u.p.UpdateRequestProcessorChain creating updateRequestProcessorChain 
"dedupe"
   [junit4]   2> 390105 INFO  (coreLoadExecutor-1090-thread-1) [    ] 
o.a.s.u.p.UpdateRequestProcessorChain inserting 
DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
   [junit4]   2> 390105 INFO  (coreLoadExecutor-1090-thread-1) [    ] 
o.a.s.u.p.UpdateRequestProcessorChain creating updateRequestProcessorChain 
"dedupe-allfields"
   [junit4]   2> 390105 INFO  (coreLoadExecutor-1090-thread-1) [    ] 
o.a.s.u.p.UpdateRequestProcessorChain inserting 
DistributedUpdateProcessorFactory into updateRequestProcessorChain 
"dedupe-allfields"
   [junit4]   2> 390105 INFO  (coreLoadExecutor-1090-thread-1) [    ] 
o.a.s.u.p.UpdateRequestProcessorChain creating updateRequestProcessorChain 
"stored_sig"
   [junit4]   2> 390105 INFO  (coreLoadExecutor-1090-thread-1) [    ] 
o.a.s.u.p.UpdateRequestProcessorChain inserting 
DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
   [junit4]   2> 390105 INFO  (coreLoadExecutor-1090-thread-1) [    ] 
o.a.s.u.p.UpdateRequestProcessorChain creating updateRequestProcessorChain 
"uniq-fields"
   [junit4]   2> 390105 INFO  (coreLoadExecutor-1090-thread-1) [    ] 
o.a.s.u.p.UpdateRequestProcessorChain inserting 
DistributedUpdateProcessorFactory into updateRequestProcessorChain "uniq-fields"
   [junit4]   2> 390105 INFO  (coreLoadExecutor-1090-thread-1) [    ] 
o.a.s.u.p.UpdateRequestProcessorChain creating updateRequestProcessorChain 
"distrib-dup-test-chain-explicit"
   [junit4]   2> 390105 INFO  (coreLoadExecutor-1090-thread-1) [    ] 
o.a.s.u.p.UpdateRequestProcessorChain creating updateRequestProcessorChain 
"distrib-dup-test-chain-implicit"
   [junit4]   2> 390105 INFO  (coreLoadExecutor-1090-thread-1) [    ] 
o.a.s.u.p.UpdateRequestProcessorChain inserting 
DistributedUpdateProcessorFactory into updateRequestProcessorChain 
"distrib-dup-test-chain-implicit"
   [junit4]   2> 390106 INFO  (coreLoadExecutor-1090-thread-1) [    ] 
o.a.s.c.SolrCore no updateRequestProcessorChain defined as default, creating 
implicit default
   [junit4]   2> 390107 INFO  (coreLoadExecutor-1090-thread-1) [    ] 
o.a.s.h.l.XMLLoader xsltCacheLifetimeSeconds=60
   [junit4]   2> 390107 INFO  (coreLoadExecutor-1090-thread-1) [    ] 
o.a.s.h.l.XMLLoader xsltCacheLifetimeSeconds=60
   [junit4]   2> 390108 INFO  (coreLoadExecutor-1090-thread-1) [    ] 
o.a.s.h.l.XMLLoader xsltCacheLifetimeSeconds=60
   [junit4]   2> 390108 INFO  (coreLoadExecutor-1090-thread-1) [    ] 
o.a.s.h.l.XMLLoader xsltCacheLifetimeSeconds=60
   [junit4]   2> 390110 INFO  (coreLoadExecutor-1090-thread-1) [    ] 
o.a.s.c.PluginBag requestHandler : 'lazy' created with startup=lazy 
   [junit4]   2> 390111 INFO  (coreLoadExecutor-1090-thread-1) [    ] 
o.a.s.c.RequestHandlers Registered paths: 
/admin/mbeans,standard,spellCheckCompRH,lazy,/update/json/docs,/admin/luke,/export,spellCheckWithWordbreak_Direct,tvrh,/get,/admin/properties,/update/json,mltrh,/admin/threads,/search-facet-def,/update/csv,/sql,/search-facet-invariants,/admin/segments,spellCheckCompRH1,/mlt,/admin/system,/replication,dismax,defaults,/config,/stream,/schema,/admin/plugins,/admin/logging,spellCheckWithWordbreak,mock,/admin/ping,/update,/admin/file,/terms,spellCheckCompRH_Direct,/debug/dump
   [junit4]   2> 390111 WARN  (coreLoadExecutor-1090-thread-1) [    ] 
o.a.s.c.SolrCore solrconfig.xml uses deprecated <admin/gettableFiles>, Please 
update your config to use the ShowFileRequestHandler.
   [junit4]   2> 390112 INFO  (coreLoadExecutor-1090-thread-1) [    ] 
o.a.s.c.SolrCore Using default statsCache cache: 
org.apache.solr.search.stats.LocalStatsCache
   [junit4]   2> 390112 INFO  (coreLoadExecutor-1090-thread-1) [    ] 
o.a.s.u.UpdateHandler Using UpdateLog implementation: 
org.apache.solr.update.UpdateLog
   [junit4]   2> 390112 INFO  (coreLoadExecutor-1090-thread-1) [    ] 
o.a.s.u.UpdateLog Initializing UpdateLog: dataDir= defaultSyncLevel=FLUSH 
numRecordsToKeep=100 maxNumLogsToKeep=10 numVersionBuckets=65536
   [junit4]   2> 390112 INFO  (coreLoadExecutor-1090-thread-1) [    ] 
o.a.s.u.CommitTracker Hard AutoCommit: disabled
   [junit4]   2> 390112 INFO  (coreLoadExecutor-1090-thread-1) [    ] 
o.a.s.u.CommitTracker Soft AutoCommit: disabled
   [junit4]   2> 390113 INFO  (coreLoadExecutor-1090-thread-1) [    ] 
o.a.s.u.RandomMergePolicy RandomMergePolicy wrapping class 
org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: 
maxMergeAtOnce=39, maxMergeAtOnceExplicit=41, maxMergedSegmentMB=67.330078125, 
floorSegmentMB=0.5947265625, forceMergeDeletesPctAllowed=27.045968539838846, 
segmentsPerTier=50.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=1.0
   [junit4]   2> 390113 INFO  (coreLoadExecutor-1090-thread-1) [    ] 
o.a.s.c.SolrDeletionPolicy SolrDeletionPolicy.onInit: commits: num=1
   [junit4]   2>        commit{dir=MockDirectoryWrapper(RAMDirectory@f4f966 
lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@e86492),segFN=segments_1,generation=1}
   [junit4]   2> 390113 INFO  (coreLoadExecutor-1090-thread-1) [    ] 
o.a.s.c.SolrDeletionPolicy newest commit generation = 1
   [junit4]   2> 390113 INFO  (coreLoadExecutor-1090-thread-1) [    ] 
o.a.s.s.SolrIndexSearcher Opening [Searcher@5ff977[collection1] main]
   [junit4]   2> 390113 INFO  (coreLoadExecutor-1090-thread-1) [    ] 
o.a.s.r.RestManager Initializing RestManager with initArgs: 
{storageIO=org.apache.solr.rest.ManagedResourceStorage$InMemoryStorageIO}
   [junit4]   2> 390113 INFO  (coreLoadExecutor-1090-thread-1) [    ] 
o.a.s.r.ManagedResourceStorage Reading _rest_managed.json using InMemoryStorage
   [junit4]   2> 390113 INFO  (coreLoadExecutor-1090-thread-1) [    ] 
o.a.s.r.RestManager Initializing 0 registered ManagedResources
   [junit4]   2> 390113 INFO  (coreLoadExecutor-1090-thread-1) [    ] 
o.a.s.h.c.SpellCheckComponent Initializing spell checkers
   [junit4]   2> 390213 INFO  (coreLoadExecutor-1090-thread-1) [    ] 
o.a.s.s.DirectSolrSpellChecker init: 
{name=direct,classname=DirectSolrSpellChecker,field=lowerfilt,minQueryLength=3}
   [junit4]   2> 390629 INFO  (coreLoadExecutor-1090-thread-1) [    ] 
o.a.s.h.ReplicationHandler Commits will be reserved for  10000
   [junit4]   2> 390629 INFO  (searcherExecutor-1091-thread-1) [    ] 
o.a.s.h.c.SpellCheckComponent Loading spell index for spellchecker: default
   [junit4]   2> 390630 INFO  (searcherExecutor-1091-thread-1) [    ] 
o.a.s.h.c.SpellCheckComponent Loading spell index for spellchecker: direct
   [junit4]   2> 390630 INFO  (searcherExecutor-1091-thread-1) [    ] 
o.a.s.h.c.SpellCheckComponent Loading spell index for spellchecker: wordbreak
   [junit4]   2> 390630 INFO  (searcherExecutor-1091-thread-1) [    ] 
o.a.s.h.c.SpellCheckComponent Loading spell index for spellchecker: 
multipleFields
   [junit4]   2> 390630 INFO  (coreLoadExecutor-1090-thread-1) [    ] 
o.a.s.u.UpdateLog Looking up max value of version field to seed version buckets
   [junit4]   2> 390630 INFO  (coreLoadExecutor-1090-thread-1) [    ] 
o.a.s.u.VersionInfo Refreshing highest value of _version_ for 65536 version 
buckets from index
   [junit4]   2> 390630 INFO  (coreLoadExecutor-1090-thread-1) [    ] 
o.a.s.u.VersionInfo No terms found for _version_, cannot seed version bucket 
highest value from index
   [junit4]   2> 390630 INFO  (coreLoadExecutor-1090-thread-1) [    ] 
o.a.s.u.UpdateLog Could not find max version in index or recent updates, using 
new clock 1524414711522656256
   [junit4]   2> 390630 INFO  (searcherExecutor-1091-thread-1) [    ] 
o.a.s.h.c.SpellCheckComponent Loading spell index for spellchecker: jarowinkler
   [junit4]   2> 390630 INFO  (searcherExecutor-1091-thread-1) [    ] 
o.a.s.h.c.SpellCheckComponent Loading spell index for spellchecker: external
   [junit4]   2> 390630 INFO  (searcherExecutor-1091-thread-1) [    ] 
o.a.s.h.c.SpellCheckComponent Loading spell index for spellchecker: freq
   [junit4]   2> 390631 INFO  (searcherExecutor-1091-thread-1) [    ] 
o.a.s.h.c.SpellCheckComponent Loading spell index for spellchecker: fqcn
   [junit4]   2> 390631 INFO  (searcherExecutor-1091-thread-1) [    ] 
o.a.s.h.c.SpellCheckComponent Loading spell index for spellchecker: perDict
   [junit4]   2> 390631 INFO  (searcherExecutor-1091-thread-1) [    ] 
o.a.s.c.SolrCore [collection1] Registered new searcher 
Searcher@5ff977[collection1] 
main{ExitableDirectoryReader(UninvertingDirectoryReader())}
   [junit4]   2> 390632 INFO  (coreLoadExecutor-1090-thread-1) [    ] 
o.a.s.u.UpdateLog Took 1.0ms to seed version buckets with highest version 
1524414711522656256
   [junit4]   2> 390632 INFO  (coreLoadExecutor-1090-thread-1) [    ] 
o.a.s.c.CoreContainer registering core: collection1
   [junit4]   2> 390633 INFO  
(SUITE-SoftAutoCommitTest-seed#[DB7C2B831BD4D005]-worker) [    ] 
o.a.s.SolrTestCaseJ4 ####initCore end
   [junit4]   2> 390635 INFO  
(TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeRapidAdds-seed#[DB7C2B831BD4D005])
 [    ] o.a.s.SolrTestCaseJ4 ###Starting testSoftAndHardCommitMaxTimeRapidAdds
   [junit4]   2> 390635 INFO  
(TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeRapidAdds-seed#[DB7C2B831BD4D005])
 [    ] o.a.s.c.SolrResourceLoader new SolrResourceLoader for directory: 
'/home/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/core/src/test-files/solr/collection1'
   [junit4]   2> 390635 INFO  
(TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeRapidAdds-seed#[DB7C2B831BD4D005])
 [    ] o.a.s.c.SolrResourceLoader JNDI not configured for solr 
(NoInitialContextEx)
   [junit4]   2> 390635 INFO  
(TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeRapidAdds-seed#[DB7C2B831BD4D005])
 [    ] o.a.s.c.SolrResourceLoader using system property solr.solr.home: 
/home/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/core/src/test-files/solr
   [junit4]   2> 390635 INFO  
(TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeRapidAdds-seed#[DB7C2B831BD4D005])
 [    ] o.a.s.c.SolrResourceLoader Adding 
'file:/home/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/core/src/test-files/solr/collection1/lib/classes/'
 to classloader
   [junit4]   2> 390635 INFO  
(TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeRapidAdds-seed#[DB7C2B831BD4D005])
 [    ] o.a.s.c.SolrResourceLoader Adding 
'file:/home/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/core/src/test-files/solr/collection1/lib/README'
 to classloader
   [junit4]   2> 390660 INFO  
(TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeRapidAdds-seed#[DB7C2B831BD4D005])
 [    ] o.a.s.c.SolrConfig current version of requestparams : -1
   [junit4]   2> 390669 INFO  
(TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeRapidAdds-seed#[DB7C2B831BD4D005])
 [    ] o.a.s.c.SolrConfig Using Lucene MatchVersion: 6.0.0
   [junit4]   2> 390690 INFO  
(TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeRapidAdds-seed#[DB7C2B831BD4D005])
 [    ] o.a.s.c.SolrConfig Loaded SolrConfig: solrconfig.xml
   [junit4]   2> 390695 INFO  
(TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeRapidAdds-seed#[DB7C2B831BD4D005])
 [    ] o.a.s.s.IndexSchema [collection1] Schema name=test
   [junit4]   2> 390759 INFO  
(TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeRapidAdds-seed#[DB7C2B831BD4D005])
 [    ] o.a.s.s.OpenExchangeRatesOrgProvider Initialized with 
rates=open-exchange-rates.json, refreshInterval=1440.
   [junit4]   2> 390763 INFO  
(TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeRapidAdds-seed#[DB7C2B831BD4D005])
 [    ] o.a.s.s.IndexSchema default search field in schema is text
   [junit4]   2> 390763 INFO  
(TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeRapidAdds-seed#[DB7C2B831BD4D005])
 [    ] o.a.s.s.IndexSchema unique key field: id
   [junit4]   2> 390766 INFO  
(TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeRapidAdds-seed#[DB7C2B831BD4D005])
 [    ] o.a.s.s.FileExchangeRateProvider Reloading exchange rates from file 
currency.xml
   [junit4]   2> 390767 INFO  
(TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeRapidAdds-seed#[DB7C2B831BD4D005])
 [    ] o.a.s.s.FileExchangeRateProvider Reloading exchange rates from file 
currency.xml
   [junit4]   2> 390769 INFO  
(TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeRapidAdds-seed#[DB7C2B831BD4D005])
 [    ] o.a.s.s.OpenExchangeRatesOrgProvider Reloading exchange rates from 
open-exchange-rates.json
   [junit4]   2> 390769 INFO  
(TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeRapidAdds-seed#[DB7C2B831BD4D005])
 [    ] o.a.s.s.OpenExchangeRatesOrgProvider Reloading exchange rates from 
open-exchange-rates.json
   [junit4]   2> 390771 INFO  
(TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeRapidAdds-seed#[DB7C2B831BD4D005])
 [    ] o.a.s.c.ConfigSetProperties Did not find ConfigSet properties, assuming 
default properties: Can't find resource 'configsetprops.json' in classpath or 
'/home/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/core/src/test-files/solr/collection1'
   [junit4]   2> 390771 INFO  
(TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeRapidAdds-seed#[DB7C2B831BD4D005])
 [    ] o.a.s.c.CoreContainer Reloading SolrCore 'collection1' using 
configuration from instancedir 
/home/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/core/src/test-files/solr/collection1
   [junit4]   2> 390771 INFO  
(TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeRapidAdds-seed#[DB7C2B831BD4D005])
 [    ] o.a.s.c.SolrCore [[collection1] ] Opening new SolrCore at 
[/home/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/core/src/test-files/solr/collection1],
 
dataDir=[/home/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/temp/solr.update.SoftAutoCommitTest_DB7C2B831BD4D005-001/init-core-data-001/]
   [junit4]   2> 390772 INFO  
(TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeRapidAdds-seed#[DB7C2B831BD4D005])
 [    ] o.a.s.c.JmxMonitoredMap JMX monitoring is enabled. Adding Solr mbeans 
to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@bd6c92
   [junit4]   2> 390772 INFO  
(TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeRapidAdds-seed#[DB7C2B831BD4D005])
 [    ] o.a.s.c.SolrCore New index directory detected: old=null 
new=/home/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/temp/solr.update.SoftAutoCommitTest_DB7C2B831BD4D005-001/init-core-data-001/index/
   [junit4]   2> 390772 INFO  
(OldIndexDirectoryCleanupThreadForCore-collection1) [    ] o.a.s.c.SolrCore 
Looking for old index directories to cleanup for core collection1 in 
/home/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/temp/solr.update.SoftAutoCommitTest_DB7C2B831BD4D005-001/init-core-data-001/
   [junit4]   2> 390775 INFO  
(TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeRapidAdds-seed#[DB7C2B831BD4D005])
 [    ] o.a.s.u.p.UpdateRequestProcessorChain creating 
updateRequestProcessorChain "dedupe"
   [junit4]   2> 390775 INFO  
(TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeRapidAdds-seed#[DB7C2B831BD4D005])
 [    ] o.a.s.u.p.UpdateRequestProcessorChain inserting 
DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
   [junit4]   2> 390775 INFO  
(TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeRapidAdds-seed#[DB7C2B831BD4D005])
 [    ] o.a.s.u.p.UpdateRequestProcessorChain creating 
updateRequestProcessorChain "dedupe-allfields"
   [junit4]   2> 390775 INFO  
(TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeRapidAdds-seed#[DB7C2B831BD4D005])
 [    ] o.a.s.u.p.UpdateRequestProcessorChain inserting 
DistributedUpdateProcessorFactory into updateRequestProcessorChain 
"dedupe-allfields"
   [junit4]   2> 390775 INFO  
(TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeRapidAdds-seed#[DB7C2B831BD4D005])
 [    ] o.a.s.u.p.UpdateRequestProcessorChain creating 
updateRequestProcessorChain "stored_sig"
   [junit4]   2> 390775 INFO  
(TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeRapidAdds-seed#[DB7C2B831BD4D005])
 [    ] o.a.s.u.p.UpdateRequestProcessorChain inserting 
DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
   [junit4]   2> 390775 INFO  
(TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeRapidAdds-seed#[DB7C2B831BD4D005])
 [    ] o.a.s.u.p.UpdateRequestProcessorChain creating 
updateRequestProcessorChain "uniq-fields"
   [junit4]   2> 390775 INFO  
(TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeRapidAdds-seed#[DB7C2B831BD4D005])
 [    ] o.a.s.u.p.UpdateRequestProcessorChain inserting 
DistributedUpdateProcessorFactory into updateRequestProcessorChain "uniq-fields"
   [junit4]   2> 390775 INFO  
(TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeRapidAdds-seed#[DB7C2B831BD4D005])
 [    ] o.a.s.u.p.UpdateRequestProcessorChain creating 
updateRequestProcessorChain "distrib-dup-test-chain-explicit"
   [junit4]   2> 390775 INFO  
(TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeRapidAdds-seed#[DB7C2B831BD4D005])
 [    ] o.a.s.u.p.UpdateRequestProcessorChain creating 
updateRequestProcessorChain "distrib-dup-test-chain-implicit"
   [junit4]   2> 390775 INFO  
(TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeRapidAdds-seed#[DB7C2B831BD4D005])
 [    ] o.a.s.u.p.UpdateRequestProcessorChain inserting 
DistributedUpdateProcessorFactory into updateRequestProcessorChain 
"distrib-dup-test-chain-implicit"
   [junit4]   2> 390775 INFO  
(TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeRapidAdds-seed#[DB7C2B831BD4D005])
 [    ] o.a.s.c.SolrCore no updateRequestProcessorChain defined as default, 
creating implicit default
   [junit4]   2> 390777 INFO  
(TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeRapidAdds-seed#[DB7C2B831BD4D005])
 [    ] o.a.s.h.l.XMLLoader xsltCacheLifetimeSeconds=60
   [junit4]   2> 390778 INFO  
(TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeRapidAdds-seed#[DB7C2B831BD4D005])
 [    ] o.a.s.h.l.XMLLoader xsltCacheLifetimeSeconds=60
   [junit4]   2> 390778 INFO  
(TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeRapidAdds-seed#[DB7C2B831BD4D005])
 [    ] o.a.s.h.l.XMLLoader xsltCacheLifetimeSeconds=60
   [junit4]   2> 390779 INFO  
(TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeRapidAdds-seed#[DB7C2B831BD4D005])
 [    ] o.a.s.h.l.XMLLoader xsltCacheLifetimeSeconds=60
   [junit4]   2> 390781 INFO  
(TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeRapidAdds-seed#[DB7C2B831BD4D005])
 [    ] o.a.s.c.PluginBag requestHandler : 'lazy' created with startup=lazy 
   [junit4]   2> 390782 INFO  
(TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeRapidAdds-seed#[DB7C2B831BD4D005])
 [    ] o.a.s.c.RequestHandlers Registered paths: 
/admin/mbeans,standard,spellCheckCompRH,lazy,/update/json/docs,/admin/luke,/export,spellCheckWithWordbreak_Direct,tvrh,/get,/admin/properties,/update/json,mltrh,/admin/threads,/search-facet-def,/update/csv,/sql,/search-facet-invariants,/admin/segments,spellCheckCompRH1,/mlt,/admin/system,/replication,dismax,defaults,/config,/stream,/schema,/admin/plugins,/admin/logging,spellCheckWithWordbreak,mock,/admin/ping,/update,/admin/file,/terms,spellCheckCompRH_Direct,/debug/dump
   [junit4]   2> 390783 WARN  
(TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeRapidAdds-seed#[DB7C2B831BD4D005])
 [    ] o.a.s.c.SolrCore solrconfig.xml uses deprecated <admin/gettableFiles>, 
Please update your config to use the ShowFileRequestHandler.
   [junit4]   2> 390784 INFO  
(TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeRapidAdds-seed#[DB7C2B831BD4D005])
 [    ] o.a.s.c.SolrCore Using default statsCache cache: 
org.apache.solr.search.stats.LocalStatsCache
   [junit4]   2> 390784 INFO  
(TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeRapidAdds-seed#[DB7C2B831BD4D005])
 [    ] o.a.s.u.CommitTracker Hard AutoCommit: disabled
   [junit4]   2> 390784 INFO  
(TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeRapidAdds-seed#[DB7C2B831BD4D005])
 [    ] o.a.s.u.CommitTracker Soft AutoCommit: disabled
   [junit4]   2> 390785 INFO  
(TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeRapidAdds-seed#[DB7C2B831BD4D005])
 [    ] o.a.s.s.SolrIndexSearcher Opening [Searcher@6d2d76[collection1] main]
   [junit4]   2> 390785 INFO  
(TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeRapidAdds-seed#[DB7C2B831BD4D005])
 [    ] o.a.s.r.RestManager Initializing RestManager with initArgs: 
{storageIO=org.apache.solr.rest.ManagedResourceStorage$InMemoryStorageIO}
   [junit4]   2> 390785 INFO  
(TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeRapidAdds-seed#[DB7C2B831BD4D005])
 [    ] o.a.s.r.ManagedResourceStorage Reading _rest_managed.json using 
InMemoryStorage
   [junit4]   2> 390785 INFO  
(TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeRapidAdds-seed#[DB7C2B831BD4D005])
 [    ] o.a.s.r.RestManager Initializing 0 registered ManagedResources
   [junit4]   2> 390785 INFO  
(TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeRapidAdds-seed#[DB7C2B831BD4D005])
 [    ] o.a.s.h.c.SpellCheckComponent Initializing spell checkers
   [junit4]   2> 390786 INFO  
(TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeRapidAdds-seed#[DB7C2B831BD4D005])
 [    ] o.a.s.s.DirectSolrSpellChecker init: 
{name=direct,classname=DirectSolrSpellChecker,field=lowerfilt,minQueryLength=3}
   [junit4]   2> 390788 INFO  
(TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeRapidAdds-seed#[DB7C2B831BD4D005])
 [    ] o.a.s.h.ReplicationHandler Commits will be reserved for  10000
   [junit4]   2> 390789 INFO  (searcherExecutor-1096-thread-1) [    ] 
o.a.s.h.c.SpellCheckComponent Loading spell index for spellchecker: default
   [junit4]   2> 390789 INFO  
(TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeRapidAdds-seed#[DB7C2B831BD4D005])
 [    ] o.a.s.u.UpdateLog Looking up max value of version field to seed version 
buckets
   [junit4]   2> 390789 INFO  (searcherExecutor-1096-thread-1) [    ] 
o.a.s.h.c.SpellCheckComponent Loading spell index for spellchecker: direct
   [junit4]   2> 390789 INFO  
(TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeRapidAdds-seed#[DB7C2B831BD4D005])
 [    ] o.a.s.u.VersionInfo Refreshing highest value of _version_ for 65536 
version buckets from index
   [junit4]   2> 390789 INFO  (searcherExecutor-1096-thread-1) [    ] 
o.a.s.h.c.SpellCheckComponent Loading spell index for spellchecker: wordbreak
   [junit4]   2> 390789 INFO  
(TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeRapidAdds-seed#[DB7C2B831BD4D005])
 [    ] o.a.s.u.VersionInfo No terms found for _version_, cannot seed version 
bucket highest value from index
   [junit4]   2> 390789 INFO  (searcherExecutor-1096-thread-1) [    ] 
o.a.s.h.c.SpellCheckComponent Loading spell index for spellchecker: 
multipleFields
   [junit4]   2> 390789 INFO  
(TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeRapidAdds-seed#[DB7C2B831BD4D005])
 [    ] o.a.s.u.UpdateLog Could not find max version in index or recent 
updates, using new clock 1524414711689379840
   [junit4]   2> 390790 INFO  (searcherExecutor-1096-thread-1) [    ] 
o.a.s.h.c.SpellCheckComponent Loading spell index for spellchecker: jarowinkler
   [junit4]   2> 390790 INFO  (searcherExecutor-1096-thread-1) [    ] 
o.a.s.h.c.SpellCheckComponent Loading spell index for spellchecker: external
   [junit4]   2> 390790 INFO  (searcherExecutor-1096-thread-1) [    ] 
o.a.s.h.c.SpellCheckComponent Loading spell index for spellchecker: freq
   [junit4]   2> 390790 INFO  (searcherExecutor-1096-thread-1) [    ] 
o.a.s.h.c.SpellCheckComponent Loading spell index for spellchecker: fqcn
   [junit4]   2> 390790 INFO  (searcherExecutor-1096-thread-1) [    ] 
o.a.s.h.c.SpellCheckComponent Loading spell index for spellchecker: perDict
   [junit4]   2> 390791 INFO  
(TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeRapidAdds-seed#[DB7C2B831BD4D005])
 [    ] o.a.s.u.UpdateLog Took 1.0ms to seed version buckets with highest 
version 1524414711689379840
   [junit4]   2> 390791 INFO  (searcherExecutor-1096-thread-1) [    ] 
o.a.s.c.SolrCore [collection1] Registered new searcher 
Searcher@6d2d76[collection1] 
main{ExitableDirectoryReader(UninvertingDirectoryReader())}
   [junit4]   2> 390792 INFO  
(TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeRapidAdds-seed#[DB7C2B831BD4D005])
 [    ] o.a.s.u.DefaultSolrCoreState Closing old IndexWriter... core=collection1
   [junit4]   2> 390792 INFO  
(TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeRapidAdds-seed#[DB7C2B831BD4D005])
 [    ] o.a.s.u.RandomMergePolicy RandomMergePolicy wrapping class 
org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: 
maxMergeAtOnce=15, maxMergeAtOnceExplicit=40, maxMergedSegmentMB=74.78125, 
floorSegmentMB=2.1044921875, forceMergeDeletesPctAllowed=29.240721118907437, 
segmentsPerTier=34.0, maxCFSSegmentSizeMB=8.796093022207999E12, 
noCFSRatio=0.6130809580357164
   [junit4]   2> 390793 INFO  
(TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeRapidAdds-seed#[DB7C2B831BD4D005])
 [    ] o.a.s.c.SolrDeletionPolicy SolrDeletionPolicy.onInit: commits: num=1
   [junit4]   2>        commit{dir=MockDirectoryWrapper(RAMDirectory@f4f966 
lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@e86492),segFN=segments_1,generation=1}
   [junit4]   2> 390794 INFO  
(TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeRapidAdds-seed#[DB7C2B831BD4D005])
 [    ] o.a.s.c.SolrDeletionPolicy newest commit generation = 1
   [junit4]   2> 390794 INFO  
(TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeRapidAdds-seed#[DB7C2B831BD4D005])
 [    ] o.a.s.u.DefaultSolrCoreState New IndexWriter is ready to be used.
   [junit4]   2> 390794 INFO  
(TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeRapidAdds-seed#[DB7C2B831BD4D005])
 [    ] o.a.s.s.SolrIndexSearcher Opening [Searcher@186e917[collection1] main]
   [junit4]   2> 390795 INFO  
(TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeRapidAdds-seed#[DB7C2B831BD4D005])
 [    ] o.a.s.c.CoreContainer replacing core: collection1
   [junit4]   2> 390796 INFO  
(TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeRapidAdds-seed#[DB7C2B831BD4D005])
 [    ] o.a.s.c.SolrCore [collection1]  CLOSING SolrCore 
org.apache.solr.core.SolrCore@b86ce7
   [junit4]   2> 390796 INFO  
(TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeRapidAdds-seed#[DB7C2B831BD4D005])
 [    ] o.a.s.u.DirectUpdateHandler2 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> 390796 INFO  
(TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeRapidAdds-seed#[DB7C2B831BD4D005])
 [    ] o.a.s.c.SolrCore [collection1] Closing main searcher on request.
   [junit4]   2> 390796 INFO  (searcherExecutor-1096-thread-1) [    ] 
o.a.s.c.SolrCore [collection1] Registered new searcher 
Searcher@186e917[collection1] 
main{ExitableDirectoryReader(UninvertingDirectoryReader())}
   [junit4]   2> 392003 INFO  
(TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeRapidAdds-seed#[DB7C2B831BD4D005])
 [    ] o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=null 
path=null params={}{add=[5000 (1524414711700914176)]} 0 1202
   [junit4]   2> 392004 INFO  
(TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeRapidAdds-seed#[DB7C2B831BD4D005])
 [    ] o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=null 
path=null params={}{add=[5001 (1524414712963399680)]} 0 0
   [junit4]   2> 392005 INFO  
(TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeRapidAdds-seed#[DB7C2B831BD4D005])
 [    ] o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=null 
path=null params={}{add=[5002 (1524414712964448256)]} 0 0
   [junit4]   2> 392005 INFO  
(TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeRapidAdds-seed#[DB7C2B831BD4D005])
 [    ] o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=null 
path=null params={}{add=[5003 (1524414712964448257)]} 0 0
   [junit4]   2> 392006 INFO  
(TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeRapidAdds-seed#[DB7C2B831BD4D005])
 [    ] o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=null 
path=null params={}{add=[5004 (1524414712965496832)]} 0 0
   [junit4]   2> 392503 INFO  (commitScheduler-1099-thread-1) [    ] 
o.a.s.u.DirectUpdateHandler2 start 
commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=true,prepareCommit=false}
   [junit4]   2> 392506 INFO  (commitScheduler-1099-thread-1) [    ] 
o.a.s.s.SolrIndexSearcher Opening [Searcher@dcc757[collection1] main]
   [junit4]   2> 392506 INFO  (commitScheduler-1099-thread-1) [    ] 
o.a.s.u.DirectUpdateHandler2 end_commit_flush
   [junit4]   2> 392506 INFO  (searcherExecutor-1096-thread-1) [    ] 
o.a.s.c.SolrCore [collection1] Registered new searcher 
Searcher@dcc757[collection1] 
main{ExitableDirectoryReader(UninvertingDirectoryReader(Uninverting(_0(6.0.0):C5)))}
   [junit4]   2> 393203 INFO  (commitScheduler-1098-thread-1) [    ] 
o.a.s.u.DirectUpdateHandler2 start 
commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
   [junit4]   2> 393204 INFO  (commitScheduler-1098-thread-1) [    ] 
o.a.s.c.SolrDeletionPolicy SolrDeletionPolicy.onCommit: commits: num=2
   [junit4]   2>        commit{dir=MockDirectoryWrapper(RAMDirectory@f4f966 
lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@e86492),segFN=segments_1,generation=1}
   [junit4]   2>        commit{dir=MockDirectoryWrapper(RAMDirectory@f4f966 
lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@e86492),segFN=segments_2,generation=2}
   [junit4]   2> 393204 INFO  (commitScheduler-1098-thread-1) [    ] 
o.a.s.c.SolrDeletionPolicy newest commit generation = 2
   [junit4]   2> 393204 INFO  (commitScheduler-1098-thread-1) [    ] 
o.a.s.s.SolrIndexSearcher Opening [Searcher@11de03b[collection1] main]
   [junit4]   2> 393205 INFO  (commitScheduler-1098-thread-1) [    ] 
o.a.s.u.DirectUpdateHandler2 end_commit_flush
   [junit4]   2> 393205 INFO  (searcherExecutor-1096-thread-1) [    ] 
o.a.s.c.SolrCore [collection1] Registered new searcher 
Searcher@11de03b[collection1] 
main{ExitableDirectoryReader(UninvertingDirectoryReader(Uninverting(_0(6.0.0):C5)))}
   [junit4]   2> 393507 INFO  
(TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeRapidAdds-seed#[DB7C2B831BD4D005])
 [    ] o.a.s.SolrTestCaseJ4 ###Ending testSoftAndHardCommitMaxTimeRapidAdds
   [junit4]   2> NOTE: reproduce with: ant test  -Dtestcase=SoftAutoCommitTest 
-Dtests.method=testSoftAndHardCommitMaxTimeRapidAdds 
-Dtests.seed=DB7C2B831BD4D005 -Dtests.multiplier=3 -Dtests.slow=true 
-Dtests.locale=en-MY -Dtests.timezone=Africa/Abidjan -Dtests.asserts=true 
-Dtests.file.encoding=UTF-8
   [junit4] FAILURE 2.88s J1 | 
SoftAutoCommitTest.testSoftAndHardCommitMaxTimeRapidAdds <<<
   [junit4]    > Throwable #1: java.lang.AssertionError: 2: soft wasn't fast 
enough
   [junit4]    >        at 
__randomizedtesting.SeedInfo.seed([DB7C2B831BD4D005:876985BAF056917D]:0)
   [junit4]    >        at 
org.apache.solr.update.SoftAutoCommitTest.testSoftAndHardCommitMaxTimeRapidAdds(SoftAutoCommitTest.java:323)
   [junit4]    >        at java.lang.Thread.run(Thread.java:747)
   [junit4]   2> 393510 INFO  
(TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeDelete-seed#[DB7C2B831BD4D005])
 [    ] o.a.s.SolrTestCaseJ4 ###Starting testSoftAndHardCommitMaxTimeDelete
   [junit4]   2> 393510 INFO  
(TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeDelete-seed#[DB7C2B831BD4D005])
 [    ] o.a.s.c.SolrResourceLoader new SolrResourceLoader for directory: 
'/home/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/core/src/test-files/solr/collection1'
   [junit4]   2> 393510 INFO  
(TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeDelete-seed#[DB7C2B831BD4D005])
 [    ] o.a.s.c.SolrResourceLoader JNDI not configured for solr 
(NoInitialContextEx)
   [junit4]   2> 393510 INFO  
(TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeDelete-seed#[DB7C2B831BD4D005])
 [    ] o.a.s.c.SolrResourceLoader using system property solr.solr.home: 
/home/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/core/src/test-files/solr
   [junit4]   2> 393510 INFO  
(TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeDelete-seed#[DB7C2B831BD4D005])
 [    ] o.a.s.c.SolrResourceLoader Adding 
'file:/home/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/core/src/test-files/solr/collection1/lib/classes/'
 to classloader
   [junit4]   2> 393510 INFO  
(TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeDelete-seed#[DB7C2B831BD4D005])
 [    ] o.a.s.c.SolrResourceLoader Adding 
'file:/home/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/core/src/test-files/solr/collection1/lib/README'
 to classloader
   [junit4]   2> 393525 INFO  
(TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeDelete-seed#[DB7C2B831BD4D005])
 [    ] o.a.s.c.SolrConfig current version of requestparams : -1
   [junit4]   2> 393530 INFO  
(TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeDelete-seed#[DB7C2B831BD4D005])
 [    ] o.a.s.c.SolrConfig Using Lucene MatchVersion: 6.0.0
   [junit4]   2> 393541 INFO  
(TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeDelete-seed#[DB7C2B831BD4D005])
 [    ] o.a.s.c.SolrConfig Loaded SolrConfig: solrconfig.xml
   [junit4]   2> 393545 INFO  
(TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeDelete-seed#[DB7C2B831BD4D005])
 [    ] o.a.s.s.IndexSchema [collection1] Schema name=test
   [junit4]   2> 393592 INFO  
(TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeDelete-seed#[DB7C2B831BD4D005])
 [    ] o.a.s.s.OpenExchangeRatesOrgProvider Initialized with 
rates=open-exchange-rates.json, refreshInterval=1440.
   [junit4]   2> 393595 INFO  
(TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeDelete-seed#[DB7C2B831BD4D005])
 [    ] o.a.s.s.IndexSchema default search field in schema is text
   [junit4]   2> 393596 INFO  
(TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeDelete-seed#[DB7C2B831BD4D005])
 [    ] o.a.s.s.IndexSchema unique key field: id
   [junit4]   2> 393598 INFO  
(TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeDelete-seed#[DB7C2B831BD4D005])
 [    ] o.a.s.s.FileExchangeRateProvider Reloading exchange rates from file 
currency.xml
   [junit4]   2> 393599 INFO  
(TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeDelete-seed#[DB7C2B831BD4D005])
 [    ] o.a.s.s.FileExchangeRateProvider Reloading exchange rates from file 
currency.xml
   [junit4]   2> 393600 INFO  
(TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeDelete-seed#[DB7C2B831BD4D005])
 [    ] o.a.s.s.OpenExchangeRatesOrgProvider Reloading exchange rates from 
open-exchange-rates.json
   [junit4]   2> 393600 INFO  
(TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeDelete-seed#[DB7C2B831BD4D005])
 [    ] o.a.s.s.OpenExchangeRatesOrgProvider Reloading exchange rates from 
open-exchange-rates.json
   [junit4]   2> 393602 INFO  
(TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeDelete-seed#[DB7C2B831BD4D005])
 [    ] o.a.s.c.ConfigSetProperties Did not find ConfigSet properties, assuming 
default properties: Can't find resource 'configsetprops.json' in classpath or 
'/home/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/core/src/test-files/solr/collection1'
   [junit4]   2> 393602 INFO  
(TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeDelete-seed#[DB7C2B831BD4D005])
 [    ] o.a.s.c.CoreContainer Reloading SolrCore 'collection1' using 
configuration from instancedir 
/home/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/core/src/test-files/solr/collection1
   [junit4]   2> 393602 INFO  
(TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeDelete-seed#[DB7C2B831BD4D005])
 [    ] o.a.s.c.SolrCore [[collection1] ] Opening new SolrCore at 
[/home/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/core/src/test-files/solr/collection1],
 
dataDir=[/home/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/temp/solr.update.SoftAutoCommitTest_DB7C2B831BD4D005-001/init-core-data-001/]
   [junit4]   2> 393602 INFO  
(TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeDelete-seed#[DB7C2B831BD4D005])
 [    ] o.a.s.c.JmxMonitoredMap JMX monitoring is enabled. Adding Solr mbeans 
to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@bd6c92
   [junit4]   2> 393603 INFO  
(TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeDelete-seed#[DB7C2B831BD4D005])
 [    ] o.a.s.c.SolrCore New index directory detected: old=null 
new=/home/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/temp/solr.update.SoftAutoCommitTest_DB7C2B831BD4D005-001/init-core-data-001/index/
   [junit4]   2> 393603 INFO  
(OldIndexDirectoryCleanupThreadForCore-collection1) [    ] o.a.s.c.SolrCore 
Looking for old index directories to cleanup for core collection1 in 
/home/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/temp/solr.update.SoftAutoCommitTest_DB7C2B831BD4D005-001/init-core-data-001/
   [junit4]   2> 393606 INFO  
(TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeDelete-seed#[DB7C2B831BD4D005])
 [    ] o.a.s.u.p.UpdateRequestProcessorChain creating 
updateRequestProcessorChain "dedupe"
   [junit4]   2> 393606 INFO  
(TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeDelete-seed#[DB7C2B831BD4D005])
 [    ] o.a.s.u.p.UpdateRequestProcessorChain inserting 
DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
   [junit4]   2> 393606 INFO  
(TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeDelete-seed#[DB7C2B831BD4D005])
 [    ] o.a.s.u.p.UpdateRequestProcessorChain creating 
updateRequestProcessorChain "dedupe-allfields"
   [junit4]   2> 393606 INFO  
(TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeDelete-seed#[DB7C2B831BD4D005])
 [    ] o.a.s.u.p.UpdateRequestProcessorChain inserting 
DistributedUpdateProcessorFactory into updateRequestProcessorChain 
"dedupe-allfields"
   [junit4]   2> 393606 INFO  
(TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeDelete-seed#[DB7C2B831BD4D005])
 [    ] o.a.s.u.p.UpdateRequestProcessorChain creating 
updateRequestProcessorChain "stored_sig"
   [junit4]   2> 393606 INFO  
(TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeDelete-seed#[DB7C2B831BD4D005])
 [    ] o.a.s.u.p.UpdateRequestProcessorChain inserting 
DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
   [junit4]   2> 393606 INFO  
(TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeDelete-seed#[DB7C2B831BD4D005])
 [    ] o.a.s.u.p.UpdateRequestProcessorChain creating 
updateRequestProcessorChain "uniq-fields"
   [junit4]   2> 393606 INFO  
(TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeDelete-seed#[DB7C2B831BD4D005])
 [    ] o.a.s.u.p.UpdateRequestProcessorChain inserting 
DistributedUpdateProcessorFactory into updateRequestProcessorChain "uniq-fields"
   [junit4]   2> 393606 INFO  
(TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeDelete-seed#[DB7C2B831BD4D005])
 [    ] o.a.s.u.p.UpdateRequestProcessorChain creating 
updateRequestProcessorChain "distrib-dup-test-chain-explicit"
   [junit4]   2> 393606 INFO  
(TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeDelete-seed#[DB7C2B831BD4D005])
 [    ] o.a.s.u.p.UpdateRequestProcessorChain creating 
updateRequestProcessorChain "distrib-dup-test-chain-implicit"
   [junit4]   2> 393606 INFO  
(TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeDelete-seed#[DB7C2B831BD4D005])
 [    ] o.a.s.u.p.UpdateRequestProcessorChain inserting 
DistributedUpdateProcessorFactory into updateRequestProcessorChain 
"distrib-dup-test-chain-implicit"
   [junit4]   2> 393606 INFO  
(TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeDelete-seed#[DB7C2B831BD4D005])
 [    ] o.a.s.c.SolrCore no updateRequestProcessorChain defined as default, 
creating implicit default
   [junit4]   2> 393607 INFO  
(TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeDelete-seed#[DB7C2B831BD4D005])
 [    ] o.a.s.h.l.XMLLoader xsltCacheLifetimeSeconds=60
   [junit4]   2> 393608 INFO  
(TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeDelete-seed#[DB7C2B831BD4D005])
 [    ] o.a.s.h.l.XMLLoader xsltCacheLifetimeSeconds=60
   [junit4]   2> 393608 INFO  
(TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeDelete-seed#[DB7C2B831BD4D005])
 [    ] o.a.s.h.l.XMLLoader xsltCacheLifetimeSeconds=60
   [junit4]   2> 393609 INFO  
(TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeDelete-seed#[DB7C2B831BD4D005])
 [    ] o.a.s.h.l.XMLLoader xsltCacheLifetimeSeconds=60
   [junit4]   2> 393611 INFO  
(TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeDelete-seed#[DB7C2B831BD4D005])
 [    ] o.a.s.c.PluginBag requestHandler : 'lazy' created with startup=lazy 
   [junit4]   2> 393612 INFO  
(TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeDelete-seed#[DB7C2B831BD4D005])
 [    ] o.a.s.c.RequestHandlers Registered paths: 
/admin/mbeans,standard,spellCheckCompRH,lazy,/update/json/docs,/admin/luke,/export,spellCheckWithWordbreak_Direct,tvrh,/get,/admin/properties,/update/json,mltrh,/admin/threads,/search-facet-def,/update/csv,/sql,/search-facet-invariants,/admin/segments,spellCheckCompRH1,/mlt,/admin/system,/replication,dismax,defaults,/config,/stream,/schema,/admin/plugins,/admin/logging,spellCheckWithWordbreak,mock,/admin/ping,/update,/admin/file,/terms,spellCheckCompRH_Direct,/debug/dump
   [junit4]   2> 393613 WARN  
(TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeDelete-seed#[DB7C2B831BD4D005])
 [    ] o.a.s.c.SolrCore solrconfig.xml uses deprecated <admin/gettableFiles>, 
Please update your config to use the ShowFileRequestHandler.
   [junit4]   2> 393613 INFO  
(TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeDelete-seed#[DB7C2B831BD4D005])
 [    ] o.a.s.c.SolrCore Using default statsCache cache: 
org.apache.solr.search.stats.LocalStatsCache
   [junit4]   2> 393614 INFO  
(TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeDelete-seed#[DB7C2B831BD4D005])
 [    ] o.a.s.u.CommitTracker Hard AutoCommit: disabled
   [junit4]   2> 393614 INFO  
(TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeDelete-seed#[DB7C2B831BD4D005])
 [    ] o.a.s.u.CommitTracker Soft AutoCommit: disabled
   [junit4]   2> 393615 INFO  
(TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeDelete-seed#[DB7C2B831BD4D005])
 [    ] o.a.s.s.SolrIndexSearcher Opening [Searcher@1a7efde[collection1] main]
   [junit4]   2> 393615 INFO  
(TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeDelete-seed#[DB7C2B831BD4D005])
 [    ] o.a.s.r.RestManager Initializing RestManager with initArgs: 
{storageIO=org.apache.solr.rest.ManagedResourceStorage$InMemoryStorageIO}
   [junit4]   2> 393615 INFO  
(TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeDelete-seed#[DB7C2B831BD4D005])
 [    ] o.a.s.r.ManagedResourceStorage Reading _rest_managed.json using 
InMemoryStorage
   [junit4]   2> 393615 INFO  
(TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeDelete-seed#[DB7C2B831BD4D005])
 [    ] o.a.s.r.RestManager Initializing 0 registered ManagedResources
   [junit4]   2> 393615 INFO  
(TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeDelete-seed#[DB7C2B831BD4D005])
 [    ] o.a.s.h.c.SpellCheckComponent Initializing spell checkers
   [junit4]   2> 393615 INFO  
(TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeDelete-seed#[DB7C2B831BD4D005])
 [    ] o.a.s.s.DirectSolrSpellChecker init: 
{name=direct,classname=DirectSolrSpellChecker,field=lowerfilt,minQueryLength=3}
   [junit4]   2> 393617 INFO  
(TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeDelete-seed#[DB7C2B831BD4D005])
 [    ] o.a.s.h.ReplicationHandler Commits will be reserved for  10000
   [junit4]   2> 393617 INFO  (searcherExecutor-1100-thread-1) [    ] 
o.a.s.h.c.SpellCheckComponent Loading spell index for spellchecker: default
   [junit4]   2> 393617 INFO  (searcherExecutor-1100-thread-1) [    ] 
o.a.s.h.c.SpellCheckComponent Loading spell index for spellchecker: direct
   [junit4]   2> 393617 INFO  (searcherExecutor-1100-thread-1) [    ] 
o.a.s.h.c.SpellCheckComponent Loading spell index for spellchecker: wordbreak
   [junit4]   2> 393617 INFO  (searcherExecutor-1100-thread-1) [    ] 
o.a.s.h.c.SpellCheckComponent Loading spell index for spellchecker: 
multipleFields
   [junit4]   2> 393618 INFO  (searcherExecutor-1100-thread-1) [    ] 
o.a.s.h.c.SpellCheckComponent Loading spell index for spellchecker: jarowinkler
   [junit4]   2> 393618 INFO  (searcherExecutor-1100-thread-1) [    ] 
o.a.s.h.c.SpellCheckComponent Loading spell index for spellchecker: external
   [junit4]   2> 393618 INFO  
(TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeDelete-seed#[DB7C2B831BD4D005])
 [    ] o.a.s.u.UpdateLog Looking up max value of version field to seed version 
buckets
   [junit4]   2> 393618 INFO  (searcherExecutor-1100-thread-1) [    ] 
o.a.s.h.c.SpellCheckComponent Loading spell index for spellchecker: freq
   [junit4]   2> 393618 INFO  
(TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeDelete-seed#[DB7C2B831BD4D005])
 [    ] o.a.s.u.VersionInfo Refreshing highest value of _version_ for 65536 
version buckets from index
   [junit4]   2> 393618 INFO  (searcherExecutor-1100-thread-1) [    ] 
o.a.s.h.c.SpellCheckComponent Loading spell index for spellchecker: fqcn
   [junit4]   2> 393618 INFO  (searcherExecutor-1100-thread-1) [    ] 
o.a.s.h.c.SpellCheckComponent Loading spell index for spellchecker: perDict
   [junit4]   2> 393618 INFO  
(TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeDelete-seed#[DB7C2B831BD4D005])
 [    ] o.a.s.u.VersionInfo Found MAX value 1524414712965496832 from Terms for 
_version_ in index
   [junit4]   2> 393619 INFO  (searcherExecutor-1100-thread-1) [    ] 
o.a.s.c.SolrCore [collection1] Registered new searcher 
Searcher@1a7efde[collection1] 
main{ExitableDirectoryReader(UninvertingDirectoryReader(Uninverting(_0(6.0.0):C5)))}
   [junit4]   2> 393620 INFO  
(TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeDelete-seed#[DB7C2B831BD4D005])
 [    ] o.a.s.u.UpdateLog Took 1.0ms to seed version buckets with highest 
version 1524414712965496832
   [junit4]   2> 393620 INFO  
(TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeDelete-seed#[DB7C2B831BD4D005])
 [    ] o.a.s.u.DefaultSolrCoreState Closing old IndexWriter... core=collection1
   [junit4]   2> 393620 INFO  
(TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeDelete-seed#[DB7C2B831BD4D005])
 [    ] o.a.s.u.RandomMergePolicy RandomMergePolicy wrapping class 
org.apache.lucene.index.LogByteSizeMergePolicy: [LogByteSizeMergePolicy: 
minMergeSize=1677721, mergeFactor=7, maxMergeSize=2147483648, 
maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=false, 
maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12, 
noCFSRatio=0.4255255546472385]
   [junit4]   2> 393621 INFO  
(TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeDelete-seed#[DB7C2B831BD4D005])
 [    ] o.a.s.c.SolrDeletionPolicy SolrDeletionPolicy.onInit: commits: num=1
   [junit4]   2>        commit{dir=MockDirectoryWrapper(RAMDirectory@f4f966 
lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@e86492),segFN=segments_2,generation=2}
   [junit4]   2> 393621 INFO  
(TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeDelete-seed#[DB7C2B831BD4D005])
 [    ] o.a.s.c.SolrDeletionPolicy newest commit generation = 2
   [junit4]   2> 393621 INFO  
(TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeDelete-seed#[DB7C2B831BD4D005])
 [    ] o.a.s.u.DefaultSolrCoreState New IndexWriter is ready to be used.
   [junit4]   2> 393622 INFO  
(TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeDelete-seed#[DB7C2B831BD4D005])
 [    ] o.a.s.s.SolrIndexSearcher Opening [Searcher@ff4188[collection1] main]
   [junit4]   2> 393622 INFO  
(TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeDelete-seed#[DB7C2B831BD4D005])
 [    ] o.a.s.c.CoreContainer replacing core: collection1
   [junit4]   2> 393622 INFO  
(TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeDelete-seed#[DB7C2B831BD4D005])
 [    ] o.a.s.c.SolrCore [collection1]  CLOSING SolrCore 
org.apache.solr.core.SolrCore@125cb1c
   [junit4]   2> 393622 INFO  
(TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeDelete-seed#[DB7C2B831BD4D005])
 [    ] o.a.s.u.DirectUpdateHandler2 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> 393622 INFO  
(TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeDelete-seed#[DB7C2B831BD4D005])
 [    ] o.a.s.c.SolrCore [collection1] Closing main searcher on request.
   [junit4]   2> 393623 INFO  (searcherExecutor-1100-thread-1) [    ] 
o.a.s.c.SolrCore [collection1] Registered new searcher 
Searcher@ff4188[collection1] 
main{ExitableDirectoryReader(UninvertingDirectoryReader(Uninverting(_0(6.0.0):C5)))}
   [junit4]   2> 393628 INFO  
(TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeDelete-seed#[DB7C2B831BD4D005])
 [    ] o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=null 
path=null params={}{add=[529 (1524414714665238528)]} 0 1
   [junit4]   2> 393629 INFO  
(TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeDelete-seed#[DB7C2B831BD4D005])
 [    ] o.a.s.u.DirectUpdateHandler2 start 
commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
   [junit4]   2> 393630 INFO  
(TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeDelete-seed#[DB7C2B831BD4D005])
 [    ] o.a.s.c.SolrDeletionPolicy SolrDeletionPolicy.onCommit: commits: num=2
   [junit4]   2>        commit{dir=MockDirectoryWrapper(RAMDirectory@f4f966 
lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@e86492),segFN=segments_2,generation=2}
   [junit4]   2>        commit{dir=MockDirectoryWrapper(RAMDirectory@f4f966 
lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@e86492),segFN=segments_3,generation=3}
   [junit4]   2> 393630 INFO  
(TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeDelete-seed#[DB7C2B831BD4D005])
 [    ] o.a.s.c.SolrDeletionPolicy newest commit generation = 3
   [junit4]   2> 393631 INFO  
(TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeDelete-seed#[DB7C2B831BD4D005])
 [    ] o.a.s.s.SolrIndexSearcher Opening [Searcher@2a1ef[collection1] main]
   [junit4]   2> 393631 INFO  
(TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeDelete-seed#[DB7C2B831BD4D005])
 [    ] o.a.s.u.DirectUpdateHandler2 end_commit_flush
   [junit4]   2> 393632 INFO  (searcherExecutor-1100-thread-1) [    ] 
o.a.s.c.SolrCore [collection1] Registered new searcher 
Searcher@2a1ef[collection1] 
main{ExitableDirectoryReader(UninvertingDirectoryReader(Uninverting(_0(6.0.0):C5)
 Uninverting(_1(6.0.0):C1)))}
   [junit4]   2> 393632 INFO  
(TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeDelete-seed#[DB7C2B831BD4D005])
 [    ] o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=null 
path=null params={}{commit=} 0 3
   [junit4]   2> 393633 INFO  
(TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeDelete-seed#[DB7C2B831BD4D005])
 [    ] o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=null 
path=null params={}{delete=[529 (-1524414714670481408)]} 0 0
   [junit4]   2> 394133 INFO  (commitScheduler-1103-thread-1) [    ] 
o.a.s.u.DirectUpdateHandler2 start 
commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=true,prepareCommit=false}
   [junit4]   2> 394135 INFO  (commitScheduler-1103-thread-1) [    ] 
o.a.s.s.SolrIndexSearcher Opening [Searcher@1133f8c[collection1] main]
   [junit4]   2> 394139 INFO  (searcherExecutor-1100-thread-1) [    ] 
o.a.s.c.SolrCore [collection1] Registered new searcher 
Searcher@1133f8c[collection1] 
main{ExitableDirectoryReader(UninvertingDirectoryReader(Uninverting(_0(6.0.0):C5)))}
   [junit4]   2> 394140 INFO  (commitScheduler-1103-thread-1) [    ] 
o.a.s.u.DirectUpdateHandler2 end_commit_flush
   [junit4]   2> 394142 INFO  
(TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeDelete-seed#[DB7C2B831BD4D005])
 [    ] o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=null 
path=null params={}{add=[550 (1524414715203158016)]} 0 1
   [junit4]   2> 394642 INFO  (commitScheduler-1103-thread-1) [    ] 
o.a.s.u.DirectUpdateHandler2 start 
commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=true,prepareCommit=false}
   [junit4]   2> 394643 INFO  (commitScheduler-1103-thread-1) [    ] 
o.a.s.s.SolrIndexSearcher Opening [Searcher@eef39f[collection1] main]
   [junit4]   2> 394643 INFO  (commitScheduler-1103-thread-1) [    ] 
o.a.s.u.DirectUpdateHandler2 end_commit_flush
   [junit4]   2> 394644 INFO  (searcherExecutor-1100-thread-1) [    ] 
o.a.s.c.SolrCore [collection1] Registered new searcher 
Searcher@eef39f[collection1] 
main{ExitableDirectoryReader(UninvertingDirectoryReader(Uninverting(_0(6.0.0):C5)
 Uninverting(_2(6.0.0):C1)))}
   [junit4]   2> 394833 INFO  (commitScheduler-1102-thread-1) [    ] 
o.a.s.u.DirectUpdateHandler2 start 
commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
   [junit4]   2> 394834 INFO  (commitScheduler-1102-thread-1) [    ] 
o.a.s.c.SolrDeletionPolicy SolrDeletionPolicy.onCommit: commits: num=2
   [junit4]   2>        commit{dir=MockDirectoryWrapper(RAMDirectory@f4f966 
lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@e86492),segFN=segments_3,generation=3}
   [junit4]   2>        commit{dir=MockDirectoryWrapper(RAMDirectory@f4f966 
lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@e86492),segFN=segments_4,generation=4}
   [junit4]   2> 394834 INFO  (commitScheduler-1102-thread-1) [    ] 
o.a.s.c.SolrDeletionPolicy newest commit generation = 4
   [junit4]   2> 394834 INFO  (commitScheduler-1102-thread-1) [    ] 
o.a.s.s.SolrIndexSearcher Opening [Searcher@1a0c43[collection1] main]
   [junit4]   2> 394835 INFO  (commitScheduler-1102-thread-1) [    ] 
o.a.s.u.DirectUpdateHandler2 end_commit_flush
   [junit4]   2> 394835 INFO  (searcherExecutor-1100-thread-1) [    ] 
o.a.s.c.SolrCore [collection1] Registered new searcher 
Searcher@1a0c43[collection1] 
main{ExitableDirectoryReader(UninvertingDirectoryReader(Uninverting(_0(6.0.0):C5)
 Uninverting(_2(6.0.0):C1)))}
   [junit4]   2> 396834 INFO  
(TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeDelete-seed#[DB7C2B831BD4D005])
 [    ] o.a.s.SolrTestCaseJ4 ###Ending testSoftAndHardCommitMaxTimeDelete
   [junit4]   2> 396836 INFO  
(TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeMixedAdds-seed#[DB7C2B831BD4D005])
 [    ] o.a.s.SolrTestCaseJ4 ###Starting testSoftAndHardCommitMaxTimeMixedAdds
   [junit4]   2> 396836 INFO  
(TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeMixedAdds-seed#[DB7C2B831BD4D005])
 [    ] o.a.s.c.SolrResourceLoader new SolrResourceLoader for directory: 
'/home/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/core/src/test-files/solr/collection1'
   [junit4]   2> 396836 INFO  
(TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeMixedAdds-seed#[DB7C2B831BD4D005])
 [    ] o.a.s.c.SolrResourceLoader JNDI not configured for solr 
(NoInitialContextEx)
   [junit4]   2> 396836 INFO  
(TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeMixedAdds-seed#[DB7C2B831BD4D005])
 [    ] o.a.s.c.SolrResourceLoader using system property solr.solr.home: 
/home/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/core/src/test-files/solr
   [junit4]   2> 396836 INFO  
(TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeMixedAdds-seed#[DB7C2B831BD4D005])
 [    ] o.a.s.c.SolrResourceLoader Adding 
'file:/home/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/core/src/test-files/solr/collection1/lib/classes/'
 to classloader
   [junit4]   2> 396836 INFO  
(TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeMixedAdds-seed#[DB7C2B831BD4D005])
 [    ] o.a.s.c.SolrResourceLoader Adding 
'file:/home/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/core/src/test-files/solr/collection1/lib/README'
 to classloader
   [junit4]   2> 396851 INFO  
(TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeMixedAdds-seed#[DB7C2B831BD4D005])
 [    ] o.a.s.c.SolrConfig current version of requestparams : -1
   [junit4]   2> 396855 INFO  
(TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeMixedAdds-seed#[DB7C2B831BD4D005])
 [    ] o.a.s.c.SolrConfig Using Lucene MatchVersion: 6.0.0
   [junit4]   2> 396867 INFO  
(TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeMixedAdds-seed#[DB7C2B831BD4D005])
 [    ] o.a.s.c.SolrConfig Loaded SolrConfig: solrconfig.xml
   [junit4]   2> 396870 INFO  
(TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeMixedAdds-seed#[DB7C2B831BD4D005])
 [    ] o.a.s.s.IndexSchema [collection1] Schema name=test
   [junit4]   2> 396917 INFO  
(TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeMixedAdds-seed#[DB7C2B831BD4D005])
 [    ] o.a.s.s.OpenExchangeRatesOrgProvider Initialized with 
rates=open-exchange-rates.json, refreshInterval=1440.
   [junit4]   2> 396920 INFO  
(TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeMixedAdds-seed#[DB7C2B831BD4D005])
 [    ] o.a.s.s.IndexSchema default search field in schema is text
   [junit4]   2> 396921 INFO  
(TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeMixedAdds-seed#[DB7C2B831BD4D005])
 [    ] o.a.s.s.IndexSchema unique key field: id
   [junit4]   2> 396925 INFO  
(TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeMixedAdds-seed#[DB7C2B831BD4D005])
 [    ] o.a.s.s.FileExchangeRateProvider Reloading exchange rates from file 
currency.xml
   [junit4]   2> 396927 INFO  
(TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeMixedAdds-seed#[DB7C2B831BD4D005])
 [    ] o.a.s.s.FileExchangeRateProvider Reloading exchange rates from file 
currency.xml
   [junit4]   2> 396928 INFO  
(TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeMixedAdds-seed#[DB7C2B831BD4D005])
 [    ] o.a.s.s.OpenExchangeRatesOrgProvider Reloading exchange rates from 
open-exchange-rates.json
   [junit4]   2> 396928 INFO  
(TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeMixedAdds-seed#[DB7C2B831BD4D005])
 [    ] o.a.s.s.OpenExchangeRatesOrgProvider Reloading exchange rates from 
open-exchange-rates.json
   [junit4]   2> 396930 INFO  
(TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeMixedAdds-seed#[DB7C2B831BD4D005])
 [    ] o.a.s.c.ConfigSetProperties Did not find ConfigSet properties, assuming 
default properties: Can't find resource 'configsetprops.json' in classpath or 
'/home/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/core/src/test-files/solr/collection1'
   [junit4]   2> 396930 INFO  
(TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeMixedAdds-seed#[DB7C2B831BD4D005])
 [    ] o.a.s.c.CoreContainer Reloading SolrCore 'collection1' using 
configuration from instancedir 
/home/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/core/src/test-files/solr/collection1
   [junit4]   2> 396931 INFO  
(TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeMixedAdds-seed#[DB7C2B831BD4D005])
 [    ] o.a.s.c.SolrCore [[collection1] ] Opening new SolrCore at 
[/home/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/core/src/test-files/solr/collection1],
 
dataDir=[/home/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/temp/solr.update.SoftAutoCommitTest_DB7C2B831BD4D005-001/init-core-data-001/]
   [junit4]   2> 396931 INFO  
(TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeMixedAdds-seed#[DB7C2B831BD4D005])
 [    ] o.a.s.c.JmxMonitoredMap JMX monitoring is enabled. Adding Solr mbeans 
to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@bd6c92
   [junit4]   2> 396931 INFO  
(TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeMixedAdds-seed#[DB7C2B831BD4D005])
 [    ] o.a.s.c.SolrCore New index directory detected: old=null 
new=/home/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/temp/solr.update.SoftAutoCommitTest_DB7C2B831BD4D005-001/init-core-data-001/index/
   [junit4]   2> 396931 INFO  
(OldIndexDirectoryCleanupThreadForCore-collection1) [    ] o.a.s.c.SolrCore 
Looking for old index directories to cleanup for core collection1 in 
/home/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/temp/solr.update.SoftAutoCommitTest_DB7C2B831BD4D005-001/init-core-data-001/
   [junit4]   2> 396934 INFO  
(TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeMixedAdds-seed#[DB7C2B831BD4D005])
 [    ] o.a.s.u.p.UpdateRequestProcessorChain creating 
updateRequestProcessorChain "dedupe"
   [junit4]   2> 396934 INFO  
(TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeMixedAdds-seed#[DB7C2B831BD4D005])
 [    ] o.a.s.u.p.UpdateRequestProcessorChain inserting 
DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
   [junit4]   2> 396934 INFO  
(TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeMixedAdds-seed#[DB7C2B831BD4D005])
 [    ] o.a.s.u.p.UpdateRequestProcessorChain creating 
updateRequestProcessorChain "dedupe-allfields"
   [junit4]   2> 396934 INFO  
(TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeMixedAdds-seed#[DB7C2B831BD4D005])
 [    ] o.a.s.u.p.UpdateRequestProcessorChain inserting 
DistributedUpdateProcessorFactory into updateRequestProcessorChain 
"dedupe-allfields"
   [junit4]   2> 396934 INFO  
(TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeMixedAdds-seed#[DB7C2B831BD4D005])
 [    ] o.a.s.u.p.UpdateRequestProcessorChain creating 
updateRequestProcessorChain "stored_sig"
   [junit4]   2> 396934 INFO  
(TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeMixedAdds-seed#[DB7C2B831BD4D005])
 [    ] o.a.s.u.p.UpdateRequestProcessorChain inserting 
DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
   [junit4]   2> 396934 INFO  
(TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeMixedAdds-seed#[DB7C2B831BD4D005])
 [    ] o.a.s.u.p.UpdateRequestProcessorChain creating 
updateRequestProcessorChain "uniq-fields"
   [junit4]   2> 396935 INFO  
(TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeMixedAdds-seed#[DB7C2B831BD4D005])
 [    ] o.a.s.u.p.UpdateRequestProcessorChain inserting 
DistributedUpdateProcessorFactory into updateRequestProcessorChain "uniq-fields"
   [junit4]   2> 396935 INFO  
(TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeMixedAdds-seed#[DB7C2B831BD4D005])
 [    ] o.a.s.u.p.UpdateRequestProcessorChain creating 
updateRequestProcessorChain "distrib-dup-test-chain-explicit"
   [junit4]   2> 396935 INFO  
(TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeMixedAdds-seed#[DB7C2B831BD4D005])
 [    ] o.a.s.u.p.UpdateRequestProcessorChain creating 
updateRequestProcessorChain "distrib-dup-test-chain-implicit"
   [junit4]   2> 396935 INFO  
(TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeMixedAdds-seed#[DB7C2B831BD4D005])
 [    ] o.a.s.u.p.UpdateRequestProcessorChain inserting 
DistributedUpdateProcessorFactory into updateRequestProcessorChain 
"distrib-dup-test-chain-implicit"
   [junit4]   2> 396935 INFO  
(TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeMixedAdds-seed#[DB7C2B831BD4D005])
 [    ] o.a.s.c.SolrCore no updateRequestProcessorChain defined as default, 
creating implicit default
   [junit4]   2> 396936 INFO  
(TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeMixedAdds-seed#[DB7C2B831BD4D005])
 [    ] o.a.s.h.l.XMLLoader xsltCacheLifetimeSeconds=60
   [junit4]   2> 396937 INFO  
(TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeMixedAdds-seed#[DB7C2B831BD4D005])
 [    ] o.a.s.h.l.XMLLoader xsltCacheLifetimeSeconds=60
   [junit4]   2> 396937 INFO  
(TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeMixedAdds-seed#[DB7C2B831BD4D005])
 [    ] o.a.s.h.l.XMLLoader xsltCacheLifetimeSeconds=60
   [junit4]   2> 396938 INFO  
(TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeMixedAdds-seed#[DB7C2B831BD4D005])
 [    ] o.a.s.h.l.XMLLoader xsltCacheLifetimeSeconds=60
   [junit4]   2> 396941 INFO  
(TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeMixedAdds-seed#[DB7C2B831BD4D005])
 [    ] o.a.s.c.PluginBag requestHandler : 'lazy' created with startup=lazy 
   [junit4]   2> 396942 INFO  
(TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeMixedAdds-seed#[DB7C2B831BD4D005])
 [    ] o.a.s.c.RequestHandlers Registered paths: 
/admin/mbeans,standard,spellCheckCompRH,lazy,/update/json/docs,/admin/luke,/export,spellCheckWithWordbreak_Direct,tvrh,/get,/admin/properties,/update/json,mltrh,/admin/threads,/search-facet-def,/update/csv,/sql,/search-facet-invariants,/admin/segments,spellCheckCompRH1,/mlt,/admin/system,/replication,dismax,defaults,/config,/stream,/schema,/admin/plugins,/admin/logging,spellCheckWithWordbreak,mock,/admin/ping,/update,/admin/file,/terms,spellCheckCompRH_Direct,/debug/dump
   [junit4]   2> 396942 WARN  
(TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeMixedAdds-seed#[DB7C2B831BD4D005])
 [    ] o.a.s.c.SolrCore solrconfig.xml uses deprecated <admin/gettableFiles>, 
Please update your config to use the ShowFileRequestHandler.
   [junit4]   2> 396942 INFO  
(TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeMixedAdds-seed#[DB7C2B831BD4D005])
 [    ] o.a.s.c.SolrCore Using default statsCache cache: 
org.apache.solr.search.stats.LocalStatsCache
   [junit4]   2> 396943 INFO  
(TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeMixedAdds-seed#[DB7C2B831BD4D005])
 [    ] o.a.s.u.CommitTracker Hard AutoCommit: disabled
   [junit4]   2> 396943 INFO  
(TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeMixedAdds-seed#[DB7C2B831BD4D005])
 [    ] o.a.s.u.CommitTracker Soft AutoCommit: disabled
   [junit4]   2> 396943 INFO  
(TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeMixedAdds-seed#[DB7C2B831BD4D005])
 [    ] o.a.s.s.SolrIndexSearcher Opening [Searcher@2218f5[collection1] main]
   [junit4]   2> 396943 INFO  
(TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeMixedAdds-seed#[DB7C2B831BD4D005])
 [    ] o.a.s.r.RestManager Initializing RestManager with initArgs: 
{storageIO=org.apache.solr.rest.ManagedResourceStorage$InMemoryStorageIO}
   [junit4]   2> 396943 INFO  
(TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeMixedAdds-seed#[DB7C2B831BD4D005])
 [    ] o.a.s.r.ManagedResourceStorage Reading _rest_managed.json using 
InMemoryStorage
   [junit4]   2> 396943 INFO  
(TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeMixedAdds-seed#[DB7C2B831BD4D005])
 [    ] o.a.s.r.RestManager Initializing 0 registered ManagedResources
   [junit4]   2> 396943 INFO  
(TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeMixedAdds-seed#[DB7C2B831BD4D005])
 [    ] o.a.s.h.c.SpellCheckComponent Initializing spell checkers
   [junit4]   2> 396944 INFO  
(TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeMixedAdds-seed#[DB7C2B831BD4D005])
 [    ] o.a.s.s.DirectSolrSpellChecker init: 
{name=direct,classname=DirectSolrSpellChecker,field=lowerfilt,minQueryLength=3}
   [junit4]   2> 396945 INFO  
(TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeMixedAdds-seed#[DB7C2B831BD4D005])
 [    ] o.a.s.h.ReplicationHandler Commits will be reserved for  10000
   [junit4]   2> 396945 INFO  (searcherExecutor-1104-thread-1) [    ] 
o.a.s.h.c.SpellCheckComponent Loading spell index for spellchecker: default
   [junit4]   2> 396946 INFO  (searcherExecutor-1104-thread-1) [    ] 
o.a.s.h.c.SpellCheckComponent Loading spell index for spellchecker: direct
   [junit4]   2> 396946 INFO  (searcherExecutor-1104-thread-1) [    ] 
o.a.s.h.c.SpellCheckComponent Loading spell index for spellchecker: wordbreak
   [junit4]   2> 396946 INFO  (sear

[...truncated too long message...]

rg.apache.solr.cloud.LeaderElector.runIamLeaderProcess(LeaderElector.java:198)
   [junit4]   2>        at 
org.apache.solr.cloud.LeaderElector.checkIfIamLeader(LeaderElector.java:158)
   [junit4]   2>        at 
org.apache.solr.cloud.LeaderElector.access$200(LeaderElector.java:59)
   [junit4]   2>        at 
org.apache.solr.cloud.LeaderElector$ElectionWatcher.process(LeaderElector.java:389)
   [junit4]   2>        at 
org.apache.solr.common.cloud.SolrZkClient$3$1.run(SolrZkClient.java:270)
   [junit4]   2>        at 
java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:514)
   [junit4]   2>        at 
java.util.concurrent.FutureTask.run(FutureTask.java:266)
   [junit4]   2>        at 
org.apache.solr.common.util.ExecutorUtil$MDCAwareThreadPoolExecutor$1.run(ExecutorUtil.java:232)
   [junit4]   2>        at 
java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1158)
   [junit4]   2>        at 
java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:632)
   [junit4]   2>        at java.lang.Thread.run(Thread.java:747)
   [junit4]   2> Caused by: 
org.apache.zookeeper.KeeperException$SessionExpiredException: KeeperErrorCode = 
Session expired for /overseer
   [junit4]   2>        at 
org.apache.zookeeper.KeeperException.create(KeeperException.java:127)
   [junit4]   2>        at 
org.apache.zookeeper.KeeperException.create(KeeperException.java:51)
   [junit4]   2>        at 
org.apache.zookeeper.ZooKeeper.create(ZooKeeper.java:783)
   [junit4]   2>        at 
org.apache.solr.common.cloud.SolrZkClient$9.execute(SolrZkClient.java:389)
   [junit4]   2>        at 
org.apache.solr.common.cloud.SolrZkClient$9.execute(SolrZkClient.java:386)
   [junit4]   2>        at 
org.apache.solr.common.cloud.ZkCmdExecutor.retryOperation(ZkCmdExecutor.java:61)
   [junit4]   2>        at 
org.apache.solr.common.cloud.SolrZkClient.create(SolrZkClient.java:386)
   [junit4]   2>        at 
org.apache.solr.cloud.Overseer.createOverseerNode(Overseer.java:949)
   [junit4]   2>        ... 26 more
   [junit4]   2> 811139 INFO  
(TEST-CollectionsAPIDistributedZkTest.test-seed#[DB7C2B831BD4D005]) [    ] 
o.e.j.s.ServerConnector Stopped ServerConnector@1ae56b4{HTTP/1.1}{127.0.0.1:0}
   [junit4]   2> 811140 INFO  
(TEST-CollectionsAPIDistributedZkTest.test-seed#[DB7C2B831BD4D005]) [    ] 
o.e.j.s.h.ContextHandler Stopped 
o.e.j.s.ServletContextHandler@b6cb2d{/v_s/w,null,UNAVAILABLE}
   [junit4]   2> 811140 INFO  
(TEST-CollectionsAPIDistributedZkTest.test-seed#[DB7C2B831BD4D005]) [    ] 
o.a.s.c.ZkTestServer connecting to 127.0.0.1:41001 41001
   [junit4]   2> 811163 INFO  (Thread-2090) [    ] o.a.s.c.ZkTestServer 
connecting to 127.0.0.1:41001 41001
   [junit4]   2> 811164 WARN  (Thread-2090) [    ] o.a.s.c.ZkTestServer Watch 
limit violations: 
   [junit4]   2> Maximum concurrent create/delete watches above limit:
   [junit4]   2> 
   [junit4]   2>        8       /solr/aliases.json
   [junit4]   2>        5       /solr/security.json
   [junit4]   2>        5       /solr/configs/conf1
   [junit4]   2>        3       /solr/configs/conf2
   [junit4]   2> 
   [junit4]   2> Maximum concurrent data watches above limit:
   [junit4]   2> 
   [junit4]   2>        8       /solr/clusterstate.json
   [junit4]   2>        4       
/solr/collections/nodes_used_collection/state.json
   [junit4]   2> 
   [junit4]   2> Maximum concurrent children watches above limit:
   [junit4]   2> 
   [junit4]   2>        8       /solr/live_nodes
   [junit4]   2>        8       /solr/collections
   [junit4]   2>        5       /solr/overseer/queue
   [junit4]   2>        5       /solr/overseer/collection-queue-work
   [junit4]   2>        2       /solr/overseer/queue-work
   [junit4]   2> 
   [junit4]   2> NOTE: reproduce with: ant test  
-Dtestcase=CollectionsAPIDistributedZkTest -Dtests.method=test 
-Dtests.seed=DB7C2B831BD4D005 -Dtests.multiplier=3 -Dtests.slow=true 
-Dtests.locale=nl-BQ -Dtests.timezone=Asia/Kashgar -Dtests.asserts=true 
-Dtests.file.encoding=UTF-8
   [junit4] ERROR   29.3s J1 | CollectionsAPIDistributedZkTest.test <<<
   [junit4]    > Throwable #1: 
org.apache.solr.client.solrj.impl.HttpSolrClient$RemoteSolrException: Error 
from server at http://127.0.0.1:43001/v_s/w/awholynewcollection_0: non ok 
status: 500, message:Server Error
   [junit4]    >        at 
__randomizedtesting.SeedInfo.seed([DB7C2B831BD4D005:53281459B528BDFD]:0)
   [junit4]    >        at 
org.apache.solr.client.solrj.impl.HttpSolrClient.executeMethod(HttpSolrClient.java:511)
   [junit4]    >        at 
org.apache.solr.client.solrj.impl.HttpSolrClient.request(HttpSolrClient.java:240)
   [junit4]    >        at 
org.apache.solr.client.solrj.impl.HttpSolrClient.request(HttpSolrClient.java:229)
   [junit4]    >        at 
org.apache.solr.client.solrj.SolrRequest.process(SolrRequest.java:150)
   [junit4]    >        at 
org.apache.solr.client.solrj.SolrClient.query(SolrClient.java:943)
   [junit4]    >        at 
org.apache.solr.client.solrj.SolrClient.query(SolrClient.java:958)
   [junit4]    >        at 
org.apache.solr.cloud.AbstractFullDistribZkTestBase.waitForNon403or404or503(AbstractFullDistribZkTestBase.java:1773)
   [junit4]    >        at 
org.apache.solr.cloud.CollectionsAPIDistributedZkTest.testCollectionsAPI(CollectionsAPIDistributedZkTest.java:644)
   [junit4]    >        at 
org.apache.solr.cloud.CollectionsAPIDistributedZkTest.test(CollectionsAPIDistributedZkTest.java:160)
   [junit4]    >        at 
org.apache.solr.BaseDistributedSearchTestCase$ShardsRepeatRule$ShardsFixedStatement.callStatement(BaseDistributedSearchTestCase.java:965)
   [junit4]    >        at 
org.apache.solr.BaseDistributedSearchTestCase$ShardsRepeatRule$ShardsStatement.evaluate(BaseDistributedSearchTestCase.java:940)
   [junit4]    >        at java.lang.Thread.run(Thread.java:747)
   [junit4]   2> 811166 INFO  
(SUITE-CollectionsAPIDistributedZkTest-seed#[DB7C2B831BD4D005]-worker) [    ] 
o.a.s.SolrTestCaseJ4 ###deleteCore
   [junit4]   2> NOTE: leaving temporary files on disk at: 
/home/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/temp/solr.cloud.CollectionsAPIDistributedZkTest_DB7C2B831BD4D005-001
   [junit4]   2> Jan 26, 2016 8:06:18 AM 
com.carrotsearch.randomizedtesting.ThreadLeakControl checkThreadLeaks
   [junit4]   2> WARNING: Will linger awaiting termination of 1 leaked 
thread(s).
   [junit4]   2> NOTE: test params are: codec=Asserting(Lucene60): {}, 
docValues:{}, sim=ClassicSimilarity, locale=nl-BQ, timezone=Asia/Kashgar
   [junit4]   2> NOTE: Linux 3.19.0-47-generic i386/Oracle Corporation 9-ea 
(32-bit)/cpus=12,threads=1,free=85884488,total=321388544
   [junit4]   2> NOTE: All tests run in this JVM: [OverseerRolesTest, 
BlockJoinFacetRandomTest, TestDefaultSearchFieldResource, 
TestDistribDocBasedVersion, HighlighterMaxOffsetTest, 
TestSha256AuthenticationProvider, TestFieldTypeResource, SolrIndexSplitterTest, 
TestSchemaResource, ClusterStateUpdateTest, TestFastLRUCache, 
MinimalSchemaTest, HdfsRecoverLeaseTest, TestSolrDynamicMBean, 
TestSortByMinMaxFunction, RulesTest, TestFiltering, BadCopyFieldTest, 
DocValuesMissingTest, HdfsChaosMonkeySafeLeaderTest, 
RecoveryAfterSoftCommitTest, SolrXmlInZkTest, DistanceUnitsTest, 
TestConfigOverlay, TestUniqueKeyFieldResource, TestBM25SimilarityFactory, 
TestSolrCoreProperties, MultiTermTest, 
TestPerFieldSimilarityWithDefaultOverride, TestLRUStatsCache, 
TestLMJelinekMercerSimilarityFactory, TestUpdate, CollectionReloadTest, 
SolrPluginUtilsTest, OutOfBoxZkACLAndCredentialsProvidersTest, 
ZkStateReaderTest, TestDFISimilarityFactory, TestQueryUtils, 
TestFieldCollectionResource, TestRequestForwarding, 
CollectionsAPIAsyncDistributedZkTest, TermsComponentTest, 
WordBreakSolrSpellCheckerTest, DistributedQueueTest, 
LeaderInitiatedRecoveryOnShardRestartTest, BasicFunctionalityTest, 
TestScoreJoinQPNoScore, ConnectionManagerTest, SoftAutoCommitTest, 
TestLFUCache, SmileWriterTest, MoreLikeThisHandlerTest, TestSmileRequest, 
AliasIntegrationTest, PreAnalyzedUpdateProcessorTest, ShardRoutingCustomTest, 
MergeStrategyTest, TestMiniSolrCloudClusterBase, TestMaxScoreQueryParser, 
CoreAdminRequestStatusTest, UpdateRequestProcessorFactoryTest, 
TestLeaderElectionZkExpiry, ChaosMonkeySafeLeaderTest, TestExceedMaxTermLength, 
TestPartialUpdateDeduplication, TestManagedSchemaFieldTypeResource, 
SortByFunctionTest, DistributedExpandComponentTest, 
TestOverriddenPrefixQueryForCustomFieldType, SolrInfoMBeanTest, 
SuggestComponentTest, IndexBasedSpellCheckerTest, NumericFieldsTest, 
TestSolrCloudWithKerberosAlt, DocumentBuilderTest, TestRandomForceMergePolicy, 
ZkSolrClientTest, TestDistribIDF, TestSolrDeletionPolicy2, TestCoreContainer, 
TestComplexPhraseQParserPlugin, TestBinaryResponseWriter, HdfsLockFactoryTest, 
TestCloudPivotFacet, RestartWhileUpdatingTest, TestBlobHandler, BitVectorTest, 
TestReqParamsAPI, HdfsSyncSliceTest, OpenCloseCoreStressTest, 
DirectSolrSpellCheckerTest, TestManagedResource, BasicDistributedZk2Test, 
CollectionsAPIDistributedZkTest]
   [junit4] Completed [236/577 (2!)] on J1 in 30.03s, 1 test, 1 error <<< 
FAILURES!

[...truncated 1117 lines...]
BUILD FAILED
/home/jenkins/workspace/Lucene-Solr-trunk-Linux/build.xml:740: The following 
error occurred while executing this line:
/home/jenkins/workspace/Lucene-Solr-trunk-Linux/build.xml:684: The following 
error occurred while executing this line:
/home/jenkins/workspace/Lucene-Solr-trunk-Linux/build.xml:59: The following 
error occurred while executing this line:
/home/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build.xml:233: The 
following error occurred while executing this line:
/home/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/common-build.xml:524: The 
following error occurred while executing this line:
/home/jenkins/workspace/Lucene-Solr-trunk-Linux/lucene/common-build.xml:1424: 
The following error occurred while executing this line:
/home/jenkins/workspace/Lucene-Solr-trunk-Linux/lucene/common-build.xml:981: 
There were test failures: 577 suites (8 ignored), 2316 tests, 1 error, 1 
failure, 115 ignored (70 assumptions) [seed: DB7C2B831BD4D005]

Total time: 47 minutes 32 seconds
Build step 'Invoke Ant' marked build as failure
Archiving artifacts
[WARNINGS] Skipping publisher since build result is FAILURE
Recording test results
Email was triggered for: Failure - Any
Sending email for trigger: Failure - Any


---------------------------------------------------------------------
To unsubscribe, e-mail: dev-unsubscr...@lucene.apache.org
For additional commands, e-mail: dev-h...@lucene.apache.org

Reply via email to