You are viewing a plain text version of this content. The canonical link for it is here.
Posted to dev@lucene.apache.org by Apache Jenkins Server <je...@builds.apache.org> on 2016/04/23 02:27:09 UTC

[JENKINS] Lucene-Solr-Tests-5.5-Java8 - Build # 3 - Still Failing

Build: https://builds.apache.org/job/Lucene-Solr-Tests-5.5-Java8/3/

3 tests failed.
FAILED:  org.apache.solr.update.AutoCommitTest.testMaxTime

Error Message:
Exception during query

Stack Trace:
java.lang.RuntimeException: Exception during query
	at __randomizedtesting.SeedInfo.seed([1CE1D579B8F796DC:8615A89B266D0AE0]:0)
	at org.apache.solr.SolrTestCaseJ4.assertQ(SolrTestCaseJ4.java:754)
	at org.apache.solr.update.AutoCommitTest.testMaxTime(AutoCommitTest.java:243)
	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:498)
	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:49)
	at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:45)
	at org.apache.lucene.util.TestRuleThreadAndTestName$1.evaluate(TestRuleThreadAndTestName.java:48)
	at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:64)
	at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:47)
	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:45)
	at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
	at org.apache.lucene.util.TestRuleStoreClassName$1.evaluate(TestRuleStoreClassName.java:41)
	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:53)
	at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:47)
	at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:64)
	at org.apache.lucene.util.TestRuleIgnoreTestSuites$1.evaluate(TestRuleIgnoreTestSuites.java:54)
	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:745)
Caused by: java.lang.RuntimeException: REQUEST FAILED: xpath=//result[@numFound=1]
	xml response was: <?xml version="1.0" encoding="UTF-8"?>
<response>
<lst name="responseHeader"><int name="status">0</int><int name="QTime">0</int></lst><result name="response" numFound="0" start="0"></result>
</response>

	request was:q=id:529&qt=standard&start=0&rows=20&version=2.2
	at org.apache.solr.SolrTestCaseJ4.assertQ(SolrTestCaseJ4.java:747)
	... 40 more


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

Error Message:
Got a soft commit we weren't expecting

Stack Trace:
java.lang.AssertionError: Got a soft commit we weren't expecting
	at __randomizedtesting.SeedInfo.seed([1CE1D579B8F796DC:DBAD6DE4A35F5B6C]:0)
	at org.junit.Assert.fail(Assert.java:93)
	at org.junit.Assert.assertTrue(Assert.java:43)
	at org.junit.Assert.assertNull(Assert.java:551)
	at org.apache.solr.update.SoftAutoCommitTest.testSoftAndHardCommitMaxTimeDelete(SoftAutoCommitTest.java:287)
	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:498)
	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:49)
	at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:45)
	at org.apache.lucene.util.TestRuleThreadAndTestName$1.evaluate(TestRuleThreadAndTestName.java:48)
	at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:64)
	at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:47)
	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:45)
	at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
	at org.apache.lucene.util.TestRuleStoreClassName$1.evaluate(TestRuleStoreClassName.java:41)
	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:53)
	at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:47)
	at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:64)
	at org.apache.lucene.util.TestRuleIgnoreTestSuites$1.evaluate(TestRuleIgnoreTestSuites.java:54)
	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:745)


FAILED:  org.apache.solr.cloud.overseer.ZkStateReaderTest.testStateFormatUpdateWithExplicitRefresh

Error Message:
Could not find collection : c1

Stack Trace:
org.apache.solr.common.SolrException: Could not find collection : c1
	at __randomizedtesting.SeedInfo.seed([1CE1D579B8F796DC:35BA48E68975019]:0)
	at org.apache.solr.common.cloud.ClusterState.getCollection(ClusterState.java:170)
	at org.apache.solr.cloud.overseer.ZkStateReaderTest.testStateFormatUpdate(ZkStateReaderTest.java:136)
	at org.apache.solr.cloud.overseer.ZkStateReaderTest.testStateFormatUpdateWithExplicitRefresh(ZkStateReaderTest.java:42)
	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:498)
	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:49)
	at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:45)
	at org.apache.lucene.util.TestRuleThreadAndTestName$1.evaluate(TestRuleThreadAndTestName.java:48)
	at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:64)
	at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:47)
	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:45)
	at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
	at org.apache.lucene.util.TestRuleStoreClassName$1.evaluate(TestRuleStoreClassName.java:41)
	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:53)
	at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:47)
	at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:64)
	at org.apache.lucene.util.TestRuleIgnoreTestSuites$1.evaluate(TestRuleIgnoreTestSuites.java:54)
	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:745)




Build Log:
[...truncated 10906 lines...]
   [junit4] Suite: org.apache.solr.update.SoftAutoCommitTest
   [junit4]   2> Creating dataDir: /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-5.5-Java8/solr/build/solr-core/test/J1/temp/solr.update.SoftAutoCommitTest_1CE1D579B8F796DC-001/init-core-data-001
   [junit4]   2> 582072 INFO  (SUITE-SoftAutoCommitTest-seed#[1CE1D579B8F796DC]-worker) [    ] o.a.s.SolrTestCaseJ4 Randomized ssl (true) and clientAuth (true)
   [junit4]   2> 582072 INFO  (SUITE-SoftAutoCommitTest-seed#[1CE1D579B8F796DC]-worker) [    ] o.a.s.SolrTestCaseJ4 ####initCore
   [junit4]   2> 582072 INFO  (SUITE-SoftAutoCommitTest-seed#[1CE1D579B8F796DC]-worker) [    ] o.a.s.c.SolrResourceLoader new SolrResourceLoader for directory: '/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-5.5-Java8/solr/core/src/test-files/solr/collection1'
   [junit4]   2> 582073 INFO  (SUITE-SoftAutoCommitTest-seed#[1CE1D579B8F796DC]-worker) [    ] o.a.s.c.SolrResourceLoader JNDI not configured for solr (NoInitialContextEx)
   [junit4]   2> 582073 INFO  (SUITE-SoftAutoCommitTest-seed#[1CE1D579B8F796DC]-worker) [    ] o.a.s.c.SolrResourceLoader using system property solr.solr.home: /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-5.5-Java8/solr/core/src/test-files/solr
   [junit4]   2> 582073 INFO  (SUITE-SoftAutoCommitTest-seed#[1CE1D579B8F796DC]-worker) [    ] o.a.s.c.SolrResourceLoader Adding 'file:/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-5.5-Java8/solr/core/src/test-files/solr/collection1/lib/classes/' to classloader
   [junit4]   2> 582073 INFO  (SUITE-SoftAutoCommitTest-seed#[1CE1D579B8F796DC]-worker) [    ] o.a.s.c.SolrResourceLoader Adding 'file:/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-5.5-Java8/solr/core/src/test-files/solr/collection1/lib/README' to classloader
   [junit4]   2> 582144 INFO  (SUITE-SoftAutoCommitTest-seed#[1CE1D579B8F796DC]-worker) [    ] o.a.s.c.SolrConfig current version of requestparams : -1
   [junit4]   2> 582158 INFO  (SUITE-SoftAutoCommitTest-seed#[1CE1D579B8F796DC]-worker) [    ] o.a.s.c.SolrConfig Using Lucene MatchVersion: 5.5.0
   [junit4]   2> 582188 INFO  (SUITE-SoftAutoCommitTest-seed#[1CE1D579B8F796DC]-worker) [    ] o.a.s.c.SolrConfig Loaded SolrConfig: solrconfig.xml
   [junit4]   2> 582192 INFO  (SUITE-SoftAutoCommitTest-seed#[1CE1D579B8F796DC]-worker) [    ] o.a.s.s.IndexSchema [null] Schema name=test
   [junit4]   2> 582259 INFO  (SUITE-SoftAutoCommitTest-seed#[1CE1D579B8F796DC]-worker) [    ] o.a.s.s.OpenExchangeRatesOrgProvider Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
   [junit4]   2> 582262 INFO  (SUITE-SoftAutoCommitTest-seed#[1CE1D579B8F796DC]-worker) [    ] o.a.s.s.IndexSchema default search field in schema is text
   [junit4]   2> 582263 INFO  (SUITE-SoftAutoCommitTest-seed#[1CE1D579B8F796DC]-worker) [    ] o.a.s.s.IndexSchema unique key field: id
   [junit4]   2> 582271 INFO  (SUITE-SoftAutoCommitTest-seed#[1CE1D579B8F796DC]-worker) [    ] o.a.s.s.FileExchangeRateProvider Reloading exchange rates from file currency.xml
   [junit4]   2> 582272 INFO  (SUITE-SoftAutoCommitTest-seed#[1CE1D579B8F796DC]-worker) [    ] o.a.s.s.FileExchangeRateProvider Reloading exchange rates from file currency.xml
   [junit4]   2> 582309 INFO  (SUITE-SoftAutoCommitTest-seed#[1CE1D579B8F796DC]-worker) [    ] o.a.s.s.OpenExchangeRatesOrgProvider Reloading exchange rates from open-exchange-rates.json
   [junit4]   2> 582309 INFO  (SUITE-SoftAutoCommitTest-seed#[1CE1D579B8F796DC]-worker) [    ] o.a.s.s.OpenExchangeRatesOrgProvider Reloading exchange rates from open-exchange-rates.json
   [junit4]   2> 582310 INFO  (SUITE-SoftAutoCommitTest-seed#[1CE1D579B8F796DC]-worker) [    ] o.a.s.c.SolrResourceLoader JNDI not configured for solr (NoInitialContextEx)
   [junit4]   2> 582310 INFO  (SUITE-SoftAutoCommitTest-seed#[1CE1D579B8F796DC]-worker) [    ] o.a.s.c.SolrResourceLoader using system property solr.solr.home: /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-5.5-Java8/solr/core/src/test-files/solr
   [junit4]   2> 582310 INFO  (SUITE-SoftAutoCommitTest-seed#[1CE1D579B8F796DC]-worker) [    ] o.a.s.c.SolrResourceLoader new SolrResourceLoader for directory: '/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-5.5-Java8/solr/core/src/test-files/solr'
   [junit4]   2> 582310 INFO  (SUITE-SoftAutoCommitTest-seed#[1CE1D579B8F796DC]-worker) [    ] o.a.s.c.SolrResourceLoader JNDI not configured for solr (NoInitialContextEx)
   [junit4]   2> 582310 INFO  (SUITE-SoftAutoCommitTest-seed#[1CE1D579B8F796DC]-worker) [    ] o.a.s.c.SolrResourceLoader using system property solr.solr.home: /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-5.5-Java8/solr/core/src/test-files/solr
   [junit4]   2> 582310 INFO  (SUITE-SoftAutoCommitTest-seed#[1CE1D579B8F796DC]-worker) [    ] o.a.s.c.CoreContainer New CoreContainer 1385203522
   [junit4]   2> 582310 INFO  (SUITE-SoftAutoCommitTest-seed#[1CE1D579B8F796DC]-worker) [    ] o.a.s.c.CoreContainer Loading cores into CoreContainer [instanceDir=/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-5.5-Java8/solr/core/src/test-files/solr]
   [junit4]   2> 582310 WARN  (SUITE-SoftAutoCommitTest-seed#[1CE1D579B8F796DC]-worker) [    ] o.a.s.c.CoreContainer Couldn't add files from /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-5.5-Java8/solr/core/src/test-files/solr/lib to classpath: /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-5.5-Java8/solr/core/src/test-files/solr/lib
   [junit4]   2> 582322 INFO  (SUITE-SoftAutoCommitTest-seed#[1CE1D579B8F796DC]-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> 582328 INFO  (SUITE-SoftAutoCommitTest-seed#[1CE1D579B8F796DC]-worker) [    ] o.a.s.u.UpdateShardHandler Creating UpdateShardHandler HTTP client with params: socketTimeout=30000&connTimeout=30000&retry=true
   [junit4]   2> 582328 INFO  (SUITE-SoftAutoCommitTest-seed#[1CE1D579B8F796DC]-worker) [    ] o.a.s.l.LogWatcher SLF4J impl is org.slf4j.impl.Log4jLoggerFactory
   [junit4]   2> 582329 INFO  (SUITE-SoftAutoCommitTest-seed#[1CE1D579B8F796DC]-worker) [    ] o.a.s.l.LogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
   [junit4]   2> 582329 INFO  (SUITE-SoftAutoCommitTest-seed#[1CE1D579B8F796DC]-worker) [    ] o.a.s.c.CoreContainer Security conf doesn't exist. Skipping setup for authorization module.
   [junit4]   2> 582329 INFO  (SUITE-SoftAutoCommitTest-seed#[1CE1D579B8F796DC]-worker) [    ] o.a.s.c.CoreContainer No authentication plugin used.
   [junit4]   2> 582329 INFO  (SUITE-SoftAutoCommitTest-seed#[1CE1D579B8F796DC]-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=/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-5.5-Java8/solr/build/solr-core/test/J1/temp/solr.update.SoftAutoCommitTest_1CE1D579B8F796DC-001/init-core-data-001, shard=shard1}
   [junit4]   2> 582329 INFO  (coreLoadExecutor-1005-thread-1) [    ] o.a.s.c.SolrResourceLoader new SolrResourceLoader for directory: '/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-5.5-Java8/solr/core/src/test-files/solr/collection1'
   [junit4]   2> 582346 INFO  (coreLoadExecutor-1005-thread-1) [    ] o.a.s.c.SolrResourceLoader JNDI not configured for solr (NoInitialContextEx)
   [junit4]   2> 582346 INFO  (coreLoadExecutor-1005-thread-1) [    ] o.a.s.c.SolrResourceLoader using system property solr.solr.home: /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-5.5-Java8/solr/core/src/test-files/solr
   [junit4]   2> 582346 INFO  (coreLoadExecutor-1005-thread-1) [    ] o.a.s.c.SolrResourceLoader Adding 'file:/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-5.5-Java8/solr/core/src/test-files/solr/collection1/lib/classes/' to classloader
   [junit4]   2> 582346 INFO  (coreLoadExecutor-1005-thread-1) [    ] o.a.s.c.SolrResourceLoader Adding 'file:/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-5.5-Java8/solr/core/src/test-files/solr/collection1/lib/README' to classloader
   [junit4]   2> 582364 INFO  (coreLoadExecutor-1005-thread-1) [    ] o.a.s.c.SolrConfig current version of requestparams : -1
   [junit4]   2> 582373 INFO  (coreLoadExecutor-1005-thread-1) [    ] o.a.s.c.SolrConfig Using Lucene MatchVersion: 5.5.0
   [junit4]   2> 582482 INFO  (coreLoadExecutor-1005-thread-1) [    ] o.a.s.c.SolrConfig Loaded SolrConfig: solrconfig.xml
   [junit4]   2> 582491 INFO  (coreLoadExecutor-1005-thread-1) [    ] o.a.s.s.IndexSchema [collection1] Schema name=test
   [junit4]   2> 582641 INFO  (coreLoadExecutor-1005-thread-1) [    ] o.a.s.s.OpenExchangeRatesOrgProvider Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
   [junit4]   2> 582664 INFO  (coreLoadExecutor-1005-thread-1) [    ] o.a.s.s.IndexSchema default search field in schema is text
   [junit4]   2> 582665 INFO  (coreLoadExecutor-1005-thread-1) [    ] o.a.s.s.IndexSchema unique key field: id
   [junit4]   2> 582676 INFO  (coreLoadExecutor-1005-thread-1) [    ] o.a.s.s.FileExchangeRateProvider Reloading exchange rates from file currency.xml
   [junit4]   2> 582677 INFO  (coreLoadExecutor-1005-thread-1) [    ] o.a.s.s.FileExchangeRateProvider Reloading exchange rates from file currency.xml
   [junit4]   2> 582684 INFO  (coreLoadExecutor-1005-thread-1) [    ] o.a.s.s.OpenExchangeRatesOrgProvider Reloading exchange rates from open-exchange-rates.json
   [junit4]   2> 582684 INFO  (coreLoadExecutor-1005-thread-1) [    ] o.a.s.s.OpenExchangeRatesOrgProvider Reloading exchange rates from open-exchange-rates.json
   [junit4]   2> 582685 INFO  (coreLoadExecutor-1005-thread-1) [    ] o.a.s.c.ConfigSetProperties Did not find ConfigSet properties, assuming default properties: Can't find resource 'configsetprops.json' in classpath or '/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-5.5-Java8/solr/core/src/test-files/solr/collection1'
   [junit4]   2> 582685 INFO  (coreLoadExecutor-1005-thread-1) [    ] o.a.s.c.CoreContainer Creating SolrCore 'collection1' using configuration from instancedir /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-5.5-Java8/solr/core/src/test-files/solr/collection1
   [junit4]   2> 582686 INFO  (coreLoadExecutor-1005-thread-1) [    x:collection1] o.a.s.c.SolrCore org.apache.solr.core.MockDirectoryFactory
   [junit4]   2> 582686 INFO  (coreLoadExecutor-1005-thread-1) [    x:collection1] o.a.s.c.SolrCore [[collection1] ] Opening new SolrCore at [/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-5.5-Java8/solr/core/src/test-files/solr/collection1], dataDir=[/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-5.5-Java8/solr/build/solr-core/test/J1/temp/solr.update.SoftAutoCommitTest_1CE1D579B8F796DC-001/init-core-data-001/]
   [junit4]   2> 582686 INFO  (coreLoadExecutor-1005-thread-1) [    x:collection1] o.a.s.c.JmxMonitoredMap JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@5b7d090b
   [junit4]   2> 582686 INFO  (coreLoadExecutor-1005-thread-1) [    x:collection1] o.a.s.c.CachingDirectoryFactory return new directory for /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-5.5-Java8/solr/build/solr-core/test/J1/temp/solr.update.SoftAutoCommitTest_1CE1D579B8F796DC-001/init-core-data-001
   [junit4]   2> 582686 INFO  (coreLoadExecutor-1005-thread-1) [    x:collection1] o.a.s.c.SolrCore New index directory detected: old=null new=/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-5.5-Java8/solr/build/solr-core/test/J1/temp/solr.update.SoftAutoCommitTest_1CE1D579B8F796DC-001/init-core-data-001/index/
   [junit4]   2> 582686 WARN  (coreLoadExecutor-1005-thread-1) [    x:collection1] o.a.s.c.SolrCore [collection1] Solr index directory '/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-5.5-Java8/solr/build/solr-core/test/J1/temp/solr.update.SoftAutoCommitTest_1CE1D579B8F796DC-001/init-core-data-001/index' doesn't exist. Creating new index...
   [junit4]   2> 582686 INFO  (coreLoadExecutor-1005-thread-1) [    x:collection1] o.a.s.c.CachingDirectoryFactory return new directory for /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-5.5-Java8/solr/build/solr-core/test/J1/temp/solr.update.SoftAutoCommitTest_1CE1D579B8F796DC-001/init-core-data-001/index
   [junit4]   2> 582687 INFO  (coreLoadExecutor-1005-thread-1) [    x:collection1] o.a.s.u.RandomMergePolicy RandomMergePolicy wrapping class org.apache.lucene.index.LogByteSizeMergePolicy: [LogByteSizeMergePolicy: minMergeSize=1677721, mergeFactor=32, maxMergeSize=2147483648, maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=true, maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.0]
   [junit4]   2> 582687 INFO  (coreLoadExecutor-1005-thread-1) [    x:collection1] o.a.s.c.SolrDeletionPolicy SolrDeletionPolicy.onCommit: commits: num=1
   [junit4]   2> 	commit{dir=MockDirectoryWrapper(RAMDirectory@7bd7ca07 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@546b13d6),segFN=segments_1,generation=1}
   [junit4]   2> 582687 INFO  (coreLoadExecutor-1005-thread-1) [    x:collection1] o.a.s.c.SolrDeletionPolicy newest commit generation = 1
   [junit4]   2> 582689 INFO  (coreLoadExecutor-1005-thread-1) [    x:collection1] o.a.s.u.p.UpdateRequestProcessorChain creating updateRequestProcessorChain "dedupe"
   [junit4]   2> 582689 INFO  (coreLoadExecutor-1005-thread-1) [    x:collection1] o.a.s.u.p.UpdateRequestProcessorChain inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
   [junit4]   2> 582689 INFO  (coreLoadExecutor-1005-thread-1) [    x:collection1] o.a.s.u.p.UpdateRequestProcessorChain creating updateRequestProcessorChain "dedupe-allfields"
   [junit4]   2> 582689 INFO  (coreLoadExecutor-1005-thread-1) [    x:collection1] o.a.s.u.p.UpdateRequestProcessorChain inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe-allfields"
   [junit4]   2> 582689 INFO  (coreLoadExecutor-1005-thread-1) [    x:collection1] o.a.s.u.p.UpdateRequestProcessorChain creating updateRequestProcessorChain "stored_sig"
   [junit4]   2> 582690 INFO  (coreLoadExecutor-1005-thread-1) [    x:collection1] o.a.s.u.p.UpdateRequestProcessorChain inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
   [junit4]   2> 582690 INFO  (coreLoadExecutor-1005-thread-1) [    x:collection1] o.a.s.u.p.UpdateRequestProcessorChain creating updateRequestProcessorChain "uniq-fields"
   [junit4]   2> 582690 INFO  (coreLoadExecutor-1005-thread-1) [    x:collection1] o.a.s.u.p.UpdateRequestProcessorChain inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "uniq-fields"
   [junit4]   2> 582690 INFO  (coreLoadExecutor-1005-thread-1) [    x:collection1] o.a.s.u.p.UpdateRequestProcessorChain creating updateRequestProcessorChain "distrib-dup-test-chain-explicit"
   [junit4]   2> 582690 INFO  (coreLoadExecutor-1005-thread-1) [    x:collection1] o.a.s.u.p.UpdateRequestProcessorChain creating updateRequestProcessorChain "distrib-dup-test-chain-implicit"
   [junit4]   2> 582690 INFO  (coreLoadExecutor-1005-thread-1) [    x:collection1] o.a.s.u.p.UpdateRequestProcessorChain inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
   [junit4]   2> 582690 INFO  (coreLoadExecutor-1005-thread-1) [    x:collection1] o.a.s.c.SolrCore no updateRequestProcessorChain defined as default, creating implicit default
   [junit4]   2> 582691 INFO  (coreLoadExecutor-1005-thread-1) [    x:collection1] o.a.s.h.l.XMLLoader xsltCacheLifetimeSeconds=60
   [junit4]   2> 582692 INFO  (coreLoadExecutor-1005-thread-1) [    x:collection1] o.a.s.h.l.XMLLoader xsltCacheLifetimeSeconds=60
   [junit4]   2> 582692 INFO  (coreLoadExecutor-1005-thread-1) [    x:collection1] o.a.s.h.l.XMLLoader xsltCacheLifetimeSeconds=60
   [junit4]   2> 582693 INFO  (coreLoadExecutor-1005-thread-1) [    x:collection1] o.a.s.h.l.XMLLoader xsltCacheLifetimeSeconds=60
   [junit4]   2> 582695 INFO  (coreLoadExecutor-1005-thread-1) [    x:collection1] o.a.s.c.PluginBag requestHandler : 'lazy' created with startup=lazy 
   [junit4]   2> 582696 INFO  (coreLoadExecutor-1005-thread-1) [    x:collection1] o.a.s.c.RequestHandlers Registered paths: /admin/mbeans,standard,spellCheckCompRH,lazy,/update/json/docs,/admin/luke,spellCheckWithWordbreak_Direct,tvrh,/get,/admin/properties,/update/json,mltrh,/admin/threads,/search-facet-def,/update/csv,/search-facet-invariants,/admin/segments,spellCheckCompRH1,/mlt,/admin/system,/replication,dismax,defaults,/config,/schema,/admin/plugins,/admin/logging,spellCheckWithWordbreak,mock,/admin/ping,/update,/admin/file,/terms,spellCheckCompRH_Direct,/debug/dump
   [junit4]   2> 582696 WARN  (coreLoadExecutor-1005-thread-1) [    x:collection1] o.a.s.c.SolrCore solrconfig.xml uses deprecated <admin/gettableFiles>, Please update your config to use the ShowFileRequestHandler.
   [junit4]   2> 582696 INFO  (coreLoadExecutor-1005-thread-1) [    x:collection1] o.a.s.c.SolrCore Using default statsCache cache: org.apache.solr.search.stats.LocalStatsCache
   [junit4]   2> 582697 INFO  (OldIndexDirectoryCleanupThreadForCore-collection1) [    x:collection1] o.a.s.c.SolrCore Looking for old index directories to cleanup for core collection1 in /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-5.5-Java8/solr/build/solr-core/test/J1/temp/solr.update.SoftAutoCommitTest_1CE1D579B8F796DC-001/init-core-data-001/
   [junit4]   2> 582697 INFO  (coreLoadExecutor-1005-thread-1) [    x:collection1] o.a.s.u.UpdateHandler Using UpdateLog implementation: org.apache.solr.update.UpdateLog
   [junit4]   2> 582697 INFO  (coreLoadExecutor-1005-thread-1) [    x:collection1] o.a.s.u.UpdateLog Initializing UpdateLog: dataDir= defaultSyncLevel=FLUSH numRecordsToKeep=100 maxNumLogsToKeep=10 numVersionBuckets=65536
   [junit4]   2> 582698 INFO  (coreLoadExecutor-1005-thread-1) [    x:collection1] o.a.s.u.CommitTracker Hard AutoCommit: disabled
   [junit4]   2> 582698 INFO  (coreLoadExecutor-1005-thread-1) [    x:collection1] o.a.s.u.CommitTracker Soft AutoCommit: disabled
   [junit4]   2> 582698 INFO  (coreLoadExecutor-1005-thread-1) [    x:collection1] o.a.s.u.RandomMergePolicy RandomMergePolicy wrapping class org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: maxMergeAtOnce=37, maxMergeAtOnceExplicit=18, maxMergedSegmentMB=4.1064453125, floorSegmentMB=1.7529296875, forceMergeDeletesPctAllowed=23.425354893011864, segmentsPerTier=29.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.8872145663403272
   [junit4]   2> 582698 INFO  (coreLoadExecutor-1005-thread-1) [    x:collection1] o.a.s.c.SolrDeletionPolicy SolrDeletionPolicy.onInit: commits: num=1
   [junit4]   2> 	commit{dir=MockDirectoryWrapper(RAMDirectory@7bd7ca07 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@546b13d6),segFN=segments_1,generation=1}
   [junit4]   2> 582698 INFO  (coreLoadExecutor-1005-thread-1) [    x:collection1] o.a.s.c.SolrDeletionPolicy newest commit generation = 1
   [junit4]   2> 582699 INFO  (coreLoadExecutor-1005-thread-1) [    x:collection1] o.a.s.s.SolrIndexSearcher Opening Searcher@3603b37[collection1] main
   [junit4]   2> 582699 INFO  (coreLoadExecutor-1005-thread-1) [    x:collection1] o.a.s.r.RestManager Initializing RestManager with initArgs: {storageIO=org.apache.solr.rest.ManagedResourceStorage$InMemoryStorageIO}
   [junit4]   2> 582699 INFO  (coreLoadExecutor-1005-thread-1) [    x:collection1] o.a.s.r.ManagedResourceStorage Reading _rest_managed.json using InMemoryStorage
   [junit4]   2> 582699 INFO  (coreLoadExecutor-1005-thread-1) [    x:collection1] o.a.s.r.RestManager Initializing 0 registered ManagedResources
   [junit4]   2> 582699 INFO  (coreLoadExecutor-1005-thread-1) [    x:collection1] o.a.s.h.c.SpellCheckComponent Initializing spell checkers
   [junit4]   2> 582706 INFO  (coreLoadExecutor-1005-thread-1) [    x:collection1] o.a.s.s.DirectSolrSpellChecker init: {name=direct,classname=DirectSolrSpellChecker,field=lowerfilt,minQueryLength=3}
   [junit4]   2> 582736 INFO  (coreLoadExecutor-1005-thread-1) [    x:collection1] o.a.s.h.ReplicationHandler Commits will be reserved for  10000
   [junit4]   2> 582737 INFO  (searcherExecutor-1006-thread-1-processing-x:collection1) [    x:collection1] o.a.s.h.c.SpellCheckComponent Loading spell index for spellchecker: default
   [junit4]   2> 582737 INFO  (searcherExecutor-1006-thread-1-processing-x:collection1) [    x:collection1] o.a.s.h.c.SpellCheckComponent Loading spell index for spellchecker: direct
   [junit4]   2> 582737 INFO  (searcherExecutor-1006-thread-1-processing-x:collection1) [    x:collection1] o.a.s.h.c.SpellCheckComponent Loading spell index for spellchecker: wordbreak
   [junit4]   2> 582737 INFO  (searcherExecutor-1006-thread-1-processing-x:collection1) [    x:collection1] o.a.s.h.c.SpellCheckComponent Loading spell index for spellchecker: multipleFields
   [junit4]   2> 582737 INFO  (searcherExecutor-1006-thread-1-processing-x:collection1) [    x:collection1] o.a.s.h.c.SpellCheckComponent Loading spell index for spellchecker: jarowinkler
   [junit4]   2> 582737 INFO  (searcherExecutor-1006-thread-1-processing-x:collection1) [    x:collection1] o.a.s.h.c.SpellCheckComponent Loading spell index for spellchecker: external
   [junit4]   2> 582737 INFO  (searcherExecutor-1006-thread-1-processing-x:collection1) [    x:collection1] o.a.s.h.c.SpellCheckComponent Loading spell index for spellchecker: freq
   [junit4]   2> 582738 INFO  (searcherExecutor-1006-thread-1-processing-x:collection1) [    x:collection1] o.a.s.h.c.SpellCheckComponent Loading spell index for spellchecker: fqcn
   [junit4]   2> 582738 INFO  (searcherExecutor-1006-thread-1-processing-x:collection1) [    x:collection1] o.a.s.h.c.SpellCheckComponent Loading spell index for spellchecker: perDict
   [junit4]   2> 582738 INFO  (coreLoadExecutor-1005-thread-1) [    x:collection1] o.a.s.u.UpdateLog Looking up max value of version field to seed version buckets
   [junit4]   2> 582738 INFO  (coreLoadExecutor-1005-thread-1) [    x:collection1] o.a.s.u.VersionInfo Refreshing highest value of _version_ for 65536 version buckets from index
   [junit4]   2> 582738 INFO  (coreLoadExecutor-1005-thread-1) [    x:collection1] o.a.s.u.VersionInfo No terms found for _version_, cannot seed version bucket highest value from index
   [junit4]   2> 582738 INFO  (coreLoadExecutor-1005-thread-1) [    x:collection1] o.a.s.u.UpdateLog Could not find max version in index or recent updates, using new clock 1532356284686270464
   [junit4]   2> 582740 INFO  (coreLoadExecutor-1005-thread-1) [    x:collection1] o.a.s.u.UpdateLog Took 1.0ms to seed version buckets with highest version 1532356284686270464
   [junit4]   2> 582740 INFO  (coreLoadExecutor-1005-thread-1) [    x:collection1] o.a.s.c.CoreContainer registering core: collection1
   [junit4]   2> 582741 INFO  (searcherExecutor-1006-thread-1-processing-x:collection1) [    x:collection1] o.a.s.c.SolrCore [collection1] Registered new searcher Searcher@3603b37[collection1] main{ExitableDirectoryReader(UninvertingDirectoryReader())}
   [junit4]   2> 582741 INFO  (SUITE-SoftAutoCommitTest-seed#[1CE1D579B8F796DC]-worker) [    ] o.a.s.SolrTestCaseJ4 ####initCore end
   [junit4]   2> 582743 INFO  (TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeRapidAdds-seed#[1CE1D579B8F796DC]) [    ] o.a.s.SolrTestCaseJ4 ###Starting testSoftAndHardCommitMaxTimeRapidAdds
   [junit4]   2> 582743 INFO  (TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeRapidAdds-seed#[1CE1D579B8F796DC]) [    ] o.a.s.c.SolrResourceLoader new SolrResourceLoader for directory: '/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-5.5-Java8/solr/core/src/test-files/solr/collection1'
   [junit4]   2> 582743 INFO  (TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeRapidAdds-seed#[1CE1D579B8F796DC]) [    ] o.a.s.c.SolrResourceLoader JNDI not configured for solr (NoInitialContextEx)
   [junit4]   2> 582743 INFO  (TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeRapidAdds-seed#[1CE1D579B8F796DC]) [    ] o.a.s.c.SolrResourceLoader using system property solr.solr.home: /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-5.5-Java8/solr/core/src/test-files/solr
   [junit4]   2> 582743 INFO  (TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeRapidAdds-seed#[1CE1D579B8F796DC]) [    ] o.a.s.c.SolrResourceLoader Adding 'file:/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-5.5-Java8/solr/core/src/test-files/solr/collection1/lib/classes/' to classloader
   [junit4]   2> 582743 INFO  (TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeRapidAdds-seed#[1CE1D579B8F796DC]) [    ] o.a.s.c.SolrResourceLoader Adding 'file:/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-5.5-Java8/solr/core/src/test-files/solr/collection1/lib/README' to classloader
   [junit4]   2> 582798 INFO  (TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeRapidAdds-seed#[1CE1D579B8F796DC]) [    ] o.a.s.c.SolrConfig current version of requestparams : -1
   [junit4]   2> 582812 INFO  (TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeRapidAdds-seed#[1CE1D579B8F796DC]) [    ] o.a.s.c.SolrConfig Using Lucene MatchVersion: 5.5.0
   [junit4]   2> 582846 INFO  (TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeRapidAdds-seed#[1CE1D579B8F796DC]) [    ] o.a.s.c.SolrConfig Loaded SolrConfig: solrconfig.xml
   [junit4]   2> 582849 INFO  (TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeRapidAdds-seed#[1CE1D579B8F796DC]) [    ] o.a.s.s.IndexSchema [collection1] Schema name=test
   [junit4]   2> 583095 INFO  (TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeRapidAdds-seed#[1CE1D579B8F796DC]) [    ] o.a.s.s.OpenExchangeRatesOrgProvider Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
   [junit4]   2> 583107 INFO  (TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeRapidAdds-seed#[1CE1D579B8F796DC]) [    ] o.a.s.s.IndexSchema default search field in schema is text
   [junit4]   2> 583107 INFO  (TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeRapidAdds-seed#[1CE1D579B8F796DC]) [    ] o.a.s.s.IndexSchema unique key field: id
   [junit4]   2> 583110 INFO  (TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeRapidAdds-seed#[1CE1D579B8F796DC]) [    ] o.a.s.s.FileExchangeRateProvider Reloading exchange rates from file currency.xml
   [junit4]   2> 583111 INFO  (TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeRapidAdds-seed#[1CE1D579B8F796DC]) [    ] o.a.s.s.FileExchangeRateProvider Reloading exchange rates from file currency.xml
   [junit4]   2> 583112 INFO  (TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeRapidAdds-seed#[1CE1D579B8F796DC]) [    ] o.a.s.s.OpenExchangeRatesOrgProvider Reloading exchange rates from open-exchange-rates.json
   [junit4]   2> 583112 INFO  (TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeRapidAdds-seed#[1CE1D579B8F796DC]) [    ] o.a.s.s.OpenExchangeRatesOrgProvider Reloading exchange rates from open-exchange-rates.json
   [junit4]   2> 583114 INFO  (TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeRapidAdds-seed#[1CE1D579B8F796DC]) [    ] o.a.s.c.ConfigSetProperties Did not find ConfigSet properties, assuming default properties: Can't find resource 'configsetprops.json' in classpath or '/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-5.5-Java8/solr/core/src/test-files/solr/collection1'
   [junit4]   2> 583114 INFO  (TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeRapidAdds-seed#[1CE1D579B8F796DC]) [    ] o.a.s.c.CoreContainer Reloading SolrCore 'collection1' using configuration from instancedir /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-5.5-Java8/solr/core/src/test-files/solr/collection1
   [junit4]   2> 583130 INFO  (TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeRapidAdds-seed#[1CE1D579B8F796DC]) [    x:collection1] o.a.s.c.SolrCore [[collection1] ] Opening new SolrCore at [/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-5.5-Java8/solr/core/src/test-files/solr/collection1], dataDir=[/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-5.5-Java8/solr/build/solr-core/test/J1/temp/solr.update.SoftAutoCommitTest_1CE1D579B8F796DC-001/init-core-data-001/]
   [junit4]   2> 583130 INFO  (TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeRapidAdds-seed#[1CE1D579B8F796DC]) [    x:collection1] o.a.s.c.JmxMonitoredMap JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@5b7d090b
   [junit4]   2> 583131 INFO  (TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeRapidAdds-seed#[1CE1D579B8F796DC]) [    x:collection1] o.a.s.c.SolrCore New index directory detected: old=null new=/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-5.5-Java8/solr/build/solr-core/test/J1/temp/solr.update.SoftAutoCommitTest_1CE1D579B8F796DC-001/init-core-data-001/index/
   [junit4]   2> 583133 INFO  (OldIndexDirectoryCleanupThreadForCore-collection1) [    x:collection1] o.a.s.c.SolrCore Looking for old index directories to cleanup for core collection1 in /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-5.5-Java8/solr/build/solr-core/test/J1/temp/solr.update.SoftAutoCommitTest_1CE1D579B8F796DC-001/init-core-data-001/
   [junit4]   2> 583166 INFO  (TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeRapidAdds-seed#[1CE1D579B8F796DC]) [    x:collection1] o.a.s.u.p.UpdateRequestProcessorChain creating updateRequestProcessorChain "dedupe"
   [junit4]   2> 583166 INFO  (TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeRapidAdds-seed#[1CE1D579B8F796DC]) [    x:collection1] o.a.s.u.p.UpdateRequestProcessorChain inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
   [junit4]   2> 583166 INFO  (TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeRapidAdds-seed#[1CE1D579B8F796DC]) [    x:collection1] o.a.s.u.p.UpdateRequestProcessorChain creating updateRequestProcessorChain "dedupe-allfields"
   [junit4]   2> 583166 INFO  (TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeRapidAdds-seed#[1CE1D579B8F796DC]) [    x:collection1] o.a.s.u.p.UpdateRequestProcessorChain inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe-allfields"
   [junit4]   2> 583166 INFO  (TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeRapidAdds-seed#[1CE1D579B8F796DC]) [    x:collection1] o.a.s.u.p.UpdateRequestProcessorChain creating updateRequestProcessorChain "stored_sig"
   [junit4]   2> 583166 INFO  (TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeRapidAdds-seed#[1CE1D579B8F796DC]) [    x:collection1] o.a.s.u.p.UpdateRequestProcessorChain inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
   [junit4]   2> 583167 INFO  (TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeRapidAdds-seed#[1CE1D579B8F796DC]) [    x:collection1] o.a.s.u.p.UpdateRequestProcessorChain creating updateRequestProcessorChain "uniq-fields"
   [junit4]   2> 583167 INFO  (TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeRapidAdds-seed#[1CE1D579B8F796DC]) [    x:collection1] o.a.s.u.p.UpdateRequestProcessorChain inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "uniq-fields"
   [junit4]   2> 583167 INFO  (TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeRapidAdds-seed#[1CE1D579B8F796DC]) [    x:collection1] o.a.s.u.p.UpdateRequestProcessorChain creating updateRequestProcessorChain "distrib-dup-test-chain-explicit"
   [junit4]   2> 583167 INFO  (TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeRapidAdds-seed#[1CE1D579B8F796DC]) [    x:collection1] o.a.s.u.p.UpdateRequestProcessorChain creating updateRequestProcessorChain "distrib-dup-test-chain-implicit"
   [junit4]   2> 583167 INFO  (TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeRapidAdds-seed#[1CE1D579B8F796DC]) [    x:collection1] o.a.s.u.p.UpdateRequestProcessorChain inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
   [junit4]   2> 583167 INFO  (TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeRapidAdds-seed#[1CE1D579B8F796DC]) [    x:collection1] o.a.s.c.SolrCore no updateRequestProcessorChain defined as default, creating implicit default
   [junit4]   2> 583189 INFO  (TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeRapidAdds-seed#[1CE1D579B8F796DC]) [    x:collection1] o.a.s.h.l.XMLLoader xsltCacheLifetimeSeconds=60
   [junit4]   2> 583190 INFO  (TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeRapidAdds-seed#[1CE1D579B8F796DC]) [    x:collection1] o.a.s.h.l.XMLLoader xsltCacheLifetimeSeconds=60
   [junit4]   2> 583191 INFO  (TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeRapidAdds-seed#[1CE1D579B8F796DC]) [    x:collection1] o.a.s.h.l.XMLLoader xsltCacheLifetimeSeconds=60
   [junit4]   2> 583196 INFO  (TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeRapidAdds-seed#[1CE1D579B8F796DC]) [    x:collection1] o.a.s.h.l.XMLLoader xsltCacheLifetimeSeconds=60
   [junit4]   2> 583205 INFO  (TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeRapidAdds-seed#[1CE1D579B8F796DC]) [    x:collection1] o.a.s.c.PluginBag requestHandler : 'lazy' created with startup=lazy 
   [junit4]   2> 583206 INFO  (TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeRapidAdds-seed#[1CE1D579B8F796DC]) [    x:collection1] o.a.s.c.RequestHandlers Registered paths: /admin/mbeans,standard,spellCheckCompRH,lazy,/update/json/docs,/admin/luke,spellCheckWithWordbreak_Direct,tvrh,/get,/admin/properties,/update/json,mltrh,/admin/threads,/search-facet-def,/update/csv,/search-facet-invariants,/admin/segments,spellCheckCompRH1,/mlt,/admin/system,/replication,dismax,defaults,/config,/schema,/admin/plugins,/admin/logging,spellCheckWithWordbreak,mock,/admin/ping,/update,/admin/file,/terms,spellCheckCompRH_Direct,/debug/dump
   [junit4]   2> 583207 WARN  (TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeRapidAdds-seed#[1CE1D579B8F796DC]) [    x:collection1] o.a.s.c.SolrCore solrconfig.xml uses deprecated <admin/gettableFiles>, Please update your config to use the ShowFileRequestHandler.
   [junit4]   2> 583207 INFO  (TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeRapidAdds-seed#[1CE1D579B8F796DC]) [    x:collection1] o.a.s.c.SolrCore Using default statsCache cache: org.apache.solr.search.stats.LocalStatsCache
   [junit4]   2> 583216 INFO  (TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeRapidAdds-seed#[1CE1D579B8F796DC]) [    x:collection1] o.a.s.u.CommitTracker Hard AutoCommit: disabled
   [junit4]   2> 583216 INFO  (TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeRapidAdds-seed#[1CE1D579B8F796DC]) [    x:collection1] o.a.s.u.CommitTracker Soft AutoCommit: disabled
   [junit4]   2> 583223 INFO  (TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeRapidAdds-seed#[1CE1D579B8F796DC]) [    x:collection1] o.a.s.s.SolrIndexSearcher Opening Searcher@68262080[collection1] main
   [junit4]   2> 583223 INFO  (TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeRapidAdds-seed#[1CE1D579B8F796DC]) [    x:collection1] o.a.s.r.RestManager Initializing RestManager with initArgs: {storageIO=org.apache.solr.rest.ManagedResourceStorage$InMemoryStorageIO}
   [junit4]   2> 583224 INFO  (TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeRapidAdds-seed#[1CE1D579B8F796DC]) [    x:collection1] o.a.s.r.ManagedResourceStorage Reading _rest_managed.json using InMemoryStorage
   [junit4]   2> 583224 INFO  (TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeRapidAdds-seed#[1CE1D579B8F796DC]) [    x:collection1] o.a.s.r.RestManager Initializing 0 registered ManagedResources
   [junit4]   2> 583224 INFO  (TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeRapidAdds-seed#[1CE1D579B8F796DC]) [    x:collection1] o.a.s.h.c.SpellCheckComponent Initializing spell checkers
   [junit4]   2> 583224 INFO  (TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeRapidAdds-seed#[1CE1D579B8F796DC]) [    x:collection1] o.a.s.s.DirectSolrSpellChecker init: {name=direct,classname=DirectSolrSpellChecker,field=lowerfilt,minQueryLength=3}
   [junit4]   2> 583226 INFO  (TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeRapidAdds-seed#[1CE1D579B8F796DC]) [    x:collection1] o.a.s.h.ReplicationHandler Commits will be reserved for  10000
   [junit4]   2> 583227 INFO  (TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeRapidAdds-seed#[1CE1D579B8F796DC]) [    x:collection1] o.a.s.u.UpdateLog Looking up max value of version field to seed version buckets
   [junit4]   2> 583227 INFO  (TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeRapidAdds-seed#[1CE1D579B8F796DC]) [    x:collection1] o.a.s.u.VersionInfo Refreshing highest value of _version_ for 65536 version buckets from index
   [junit4]   2> 583227 INFO  (TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeRapidAdds-seed#[1CE1D579B8F796DC]) [    x:collection1] o.a.s.u.VersionInfo No terms found for _version_, cannot seed version bucket highest value from index
   [junit4]   2> 583227 INFO  (TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeRapidAdds-seed#[1CE1D579B8F796DC]) [    x:collection1] o.a.s.u.UpdateLog Could not find max version in index or recent updates, using new clock 1532356285199024128
   [junit4]   2> 583229 INFO  (TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeRapidAdds-seed#[1CE1D579B8F796DC]) [    x:collection1] o.a.s.u.UpdateLog Took 1.0ms to seed version buckets with highest version 1532356285199024128
   [junit4]   2> 583229 INFO  (TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeRapidAdds-seed#[1CE1D579B8F796DC]) [    x:collection1] o.a.s.u.DefaultSolrCoreState Closing old IndexWriter... core=collection1
   [junit4]   2> 583242 INFO  (searcherExecutor-1011-thread-1-processing-x:collection1) [    x:collection1] o.a.s.h.c.SpellCheckComponent Loading spell index for spellchecker: default
   [junit4]   2> 583242 INFO  (searcherExecutor-1011-thread-1-processing-x:collection1) [    x:collection1] o.a.s.h.c.SpellCheckComponent Loading spell index for spellchecker: direct
   [junit4]   2> 583242 INFO  (searcherExecutor-1011-thread-1-processing-x:collection1) [    x:collection1] o.a.s.h.c.SpellCheckComponent Loading spell index for spellchecker: wordbreak
   [junit4]   2> 583243 INFO  (searcherExecutor-1011-thread-1-processing-x:collection1) [    x:collection1] o.a.s.h.c.SpellCheckComponent Loading spell index for spellchecker: multipleFields
   [junit4]   2> 583243 INFO  (searcherExecutor-1011-thread-1-processing-x:collection1) [    x:collection1] o.a.s.h.c.SpellCheckComponent Loading spell index for spellchecker: jarowinkler
   [junit4]   2> 583243 INFO  (searcherExecutor-1011-thread-1-processing-x:collection1) [    x:collection1] o.a.s.h.c.SpellCheckComponent Loading spell index for spellchecker: external
   [junit4]   2> 583243 INFO  (searcherExecutor-1011-thread-1-processing-x:collection1) [    x:collection1] o.a.s.h.c.SpellCheckComponent Loading spell index for spellchecker: freq
   [junit4]   2> 583243 INFO  (searcherExecutor-1011-thread-1-processing-x:collection1) [    x:collection1] o.a.s.h.c.SpellCheckComponent Loading spell index for spellchecker: fqcn
   [junit4]   2> 583243 INFO  (searcherExecutor-1011-thread-1-processing-x:collection1) [    x:collection1] o.a.s.h.c.SpellCheckComponent Loading spell index for spellchecker: perDict
   [junit4]   2> 583244 INFO  (searcherExecutor-1011-thread-1-processing-x:collection1) [    x:collection1] o.a.s.c.SolrCore [collection1] Registered new searcher Searcher@68262080[collection1] main{ExitableDirectoryReader(UninvertingDirectoryReader())}
   [junit4]   2> 583250 INFO  (TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeRapidAdds-seed#[1CE1D579B8F796DC]) [    x:collection1] o.a.s.u.RandomMergePolicy RandomMergePolicy wrapping class org.apache.lucene.index.LogDocMergePolicy: [LogDocMergePolicy: minMergeSize=1000, mergeFactor=14, maxMergeSize=9223372036854775807, maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=true, maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=1.0]
   [junit4]   2> 583251 INFO  (TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeRapidAdds-seed#[1CE1D579B8F796DC]) [    x:collection1] o.a.s.c.SolrDeletionPolicy SolrDeletionPolicy.onInit: commits: num=1
   [junit4]   2> 	commit{dir=MockDirectoryWrapper(RAMDirectory@7bd7ca07 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@546b13d6),segFN=segments_1,generation=1}
   [junit4]   2> 583251 INFO  (TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeRapidAdds-seed#[1CE1D579B8F796DC]) [    x:collection1] o.a.s.c.SolrDeletionPolicy newest commit generation = 1
   [junit4]   2> 583251 INFO  (TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeRapidAdds-seed#[1CE1D579B8F796DC]) [    x:collection1] o.a.s.u.DefaultSolrCoreState New IndexWriter is ready to be used.
   [junit4]   2> 583251 INFO  (TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeRapidAdds-seed#[1CE1D579B8F796DC]) [    x:collection1] o.a.s.s.SolrIndexSearcher Opening Searcher@4bcebcc3[collection1] main
   [junit4]   2> 583251 INFO  (TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeRapidAdds-seed#[1CE1D579B8F796DC]) [    x:collection1] o.a.s.c.CoreContainer replacing core: collection1
   [junit4]   2> 583251 INFO  (TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeRapidAdds-seed#[1CE1D579B8F796DC]) [    x:collection1] o.a.s.c.SolrCore [collection1]  CLOSING SolrCore org.apache.solr.core.SolrCore@6ebec18e
   [junit4]   2> 583251 INFO  (TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeRapidAdds-seed#[1CE1D579B8F796DC]) [    x:collection1] 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> 583252 INFO  (TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeRapidAdds-seed#[1CE1D579B8F796DC]) [    x:collection1] o.a.s.c.SolrCore [collection1] Closing main searcher on request.
   [junit4]   2> 583253 INFO  (searcherExecutor-1011-thread-1-processing-x:collection1) [    x:collection1] o.a.s.c.SolrCore [collection1] Registered new searcher Searcher@4bcebcc3[collection1] main{ExitableDirectoryReader(UninvertingDirectoryReader())}
   [junit4]   2> 583265 INFO  (TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeRapidAdds-seed#[1CE1D579B8F796DC]) [    x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=null path=null params={}{add=[5000 (1532356285236772864)]} 0 1
   [junit4]   2> 583266 INFO  (TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeRapidAdds-seed#[1CE1D579B8F796DC]) [    x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=null path=null params={}{add=[5001 (1532356285239918592)]} 0 0
   [junit4]   2> 583267 INFO  (TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeRapidAdds-seed#[1CE1D579B8F796DC]) [    x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=null path=null params={}{add=[5002 (1532356285240967168)]} 0 0
   [junit4]   2> 583268 INFO  (TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeRapidAdds-seed#[1CE1D579B8F796DC]) [    x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=null path=null params={}{add=[5003 (1532356285242015744)]} 0 0
   [junit4]   2> 583268 INFO  (TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeRapidAdds-seed#[1CE1D579B8F796DC]) [    x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=null path=null params={}{add=[5004 (1532356285242015745)]} 0 0
   [junit4]   2> 583269 INFO  (TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeRapidAdds-seed#[1CE1D579B8F796DC]) [    x:collection1] o.a.s.SolrTestCaseJ4 ###Ending testSoftAndHardCommitMaxTimeRapidAdds
   [junit4]   2> 583272 INFO  (TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeDelete-seed#[1CE1D579B8F796DC]) [    x:collection1] o.a.s.SolrTestCaseJ4 ###Starting testSoftAndHardCommitMaxTimeDelete
   [junit4]   2> 583272 INFO  (TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeDelete-seed#[1CE1D579B8F796DC]) [    x:collection1] o.a.s.c.SolrResourceLoader new SolrResourceLoader for directory: '/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-5.5-Java8/solr/core/src/test-files/solr/collection1'
   [junit4]   2> 583272 INFO  (TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeDelete-seed#[1CE1D579B8F796DC]) [    x:collection1] o.a.s.c.SolrResourceLoader JNDI not configured for solr (NoInitialContextEx)
   [junit4]   2> 583272 INFO  (TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeDelete-seed#[1CE1D579B8F796DC]) [    x:collection1] o.a.s.c.SolrResourceLoader using system property solr.solr.home: /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-5.5-Java8/solr/core/src/test-files/solr
   [junit4]   2> 583272 INFO  (TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeDelete-seed#[1CE1D579B8F796DC]) [    x:collection1] o.a.s.c.SolrResourceLoader Adding 'file:/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-5.5-Java8/solr/core/src/test-files/solr/collection1/lib/classes/' to classloader
   [junit4]   2> 583273 INFO  (TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeDelete-seed#[1CE1D579B8F796DC]) [    x:collection1] o.a.s.c.SolrResourceLoader Adding 'file:/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-5.5-Java8/solr/core/src/test-files/solr/collection1/lib/README' to classloader
   [junit4]   2> 583315 INFO  (TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeDelete-seed#[1CE1D579B8F796DC]) [    x:collection1] o.a.s.c.SolrConfig current version of requestparams : -1
   [junit4]   2> 583327 INFO  (TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeDelete-seed#[1CE1D579B8F796DC]) [    x:collection1] o.a.s.c.SolrConfig Using Lucene MatchVersion: 5.5.0
   [junit4]   2> 583360 INFO  (TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeDelete-seed#[1CE1D579B8F796DC]) [    x:collection1] o.a.s.c.SolrConfig Loaded SolrConfig: solrconfig.xml
   [junit4]   2> 583369 INFO  (TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeDelete-seed#[1CE1D579B8F796DC]) [    x:collection1] o.a.s.s.IndexSchema [collection1] Schema name=test
   [junit4]   2> 583731 INFO  (TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeDelete-seed#[1CE1D579B8F796DC]) [    x:collection1] o.a.s.s.OpenExchangeRatesOrgProvider Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
   [junit4]   2> 583778 INFO  (commitScheduler-1014-thread-1) [    x:collection1] o.a.s.u.DirectUpdateHandler2 start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=true,prepareCommit=false}
   [junit4]   2> 583812 INFO  (commitScheduler-1014-thread-1) [    x:collection1] o.a.s.s.SolrIndexSearcher Opening Searcher@b44d014[collection1] main
   [junit4]   2> 583813 INFO  (searcherExecutor-1011-thread-1-processing-x:collection1) [    x:collection1] o.a.s.c.SolrCore [collection1] Registered new searcher Searcher@b44d014[collection1] main{ExitableDirectoryReader(UninvertingDirectoryReader(Uninverting(_0(5.5.0):C5)))}
   [junit4]   2> 583813 INFO  (commitScheduler-1014-thread-1) [    x:collection1] o.a.s.u.DirectUpdateHandler2 end_commit_flush
   [junit4]   2> 583815 INFO  (TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeDelete-seed#[1CE1D579B8F796DC]) [    x:collection1] o.a.s.s.IndexSchema default search field in schema is text
   [junit4]   2> 583816 INFO  (TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeDelete-seed#[1CE1D579B8F796DC]) [    x:collection1] o.a.s.s.IndexSchema unique key field: id
   [junit4]   2> 583818 INFO  (TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeDelete-seed#[1CE1D579B8F796DC]) [    x:collection1] o.a.s.s.FileExchangeRateProvider Reloading exchange rates from file currency.xml
   [junit4]   2> 583827 INFO  (TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeDelete-seed#[1CE1D579B8F796DC]) [    x:collection1] o.a.s.s.FileExchangeRateProvider Reloading exchange rates from file currency.xml
   [junit4]   2> 583828 INFO  (TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeDelete-seed#[1CE1D579B8F796DC]) [    x:collection1] o.a.s.s.OpenExchangeRatesOrgProvider Reloading exchange rates from open-exchange-rates.json
   [junit4]   2> 583828 INFO  (TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeDelete-seed#[1CE1D579B8F796DC]) [    x:collection1] o.a.s.s.OpenExchangeRatesOrgProvider Reloading exchange rates from open-exchange-rates.json
   [junit4]   2> 583829 INFO  (TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeDelete-seed#[1CE1D579B8F796DC]) [    x:collection1] o.a.s.c.ConfigSetProperties Did not find ConfigSet properties, assuming default properties: Can't find resource 'configsetprops.json' in classpath or '/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-5.5-Java8/solr/core/src/test-files/solr/collection1'
   [junit4]   2> 583829 INFO  (TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeDelete-seed#[1CE1D579B8F796DC]) [    x:collection1] o.a.s.c.CoreContainer Reloading SolrCore 'collection1' using configuration from instancedir /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-5.5-Java8/solr/core/src/test-files/solr/collection1
   [junit4]   2> 583838 INFO  (TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeDelete-seed#[1CE1D579B8F796DC]) [    x:collection1] o.a.s.c.SolrCore [[collection1] ] Opening new SolrCore at [/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-5.5-Java8/solr/core/src/test-files/solr/collection1], dataDir=[/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-5.5-Java8/solr/build/solr-core/test/J1/temp/solr.update.SoftAutoCommitTest_1CE1D579B8F796DC-001/init-core-data-001/]
   [junit4]   2> 583838 INFO  (TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeDelete-seed#[1CE1D579B8F796DC]) [    x:collection1] o.a.s.c.JmxMonitoredMap JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@5b7d090b
   [junit4]   2> 583838 INFO  (TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeDelete-seed#[1CE1D579B8F796DC]) [    x:collection1] o.a.s.c.SolrCore New index directory detected: old=null new=/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-5.5-Java8/solr/build/solr-core/test/J1/temp/solr.update.SoftAutoCommitTest_1CE1D579B8F796DC-001/init-core-data-001/index/
   [junit4]   2> 583844 INFO  (TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeDelete-seed#[1CE1D579B8F796DC]) [    x:collection1] o.a.s.u.p.UpdateRequestProcessorChain creating updateRequestProcessorChain "dedupe"
   [junit4]   2> 583845 INFO  (TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeDelete-seed#[1CE1D579B8F796DC]) [    x:collection1] o.a.s.u.p.UpdateRequestProcessorChain inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
   [junit4]   2> 583845 INFO  (TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeDelete-seed#[1CE1D579B8F796DC]) [    x:collection1] o.a.s.u.p.UpdateRequestProcessorChain creating updateRequestProcessorChain "dedupe-allfields"
   [junit4]   2> 583845 INFO  (TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeDelete-seed#[1CE1D579B8F796DC]) [    x:collection1] o.a.s.u.p.UpdateRequestProcessorChain inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe-allfields"
   [junit4]   2> 583845 INFO  (TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeDelete-seed#[1CE1D579B8F796DC]) [    x:collection1] o.a.s.u.p.UpdateRequestProcessorChain creating updateRequestProcessorChain "stored_sig"
   [junit4]   2> 583845 INFO  (TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeDelete-seed#[1CE1D579B8F796DC]) [    x:collection1] o.a.s.u.p.UpdateRequestProcessorChain inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
   [junit4]   2> 583845 INFO  (TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeDelete-seed#[1CE1D579B8F796DC]) [    x:collection1] o.a.s.u.p.UpdateRequestProcessorChain creating updateRequestProcessorChain "uniq-fields"
   [junit4]   2> 583845 INFO  (TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeDelete-seed#[1CE1D579B8F796DC]) [    x:collection1] o.a.s.u.p.UpdateRequestProcessorChain inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "uniq-fields"
   [junit4]   2> 583845 INFO  (TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeDelete-seed#[1CE1D579B8F796DC]) [    x:collection1] o.a.s.u.p.UpdateRequestProcessorChain creating updateRequestProcessorChain "distrib-dup-test-chain-explicit"
   [junit4]   2> 583845 INFO  (TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeDelete-seed#[1CE1D579B8F796DC]) [    x:collection1] o.a.s.u.p.UpdateRequestProcessorChain creating updateRequestProcessorChain "distrib-dup-test-chain-implicit"
   [junit4]   2> 583845 INFO  (TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeDelete-seed#[1CE1D579B8F796DC]) [    x:collection1] o.a.s.u.p.UpdateRequestProcessorChain inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
   [junit4]   2> 583845 INFO  (TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeDelete-seed#[1CE1D579B8F796DC]) [    x:collection1] o.a.s.c.SolrCore no updateRequestProcessorChain defined as default, creating implicit default
   [junit4]   2> 583846 INFO  (OldIndexDirectoryCleanupThreadForCore-collection1) [    x:collection1] o.a.s.c.SolrCore Looking for old index directories to cleanup for core collection1 in /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-5.5-Java8/solr/build/solr-core/test/J1/temp/solr.update.SoftAutoCommitTest_1CE1D579B8F796DC-001/init-core-data-001/
   [junit4]   2> 583853 INFO  (TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeDelete-seed#[1CE1D579B8F796DC]) [    x:collection1] o.a.s.h.l.XMLLoader xsltCacheLifetimeSeconds=60
   [junit4]   2> 583854 INFO  (TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeDelete-seed#[1CE1D579B8F796DC]) [    x:collection1] o.a.s.h.l.XMLLoader xsltCacheLifetimeSeconds=60
   [junit4]   2> 583854 INFO  (TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeDelete-seed#[1CE1D579B8F796DC]) [    x:collection1] o.a.s.h.l.XMLLoader xsltCacheLifetimeSeconds=60
   [junit4]   2> 583855 INFO  (TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeDelete-seed#[1CE1D579B8F796DC]) [    x:collection1] o.a.s.h.l.XMLLoader xsltCacheLifetimeSeconds=60
   [junit4]   2> 583869 INFO  (TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeDelete-seed#[1CE1D579B8F796DC]) [    x:collection1] o.a.s.c.PluginBag requestHandler : 'lazy' created with startup=lazy 
   [junit4]   2> 583870 INFO  (TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeDelete-seed#[1CE1D579B8F796DC]) [    x:collection1] o.a.s.c.RequestHandlers Registered paths: /admin/mbeans,standard,spellCheckCompRH,lazy,/update/json/docs,/admin/luke,spellCheckWithWordbreak_Direct,tvrh,/get,/admin/properties,/update/json,mltrh,/admin/threads,/search-facet-def,/update/csv,/search-facet-invariants,/admin/segments,spellCheckCompRH1,/mlt,/admin/system,/replication,dismax,defaults,/config,/schema,/admin/plugins,/admin/logging,spellCheckWithWordbreak,mock,/admin/ping,/update,/admin/file,/terms,spellCheckCompRH_Direct,/debug/dump
   [junit4]   2> 583870 WARN  (TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeDelete-seed#[1CE1D579B8F796DC]) [    x:collection1] o.a.s.c.SolrCore solrconfig.xml uses deprecated <admin/gettableFiles>, Please update your config to use the ShowFileRequestHandler.
   [junit4]   2> 583871 INFO  (TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeDelete-seed#[1CE1D579B8F796DC]) [    x:collection1] o.a.s.c.SolrCore Using default statsCache cache: org.apache.solr.search.stats.LocalStatsCache
   [junit4]   2> 583875 INFO  (TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeDelete-seed#[1CE1D579B8F796DC]) [    x:collection1] o.a.s.u.CommitTracker Hard AutoCommit: disabled
   [junit4]   2> 583875 INFO  (TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeDelete-seed#[1CE1D579B8F796DC]) [    x:collection1] o.a.s.u.CommitTracker Soft AutoCommit: disabled
   [junit4]   2> 583883 INFO  (TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeDelete-seed#[1CE1D579B8F796DC]) [    x:collection1] o.a.s.s.SolrIndexSearcher Opening Searcher@3dcff18d[collection1] main
   [junit4]   2> 583883 INFO  (TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeDelete-seed#[1CE1D579B8F796DC]) [    x:collection1] o.a.s.r.RestManager Initializing RestManager with initArgs: {storageIO=org.apache.solr.rest.ManagedResourceStorage$InMemoryStorageIO}
   [junit4]   2> 583883 INFO  (TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeDelete-seed#[1CE1D579B8F796DC]) [    x:collection1] o.a.s.r.ManagedResourceStorage Reading _rest_managed.json using InMemoryStorage
   [junit4]   2> 583883 INFO  (TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeDelete-seed#[1CE1D579B8F796DC]) [    x:collection1] o.a.s.r.RestManager Initializing 0 registered ManagedResources
   [junit4]   2> 583883 INFO  (TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeDelete-seed#[1CE1D579B8F796DC]) [    x:collection1] o.a.s.h.c.SpellCheckComponent Initializing spell checkers
   [junit4]   2> 583884 INFO  (TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeDelete-seed#[1CE1D579B8F796DC]) [    x:collection1] o.a.s.s.DirectSolrSpellChecker init: {name=direct,classname=DirectSolrSpellChecker,field=lowerfilt,minQueryLength=3}
   [junit4]   2> 583887 INFO  (TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeDelete-seed#[1CE1D579B8F796DC]) [    x:collection1] o.a.s.h.ReplicationHandler Commits will be reserved for  10000
   [junit4]   2> 583889 INFO  (TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeDelete-seed#[1CE1D579B8F796DC]) [    x:collection1] o.a.s.u.UpdateLog Looking up max value of version field to seed version buckets
   [junit4]   2> 583889 INFO  (TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeDelete-seed#[1CE1D579B8F796DC]) [    x:collection1] o.a.s.u.VersionInfo Refreshing highest value of _version_ for 65536 version buckets from index
   [junit4]   2> 583891 INFO  (TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeDelete-seed#[1CE1D579B8F796DC]) [    x:collection1] o.a.s.u.VersionInfo Found MAX value 1532356285242015745 from Terms for _version_ in index
   [junit4]   2> 583893 INFO  (TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeDelete-seed#[1CE1D579B8F796DC]) [    x:collection1] o.a.s.u.UpdateLog Took 3.0ms to seed version buckets with highest version 1532356285242015745
   [junit4]   2> 583893 INFO  (TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeDelete-seed#[1CE1D579B8F796DC]) [    x:collection1] o.a.s.u.DefaultSolrCoreState Closing old IndexWriter... core=collection1
   [junit4]   2> 583893 INFO  (searcherExecutor-1015-thread-1-processing-x:collection1) [    x:collection1] o.a.s.h.c.SpellCheckComponent Loading spell index for spellchecker: default
   [junit4]   2> 583893 INFO  (searcherExecutor-1015-thread-1-processing-x:collection1) [    x:collection1] o.a.s.h.c.SpellCheckComponent Loading spell index for spellchecker: direct
   [junit4]   2> 583893 INFO  (searcherExecutor-1015-thread-1-processing-x:collection1) [    x:collection1] o.a.s.h.c.SpellCheckComponent Loading spell index for spellchecker: wordbreak
   [junit4]   2> 583893 INFO  (searcherExecutor-1015-thread-1-processing-x:collection1) [    x:collection1] o.a.s.h.c.SpellCheckComponent Loading spell index for spellchecker: multipleFields
   [junit4]   2> 583893 INFO  (searcherExecutor-1015-thread-1-processing-x:collection1) [    x:collection1] o.a.s.h.c.SpellCheckComponent Loading spell index for spellchecker: jarowinkler
   [junit4]   2> 583894 INFO  (searcherExecutor-1015-thread-1-processing-x:collection1) [    x:collection1] o.a.s.h.c.SpellCheckComponent Loading spell index for spellchecker: external
   [junit4]   2> 583894 INFO  (searcherExecutor-1015-thread-1-processing-x:collection1) [    x:collection1] o.a.s.h.c.SpellCheckComponent Loading spell index for spellchecker: freq
   [junit4]   2> 583894 INFO  (searcherExecutor-1015-thread-1-processing-x:collection1) [    x:collection1] o.a.s.h.c.SpellCheckComponent Loading spell index for spellchecker: fqcn
   [junit4]   2> 583894 INFO  (searcherExecutor-1015-thread-1-processing-x:collection1) [    x:collection1] o.a.s.h.c.SpellCheckComponent Loading spell index for spellchecker: perDict
   [junit4]   2> 583895 INFO  (searcherExecutor-1015-thread-1-processing-x:collection1) [    x:collection1] o.a.s.c.SolrCore [collection1] Registered new searcher Searcher@3dcff18d[collection1] main{ExitableDirectoryReader(UninvertingDirectoryReader(Uninverting(_0(5.5.0):C5)))}
   [junit4]   2> 583903 INFO  (TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeDelete-seed#[1CE1D579B8F796DC]) [    x:collection1] o.a.s.c.SolrDeletionPolicy SolrDeletionPolicy.onCommit: commits: num=2
   [junit4]   2> 	commit{dir=MockDirectoryWrapper(RAMDirectory@7bd7ca07 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@546b13d6),segFN=segments_1,generation=1}
   [junit4]   2> 	commit{dir=MockDirectoryWrapper(RAMDirectory@7bd7ca07 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@546b13d6),segFN=segments_2,generation=2}
   [junit4]   2> 583903 INFO  (TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeDelete-seed#[1CE1D579B8F796DC]) [    x:collection1] o.a.s.c.SolrDeletionPolicy newest commit generation = 2
   [junit4]   2> 583904 INFO  (TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeDelete-seed#[1CE1D579B8F796DC]) [    x:collection1] o.a.s.u.RandomMergePolicy RandomMergePolicy wrapping class org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: maxMergeAtOnce=34, maxMergeAtOnceExplicit=13, maxMergedSegmentMB=80.1572265625, floorSegmentMB=1.9609375, forceMergeDeletesPctAllowed=23.35010565591937, segmentsPerTier=22.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=1.0
   [junit4]   2> 583918 INFO  (TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeDelete-seed#[1CE1D579B8F796DC]) [    x:collection1] o.a.s.c.SolrDeletionPolicy SolrDeletionPolicy.onInit: commits: num=1
   [junit4]   2> 	commit{dir=MockDirectoryWrapper(RAMDirectory@7bd7ca07 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@546b13d6),segFN=segments_2,generation=2}
   [junit4]   2> 583918 INFO  (TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeDelete-seed#[1CE1D579B8F796DC]) [    x:collection1] o.a.s.c.SolrDeletionPolicy newest commit generation = 2
   [junit4]   2> 583934 INFO  (TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeDelete-seed#[1CE1D579B8F796DC]) [    x:collection1] o.a.s.u.DefaultSolrCoreState New IndexWriter is ready to be used.
   [junit4]   2> 583939 INFO  (TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeDelete-seed#[1CE1D579B8F796DC]) [    x:collection1] o.a.s.s.SolrIndexSearcher Opening Searcher@368ace18[collection1] main
   [junit4]   2> 583939 INFO  (TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeDelete-seed#[1CE1D579B8F796DC]) [    x:collection1] o.a.s.c.CoreContainer replacing core: collection1
   [junit4]   2> 583939 INFO  (TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeDelete-seed#[1CE1D579B8F796DC]) [    x:collection1] o.a.s.c.SolrCore [collection1]  CLOSING SolrCore org.apache.solr.core.SolrCore@1f09fa16
   [junit4]   2> 583939 INFO  (TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeDelete-seed#[1CE1D579B8F796DC]) [    x:collection1] o.a.s.u.DirectUpdateHandler2 closing DirectUpdateHandler2{commits=1,autocommit maxTime=1200ms,autocommits=0,soft autocommit maxTime=500ms,soft autocommits=1,optimizes=0,rollbacks=0,expungeDeletes=0,docsPending=5,adds=0,deletesById=0,deletesByQuery=0,errors=0,cumulative_adds=5,cumulative_deletesById=0,cumulative_deletesByQuery=0,cumulative_errors=0,transaction_logs_total_size=0,transaction_logs_total_number=0}
   [junit4]   2> 583940 INFO  (searcherExecutor-1015-thread-1-processing-x:collection1) [    x:collection1] o.a.s.c.SolrCore [collection1] Registered new searcher Searcher@368ace18[collection1] main{ExitableDirectoryReader(UninvertingDirectoryReader(Uninverting(_0(5.5.0):C5)))}
   [junit4]   2> 583940 INFO  (TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeDelete-seed#[1CE1D579B8F796DC]) [    x:collection1] o.a.s.c.SolrCore [collection1] Closing main searcher on request.
   [junit4]   2> 583986 INFO  (TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeDelete-seed#[1CE1D579B8F796DC]) [    x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=null path=null params={}{add=[529 (1532356285970776064)]} 0 23
   [junit4]   2> 583987 INFO  (TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeDelete-seed#[1CE1D579B8F796DC]) [    x:collection1] o.a.s.u.DirectUpdateHandler2 start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
   [junit4]   2> 583998 INFO  (TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeDelete-seed#[1CE1D579B8F796DC]) [    x:collection1] o.a.s.c.SolrDeletionPolicy SolrDeletionPolicy.onCommit: commits: num=2
   [junit4]   2> 	commit{dir=MockDirectoryWrapper(RAMDirectory@7bd7ca07 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@546b13d6),segFN=segments_2,generation=2}
   [junit4]   2> 	commit{dir=MockDirectoryWrapper(RAMDirectory@7bd7ca07 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@546b13d6),segFN=segments_3,generation=3}
   [junit4]   2> 583998 INFO  (TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeDelete-seed#[1CE1D579B8F796DC]) [    x:collection1] o.a.s.c.SolrDeletionPolicy newest commit generation = 3
   [junit4]   2> 583998 INFO  (TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeDelete-seed#[1CE1D579B8F796DC]) [    x:collection1] o.a.s.s.SolrIndexSearcher Opening Searcher@2ea2e9ff[collection1] main
   [junit4]   2> 583999 INFO  (TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeDelete-seed#[1CE1D579B8F796DC]) [    x:collection1] o.a.s.u.DirectUpdateHandler2 end_commit_flush
   [junit4]   2> 584032 INFO  (searcherExecutor-1015-thread-1-processing-x:collection1) [    x:collection1] o.a.s.c.SolrCore [collection1] Registered new searcher Searcher@2ea2e9ff[collection1] main{ExitableDirectoryReader(UninvertingDirectoryReader(Uninverting(_0(5.5.0):C5) Uninverting(_1(5.5.0):C1)))}
   [junit4]   2> 584034 INFO  (TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeDelete-seed#[1CE1D579B8F796DC]) [    x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=null path=null params={}{commit=} 0 47
   [junit4]   2> 584035 INFO  (TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeDelete-seed#[1CE1D579B8F796DC]) [    x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=null path=null params={}{delete=[529 (-1532356286045224960)]} 0 0
   [junit4]   2> 584673 INFO  (commitScheduler-1018-thread-1) [    x:collection1] o.a.s.u.DirectUpdateHandler2 start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=true,prepareCommit=false}
   [junit4]   2> 584677 INFO  (commitScheduler-1018-thread-1) [    x:collection1] o.a.s.s.SolrIndexSearcher Opening Searcher@1e53f597[collection1] main
   [junit4]   2> 584678 INFO  (searcherExecutor-1015-thread-1-processing-x:collection1) [    x:collection1] o.a.s.c.SolrCore [collection1] Registered new searcher Searcher@1e53f597[collection1] main{ExitableDirectoryReader(UninvertingDirectoryReader(Uninverting(_0(5.5.0):C5)))}
   [junit4]   2> 584678 INFO  (commitScheduler-1018-thread-1) [    x:collection1] o.a.s.u.DirectUpdateHandler2 end_commit_flush
   [junit4]   2> 584684 INFO  (TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeDelete-seed#[1CE1D579B8F796DC]) [    x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=null path=null params={}{add=[550 (1532356286720507904)]} 0 5
   [junit4]   2> 585323 INFO  (commitScheduler-1018-thread-1) [    x:collection1] o.a.s.u.DirectUpdateHandler2 start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=true,prepareCommit=false}
   [junit4]   2> 585324 INFO  (commitScheduler-1017-thread-1) [    x:collection1] o.a.s.u.DirectUpdateHandler2 start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
   [junit4]   2> 585327 INFO  (commitScheduler-1018-thread-1) [    x:collection1] o.a.s.s.SolrIndexSearcher Opening Searcher@604541c6[collection1] main
   [junit4]   2> 585329 INFO  (searcherExecutor-1015-thread-1-processing-x:collection1) [    x:collection1] o.a.s.c.SolrCore [collection1] Registered new searcher Searcher@604541c6[collection1] main{ExitableDirectoryReader(UninvertingDirectoryReader(Uninverting(_0(5.5.0):C5) Uninverting(_2(5.5.0):C1)))}
   [junit4]   2> 585330 INFO  (commitScheduler-1017-thread-1) [    x:collection1] o.a.s.c.SolrDeletionPolicy SolrDeletionPolicy.onCommit: commits: num=2
   [junit4]   2> 	commit{dir=MockDirectoryWrapper(RAMDirectory@7bd7ca07 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@546b13d6),segFN=segments_3,generation=3}
   [junit4]   2> 	commit{dir=MockDirectoryWrapper(RAMDirectory@7bd7ca07 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@546b13d6),segFN=segments_4,generation=4}
   [junit4]   2> 585330 INFO  (commitScheduler-1017-thread-1) [    x:collection1] o.a.s.c.SolrDeletionPolicy newest commit generation = 4
   [junit4]   2> 585330 INFO  (commitScheduler-1017-thread-1) [    x:collection1] o.a.s.s.SolrIndexSearcher Opening Searcher@42515eef[collection1] main
   [junit4]   2> 585331 INFO  (searcherExecutor-1015-thread-1-processing-x:collection1) [    x:collection1] o.a.s.c.SolrCore [collection1] Registered new searcher Searcher@42515eef[collection1] main{ExitableDirectoryReader(UninvertingDirectoryReader(Uninverting(_0(5.5.0):C5) Uninverting(_2(5.5.0):C1)))}
   [junit4]   2> 585331 INFO  (commitScheduler-1017-thread-1) [    x:collection1] o.a.s.u.DirectUpdateHandler2 end_commit_flush
   [junit4]   2> 585331 INFO  (commitScheduler-1018-thread-1) [    x:collection1] o.a.s.u.DirectUpdateHandler2 end_commit_flush
   [junit4]   2> 587331 INFO  (TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeDelete-seed#[1CE1D579B8F796DC]) [    x:collection1] o.a.s.SolrTestCaseJ4 ###Ending testSoftAndHardCommitMaxTimeDelete
   [junit4]   2> NOTE: reproduce with: ant test  -Dtestcase=SoftAutoCommitTest -Dtests.method=testSoftAndHardCommitMaxTimeDelete -Dtests.seed=1CE1D579B8F796DC -Dtests.multiplier=2 -Dtests.slow=true -Dtests.locale=en -Dtests.timezone=Pacific/Honolulu -Dtests.asserts=true -Dtests.file.encoding=ISO-8859-1
   [junit4] FAILURE 4.07s J1 | SoftAutoCommitTest.testSoftAndHardCommitMaxTimeDelete <<<
   [junit4]    > Throwable #1: java.lang.AssertionError: Got a soft commit we weren't expecting
   [junit4]    > 	at __randomizedtesting.SeedInfo.seed([1CE1D579B8F796DC:DBAD6DE4A35F5B6C]:0)
   [junit4]    > 	at org.apache.solr.update.SoftAutoCommitTest.testSoftAndHardCommitMaxTimeDelete(SoftAutoCommitTest.java:287)
   [junit4]    > 	at java.lang.Thread.run(Thread.java:745)
   [junit4]   2> 587347 INFO  (TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeMixedAdds-seed#[1CE1D579B8F796DC]) [    x:collection1] o.a.s.SolrTestCaseJ4 ###Starting testSoftAndHardCommitMaxTimeMixedAdds
   [junit4]   2> 587347 INFO  (TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeMixedAdds-seed#[1CE1D579B8F796DC]) [    x:collection1] o.a.s.c.SolrResourceLoader new SolrResourceLoader for directory: '/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-5.5-Java8/solr/core/src/test-files/solr/collection1'
   [junit4]   2> 587347 INFO  (TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeMixedAdds-seed#[1CE1D579B8F796DC]) [    x:collection1] o.a.s.c.SolrResourceLoader JNDI not configured for solr (NoInitialContextEx)
   [junit4]   2> 587347 INFO  (TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeMixedAdds-seed#[1CE1D579B8F796DC]) [    x:collection1] o.a.s.c.SolrResourceLoader using system property solr.solr.home: /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-5.5-Java8/solr/core/src/test-files/solr
   [junit4]   2> 587348 INFO  (TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeMixedAdds-seed#[1CE1D579B8F796DC]) [    x:collection1] o.a.s.c.SolrResourceLoader Adding 'file:/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-5.5-Java8/solr/core/src/test-files/solr/collection1/lib/classes/' to classloader
   [junit4]   2> 587348 INFO  (TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeMixedAdds-seed#[1CE1D579B8F796DC]) [    x:collection1] o.a.s.c.SolrResourceLoader Adding 'file:/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-5.5-Java8/solr/core/src/test-files/solr/collection1/lib/README' to classloader
   [junit4]   2> 587385 INFO  (TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeMixedAdds-seed#[1CE1D579B8F796DC]) [    x:collection1] o.a.s.c.SolrConfig current version of requestparams : -1
   [junit4]   2> 587390 INFO  (TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeMixedAdds-seed#[1CE1D579B8F796DC]) [    x:collection1] o.a.s.c.SolrConfig Using Lucene MatchVersion: 5.5.0
   [junit4]   2> 587403 INFO  (TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeMixedAdds-seed#[1CE1D579B8F796DC]) [    x:collection1] o.a.s.c.SolrConfig Loaded SolrConfig: solrconfig.xml
   [junit4]   2> 587407 INFO  (TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeMixedAdds-seed#[1CE1D579B8F796DC]) [    x:collection1] o.a.s.s.IndexSchema [collection1] Schema name=test
   [junit4]   2> 587563 INFO  (TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeMixedAdds-seed#[1CE1D579B8F796DC]) [    x:collection1] o.a.s.s.OpenExchangeRatesOrgProvider Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
   [junit4]   2> 587577 INFO  (TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeMixedAdds-seed#[1CE1D579B8F796DC]) [    x:collection1] o.a.s.s.IndexSchema default search field in schema is text
   [junit4]   2> 587578 INFO  (TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeMixedAdds-seed#[1CE1D579B8F796DC]) [    x:collection1] o.a.s.s.IndexSchema unique key field: id
   [junit4]   2> 587580 INFO  (TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeMixedAdds-seed#[1CE1D579B8F796DC]) [    x:collection1] o.a.s.s.FileExchangeRateProvider Reloading exchange rates from file currency.xml
   [junit4]   2> 587582 INFO  (TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeMixedAdds-seed#[1CE1D579B8F796DC]) [    x:collection1] o.a.s.s.FileExchangeRateProvider Reloading exchange rates from file currency.xml
   [junit4]   2> 587591 INFO  (TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeMixedAdds-seed#[1CE1D579B8F796DC]) [    x:collection1] o.a.s.s.OpenExchangeRatesOrgProvider Reloading exchange rates from open-exchange-rates.json
   [junit4]   2> 587591 INFO  (TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeMixedAdds-seed#[1CE1D579B8F796DC]) [    x:collection1] o.a.s.s.OpenExchangeRatesOrgProvider Reloading exchange rates from open-exchange-rates.json
   [junit4]   2> 587592 INFO  (TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeMixedAdds-seed#[1CE1D579B8F796DC]) [    x:collection1] o.a.s.c.ConfigSetProperties Did not find ConfigSet properties, assuming default properties: Can't find resource 'configsetprops.json' in classpath or '/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-5.5-Java8/solr/core/src/test-files/solr/collection1'
   [junit4]   2> 587592 INFO  (TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeMixedAdds-seed#[1CE1D579B8F796DC]) [    x:collection1] o.a.s.c.CoreContainer Reloading SolrCore 'collection1' using configuration from instancedir /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-5.5-Java8/solr/core/src/test-files/solr/collection1
   [junit4]   2> 587593 INFO  (TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeMixedAdds-seed#[1CE1D579B8F796DC]) [    x:collection1] o.a.s.c.SolrCore [[collection1] ] Opening new SolrCore at [/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-5.5-Java8/solr/core/src/test-files/solr/collection1], dataDir=[/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-5.5-Java8/solr/build/solr-core/test/J1/temp/solr.update.SoftAutoCommitTest_1CE1D579B8F796DC-001/init-core-data-001/]
   [j

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

state from ZooKeeper... 
   [junit4]   2> 2458633 INFO  (TEST-ZkStateReaderTest.testStateFormatUpdateWithExplicitRefresh-seed#[1CE1D579B8F796DC]) [    ] o.a.s.c.c.ZkStateReader addZkWatch [c1]
   [junit4]   2> 2458633 INFO  (TEST-ZkStateReaderTest.testStateFormatUpdateWithExplicitRefresh-seed#[1CE1D579B8F796DC]) [    ] o.a.s.c.c.ZkStateReader Deleting data for [c1]
   [junit4]   2> 2458633 INFO  (TEST-ZkStateReaderTest.testStateFormatUpdateWithExplicitRefresh-seed#[1CE1D579B8F796DC]) [    ] o.a.s.c.c.SolrZkClient makePath: /collections/c1
   [junit4]   2> 2458635 INFO  (TEST-ZkStateReaderTest.testStateFormatUpdateWithExplicitRefresh-seed#[1CE1D579B8F796DC]) [    ] o.a.s.c.o.ZkStateWriter going to create_collection /collections/c1/state.json
   [junit4]   2> 2458636 INFO  (zkCallback-2205-thread-1) [    ] o.a.s.c.c.ZkStateReader A collections change: [WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/collections], has occurred - updating...
   [junit4]   2> 2458636 INFO  (zkCallback-2205-thread-2) [    ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json], has occurred - updating... (live nodes size: [0])
   [junit4]   2> 2458636 INFO  (zkCallback-2205-thread-3) [    ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeCreated path:/collections/c1/state.json] for collection [c1] has occurred - updating... (live nodes size: [0])
   [junit4]   2> 2460275 WARN  (zkCallback-2205-thread-1) [    ] o.a.s.c.c.ZkStateReader ZooKeeper watch triggered, but Solr cannot talk to ZK: [KeeperErrorCode = Session expired for /collections]
   [junit4]   2> 2460275 WARN  (zkCallback-2205-thread-3) [    ] o.a.s.c.c.ZkStateReader ZooKeeper watch triggered, but Solr cannot talk to ZK: [KeeperErrorCode = Session expired for /collections/c1/state.json]
   [junit4]   2> 2460275 WARN  (zkCallback-2205-thread-2) [    ] o.a.s.c.c.ZkStateReader ZooKeeper watch triggered, but Solr cannot talk to ZK: [KeeperErrorCode = Session expired for /clusterstate.json]
   [junit4]   2> 2460287 INFO  (TEST-ZkStateReaderTest.testStateFormatUpdateWithExplicitRefresh-seed#[1CE1D579B8F796DC]) [    ] o.a.s.c.ZkTestServer connecting to 127.0.0.1:37517 37517
   [junit4]   2> 2460419 INFO  (Thread-5640) [    ] o.a.s.c.ZkTestServer connecting to 127.0.0.1:37517 37517
   [junit4]   2> 2460420 INFO  (TEST-ZkStateReaderTest.testStateFormatUpdateWithExplicitRefresh-seed#[1CE1D579B8F796DC]) [    ] o.a.s.SolrTestCaseJ4 ###Ending testStateFormatUpdateWithExplicitRefresh
   [junit4]   2> NOTE: reproduce with: ant test  -Dtestcase=ZkStateReaderTest -Dtests.method=testStateFormatUpdateWithExplicitRefresh -Dtests.seed=1CE1D579B8F796DC -Dtests.multiplier=2 -Dtests.slow=true -Dtests.locale=pt-PT -Dtests.timezone=America/Cancun -Dtests.asserts=true -Dtests.file.encoding=ISO-8859-1
   [junit4] ERROR   2.09s J1 | ZkStateReaderTest.testStateFormatUpdateWithExplicitRefresh <<<
   [junit4]    > Throwable #1: org.apache.solr.common.SolrException: Could not find collection : c1
   [junit4]    > 	at __randomizedtesting.SeedInfo.seed([1CE1D579B8F796DC:35BA48E68975019]:0)
   [junit4]    > 	at org.apache.solr.common.cloud.ClusterState.getCollection(ClusterState.java:170)
   [junit4]    > 	at org.apache.solr.cloud.overseer.ZkStateReaderTest.testStateFormatUpdate(ZkStateReaderTest.java:136)
   [junit4]    > 	at org.apache.solr.cloud.overseer.ZkStateReaderTest.testStateFormatUpdateWithExplicitRefresh(ZkStateReaderTest.java:42)
   [junit4]    > 	at java.lang.Thread.run(Thread.java:745)
   [junit4]   2> 2460421 INFO  (SUITE-ZkStateReaderTest-seed#[1CE1D579B8F796DC]-worker) [    ] o.a.s.SolrTestCaseJ4 ###deleteCore
   [junit4]   2> NOTE: leaving temporary files on disk at: /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-5.5-Java8/solr/build/solr-core/test/J1/temp/solr.cloud.overseer.ZkStateReaderTest_1CE1D579B8F796DC-001
   [junit4]   2> Apr 23, 2016 12:18:29 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(Lucene54): {}, docValues:{}, sim=DefaultSimilarity, locale=pt-PT, timezone=America/Cancun
   [junit4]   2> NOTE: Linux 3.13.0-52-generic amd64/Oracle Corporation 1.8.0_74 (64-bit)/cpus=4,threads=1,free=230324144,total=522190848
   [junit4]   2> NOTE: All tests run in this JVM: [TestPerFieldSimilarityWithDefaultOverride, TestCursorMarkWithoutUniqueKey, OverseerRolesTest, TestSearcherReuse, TestDocumentBuilder, SaslZkACLProviderTest, TestHashPartitioner, LeaderInitiatedRecoveryOnShardRestartTest, TestSolrDeletionPolicy2, TestConfigOverlay, TestLFUCache, SpatialFilterTest, UpdateRequestProcessorFactoryTest, SimplePostToolTest, TestJsonRequest, SpellPossibilityIteratorTest, SortByFunctionTest, SpellCheckCollatorTest, AliasIntegrationTest, SpellCheckComponentTest, TestSolrConfigHandlerConcurrent, HighlighterTest, ConvertedLegacyTest, CollectionsAPIDistributedZkTest, DistanceFunctionTest, TestPartialUpdateDeduplication, DistribCursorPagingTest, TestMiniSolrCloudClusterSSL, BlockJoinFacetSimpleTest, TestSerializedLuceneMatchVersion, CursorMarkTest, SoftAutoCommitTest, RecoveryAfterSoftCommitTest, TestAnalyzeInfixSuggestions, TestManagedSchemaAPI, CloudExitableDirectoryReaderTest, RulesTest, MoreLikeThisHandlerTest, TestReqParamsAPI, TestStressVersions, TestDistribIDF, TestCloudInspectUtil, TestAuthorizationFramework, DocumentBuilderTest, TestUseDocValuesAsStored2, ExitableDirectoryReaderTest, HdfsWriteToMultipleCollectionsTest, DistributedTermsComponentTest, TestFreeTextSuggestions, OpenExchangeRatesOrgProviderTest, MinimalSchemaTest, TestFastLRUCache, ShardRoutingTest, TestSolr4Spatial2, TestExclusionRuleCollectionAccess, DistributedMLTComponentTest, CollectionTooManyReplicasTest, TestTrie, BitVectorTest, TestUniqueKeyFieldResource, UniqFieldsUpdateProcessorFactoryTest, HdfsLockFactoryTest, TestTrieFacet, TestMiniSolrCloudCluster, TestTestInjection, TestDFRSimilarityFactory, DistributedFacetPivotLargeTest, SpatialHeatmapFacetsTest, TestBulkSchemaAPI, SolrCmdDistributorTest, TestDistributedStatsComponentCardinality, TestRequestStatusCollectionAPI, BasicFunctionalityTest, FastVectorHighlighterTest, TestLRUStatsCache, TestEmbeddedSolrServerConstructors, TestQuerySenderListener, MultiTermTest, TestBlobHandler, TestDistributedGrouping, BJQParserTest, DataDrivenBlockJoinTest, TestMaxScoreQueryParser, TestInfoStreamLogging, TestCryptoKeys, TimeZoneUtilsTest, OpenCloseCoreStressTest, TestMinMaxOnMultiValuedField, OutOfBoxZkACLAndCredentialsProvidersTest, MBeansHandlerTest, TestTrackingShardHandlerFactory, DistributedSpellCheckComponentTest, ZkControllerTest, TestReload, HardAutoCommitTest, BadIndexSchemaTest, TestFiltering, SolrIndexSplitterTest, SuggesterFSTTest, DocValuesTest, SuggesterTSTTest, TestStressLucene, NoCacheHeaderTest, SchemaVersionSpecificBehaviorTest, FieldMutatingUpdateProcessorTest, QueryEqualityTest, TestRemoteStreaming, DocValuesMultiTest, TestSolrDeletionPolicy1, DebugComponentTest, IndexBasedSpellCheckerTest, LukeRequestHandlerTest, TestQueryTypes, RequestHandlersTest, TermVectorComponentTest, RequiredFieldsTest, IndexSchemaRuntimeFieldTest, SolrPluginUtilsTest, TestCollationField, TestCSVResponseWriter, TestAnalyzedSuggestions, BinaryUpdateRequestHandlerTest, CSVRequestHandlerTest, TestComponentsName, TestBinaryResponseWriter, UpdateParamsTest, AlternateDirectoryTest, TestQuerySenderNoQuery, ResponseLogComponentTest, SolrIndexConfigTest, TestDocSet, TestBinaryField, NumericFieldsTest, TestConfig, OutputWriterTest, TestSolrCoreProperties, DirectSolrConnectionTest, NotRequiredUniqueKeyTest, TestPhraseSuggestions, TestCodecSupport, TestXIncludeConfig, EchoParamsTest, TestLMJelinekMercerSimilarityFactory, TestFastWriter, PluginInfoTest, ChaosMonkeyNothingIsSafeTest, TestCrossCoreJoin, TestSimpleTrackingShardHandler, TestTolerantSearch, ConnectionReuseTest, CleanupOldIndexTest, ConfigSetsAPITest, DeleteInactiveReplicaTest, DeleteReplicaTest, DistributedQueueTest, DistributedVersionInfoTest, LeaderFailoverAfterPartitionTest, MigrateRouteKeyTest, TestCollectionAPI, TestLeaderInitiatedRecoveryThread, TestRequestForwarding, TestSolrCloudWithKerberosAlt, VMParamsZkACLAndCredentialsProvidersTest, HdfsBasicDistributedZk2Test, HdfsBasicDistributedZkTest, HdfsChaosMonkeySafeLeaderTest, HdfsRecoverLeaseTest, TestClusterStateMutator, ZkStateReaderTest]
   [junit4] Completed [462/571 (3!)] on J1 in 6.42s, 6 tests, 1 error <<< FAILURES!

[...truncated 356 lines...]
BUILD FAILED
/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-5.5-Java8/build.xml:750: The following error occurred while executing this line:
/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-5.5-Java8/build.xml:694: The following error occurred while executing this line:
/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-5.5-Java8/build.xml:59: The following error occurred while executing this line:
/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-5.5-Java8/solr/build.xml:233: The following error occurred while executing this line:
/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-5.5-Java8/solr/common-build.xml:534: The following error occurred while executing this line:
/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-5.5-Java8/lucene/common-build.xml:1477: The following error occurred while executing this line:
/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-5.5-Java8/lucene/common-build.xml:1033: There were test failures: 571 suites (7 ignored), 2289 tests, 2 errors, 1 failure, 55 ignored (39 assumptions) [seed: 1CE1D579B8F796DC]

Total time: 88 minutes 11 seconds
Build step 'Invoke Ant' marked build as failure
Archiving artifacts
No prior successful build to compare, so performing full copy of artifacts
Recording test results
Email was triggered for: Failure - Any
Sending email for trigger: Failure - Any