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 2018/06/29 04:08:39 UTC

[JENKINS] Lucene-Solr-NightlyTests-master - Build # 1574 - Still Unstable

Build: https://builds.apache.org/job/Lucene-Solr-NightlyTests-master/1574/

1 tests failed.
FAILED:  org.apache.solr.update.SoftAutoCommitTest.testHardCommitWithinAndSoftCommitMaxTimeMixedAdds

Error Message:
Tracker reports too many soft commits expected:<1> but was:<2>

Stack Trace:
java.lang.AssertionError: Tracker reports too many soft commits expected:<1> but was:<2>
	at __randomizedtesting.SeedInfo.seed([221449B83BEEB73D:E1F395A90AD26040]:0)
	at org.junit.Assert.fail(Assert.java:93)
	at org.junit.Assert.failNotEquals(Assert.java:647)
	at org.junit.Assert.assertEquals(Assert.java:128)
	at org.junit.Assert.assertEquals(Assert.java:472)
	at org.apache.solr.update.SoftAutoCommitTest.doTestSoftAndHardCommitMaxTimeMixedAdds(SoftAutoCommitTest.java:273)
	at org.apache.solr.update.SoftAutoCommitTest.testHardCommitWithinAndSoftCommitMaxTimeMixedAdds(SoftAutoCommitTest.java:174)
	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:1737)
	at com.carrotsearch.randomizedtesting.RandomizedRunner$8.evaluate(RandomizedRunner.java:934)
	at com.carrotsearch.randomizedtesting.RandomizedRunner$9.evaluate(RandomizedRunner.java:970)
	at com.carrotsearch.randomizedtesting.RandomizedRunner$10.evaluate(RandomizedRunner.java:984)
	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:368)
	at com.carrotsearch.randomizedtesting.ThreadLeakControl.forkTimeoutingTask(ThreadLeakControl.java:817)
	at com.carrotsearch.randomizedtesting.ThreadLeakControl$3.evaluate(ThreadLeakControl.java:468)
	at com.carrotsearch.randomizedtesting.RandomizedRunner.runSingleTest(RandomizedRunner.java:943)
	at com.carrotsearch.randomizedtesting.RandomizedRunner$5.evaluate(RandomizedRunner.java:829)
	at com.carrotsearch.randomizedtesting.RandomizedRunner$6.evaluate(RandomizedRunner.java:879)
	at com.carrotsearch.randomizedtesting.RandomizedRunner$7.evaluate(RandomizedRunner.java:890)
	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:368)
	at java.lang.Thread.run(Thread.java:748)




Build Log:
[...truncated 13166 lines...]
   [junit4] Suite: org.apache.solr.update.SoftAutoCommitTest
   [junit4]   2> Creating dataDir: /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-master/checkout/solr/build/solr-core/test/J2/temp/solr.update.SoftAutoCommitTest_221449B83BEEB73D-001/init-core-data-001
   [junit4]   2> 186297 INFO  (SUITE-SoftAutoCommitTest-seed#[221449B83BEEB73D]-worker) [    ] o.a.s.SolrTestCaseJ4 Using PointFields (NUMERIC_POINTS_SYSPROP=true) w/NUMERIC_DOCVALUES_SYSPROP=false
   [junit4]   2> 186309 INFO  (SUITE-SoftAutoCommitTest-seed#[221449B83BEEB73D]-worker) [    ] o.a.s.SolrTestCaseJ4 Randomized ssl (true) and clientAuth (true) via: @org.apache.solr.util.RandomizeSSL(reason=, value=NaN, ssl=NaN, clientAuth=NaN)
   [junit4]   2> 186310 INFO  (SUITE-SoftAutoCommitTest-seed#[221449B83BEEB73D]-worker) [    ] o.a.s.SolrTestCaseJ4 SecureRandom sanity checks: test.solr.allowed.securerandom=null & java.security.egd=file:/dev/./urandom
   [junit4]   2> 186311 INFO  (SUITE-SoftAutoCommitTest-seed#[221449B83BEEB73D]-worker) [    ] o.a.s.SolrTestCaseJ4 ####initCore
   [junit4]   2> 186311 INFO  (SUITE-SoftAutoCommitTest-seed#[221449B83BEEB73D]-worker) [    ] o.a.s.c.SolrResourceLoader [null] Added 2 libs to classloader, from paths: [/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-master/checkout/solr/core/src/test-files/solr/collection1/lib, /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-master/checkout/solr/core/src/test-files/solr/collection1/lib/classes]
   [junit4]   2> 186622 INFO  (SUITE-SoftAutoCommitTest-seed#[221449B83BEEB73D]-worker) [    ] o.a.s.c.SolrConfig Using Lucene MatchVersion: 8.0.0
   [junit4]   2> 186682 INFO  (SUITE-SoftAutoCommitTest-seed#[221449B83BEEB73D]-worker) [    ] o.a.s.s.IndexSchema [null] Schema name=test
   [junit4]   2> 187411 INFO  (SUITE-SoftAutoCommitTest-seed#[221449B83BEEB73D]-worker) [    ] o.a.s.s.IndexSchema Loaded schema test/1.0 with uniqueid field id
   [junit4]   2> 188011 INFO  (SUITE-SoftAutoCommitTest-seed#[221449B83BEEB73D]-worker) [    ] o.a.s.c.TransientSolrCoreCacheDefault Allocating transient cache for 2147483647 transient cores
   [junit4]   2> 188011 INFO  (SUITE-SoftAutoCommitTest-seed#[221449B83BEEB73D]-worker) [    ] o.a.s.h.a.MetricsHistoryHandler No .system collection, keeping metrics history in memory.
   [junit4]   2> 188082 INFO  (SUITE-SoftAutoCommitTest-seed#[221449B83BEEB73D]-worker) [    ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr.node' (registry 'solr.node') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@c454ae3
   [junit4]   2> 188133 INFO  (SUITE-SoftAutoCommitTest-seed#[221449B83BEEB73D]-worker) [    ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr.jvm' (registry 'solr.jvm') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@c454ae3
   [junit4]   2> 188133 INFO  (SUITE-SoftAutoCommitTest-seed#[221449B83BEEB73D]-worker) [    ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr.jetty' (registry 'solr.jetty') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@c454ae3
   [junit4]   2> 188150 INFO  (coreLoadExecutor-596-thread-1) [    x:collection1] o.a.s.c.SolrResourceLoader [null] Added 2 libs to classloader, from paths: [/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-master/checkout/solr/core/src/test-files/solr/collection1/lib, /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-master/checkout/solr/core/src/test-files/solr/collection1/lib/classes]
   [junit4]   2> 188265 INFO  (coreLoadExecutor-596-thread-1) [    x:collection1] o.a.s.c.SolrConfig Using Lucene MatchVersion: 8.0.0
   [junit4]   2> 188338 INFO  (coreLoadExecutor-596-thread-1) [    x:collection1] o.a.s.s.IndexSchema [collection1] Schema name=test
   [junit4]   2> 188781 INFO  (coreLoadExecutor-596-thread-1) [    x:collection1] o.a.s.s.IndexSchema Loaded schema test/1.0 with uniqueid field id
   [junit4]   2> 188818 INFO  (coreLoadExecutor-596-thread-1) [    x:collection1] o.a.s.c.CoreContainer Creating SolrCore 'collection1' using configuration from instancedir /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-master/checkout/solr/core/src/test-files/solr/collection1, trusted=true
   [junit4]   2> 188819 INFO  (coreLoadExecutor-596-thread-1) [    x:collection1] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr.core.collection1' (registry 'solr.core.collection1') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@c454ae3
   [junit4]   2> 188819 INFO  (coreLoadExecutor-596-thread-1) [    x:collection1] o.a.s.c.SolrCore solr.RecoveryStrategy.Builder
   [junit4]   2> 188819 INFO  (coreLoadExecutor-596-thread-1) [    x:collection1] o.a.s.c.SolrCore [[collection1] ] Opening new SolrCore at [/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-master/checkout/solr/core/src/test-files/solr/collection1], dataDir=[/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-master/checkout/solr/build/solr-core/test/J2/temp/solr.update.SoftAutoCommitTest_221449B83BEEB73D-001/init-core-data-001/]
   [junit4]   2> 188840 INFO  (coreLoadExecutor-596-thread-1) [    x:collection1] o.a.s.u.RandomMergePolicy RandomMergePolicy wrapping class org.apache.lucene.index.LogByteSizeMergePolicy: [LogByteSizeMergePolicy: minMergeSize=1677721, mergeFactor=13, maxMergeSize=2147483648, maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=true, maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.8064210139848956]
   [junit4]   2> 189316 INFO  (coreLoadExecutor-596-thread-1) [    x:collection1] o.a.s.u.UpdateHandler Using UpdateLog implementation: org.apache.solr.update.UpdateLog
   [junit4]   2> 189316 INFO  (coreLoadExecutor-596-thread-1) [    x:collection1] o.a.s.u.UpdateLog Initializing UpdateLog: dataDir= defaultSyncLevel=FLUSH numRecordsToKeep=100 maxNumLogsToKeep=10 numVersionBuckets=65536
   [junit4]   2> 189317 INFO  (coreLoadExecutor-596-thread-1) [    x:collection1] o.a.s.u.CommitTracker Hard AutoCommit: disabled
   [junit4]   2> 189317 INFO  (coreLoadExecutor-596-thread-1) [    x:collection1] o.a.s.u.CommitTracker Soft AutoCommit: disabled
   [junit4]   2> 189319 INFO  (coreLoadExecutor-596-thread-1) [    x:collection1] o.a.s.u.RandomMergePolicy RandomMergePolicy wrapping class org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: maxMergeAtOnce=19, maxMergeAtOnceExplicit=10, maxMergedSegmentMB=30.02734375, floorSegmentMB=2.134765625, forceMergeDeletesPctAllowed=28.325031765804734, segmentsPerTier=8.0, maxCFSSegmentSizeMB=0.8896484375, noCFSRatio=0.4091939390478154, reclaimDeletesWeight=1.40326945354896
   [junit4]   2> 189319 INFO  (coreLoadExecutor-596-thread-1) [    x:collection1] o.a.s.s.SolrIndexSearcher Opening [Searcher@100a433a[collection1] main]
   [junit4]   2> 189321 INFO  (coreLoadExecutor-596-thread-1) [    x:collection1] o.a.s.h.c.SpellCheckComponent Initializing spell checkers
   [junit4]   2> 189368 INFO  (coreLoadExecutor-596-thread-1) [    x:collection1] o.a.s.s.DirectSolrSpellChecker init: {name=direct,classname=DirectSolrSpellChecker,field=lowerfilt,minQueryLength=3}
   [junit4]   2> 189786 INFO  (coreLoadExecutor-596-thread-1) [    x:collection1] o.a.s.h.ReplicationHandler Commits will be reserved for 10000ms.
   [junit4]   2> 189787 INFO  (searcherExecutor-597-thread-1-processing-x:collection1) [    x:collection1] o.a.s.h.c.SpellCheckComponent Loading spell index for spellchecker: default
   [junit4]   2> 189787 INFO  (searcherExecutor-597-thread-1-processing-x:collection1) [    x:collection1] o.a.s.h.c.SpellCheckComponent Loading spell index for spellchecker: direct
   [junit4]   2> 189787 INFO  (searcherExecutor-597-thread-1-processing-x:collection1) [    x:collection1] o.a.s.h.c.SpellCheckComponent Loading spell index for spellchecker: wordbreak
   [junit4]   2> 189787 INFO  (searcherExecutor-597-thread-1-processing-x:collection1) [    x:collection1] o.a.s.h.c.SpellCheckComponent Loading spell index for spellchecker: multipleFields
   [junit4]   2> 189788 INFO  (searcherExecutor-597-thread-1-processing-x:collection1) [    x:collection1] o.a.s.h.c.SpellCheckComponent Loading spell index for spellchecker: jarowinkler
   [junit4]   2> 189789 INFO  (coreLoadExecutor-596-thread-1) [    x:collection1] o.a.s.u.UpdateLog Could not find max version in index or recent updates, using new clock 1604571173918605312
   [junit4]   2> 189790 INFO  (searcherExecutor-597-thread-1-processing-x:collection1) [    x:collection1] o.a.s.h.c.SpellCheckComponent Loading spell index for spellchecker: external
   [junit4]   2> 189790 INFO  (searcherExecutor-597-thread-1-processing-x:collection1) [    x:collection1] o.a.s.h.c.SpellCheckComponent Loading spell index for spellchecker: freq
   [junit4]   2> 189796 INFO  (searcherExecutor-597-thread-1-processing-x:collection1) [    x:collection1] o.a.s.h.c.SpellCheckComponent Loading spell index for spellchecker: fqcn
   [junit4]   2> 189796 INFO  (searcherExecutor-597-thread-1-processing-x:collection1) [    x:collection1] o.a.s.h.c.SpellCheckComponent Loading spell index for spellchecker: perDict
   [junit4]   2> 189797 INFO  (searcherExecutor-597-thread-1-processing-x:collection1) [    x:collection1] o.a.s.c.SolrCore [collection1] Registered new searcher Searcher@100a433a[collection1] main{ExitableDirectoryReader(UninvertingDirectoryReader())}
   [junit4]   2> 189799 INFO  (SUITE-SoftAutoCommitTest-seed#[221449B83BEEB73D]-worker) [    ] o.a.s.SolrTestCaseJ4 ####initCore end
   [junit4]   2> 189805 INFO  (TEST-SoftAutoCommitTest.testHardCommitWithinAndSoftCommitMaxTimeRapidAdds-seed#[221449B83BEEB73D]) [    ] o.a.s.SolrTestCaseJ4 ###Starting testHardCommitWithinAndSoftCommitMaxTimeRapidAdds
   [junit4]   2> 194830 INFO  (TEST-SoftAutoCommitTest.testHardCommitWithinAndSoftCommitMaxTimeRapidAdds-seed#[221449B83BEEB73D]) [    ] o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=null path=null params={}{add=[5000 (1604571179185602560)]} 0 21
   [junit4]   2> 194845 INFO  (TEST-SoftAutoCommitTest.testHardCommitWithinAndSoftCommitMaxTimeRapidAdds-seed#[221449B83BEEB73D]) [    ] o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=null path=null params={}{add=[5001 (1604571179218108416)]} 0 11
   [junit4]   2> 194848 INFO  (TEST-SoftAutoCommitTest.testHardCommitWithinAndSoftCommitMaxTimeRapidAdds-seed#[221449B83BEEB73D]) [    ] o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=null path=null params={}{add=[5002 (1604571179221254144)]} 0 2
   [junit4]   2> 194853 INFO  (TEST-SoftAutoCommitTest.testHardCommitWithinAndSoftCommitMaxTimeRapidAdds-seed#[221449B83BEEB73D]) [    ] o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=null path=null params={}{add=[5003 (1604571179224399872)]} 0 4
   [junit4]   2> 194857 INFO  (TEST-SoftAutoCommitTest.testHardCommitWithinAndSoftCommitMaxTimeRapidAdds-seed#[221449B83BEEB73D]) [    ] o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=null path=null params={}{add=[5004 (1604571179230691328)]} 0 1
   [junit4]   2> 194857 INFO  (TEST-SoftAutoCommitTest.testHardCommitWithinAndSoftCommitMaxTimeRapidAdds-seed#[221449B83BEEB73D]) [    ] o.a.s.u.SoftAutoCommitTest maxTimeMillis: 30490219521463279ns - 30490219472830436ns == 48ms
   [junit4]   2> 194857 INFO  (TEST-SoftAutoCommitTest.testHardCommitWithinAndSoftCommitMaxTimeRapidAdds-seed#[221449B83BEEB73D]) [    ] o.a.s.u.SoftAutoCommitTest maxExpectedSoft=1
   [junit4]   2> 194857 INFO  (TEST-SoftAutoCommitTest.testHardCommitWithinAndSoftCommitMaxTimeRapidAdds-seed#[221449B83BEEB73D]) [    ] o.a.s.u.SoftAutoCommitTest maxExpectedHard=1
   [junit4]   2> 195330 INFO  (commitScheduler-601-thread-1) [    ] o.a.s.u.DirectUpdateHandler2 start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=true,prepareCommit=false}
   [junit4]   2> 195436 INFO  (commitScheduler-601-thread-1) [    ] o.a.s.s.SolrIndexSearcher Opening [Searcher@259075d6[collection1] main]
   [junit4]   2> 195436 INFO  (commitScheduler-601-thread-1) [    ] o.a.s.u.DirectUpdateHandler2 end_commit_flush
   [junit4]   2> 195438 INFO  (searcherExecutor-597-thread-1) [    ] o.a.s.c.SolrCore [collection1] Registered new searcher Searcher@259075d6[collection1] main{ExitableDirectoryReader(UninvertingDirectoryReader(Uninverting(_0(8.0.0):c5)))}
   [junit4]   2> 196032 INFO  (commitScheduler-600-thread-1) [    ] o.a.s.u.DirectUpdateHandler2 start commit{,optimize=false,openSearcher=false,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
   [junit4]   2> 196032 INFO  (commitScheduler-600-thread-1) [    ] o.a.s.u.SolrIndexWriter Calling setCommitData with IW:org.apache.solr.update.SolrIndexWriter@39a2b3f2 commitCommandVersion:0
   [junit4]   2> 196035 INFO  (commitScheduler-600-thread-1) [    ] o.a.s.s.SolrIndexSearcher Opening [Searcher@65a17125[collection1] realtime]
   [junit4]   2> 196036 INFO  (commitScheduler-600-thread-1) [    ] o.a.s.u.DirectUpdateHandler2 end_commit_flush
   [junit4]   2> 201540 INFO  (TEST-SoftAutoCommitTest.testHardCommitWithinAndSoftCommitMaxTimeRapidAdds-seed#[221449B83BEEB73D]) [    ] o.a.s.SolrTestCaseJ4 ###Ending testHardCommitWithinAndSoftCommitMaxTimeRapidAdds
   [junit4]   2> 201545 INFO  (TEST-SoftAutoCommitTest.testSoftCommitWithinAndHardCommitMaxTimeDelete-seed#[221449B83BEEB73D]) [    ] o.a.s.SolrTestCaseJ4 ###Starting testSoftCommitWithinAndHardCommitMaxTimeDelete
   [junit4]   2> 206549 INFO  (TEST-SoftAutoCommitTest.testSoftCommitWithinAndHardCommitMaxTimeDelete-seed#[221449B83BEEB73D]) [    ] o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=null path=null params={}{add=[529 (1604571191489593344)]} 0 3
   [junit4]   2> 206550 INFO  (TEST-SoftAutoCommitTest.testSoftCommitWithinAndHardCommitMaxTimeDelete-seed#[221449B83BEEB73D]) [    ] o.a.s.u.DirectUpdateHandler2 start commit{_version_=1604571191493787648,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
   [junit4]   2> 206550 INFO  (TEST-SoftAutoCommitTest.testSoftCommitWithinAndHardCommitMaxTimeDelete-seed#[221449B83BEEB73D]) [    ] o.a.s.u.SolrIndexWriter Calling setCommitData with IW:org.apache.solr.update.SolrIndexWriter@39a2b3f2 commitCommandVersion:1604571191493787648
   [junit4]   2> 206614 INFO  (TEST-SoftAutoCommitTest.testSoftCommitWithinAndHardCommitMaxTimeDelete-seed#[221449B83BEEB73D]) [    ] o.a.s.s.SolrIndexSearcher Opening [Searcher@2b3accdf[collection1] main]
   [junit4]   2> 206615 INFO  (TEST-SoftAutoCommitTest.testSoftCommitWithinAndHardCommitMaxTimeDelete-seed#[221449B83BEEB73D]) [    ] o.a.s.u.DirectUpdateHandler2 end_commit_flush
   [junit4]   2> 206617 INFO  (searcherExecutor-597-thread-1) [    ] o.a.s.c.SolrCore [collection1] Registered new searcher Searcher@2b3accdf[collection1] main{ExitableDirectoryReader(UninvertingDirectoryReader(Uninverting(_0(8.0.0):c5) Uninverting(_1(8.0.0):c1)))}
   [junit4]   2> 206618 INFO  (TEST-SoftAutoCommitTest.testSoftCommitWithinAndHardCommitMaxTimeDelete-seed#[221449B83BEEB73D]) [    ] o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=null path=null params={}{commit=} 0 68
   [junit4]   2> 206621 INFO  (TEST-SoftAutoCommitTest.testSoftCommitWithinAndHardCommitMaxTimeDelete-seed#[221449B83BEEB73D]) [    ] o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=null path=null params={}{delete=[529 (-1604571191566139392)]} 0 2
   [junit4]   2> 207121 INFO  (commitScheduler-601-thread-1) [    ] o.a.s.u.DirectUpdateHandler2 start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=true,prepareCommit=false}
   [junit4]   2> 207123 INFO  (commitScheduler-601-thread-1) [    ] o.a.s.s.SolrIndexSearcher Opening [Searcher@5fe244f2[collection1] main]
   [junit4]   2> 207123 INFO  (commitScheduler-601-thread-1) [    ] o.a.s.u.DirectUpdateHandler2 end_commit_flush
   [junit4]   2> 207129 INFO  (searcherExecutor-597-thread-1) [    ] o.a.s.c.SolrCore [collection1] Registered new searcher Searcher@5fe244f2[collection1] main{ExitableDirectoryReader(UninvertingDirectoryReader(Uninverting(_0(8.0.0):c5)))}
   [junit4]   2> 207134 INFO  (TEST-SoftAutoCommitTest.testSoftCommitWithinAndHardCommitMaxTimeDelete-seed#[221449B83BEEB73D]) [    ] o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=null path=null params={}{add=[550 (1604571192104058880)]} 0 4
   [junit4]   2> 207634 INFO  (commitScheduler-601-thread-1) [    ] o.a.s.u.DirectUpdateHandler2 start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=true,prepareCommit=false}
   [junit4]   2> 207702 INFO  (commitScheduler-601-thread-1) [    ] o.a.s.s.SolrIndexSearcher Opening [Searcher@3ff942c4[collection1] main]
   [junit4]   2> 207704 INFO  (searcherExecutor-597-thread-1) [    ] o.a.s.c.SolrCore [collection1] Registered new searcher Searcher@3ff942c4[collection1] main{ExitableDirectoryReader(UninvertingDirectoryReader(Uninverting(_0(8.0.0):c5) Uninverting(_2(8.0.0):c1)))}
   [junit4]   2> 207704 INFO  (commitScheduler-601-thread-1) [    ] o.a.s.u.DirectUpdateHandler2 end_commit_flush
   [junit4]   2> 207821 INFO  (commitScheduler-600-thread-1) [    ] o.a.s.u.DirectUpdateHandler2 start commit{,optimize=false,openSearcher=false,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
   [junit4]   2> 207822 INFO  (commitScheduler-600-thread-1) [    ] o.a.s.u.SolrIndexWriter Calling setCommitData with IW:org.apache.solr.update.SolrIndexWriter@39a2b3f2 commitCommandVersion:0
   [junit4]   2> 207825 INFO  (commitScheduler-600-thread-1) [    ] o.a.s.s.SolrIndexSearcher Opening [Searcher@64f5dccb[collection1] realtime]
   [junit4]   2> 207826 INFO  (commitScheduler-600-thread-1) [    ] o.a.s.u.DirectUpdateHandler2 end_commit_flush
   [junit4]   2> 213832 INFO  (TEST-SoftAutoCommitTest.testSoftCommitWithinAndHardCommitMaxTimeDelete-seed#[221449B83BEEB73D]) [    ] o.a.s.SolrTestCaseJ4 ###Ending testSoftCommitWithinAndHardCommitMaxTimeDelete
   [junit4]   2> 213835 INFO  (TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeDelete-seed#[221449B83BEEB73D]) [    ] o.a.s.SolrTestCaseJ4 ###Starting testSoftAndHardCommitMaxTimeDelete
   [junit4]   2> 218838 INFO  (TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeDelete-seed#[221449B83BEEB73D]) [    ] o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=null path=null params={}{add=[529 (1604571204375543808)]} 0 2
   [junit4]   2> 218838 INFO  (TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeDelete-seed#[221449B83BEEB73D]) [    ] o.a.s.u.DirectUpdateHandler2 start commit{_version_=1604571204378689536,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
   [junit4]   2> 218838 INFO  (TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeDelete-seed#[221449B83BEEB73D]) [    ] o.a.s.u.SolrIndexWriter Calling setCommitData with IW:org.apache.solr.update.SolrIndexWriter@39a2b3f2 commitCommandVersion:1604571204378689536
   [junit4]   2> 218883 INFO  (TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeDelete-seed#[221449B83BEEB73D]) [    ] o.a.s.s.SolrIndexSearcher Opening [Searcher@820a56d[collection1] main]
   [junit4]   2> 218884 INFO  (TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeDelete-seed#[221449B83BEEB73D]) [    ] o.a.s.u.DirectUpdateHandler2 end_commit_flush
   [junit4]   2> 218885 INFO  (searcherExecutor-597-thread-1) [    ] o.a.s.c.SolrCore [collection1] Registered new searcher Searcher@820a56d[collection1] main{ExitableDirectoryReader(UninvertingDirectoryReader(Uninverting(_0(8.0.0):c5) Uninverting(_2(8.0.0):c1) Uninverting(_3(8.0.0):c1)))}
   [junit4]   2> 218887 INFO  (TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeDelete-seed#[221449B83BEEB73D]) [    ] o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=null path=null params={}{commit=} 0 48
   [junit4]   2> 218888 INFO  (TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeDelete-seed#[221449B83BEEB73D]) [    ] o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=null path=null params={}{delete=[529 (-1604571204431118336)]} 0 0
   [junit4]   2> 219388 INFO  (commitScheduler-601-thread-1) [    ] o.a.s.u.DirectUpdateHandler2 start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=true,prepareCommit=false}
   [junit4]   2> 219390 INFO  (commitScheduler-601-thread-1) [    ] o.a.s.s.SolrIndexSearcher Opening [Searcher@50743dc4[collection1] main]
   [junit4]   2> 219390 INFO  (commitScheduler-601-thread-1) [    ] o.a.s.u.DirectUpdateHandler2 end_commit_flush
   [junit4]   2> 219392 INFO  (searcherExecutor-597-thread-1) [    ] o.a.s.c.SolrCore [collection1] Registered new searcher Searcher@50743dc4[collection1] main{ExitableDirectoryReader(UninvertingDirectoryReader(Uninverting(_0(8.0.0):c5) Uninverting(_2(8.0.0):c1)))}
   [junit4]   2> 219394 INFO  (TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeDelete-seed#[221449B83BEEB73D]) [    ] o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=null path=null params={}{add=[550 (1604571204960649216)]} 0 1
   [junit4]   2> 219895 INFO  (commitScheduler-601-thread-1) [    ] o.a.s.u.DirectUpdateHandler2 start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=true,prepareCommit=false}
   [junit4]   2> 219922 INFO  (commitScheduler-601-thread-1) [    ] o.a.s.s.SolrIndexSearcher Opening [Searcher@5c3dcd93[collection1] main]
   [junit4]   2> 219924 INFO  (searcherExecutor-597-thread-1) [    ] o.a.s.c.SolrCore [collection1] Registered new searcher Searcher@5c3dcd93[collection1] main{ExitableDirectoryReader(UninvertingDirectoryReader(Uninverting(_0(8.0.0):c5) Uninverting(_4(8.0.0):c1)))}
   [junit4]   2> 219926 INFO  (commitScheduler-601-thread-1) [    ] o.a.s.u.DirectUpdateHandler2 end_commit_flush
   [junit4]   2> 220088 INFO  (commitScheduler-600-thread-1) [    ] o.a.s.u.DirectUpdateHandler2 start commit{,optimize=false,openSearcher=false,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
   [junit4]   2> 220089 INFO  (commitScheduler-600-thread-1) [    ] o.a.s.u.SolrIndexWriter Calling setCommitData with IW:org.apache.solr.update.SolrIndexWriter@39a2b3f2 commitCommandVersion:0
   [junit4]   2> 220091 INFO  (commitScheduler-600-thread-1) [    ] o.a.s.s.SolrIndexSearcher Opening [Searcher@338f44da[collection1] realtime]
   [junit4]   2> 220094 INFO  (commitScheduler-600-thread-1) [    ] o.a.s.u.DirectUpdateHandler2 end_commit_flush
   [junit4]   2> 226092 INFO  (TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeDelete-seed#[221449B83BEEB73D]) [    ] o.a.s.SolrTestCaseJ4 ###Ending testSoftAndHardCommitMaxTimeDelete
   [junit4]   2> 226100 INFO  (TEST-SoftAutoCommitTest.testHardCommitWithinAndSoftCommitMaxTimeDelete-seed#[221449B83BEEB73D]) [    ] o.a.s.SolrTestCaseJ4 ###Starting testHardCommitWithinAndSoftCommitMaxTimeDelete
   [junit4]   2> 231270 INFO  (TEST-SoftAutoCommitTest.testHardCommitWithinAndSoftCommitMaxTimeDelete-seed#[221449B83BEEB73D]) [    ] o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=null path=null params={}{add=[529 (1604571217405149184)]} 0 9
   [junit4]   2> 231270 INFO  (TEST-SoftAutoCommitTest.testHardCommitWithinAndSoftCommitMaxTimeDelete-seed#[221449B83BEEB73D]) [    ] o.a.s.u.DirectUpdateHandler2 start commit{_version_=1604571217414586368,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
   [junit4]   2> 231271 INFO  (TEST-SoftAutoCommitTest.testHardCommitWithinAndSoftCommitMaxTimeDelete-seed#[221449B83BEEB73D]) [    ] o.a.s.u.SolrIndexWriter Calling setCommitData with IW:org.apache.solr.update.SolrIndexWriter@39a2b3f2 commitCommandVersion:1604571217414586368
   [junit4]   2> 231313 INFO  (TEST-SoftAutoCommitTest.testHardCommitWithinAndSoftCommitMaxTimeDelete-seed#[221449B83BEEB73D]) [    ] o.a.s.s.SolrIndexSearcher Opening [Searcher@287f0cec[collection1] main]
   [junit4]   2> 231314 INFO  (TEST-SoftAutoCommitTest.testHardCommitWithinAndSoftCommitMaxTimeDelete-seed#[221449B83BEEB73D]) [    ] o.a.s.u.DirectUpdateHandler2 end_commit_flush
   [junit4]   2> 231316 INFO  (searcherExecutor-597-thread-1) [    ] o.a.s.c.SolrCore [collection1] Registered new searcher Searcher@287f0cec[collection1] main{ExitableDirectoryReader(UninvertingDirectoryReader(Uninverting(_0(8.0.0):c5) Uninverting(_4(8.0.0):c1) Uninverting(_5(8.0.0):c1)))}
   [junit4]   2> 231320 INFO  (TEST-SoftAutoCommitTest.testHardCommitWithinAndSoftCommitMaxTimeDelete-seed#[221449B83BEEB73D]) [    ] o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=null path=null params={}{commit=} 0 49
   [junit4]   2> 231327 INFO  (TEST-SoftAutoCommitTest.testHardCommitWithinAndSoftCommitMaxTimeDelete-seed#[221449B83BEEB73D]) [    ] o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=null path=null params={}{delete=[529 (-1604571217473306624)]} 0 4
   [junit4]   2> 231827 INFO  (commitScheduler-601-thread-1) [    ] o.a.s.u.DirectUpdateHandler2 start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=true,prepareCommit=false}
   [junit4]   2> 231829 INFO  (commitScheduler-601-thread-1) [    ] o.a.s.s.SolrIndexSearcher Opening [Searcher@1bc9e020[collection1] main]
   [junit4]   2> 231830 INFO  (commitScheduler-601-thread-1) [    ] o.a.s.u.DirectUpdateHandler2 end_commit_flush
   [junit4]   2> 231831 INFO  (searcherExecutor-597-thread-1) [    ] o.a.s.c.SolrCore [collection1] Registered new searcher Searcher@1bc9e020[collection1] main{ExitableDirectoryReader(UninvertingDirectoryReader(Uninverting(_0(8.0.0):c5) Uninverting(_4(8.0.0):c1)))}
   [junit4]   2> 231837 INFO  (TEST-SoftAutoCommitTest.testHardCommitWithinAndSoftCommitMaxTimeDelete-seed#[221449B83BEEB73D]) [    ] o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=null path=null params={}{add=[550 (1604571218003886080)]} 0 4
   [junit4]   2> 232337 INFO  (commitScheduler-601-thread-1) [    ] o.a.s.u.DirectUpdateHandler2 start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=true,prepareCommit=false}
   [junit4]   2> 232358 INFO  (commitScheduler-601-thread-1) [    ] o.a.s.s.SolrIndexSearcher Opening [Searcher@58796dd[collection1] main]
   [junit4]   2> 232361 INFO  (searcherExecutor-597-thread-1) [    ] o.a.s.c.SolrCore [collection1] Registered new searcher Searcher@58796dd[collection1] main{ExitableDirectoryReader(UninvertingDirectoryReader(Uninverting(_0(8.0.0):c5) Uninverting(_6(8.0.0):c1)))}
   [junit4]   2> 232363 INFO  (commitScheduler-601-thread-1) [    ] o.a.s.u.DirectUpdateHandler2 end_commit_flush
   [junit4]   2> 232527 INFO  (commitScheduler-600-thread-1) [    ] o.a.s.u.DirectUpdateHandler2 start commit{,optimize=false,openSearcher=false,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
   [junit4]   2> 232527 INFO  (commitScheduler-600-thread-1) [    ] o.a.s.u.SolrIndexWriter Calling setCommitData with IW:org.apache.solr.update.SolrIndexWriter@39a2b3f2 commitCommandVersion:0
   [junit4]   2> 232529 INFO  (commitScheduler-600-thread-1) [    ] o.a.s.s.SolrIndexSearcher Opening [Searcher@617353c8[collection1] realtime]
   [junit4]   2> 232531 INFO  (commitScheduler-600-thread-1) [    ] o.a.s.u.DirectUpdateHandler2 end_commit_flush
   [junit4]   2> 238530 INFO  (TEST-SoftAutoCommitTest.testHardCommitWithinAndSoftCommitMaxTimeDelete-seed#[221449B83BEEB73D]) [    ] o.a.s.SolrTestCaseJ4 ###Ending testHardCommitWithinAndSoftCommitMaxTimeDelete
   [junit4]   2> 238537 INFO  (TEST-SoftAutoCommitTest.testSoftCommitWithinAndHardCommitMaxTimeMixedAdds-seed#[221449B83BEEB73D]) [    ] o.a.s.SolrTestCaseJ4 ###Starting testSoftCommitWithinAndHardCommitMaxTimeMixedAdds
   [junit4]   2> 246943 INFO  (TEST-SoftAutoCommitTest.testSoftCommitWithinAndHardCommitMaxTimeMixedAdds-seed#[221449B83BEEB73D]) [    ] o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=null path=null params={}{add=[529 (1604571233846820864)]} 0 2
   [junit4]   2> 247444 INFO  (commitScheduler-601-thread-1) [    ] o.a.s.u.DirectUpdateHandler2 start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=true,prepareCommit=false}
   [junit4]   2> 247465 INFO  (commitScheduler-601-thread-1) [    ] o.a.s.s.SolrIndexSearcher Opening [Searcher@27dd0f6a[collection1] main]
   [junit4]   2> 247467 INFO  (searcherExecutor-597-thread-1) [    ] o.a.s.c.SolrCore [collection1] Registered new searcher Searcher@27dd0f6a[collection1] main{ExitableDirectoryReader(UninvertingDirectoryReader(Uninverting(_0(8.0.0):c5) Uninverting(_6(8.0.0):c1) Uninverting(_7(8.0.0):c1)))}
   [junit4]   2> 247467 INFO  (commitScheduler-601-thread-1) [    ] o.a.s.u.DirectUpdateHandler2 end_commit_flush
   [junit4]   2> 248260 INFO  (commitScheduler-600-thread-1) [    ] o.a.s.u.DirectUpdateHandler2 start commit{,optimize=false,openSearcher=false,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
   [junit4]   2> 248260 INFO  (commitScheduler-600-thread-1) [    ] o.a.s.u.SolrIndexWriter Calling setCommitData with IW:org.apache.solr.update.SolrIndexWriter@39a2b3f2 commitCommandVersion:0
   [junit4]   2> 248265 INFO  (commitScheduler-600-thread-1) [    ] o.a.s.s.SolrIndexSearcher Opening [Searcher@45cebe15[collection1] realtime]
   [junit4]   2> 248266 INFO  (commitScheduler-600-thread-1) [    ] o.a.s.u.DirectUpdateHandler2 end_commit_flush
   [junit4]   2> 248268 INFO  (TEST-SoftAutoCommitTest.testSoftCommitWithinAndHardCommitMaxTimeMixedAdds-seed#[221449B83BEEB73D]) [    ] o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=null path=null params={}{add=[530 (1604571235235135488)]} 0 3
   [junit4]   2> 248768 INFO  (commitScheduler-601-thread-1) [    ] o.a.s.u.DirectUpdateHandler2 start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=true,prepareCommit=false}
   [junit4]   2> 248786 INFO  (commitScheduler-601-thread-1) [    ] o.a.s.s.SolrIndexSearcher Opening [Searcher@14ccd14b[collection1] main]
   [junit4]   2> 248788 INFO  (searcherExecutor-597-thread-1) [    ] o.a.s.c.SolrCore [collection1] Registered new searcher Searcher@14ccd14b[collection1] main{ExitableDirectoryReader(UninvertingDirectoryReader(Uninverting(_0(8.0.0):c5) Uninverting(_6(8.0.0):c1) Uninverting(_7(8.0.0):c1) Uninverting(_8(8.0.0):c1)))}
   [junit4]   2> 248789 INFO  (commitScheduler-601-thread-1) [    ] o.a.s.u.DirectUpdateHandler2 end_commit_flush
   [junit4]   2> 249468 INFO  (commitScheduler-600-thread-1) [    ] o.a.s.u.DirectUpdateHandler2 start commit{,optimize=false,openSearcher=false,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
   [junit4]   2> 249468 INFO  (commitScheduler-600-thread-1) [    ] o.a.s.u.SolrIndexWriter Calling setCommitData with IW:org.apache.solr.update.SolrIndexWriter@39a2b3f2 commitCommandVersion:0
   [junit4]   2> 249470 INFO  (commitScheduler-600-thread-1) [    ] o.a.s.s.SolrIndexSearcher Opening [Searcher@441e81e5[collection1] realtime]
   [junit4]   2> 249473 INFO  (commitScheduler-600-thread-1) [    ] o.a.s.u.DirectUpdateHandler2 end_commit_flush
   [junit4]   2> 250470 INFO  (TEST-SoftAutoCommitTest.testSoftCommitWithinAndHardCommitMaxTimeMixedAdds-seed#[221449B83BEEB73D]) [    ] o.a.s.SolrTestCaseJ4 ###Ending testSoftCommitWithinAndHardCommitMaxTimeMixedAdds
   [junit4]   2> 250473 INFO  (TEST-SoftAutoCommitTest.testSoftCommitWithinAndHardCommitMaxTimeRapidAdds-seed#[221449B83BEEB73D]) [    ] o.a.s.SolrTestCaseJ4 ###Starting testSoftCommitWithinAndHardCommitMaxTimeRapidAdds
   [junit4]   2> 255478 INFO  (TEST-SoftAutoCommitTest.testSoftCommitWithinAndHardCommitMaxTimeRapidAdds-seed#[221449B83BEEB73D]) [    ] o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=null path=null params={}{add=[5000 (1604571242794319872)]} 0 4
   [junit4]   2> 255487 INFO  (TEST-SoftAutoCommitTest.testSoftCommitWithinAndHardCommitMaxTimeRapidAdds-seed#[221449B83BEEB73D]) [    ] o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=null path=null params={}{add=[5001 (1604571242799562752)]} 0 8
   [junit4]   2> 255489 INFO  (TEST-SoftAutoCommitTest.testSoftCommitWithinAndHardCommitMaxTimeRapidAdds-seed#[221449B83BEEB73D]) [    ] o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=null path=null params={}{add=[5002 (1604571242808999936)]} 0 1
   [junit4]   2> 255490 INFO  (TEST-SoftAutoCommitTest.testSoftCommitWithinAndHardCommitMaxTimeRapidAdds-seed#[221449B83BEEB73D]) [    ] o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=null path=null params={}{add=[5003 (1604571242810048512)]} 0 0
   [junit4]   2> 255491 INFO  (TEST-SoftAutoCommitTest.testSoftCommitWithinAndHardCommitMaxTimeRapidAdds-seed#[221449B83BEEB73D]) [    ] o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=null path=null params={}{add=[5004 (1604571242812145664)]} 0 0
   [junit4]   2> 255492 INFO  (TEST-SoftAutoCommitTest.testSoftCommitWithinAndHardCommitMaxTimeRapidAdds-seed#[221449B83BEEB73D]) [    ] o.a.s.u.SoftAutoCommitTest maxTimeMillis: 30490280156085026ns - 30490280137494046ns == 18ms
   [junit4]   2> 255492 INFO  (TEST-SoftAutoCommitTest.testSoftCommitWithinAndHardCommitMaxTimeRapidAdds-seed#[221449B83BEEB73D]) [    ] o.a.s.u.SoftAutoCommitTest maxExpectedSoft=1
   [junit4]   2> 255492 INFO  (TEST-SoftAutoCommitTest.testSoftCommitWithinAndHardCommitMaxTimeRapidAdds-seed#[221449B83BEEB73D]) [    ] o.a.s.u.SoftAutoCommitTest maxExpectedHard=1
   [junit4]   2> 256007 INFO  (commitScheduler-601-thread-1) [    ] o.a.s.u.DirectUpdateHandler2 start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=true,prepareCommit=false}
   [junit4]   2> 256240 INFO  (commitScheduler-601-thread-1) [    ] o.a.s.s.SolrIndexSearcher Opening [Searcher@50762b94[collection1] main]
   [junit4]   2> 256243 INFO  (searcherExecutor-597-thread-1) [    ] o.a.s.c.SolrCore [collection1] Registered new searcher Searcher@50762b94[collection1] main{ExitableDirectoryReader(UninvertingDirectoryReader(Uninverting(_6(8.0.0):c1) Uninverting(_7(8.0.0):c1) Uninverting(_8(8.0.0):c1) Uninverting(_9(8.0.0):c5)))}
   [junit4]   2> 256247 INFO  (commitScheduler-601-thread-1) [    ] o.a.s.u.DirectUpdateHandler2 end_commit_flush
   [junit4]   2> 256678 INFO  (commitScheduler-600-thread-1) [    ] o.a.s.u.DirectUpdateHandler2 start commit{,optimize=false,openSearcher=false,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
   [junit4]   2> 256678 INFO  (commitScheduler-600-thread-1) [    ] o.a.s.u.SolrIndexWriter Calling setCommitData with IW:org.apache.solr.update.SolrIndexWriter@39a2b3f2 commitCommandVersion:0
   [junit4]   2> 256682 INFO  (commitScheduler-600-thread-1) [    ] o.a.s.s.SolrIndexSearcher Opening [Searcher@342afcf5[collection1] realtime]
   [junit4]   2> 256683 INFO  (commitScheduler-600-thread-1) [    ] o.a.s.u.DirectUpdateHandler2 end_commit_flush
   [junit4]   2> 262348 INFO  (TEST-SoftAutoCommitTest.testSoftCommitWithinAndHardCommitMaxTimeRapidAdds-seed#[221449B83BEEB73D]) [    ] o.a.s.SolrTestCaseJ4 ###Ending testSoftCommitWithinAndHardCommitMaxTimeRapidAdds
   [junit4]   2> 262351 INFO  (TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxDocs-seed#[221449B83BEEB73D]) [    ] o.a.s.SolrTestCaseJ4 ###Starting testSoftAndHardCommitMaxDocs
   [junit4]   2> 270363 INFO  (TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxDocs-seed#[221449B83BEEB73D]) [    ] o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=null path=null params={}{add=[8000 (1604571258402373632)]} 0 7
   [junit4]   2> 270372 INFO  (TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxDocs-seed#[221449B83BEEB73D]) [    ] o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=null path=null params={}{add=[8001 (1604571258414956544)]} 0 8
   [junit4]   2> 270375 INFO  (TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxDocs-seed#[221449B83BEEB73D]) [    ] o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=null path=null params={}{add=[8002 (1604571258418102272)]} 0 2
   [junit4]   2> 270376 INFO  (TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxDocs-seed#[221449B83BEEB73D]) [    ] o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=null path=null params={}{add=[8003 (1604571258420199424)]} 0 0
   [junit4]   2> 270381 INFO  (TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxDocs-seed#[221449B83BEEB73D]) [    ] o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=null path=null params={}{add=[8004 (1604571258424393728)]} 0 0
   [junit4]   2> 270418 INFO  (TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxDocs-seed#[221449B83BEEB73D]) [    ] o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=null path=null params={}{add=[8005 (1604571258463191040)]} 0 36
   [junit4]   2> 270420 INFO  (commitScheduler-601-thread-1) [    ] o.a.s.u.DirectUpdateHandler2 start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=true,prepareCommit=false}
   [junit4]   2> 270420 INFO  (TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxDocs-seed#[221449B83BEEB73D]) [    ] o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=null path=null params={}{add=[8006 (1604571258465288192)]} 0 1
   [junit4]   2> 270441 INFO  (TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxDocs-seed#[221449B83BEEB73D]) [    ] o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=null path=null params={}{add=[8007 (1604571258484162560)]} 0 9
   [junit4]   2> 270442 INFO  (commitScheduler-600-thread-1) [    ] o.a.s.u.DirectUpdateHandler2 start commit{,optimize=false,openSearcher=false,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
   [junit4]   2> 270488 INFO  (commitScheduler-601-thread-1) [    ] o.a.s.s.SolrIndexSearcher Opening [Searcher@ddbb549[collection1] main]
   [junit4]   2> 270492 INFO  (searcherExecutor-597-thread-1) [    ] o.a.s.c.SolrCore [collection1] Registered new searcher Searcher@ddbb549[collection1] main{ExitableDirectoryReader(UninvertingDirectoryReader(Uninverting(_6(8.0.0):c1) Uninverting(_7(8.0.0):c1) Uninverting(_8(8.0.0):c1) Uninverting(_9(8.0.0):c5) Uninverting(_a(8.0.0):c7)))}
   [junit4]   2> 270492 INFO  (commitScheduler-600-thread-1) [    ] o.a.s.u.SolrIndexWriter Calling setCommitData with IW:org.apache.solr.update.SolrIndexWriter@39a2b3f2 commitCommandVersion:0
   [junit4]   2> 270492 INFO  (commitScheduler-601-thread-1) [    ] o.a.s.u.DirectUpdateHandler2 end_commit_flush
   [junit4]   2> 270506 INFO  (commitScheduler-600-thread-1) [    ] o.a.s.s.SolrIndexSearcher Opening [Searcher@640de64c[collection1] realtime]
   [junit4]   2> 270509 INFO  (commitScheduler-600-thread-1) [    ] o.a.s.u.DirectUpdateHandler2 end_commit_flush
   [junit4]   2> 271507 INFO  (TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxDocs-seed#[221449B83BEEB73D]) [    ] o.a.s.SolrTestCaseJ4 ###Ending testSoftAndHardCommitMaxDocs
   [junit4]   2> 271511 INFO  (TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeRapidAdds-seed#[221449B83BEEB73D]) [    ] o.a.s.SolrTestCaseJ4 ###Starting testSoftAndHardCommitMaxTimeRapidAdds
   [junit4]   2> 276517 INFO  (TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeRapidAdds-seed#[221449B83BEEB73D]) [    ] o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=null path=null params={}{add=[5000 (1604571264855310336)]} 0 4
   [junit4]   2> 276518 INFO  (TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeRapidAdds-seed#[221449B83BEEB73D]) [    ] o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=null path=null params={}{add=[5001 (1604571264859504640)]} 0 0
   [junit4]   2> 276519 INFO  (TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeRapidAdds-seed#[221449B83BEEB73D]) [    ] o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=null path=null params={}{add=[5002 (1604571264861601792)]} 0 0
   [junit4]   2> 276527 INFO  (TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeRapidAdds-seed#[221449B83BEEB73D]) [    ] o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=null path=null params={}{add=[5003 (1604571264868941824)]} 0 0
   [junit4]   2> 276528 INFO  (TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeRapidAdds-seed#[221449B83BEEB73D]) [    ] o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=null path=null params={}{add=[5004 (1604571264871038976)]} 0 0
   [junit4]   2> 276529 INFO  (TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeRapidAdds-seed#[221449B83BEEB73D]) [    ] o.a.s.u.SoftAutoCommitTest maxTimeMillis: 30490301193158957ns - 30490301176440271ns == 16ms
   [junit4]   2> 276529 INFO  (TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeRapidAdds-seed#[221449B83BEEB73D]) [    ] o.a.s.u.SoftAutoCommitTest maxExpectedSoft=1
   [junit4]   2> 276529 INFO  (TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeRapidAdds-seed#[221449B83BEEB73D]) [    ] o.a.s.u.SoftAutoCommitTest maxExpectedHard=1
   [junit4]   2> 277017 INFO  (commitScheduler-601-thread-1) [    ] o.a.s.u.DirectUpdateHandler2 start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=true,prepareCommit=false}
   [junit4]   2> 277050 INFO  (commitScheduler-601-thread-1) [    ] o.a.s.s.SolrIndexSearcher Opening [Searcher@1b22621c[collection1] main]
   [junit4]   2> 277051 INFO  (commitScheduler-601-thread-1) [    ] o.a.s.u.DirectUpdateHandler2 end_commit_flush
   [junit4]   2> 277053 INFO  (searcherExecutor-597-thread-1) [    ] o.a.s.c.SolrCore [collection1] Registered new searcher Searcher@1b22621c[collection1] main{ExitableDirectoryReader(UninvertingDirectoryReader(Uninverting(_6(8.0.0):c1) Uninverting(_7(8.0.0):c1) Uninverting(_8(8.0.0):c1) Uninverting(_a(8.0.0):c7) Uninverting(_b(8.0.0):c1) Uninverting(_c(8.0.0):c5)))}
   [junit4]   2> 277717 INFO  (commitScheduler-600-thread-1) [    ] o.a.s.u.DirectUpdateHandler2 start commit{,optimize=false,openSearcher=false,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
   [junit4]   2> 277717 INFO  (commitScheduler-600-thread-1) [    ] o.a.s.u.SolrIndexWriter Calling setCommitData with IW:org.apache.solr.update.SolrIndexWriter@39a2b3f2 commitCommandVersion:0
   [junit4]   2> 277722 INFO  (commitScheduler-600-thread-1) [    ] o.a.s.s.SolrIndexSearcher Opening [Searcher@522711[collection1] realtime]
   [junit4]   2> 277725 INFO  (commitScheduler-600-thread-1) [    ] o.a.s.u.DirectUpdateHandler2 end_commit_flush
   [junit4]   2> 283152 INFO  (TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeRapidAdds-seed#[221449B83BEEB73D]) [    ] o.a.s.SolrTestCaseJ4 ###Ending testSoftAndHardCommitMaxTimeRapidAdds
   [junit4]   2> 283155 INFO  (TEST-SoftAutoCommitTest.testHardCommitWithinAndSoftCommitMaxTimeMixedAdds-seed#[221449B83BEEB73D]) [    ] o.a.s.SolrTestCaseJ4 ###Starting testHardCommitWithinAndSoftCommitMaxTimeMixedAdds
   [junit4]   2> 291559 INFO  (TEST-SoftAutoCommitTest.testHardCommitWithinAndSoftCommitMaxTimeMixedAdds-seed#[221449B83BEEB73D]) [    ] o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=null path=null params={}{add=[529 (1604571280629039104)]} 0 2
   [junit4]   2> 292059 INFO  (commitScheduler-601-thread-1) [    ] o.a.s.u.DirectUpdateHandler2 start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=true,prepareCommit=false}
   [junit4]   2> 292153 INFO  (commitScheduler-601-thread-1) [    ] o.a.s.s.SolrIndexSearcher Opening [Searcher@2b3d9110[collection1] main]
   [junit4]   2> 292156 INFO  (searcherExecutor-597-thread-1) [    ] o.a.s.c.SolrCore [collection1] Registered new searcher Searcher@2b3d9110[collection1] main{ExitableDirectoryReader(UninvertingDirectoryReader(Uninverting(_6(8.0.0):c1) Uninverting(_8(8.0.0):c1) Uninverting(_a(8.0.0):c7) Uninverting(_b(8.0.0):c1) Uninverting(_c(8.0.0):c5) Uninverting(_d(8.0.0):c1)))}
   [junit4]   2> 292171 INFO  (commitScheduler-601-thread-1) [    ] o.a.s.u.DirectUpdateHandler2 end_commit_flush
   [junit4]   2> 292759 INFO  (commitScheduler-600-thread-1) [    ] o.a.s.u.DirectUpdateHandler2 start commit{,optimize=false,openSearcher=false,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
   [junit4]   2> 292759 INFO  (commitScheduler-600-thread-1) [    ] o.a.s.u.SolrIndexWriter Calling setCommitData with IW:org.apache.solr.update.SolrIndexWriter@39a2b3f2 commitCommandVersion:0
   [junit4]   2> 292770 INFO  (TEST-SoftAutoCommitTest.testHardCommitWithinAndSoftCommitMaxTimeMixedAdds-seed#[221449B83BEEB73D]) [    ] o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=null path=null params={}{add=[530 (1604571281891524608)]} 0 9
   [junit4]   2> 292771 INFO  (commitScheduler-600-thread-1) [    ] o.a.s.s.SolrIndexSearcher Opening [Searcher@2b3cf9ca[collection1] realtime]
   [junit4]   2> 292772 INFO  (commitScheduler-600-thread-1) [    ] o.a.s.u.DirectUpdateHandler2 end_commit_flush
   [junit4]   2> 293270 INFO  (commitScheduler-601-thread-1) [    ] o.a.s.u.DirectUpdateHandler2 start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=true,prepareCommit=false}
   [junit4]   2> 293970 INFO  (commitScheduler-600-thread-1) [    ] o.a.s.u.DirectUpdateHandler2 start commit{,optimize=false,openSearcher=false,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
   [junit4]   2> 294141 INFO  (commitScheduler-601-thread-1) [    ] o.a.s.s.SolrIndexSearcher Opening [Searcher@6161aec6[collection1] main]
   [junit4]   2> 294144 INFO  (searcherExecutor-597-thread-1) [    ] o.a.s.c.SolrCore [collection1] Registered new searcher Searcher@6161aec6[collection1] main{ExitableDirectoryReader(UninvertingDirectoryReader(Uninverting(_6(8.0.0):c1) Uninverting(_a(8.0.0):c7) Uninverting(_b(8.0.0):c1) Uninverting(_c(8.0.0):c5) Uninverting(_d(8.0.0):c1) Uninverting(_e(8.0.0):c1)))}
   [junit4]   2> 294146 INFO  (commitScheduler-600-thread-1) [    ] o.a.s.u.SolrIndexWriter Calling setCommitData with IW:org.apache.solr.update.SolrIndexWriter@39a2b3f2 commitCommandVersion:0
   [junit4]   2> 294147 INFO  (commitScheduler-600-thread-1) [    ] o.a.s.s.SolrIndexSearcher Opening [Searcher@2a4b0763[collection1] realtime]
   [junit4]   2> 294148 INFO  (TEST-SoftAutoCommitTest.testHardCommitWithinAndSoftCommitMaxTimeMixedAdds-seed#[221449B83BEEB73D]) [    ] o.a.s.SolrTestCaseJ4 ###Ending testHardCommitWithinAndSoftCommitMaxTimeMixedAdds
   [junit4]   2> 294152 INFO  (commitScheduler-600-thread-1) [    ] o.a.s.u.DirectUpdateHandler2 end_commit_flush
   [junit4]   2> NOTE: download the large Jenkins line-docs file by running 'ant get-jenkins-line-docs' in the lucene directory.
   [junit4]   2> NOTE: reproduce with: ant test  -Dtestcase=SoftAutoCommitTest -Dtests.method=testHardCommitWithinAndSoftCommitMaxTimeMixedAdds -Dtests.seed=221449B83BEEB73D -Dtests.multiplier=2 -Dtests.nightly=true -Dtests.slow=true -Dtests.linedocsfile=/home/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-master/test-data/enwiki.random.lines.txt -Dtests.locale=nl-BE -Dtests.timezone=Etc/GMT+10 -Dtests.asserts=true -Dtests.file.encoding=UTF-8
   [junit4] FAILURE 11.0s J2 | SoftAutoCommitTest.testHardCommitWithinAndSoftCommitMaxTimeMixedAdds <<<
   [junit4]    > Throwable #1: java.lang.AssertionError: Tracker reports too many soft commits expected:<1> but was:<2>
   [junit4]    > 	at __randomizedtesting.SeedInfo.seed([221449B83BEEB73D:E1F395A90AD26040]:0)
   [junit4]    > 	at org.apache.solr.update.SoftAutoCommitTest.doTestSoftAndHardCommitMaxTimeMixedAdds(SoftAutoCommitTest.java:273)
   [junit4]    > 	at org.apache.solr.update.SoftAutoCommitTest.testHardCommitWithinAndSoftCommitMaxTimeMixedAdds(SoftAutoCommitTest.java:174)
   [junit4]    > 	at java.lang.Thread.run(Thread.java:748)
   [junit4]   2> 294170 INFO  (TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeMixedAdds-seed#[221449B83BEEB73D]) [    ] o.a.s.SolrTestCaseJ4 ###Starting testSoftAndHardCommitMaxTimeMixedAdds
   [junit4]   2> 294177 INFO  (commitScheduler-601-thread-1) [    ] o.a.s.u.DirectUpdateHandler2 end_commit_flush
   [junit4]   2> 301577 INFO  (TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeMixedAdds-seed#[221449B83BEEB73D]) [    ] o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=null path=null params={}{add=[529 (1604571291130527744)]} 0 7
   [junit4]   2> 302077 INFO  (commitScheduler-601-thread-1) [    ] o.a.s.u.DirectUpdateHandler2 start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=true,prepareCommit=false}
   [junit4]   2> 302189 INFO  (commitScheduler-601-thread-1) [    ] o.a.s.s.SolrIndexSearcher Opening [Searcher@7902875d[collection1] main]
   [junit4]   2> 302190 INFO  (commitScheduler-601-thread-1) [    ] o.a.s.u.DirectUpdateHandler2 end_commit_flush
   [junit4]   2> 302192 INFO  (searcherExecutor-597-thread-1) [    ] o.a.s.c.SolrCore [collection1] Registered new searcher Searcher@7902875d[collection1] main{ExitableDirectoryReader(UninvertingDirectoryReader(Uninverting(_6(8.0.0):c1) Uninverting(_a(8.0.0):c7) Uninverting(_b(8.0.0):c1) Uninverting(_c(8.0.0):c5) Uninverting(_e(8.0.0):c1) Uninverting(_f(8.0.0):c1)))}
   [junit4]   2> 302777 INFO  (commitScheduler-600-thread-1) [    ] o.a.s.u.DirectUpdateHandler2 start commit{,optimize=false,openSearcher=false,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
   [junit4]   2> 302777 INFO  (commitScheduler-600-thread-1) [    ] o.a.s.u.SolrIndexWriter Calling setCommitData with IW:org.apache.solr.update.SolrIndexWriter@39a2b3f2 commitCommandVersion:0
   [junit4]   2> 302781 INFO  (commitScheduler-600-thread-1) [    ] o.a.s.s.SolrIndexSearcher Opening [Searcher@9e0418[collection1] realtime]
   [junit4]   2> 303077 INFO  (TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeMixedAdds-seed#[221449B83BEEB73D]) [    ] o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=null path=null params={}{add=[530 (1604571292397207552)]} 0 297
   [junit4]   2> 303080 INFO  (commitScheduler-600-thread-1) [    ] o.a.s.u.DirectUpdateHandler2 end_commit_flush
   [junit4]   2> 303577 INFO  (commitScheduler-601-thread-1) [    ] o.a.s.u.DirectUpdateHandler2 start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=true,prepareCommit=false}
   [junit4]   2> 303631 INFO  (commitScheduler-601-thread-1) [    ] o.a.s.s.SolrIndexSearcher Opening [Searcher@3c720527[collection1] main]
   [junit4]   2> 303635 INFO  (searcherExecutor-597-thread-1) [    ] o.a.s.c.SolrCore [collection1] Registered new searcher Searcher@3c720527[collection1] main{ExitableDirectoryReader(UninvertingDirectoryReader(Uninverting(_6(8.0.0):c1) Uninverting(_a(8.0.0):c7) Uninverting(_b(8.0.0):c1) Uninverting(_c(8.0.0):c5) Uninverting(_f(8.0.0):c1) Uninverting(_g(8.0.0):c1)))}
   [junit4]   2> 303636 INFO  (commitScheduler-601-thread-1) [    ] o.a.s.u.DirectUpdateHandler2 end_commit_flush
   [junit4]   2> 304277 INFO  (commitScheduler-600-thread-1) [    ] o.a.s.u.DirectUpdateHandler2 start commit{,optimize=false,openSearcher=false,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
   [junit4]   2> 304277 INFO  (commitScheduler-600-thread-1) [    ] o.a.s.u.SolrIndexWriter Calling setCommitData with IW:org.apache.solr.update.SolrIndexWriter@39a2b3f2 commitCommandVersion:0
   [junit4]   2> 304281 INFO  (commitScheduler-600-thread-1) [    ] o.a.s.s.SolrIndexSearcher Opening [Searcher@4a2a222c[collection1] realtime]
   [junit4]   2> 304294 INFO  (commitScheduler-600-thread-1) [    ] o.a.s.u.DirectUpdateHandler2 end_commit_flush
   [junit4]   2> 305281 INFO  (TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeMixedAdds-seed#[221449B83BEEB73D]) [    ] o.a.s.SolrTestCaseJ4 ###Ending testSoftAndHardCommitMaxTimeMixedAdds
   [junit4]   2> 305281 INFO  (SUITE-SoftAutoCommitTest-seed#[221449B83BEEB73D]-worker) [    ] o.a.s.SolrTestCaseJ4 ###deleteCore
   [junit4]   2> 305281 INFO  (SUITE-SoftAutoCommitTest-seed#[221449B83BEEB73D]-worker) [    ] o.a.s.c.CoreContainer Shutting down CoreContainer instance=239689303
   [junit4]   2> 305282 INFO  (SUITE-SoftAutoCommitTest-seed#[221449B83BEEB73D]-worker) [    ] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.node, tag=null
   [junit4]   2> 305282 INFO  (SUITE-SoftAutoCommitTest-seed#[221449B83BEEB73D]-worker) [    ] o.a.s.m.r.SolrJmxReporter Closing reporter [org.apache.solr.metrics.reporters.SolrJmxReporter@3ce46880: rootName = null, domain = solr.node, service url = null, agent id = null] for registry solr.node / com.codahale.metrics.MetricRegistry@4c11852
   [junit4]   2> 305287 INFO  (SUITE-SoftAutoCommitTest-seed#[221449B83BEEB73D]-worker) [    ] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.jvm, tag=null
   [junit4]   2> 305287 INFO  (SUITE-SoftAutoCommitTest-seed#[221449B83BEEB73D]-worker) [    ] o.a.s.m.r.SolrJmxReporter Closing reporter [org.apache.solr.metrics.reporters.SolrJmxReporter@72d7e9a8: rootName = null, domain = solr.jvm, service url = null, agent id = null] for registry solr.jvm / com.codahale.metrics.MetricRegistry@3630e2f1
   [junit4]   2> 305300 INFO  (SUITE-SoftAutoCommitTest-seed#[221449B83BEEB73D]-worker) [    ] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.jetty, tag=null
   [junit4]   2> 305300 INFO  (SUITE-SoftAutoCommitTest-seed#[221449B83BEEB73D]-worker) [    ] o.a.s.m.r.SolrJmxReporter Closing reporter [org.apache.solr.metrics.reporters.SolrJmxReporter@efca438: rootName = null, domain = solr.jetty, service url = null, agent id = null] for registry solr.jetty / com.codahale.metrics.MetricRegistry@744eb17a
   [junit4]   2> 305308 INFO  (coreCloseExecutor-602-thread-1) [    x:collection1] o.a.s.c.SolrCore [collection1]  CLOSING SolrCore org.apache.solr.core.SolrCore@7af5cc53
   [junit4]   2> 305308 INFO  (coreCloseExecutor-602-thread-1) [    x:collection1] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.core.collection1, tag=7af5cc53
   [junit4]   2> 305308 INFO  (coreCloseExecutor-602-thread-1) [    x:collection1] o.a.s.m.r.SolrJmxReporter Closing reporter [org.apache.solr.metrics.reporters.SolrJmxReporter@1f0d8a13: rootName = null, domain = solr.core.collection1, service url = null, agent id = null] for registry solr.core.collection1 / com.codahale.metrics.MetricRegistry@36f9ec5f
   [junit4]   2> NOTE: leaving temporary files on disk at: /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-master/checkout/solr/build/solr-core/test/J2/temp/solr.update.SoftAutoCommitTest_221449B83BEEB73D-001
   [junit4]   2> Jun 29, 2018 2:13:53 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(Lucene70): {multiDefault=Lucene50(blocksize=128), subject=Lucene50(blocksize=128), id=Lucene50(blocksize=128), text=PostingsFormat(name=LuceneVarGapFixedInterval)}, docValues:{range_facet_l_dv=DocValuesFormat(name=Asserting), _version_=DocValuesFormat(name=Lucene70), range_facet_i_dv=DocValuesFormat(name=Lucene70), intDvoDefault=DocValuesFormat(name=Direct), timestamp=DocValuesFormat(name=Lucene70)}, maxPointsInLeafNode=1299, maxMBSortInHeap=7.2165144308939855, sim=Asserting(org.apache.lucene.search.similarities.AssertingSimilarity@665a524a), locale=nl-BE, timezone=Etc/GMT+10
   [junit4]   2> NOTE: Linux 3.13.0-88-generic amd64/Oracle Corporation 1.8.0_172 (64-bit)/cpus=4,threads=1,free=263547528,total=477102080
   [junit4]   2> NOTE: All tests run in this JVM: [TestCSVResponseWriter, TestMiniSolrCloudClusterSSL, CircularListTest, SolrTestCaseJ4Test, BadComponentTest, TestSQLHandlerNonCloud, TestHalfAndHalfDocValues, AtomicUpdateProcessorFactoryTest, TestShardHandlerFactory, SoftAutoCommitTest]
   [junit4] Completed [50/820 (1!)] on J2 in 119.54s, 10 tests, 1 failure <<< FAILURES!

[...truncated 53183 lines...]
[asciidoctor:convert] asciidoctor: ERROR: about-this-guide.adoc: line 1: invalid part, must have at least one section (e.g., chapter, appendix, etc.)
[asciidoctor:convert] asciidoctor: ERROR: solr-glossary.adoc: line 1: invalid part, must have at least one section (e.g., chapter, appendix, etc.)
     [java] Processed 2240 links (1790 relative) to 3131 anchors in 247 files
     [echo] Validated Links & Anchors via: /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-master/checkout/solr/build/solr-ref-guide/bare-bones-html/

-documentation-lint:
    [jtidy] Checking for broken html (such as invalid tags)...
   [delete] Deleting directory /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-master/checkout/lucene/build/jtidy_tmp
     [echo] Checking for broken links...
     [exec] 
     [exec] Crawl/parse...
     [exec] 
     [exec] Verify...
     [echo] Checking for malformed docs...

jar-checksums:

resolve:

ivy-availability-check:
[loadresource] Do not set property disallowed.ivy.jars.list as its length is 0.

-ivy-fail-disallowed-ivy-version:

ivy-fail:

ivy-configure:
[ivy:configure] :: loading settings :: file = /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-master/checkout/lucene/top-level-ivy-settings.xml

resolve:

ivy-availability-check:
[loadresource] Do not set property disallowed.ivy.jars.list as its length is 0.

-ivy-fail-disallowed-ivy-version:

ivy-fail:

ivy-configure:
[ivy:configure] :: loading settings :: file = /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-master/checkout/lucene/top-level-ivy-settings.xml

resolve:

resolve:

ivy-availability-check:
[loadresource] Do not set property disallowed.ivy.jars.list as its length is 0.

-ivy-fail-disallowed-ivy-version:

ivy-fail:

ivy-configure:
[ivy:configure] :: loading settings :: file = /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-master/checkout/lucene/top-level-ivy-settings.xml

resolve:

ivy-availability-check:
[loadresource] Do not set property disallowed.ivy.jars.list as its length is 0.

-ivy-fail-disallowed-ivy-version:

ivy-fail:

ivy-configure:
[ivy:configure] :: loading settings :: file = /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-master/checkout/lucene/top-level-ivy-settings.xml

resolve:

ivy-availability-check:
[loadresource] Do not set property disallowed.ivy.jars.list as its length is 0.

-ivy-fail-disallowed-ivy-version:

ivy-fail:

ivy-configure:
[ivy:configure] :: loading settings :: file = /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-master/checkout/lucene/top-level-ivy-settings.xml

resolve:

ivy-availability-check:
[loadresource] Do not set property disallowed.ivy.jars.list as its length is 0.

-ivy-fail-disallowed-ivy-version:

ivy-fail:

ivy-configure:
[ivy:configure] :: loading settings :: file = /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-master/checkout/lucene/top-level-ivy-settings.xml

resolve:

ivy-availability-check:
[loadresource] Do not set property disallowed.ivy.jars.list as its length is 0.

-ivy-fail-disallowed-ivy-version:

ivy-fail:

ivy-configure:
[ivy:configure] :: loading settings :: file = /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-master/checkout/lucene/top-level-ivy-settings.xml

resolve:

ivy-availability-check:
[loadresource] Do not set property disallowed.ivy.jars.list as its length is 0.

-ivy-fail-disallowed-ivy-version:

ivy-fail:

ivy-configure:
[ivy:configure] :: loading settings :: file = /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-master/checkout/lucene/top-level-ivy-settings.xml

resolve:

ivy-availability-check:
[loadresource] Do not set property disallowed.ivy.jars.list as its length is 0.

-ivy-fail-disallowed-ivy-version:

ivy-fail:

ivy-configure:
[ivy:configure] :: loading settings :: file = /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-master/checkout/lucene/top-level-ivy-settings.xml

resolve:

ivy-availability-check:
[loadresource] Do not set property disallowed.ivy.jars.list as its length is 0.

-ivy-fail-disallowed-ivy-version:

ivy-fail:

ivy-configure:
[ivy:configure] :: loading settings :: file = /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-master/checkout/lucene/top-level-ivy-settings.xml

resolve:

ivy-availability-check:
[loadresource] Do not set property disallowed.ivy.jars.list as its length is 0.

-ivy-fail-disallowed-ivy-version:

ivy-fail:

ivy-configure:
[ivy:configure] :: loading settings :: file = /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-master/checkout/lucene/top-level-ivy-settings.xml

resolve:

ivy-availability-check:
[loadresource] Do not set property disallowed.ivy.jars.list as its length is 0.

-ivy-fail-disallowed-ivy-version:

ivy-fail:

ivy-configure:
[ivy:configure] :: loading settings :: file = /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-master/checkout/lucene/top-level-ivy-settings.xml

resolve:

ivy-availability-check:
[loadresource] Do not set property disallowed.ivy.jars.list as its length is 0.

-ivy-fail-disallowed-ivy-version:

ivy-fail:

ivy-configure:
[ivy:configure] :: loading settings :: file = /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-master/checkout/lucene/top-level-ivy-settings.xml

resolve:

ivy-availability-check:
[loadresource] Do not set property disallowed.ivy.jars.list as its length is 0.

-ivy-fail-disallowed-ivy-version:

ivy-fail:

ivy-configure:
[ivy:configure] :: loading settings :: file = /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-master/checkout/lucene/top-level-ivy-settings.xml

resolve:

ivy-availability-check:
[loadresource] Do not set property disallowed.ivy.jars.list as its length is 0.

-ivy-fail-disallowed-ivy-version:

ivy-fail:

ivy-configure:
[ivy:configure] :: loading settings :: file = /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-master/checkout/lucene/top-level-ivy-settings.xml

resolve:

ivy-availability-check:
[loadresource] Do not set property disallowed.ivy.jars.list as its length is 0.

-ivy-fail-disallowed-ivy-version:

ivy-fail:

ivy-configure:
[ivy:configure] :: loading settings :: file = /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-master/checkout/lucene/top-level-ivy-settings.xml

resolve:

ivy-availability-check:
[loadresource] Do not set property disallowed.ivy.jars.list as its length is 0.

-ivy-fail-disallowed-ivy-version:

ivy-fail:

ivy-configure:
[ivy:configure] :: loading settings :: file = /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-master/checkout/lucene/top-level-ivy-settings.xml

resolve:

ivy-availability-check:
[loadresource] Do not set property disallowed.ivy.jars.list as its length is 0.

-ivy-fail-disallowed-ivy-version:

ivy-fail:

ivy-configure:
[ivy:configure] :: loading settings :: file = /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-master/checkout/lucene/top-level-ivy-settings.xml

resolve:

ivy-availability-check:
[loadresource] Do not set property disallowed.ivy.jars.list as its length is 0.

-ivy-fail-disallowed-ivy-version:

ivy-fail:

ivy-configure:
[ivy:configure] :: loading settings :: file = /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-master/checkout/lucene/top-level-ivy-settings.xml

resolve:

ivy-availability-check:
[loadresource] Do not set property disallowed.ivy.jars.list as its length is 0.

-ivy-fail-disallowed-ivy-version:

ivy-fail:

ivy-configure:
[ivy:configure] :: loading settings :: file = /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-master/checkout/lucene/top-level-ivy-settings.xml

resolve:

ivy-availability-check:
[loadresource] Do not set property disallowed.ivy.jars.list as its length is 0.

-ivy-fail-disallowed-ivy-version:

ivy-fail:

ivy-configure:
[ivy:configure] :: loading settings :: file = /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-master/checkout/lucene/top-level-ivy-settings.xml

resolve:

ivy-availability-check:
[loadresource] Do not set property disallowed.ivy.jars.list as its length is 0.

-ivy-fail-disallowed-ivy-version:

ivy-fail:

ivy-configure:
[ivy:configure] :: loading settings :: file = /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-master/checkout/lucene/top-level-ivy-settings.xml

resolve:

ivy-availability-check:
[loadresource] Do not set property disallowed.ivy.jars.list as its length is 0.

-ivy-fail-disallowed-ivy-version:

ivy-fail:

ivy-configure:
[ivy:configure] :: loading settings :: file = /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-master/checkout/lucene/top-level-ivy-settings.xml

resolve:

ivy-availability-check:
[loadresource] Do not set property disallowed.ivy.jars.list as its length is 0.

-ivy-fail-disallowed-ivy-version:

ivy-fail:

ivy-configure:
[ivy:configure] :: loading settings :: file = /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-master/checkout/lucene/top-level-ivy-settings.xml

resolve:

ivy-availability-check:
[loadresource] Do not set property disallowed.ivy.jars.list as its length is 0.

-ivy-fail-disallowed-ivy-version:

ivy-fail:

ivy-configure:
[ivy:configure] :: loading settings :: file = /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-master/checkout/lucene/top-level-ivy-settings.xml

resolve:

ivy-availability-check:
[loadresource] Do not set property disallowed.ivy.jars.list as its length is 0.

-ivy-fail-disallowed-ivy-version:

ivy-fail:

ivy-configure:
[ivy:configure] :: loading settings :: file = /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-master/checkout/lucene/top-level-ivy-settings.xml

resolve:

ivy-availability-check:
[loadresource] Do not set property disallowed.ivy.jars.list as its length is 0.

-ivy-fail-disallowed-ivy-version:

ivy-fail:

ivy-configure:
[ivy:configure] :: loading settings :: file = /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-master/checkout/lucene/top-level-ivy-settings.xml

common.resolve:

resolve:

ivy-availability-check:
[loadresource] Do not set property disallowed.ivy.jars.list as its length is 0.

-ivy-fail-disallowed-ivy-version:

ivy-fail:

ivy-configure:
[ivy:configure] :: loading settings :: file = /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-master/checkout/lucene/top-level-ivy-settings.xml

resolve:

ivy-availability-check:
[loadresource] Do not set property disallowed.ivy.jars.list as its length is 0.

-ivy-fail-disallowed-ivy-version:

ivy-fail:

ivy-configure:
[ivy:configure] :: loading settings :: file = /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-master/checkout/lucene/top-level-ivy-settings.xml

resolve:

ivy-availability-check:
[loadresource] Do not set property disallowed.ivy.jars.list as its length is 0.

-ivy-fail-disallowed-ivy-version:

ivy-fail:

ivy-configure:
[ivy:configure] :: loading settings :: file = /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-master/checkout/lucene/top-level-ivy-settings.xml

resolve:

ivy-availability-check:
[loadresource] Do not set property disallowed.ivy.jars.list as its length is 0.

-ivy-fail-disallowed-ivy-version:

ivy-fail:

ivy-configure:
[ivy:configure] :: loading settings :: file = /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-master/checkout/lucene/top-level-ivy-settings.xml

resolve:

ivy-availability-check:
[loadresource] Do not set property disallowed.ivy.jars.list as its length is 0.

-ivy-fail-disallowed-ivy-version:

ivy-fail:

ivy-configure:
[ivy:configure] :: loading settings :: file = /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-master/checkout/lucene/top-level-ivy-settings.xml

resolve:

jar-checksums:
    [mkdir] Created dir: /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-master/checkout/lucene/null1454361856
     [copy] Copying 39 files to /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-master/checkout/lucene/null1454361856
   [delete] Deleting directory /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-master/checkout/lucene/null1454361856

resolve-example:

ivy-availability-check:
[loadresource] Do not set property disallowed.ivy.jars.list as its length is 0.

-ivy-fail-disallowed-ivy-version:

ivy-fail:

ivy-configure:
[ivy:configure] :: loading settings :: file = /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-master/checkout/lucene/top-level-ivy-settings.xml

resolve:

resolve-server:

ivy-availability-check:
[loadresource] Do not set property disallowed.ivy.jars.list as its length is 0.

-ivy-fail-disallowed-ivy-version:

ivy-fail:

ivy-fail:

ivy-configure:
[ivy:configure] :: loading settings :: file = /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-master/checkout/lucene/top-level-ivy-settings.xml

resolve:

resolve:

ivy-availability-check:
[loadresource] Do not set property disallowed.ivy.jars.list as its length is 0.

-ivy-fail-disallowed-ivy-version:

ivy-fail:

ivy-fail:

ivy-configure:
[ivy:configure] :: loading settings :: file = /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-master/checkout/lucene/top-level-ivy-settings.xml

resolve:

ivy-availability-check:
[loadresource] Do not set property disallowed.ivy.jars.list as its length is 0.

-ivy-fail-disallowed-ivy-version:

ivy-fail:

ivy-fail:

ivy-configure:
[ivy:configure] :: loading settings :: file = /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-master/checkout/lucene/top-level-ivy-settings.xml

resolve:

ivy-availability-check:
[loadresource] Do not set property disallowed.ivy.jars.list as its length is 0.

-ivy-fail-disallowed-ivy-version:

ivy-fail:

ivy-configure:
[ivy:configure] :: loading settings :: file = /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-master/checkout/lucene/top-level-ivy-settings.xml

resolve:

ivy-availability-check:
[loadresource] Do not set property disallowed.ivy.jars.list as its length is 0.

-ivy-fail-disallowed-ivy-version:

ivy-fail:

ivy-fail:

ivy-configure:
[ivy:configure] :: loading settings :: file = /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-master/checkout/lucene/top-level-ivy-settings.xml

resolve:

ivy-availability-check:
[loadresource] Do not set property disallowed.ivy.jars.list as its length is 0.

-ivy-fail-disallowed-ivy-version:

ivy-fail:

ivy-configure:
[ivy:configure] :: loading settings :: file = /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-master/checkout/lucene/top-level-ivy-settings.xml

resolve:

ivy-availability-check:
[loadresource] Do not set property disallowed.ivy.jars.list as its length is 0.

-ivy-fail-disallowed-ivy-version:

ivy-fail:

ivy-fail:

ivy-configure:
[ivy:configure] :: loading settings :: file = /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-master/checkout/lucene/top-level-ivy-settings.xml

resolve:

ivy-availability-check:
[loadresource] Do not set property disallowed.ivy.jars.list as its length is 0.

-ivy-fail-disallowed-ivy-version:

ivy-fail:

ivy-fail:

ivy-configure:
[ivy:configure] :: loading settings :: file = /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-master/checkout/lucene/top-level-ivy-settings.xml

resolve:

ivy-availability-check:
[loadresource] Do not set property disallowed.ivy.jars.list as its length is 0.

-ivy-fail-disallowed-ivy-version:

ivy-fail:

ivy-fail:

ivy-configure:
[ivy:configure] :: loading settings :: file = /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-master/checkout/lucene/top-level-ivy-settings.xml

resolve:

ivy-availability-check:
[loadresource] Do not set property disallowed.ivy.jars.list as its length is 0.

-ivy-fail-disallowed-ivy-version:

ivy-fail:

ivy-fail:

ivy-configure:
[ivy:configure] :: loading settings :: file = /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-master/checkout/lucene/top-level-ivy-settings.xml

resolve:

ivy-availability-check:
[loadresource] Do not set property disallowed.ivy.jars.list as its length is 0.

-ivy-fail-disallowed-ivy-version:

ivy-fail:

ivy-fail:

ivy-configure:
[ivy:configure] :: loading settings :: file = /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-master/checkout/lucene/top-level-ivy-settings.xml

resolve:

ivy-availability-check:
[loadresource] Do not set property disallowed.ivy.jars.list as its length is 0.

-ivy-fail-disallowed-ivy-version:

ivy-fail:

ivy-fail:

ivy-configure:
[ivy:configure] :: loading settings :: file = /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-master/checkout/lucene/top-level-ivy-settings.xml

resolve:

ivy-availability-check:
[loadresource] Do not set property disallowed.ivy.jars.list as its length is 0.

-ivy-fail-disallowed-ivy-version:

ivy-fail:

ivy-fail:

ivy-configure:
[ivy:configure] :: loading settings :: file = /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-master/checkout/lucene/top-level-ivy-settings.xml

resolve:

ivy-availability-check:
[loadresource] Do not set property disallowed.ivy.jars.list as its length is 0.

-ivy-fail-disallowed-ivy-version:

ivy-fail:

ivy-fail:

ivy-configure:
[ivy:configure] :: loading settings :: file = /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-master/checkout/lucene/top-level-ivy-settings.xml

resolve:

ivy-availability-check:
[loadresource] Do not set property disallowed.ivy.jars.list as its length is 0.

-ivy-fail-disallowed-ivy-version:

ivy-fail:

ivy-fail:

ivy-configure:
[ivy:configure] :: loading settings :: file = /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-master/checkout/lucene/top-level-ivy-settings.xml

resolve:

ivy-availability-check:
[loadresource] Do not set property disallowed.ivy.jars.list as its length is 0.

-ivy-fail-disallowed-ivy-version:

ivy-fail:

ivy-fail:

ivy-configure:
[ivy:configure] :: loading settings :: file = /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-master/checkout/lucene/top-level-ivy-settings.xml

resolve:

ivy-availability-check:
[loadresource] Do not set property disallowed.ivy.jars.list as its length is 0.

-ivy-fail-disallowed-ivy-version:

ivy-fail:

ivy-fail:

ivy-configure:
[ivy:configure] :: loading settings :: file = /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-master/checkout/lucene/top-level-ivy-settings.xml

resolve:

jar-checksums:
    [mkdir] Created dir: /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-master/checkout/solr/null913843064
     [copy] Copying 247 files to /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-master/checkout/solr/null913843064
   [delete] Deleting directory /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-master/checkout/solr/null913843064

check-working-copy:
[ivy:cachepath] :: resolving dependencies :: org.eclipse.jgit#org.eclipse.jgit-caller;working
[ivy:cachepath] 	confs: [default]
[ivy:cachepath] 	found org.eclipse.jgit#org.eclipse.jgit;4.6.0.201612231935-r in public
[ivy:cachepath] 	found com.jcraft#jsch;0.1.53 in public
[ivy:cachepath] 	found com.googlecode.javaewah#JavaEWAH;1.1.6 in public
[ivy:cachepath] 	found org.apache.httpcomponents#httpclient;4.3.6 in public
[ivy:cachepath] 	found org.apache.httpcomponents#httpcore;4.3.3 in public
[ivy:cachepath] 	found commons-logging#commons-logging;1.1.3 in public
[ivy:cachepath] 	found commons-codec#commons-codec;1.6 in public
[ivy:cachepath] 	found org.slf4j#slf4j-api;1.7.2 in public
[ivy:cachepath] :: resolution report :: resolve 62ms :: artifacts dl 11ms
	---------------------------------------------------------------------
	|                  |            modules            ||   artifacts   |
	|       conf       | number| search|dwnlded|evicted|| number|dwnlded|
	---------------------------------------------------------------------
	|      default     |   8   |   0   |   0   |   0   ||   8   |   0   |
	---------------------------------------------------------------------
[wc-checker] Initializing working copy...
[wc-checker] SLF4J: Failed to load class "org.slf4j.impl.StaticLoggerBinder".
[wc-checker] SLF4J: Defaulting to no-operation (NOP) logger implementation
[wc-checker] SLF4J: See http://www.slf4j.org/codes.html#StaticLoggerBinder for further details.
[wc-checker] Checking working copy status...

-jenkins-base:

BUILD SUCCESSFUL
Total time: 392 minutes 50 seconds
Archiving artifacts
WARN: No artifacts found that match the file pattern "**/*.events,heapdumps/**,**/hs_err_pid*". Configuration error?
WARN: java.lang.InterruptedException: no matches found within 10000
Recording test results
Build step 'Publish JUnit test result report' changed build result to UNSTABLE
Email was triggered for: Unstable (Test Failures)
Sending email for trigger: Unstable (Test Failures)