You are viewing a plain text version of this content. The canonical link for it is here.
Posted to builds@lucene.apache.org by Apache Jenkins Server <je...@builds.apache.org> on 2020/05/05 05:31:19 UTC
[JENKINS] Lucene-Solr-Tests-8.x - Build # 1486 - Unstable
Build: https://builds.apache.org/job/Lucene-Solr-Tests-8.x/1486/
1 tests failed.
FAILED: org.apache.solr.update.SoftAutoCommitTest.testHardCommitWithinAndSoftCommitMaxTimeMixedAdds
Error Message:
soft529 wasn't fast enough
Stack Trace:
java.lang.AssertionError: soft529 wasn't fast enough
at __randomizedtesting.SeedInfo.seed([E18D0666487F85D3:226ADA77794352AE]:0)
at org.junit.Assert.fail(Assert.java:88)
at org.junit.Assert.assertTrue(Assert.java:41)
at org.junit.Assert.assertNotNull(Assert.java:712)
at org.apache.solr.update.SoftAutoCommitTest.doTestSoftAndHardCommitMaxTimeMixedAdds(SoftAutoCommitTest.java:209)
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:1750)
at com.carrotsearch.randomizedtesting.RandomizedRunner$8.evaluate(RandomizedRunner.java:938)
at com.carrotsearch.randomizedtesting.RandomizedRunner$9.evaluate(RandomizedRunner.java:974)
at com.carrotsearch.randomizedtesting.RandomizedRunner$10.evaluate(RandomizedRunner.java:988)
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:947)
at com.carrotsearch.randomizedtesting.RandomizedRunner$5.evaluate(RandomizedRunner.java:832)
at com.carrotsearch.randomizedtesting.RandomizedRunner$6.evaluate(RandomizedRunner.java:883)
at com.carrotsearch.randomizedtesting.RandomizedRunner$7.evaluate(RandomizedRunner.java:894)
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 16211 lines...]
[junit4] Suite: org.apache.solr.update.SoftAutoCommitTest
[junit4] 2> 4532269 INFO (SUITE-SoftAutoCommitTest-seed#[E18D0666487F85D3]-worker) [ ] o.a.s.SolrTestCase Setting 'solr.default.confdir' system property to test-framework derived value of '/home/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-8.x/solr/server/solr/configsets/_default/conf'
[junit4] 2> 4532270 INFO (SUITE-SoftAutoCommitTest-seed#[E18D0666487F85D3]-worker) [ ] o.a.s.SolrTestCaseJ4 Created dataDir: /home/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-8.x/solr/build/solr-core/test/J1/temp/solr.update.SoftAutoCommitTest_E18D0666487F85D3-001/data-dir-242-001
[junit4] 2> 4532270 WARN (SUITE-SoftAutoCommitTest-seed#[E18D0666487F85D3]-worker) [ ] o.a.s.SolrTestCaseJ4 startTrackingSearchers: numOpens=1 numCloses=1
[junit4] 2> 4532270 INFO (SUITE-SoftAutoCommitTest-seed#[E18D0666487F85D3]-worker) [ ] o.a.s.SolrTestCaseJ4 Using PointFields (NUMERIC_POINTS_SYSPROP=true) w/NUMERIC_DOCVALUES_SYSPROP=false
[junit4] 2> 4532272 INFO (SUITE-SoftAutoCommitTest-seed#[E18D0666487F85D3]-worker) [ ] o.a.s.SolrTestCaseJ4 Randomized ssl (true) and clientAuth (false) via: @org.apache.solr.util.RandomizeSSL(reason=, ssl=NaN, value=NaN, clientAuth=NaN)
[junit4] 2> 4532272 INFO (SUITE-SoftAutoCommitTest-seed#[E18D0666487F85D3]-worker) [ ] o.a.s.SolrTestCaseJ4 SecureRandom sanity checks: test.solr.allowed.securerandom=null & java.security.egd=file:/dev/./urandom
[junit4] 2> 4532272 INFO (SUITE-SoftAutoCommitTest-seed#[E18D0666487F85D3]-worker) [ ] o.a.s.SolrTestCaseJ4 ####initCore
[junit4] 2> 4532292 INFO (SUITE-SoftAutoCommitTest-seed#[E18D0666487F85D3]-worker) [ ] o.a.s.c.SolrConfig Using Lucene MatchVersion: 8.6.0
[junit4] 2> 4532326 INFO (SUITE-SoftAutoCommitTest-seed#[E18D0666487F85D3]-worker) [ ] o.a.s.s.IndexSchema Schema name=test
[junit4] 2> 4532456 INFO (SUITE-SoftAutoCommitTest-seed#[E18D0666487F85D3]-worker) [ ] o.a.s.s.IndexSchema Loaded schema test/1.0 with uniqueid field id
[junit4] 2> 4533438 WARN (SUITE-SoftAutoCommitTest-seed#[E18D0666487F85D3]-worker) [ ] o.a.s.f.DistribPackageStore Unable to create [/home/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-8.x/solr/core/src/test-files/solr/filestore] directory in SOLR_HOME [/home/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-8.x/solr/core/src/test-files/solr]. Features requiring this directory may fail.
[junit4] 2> => java.security.AccessControlException: access denied ("java.io.FilePermission" "/home/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-8.x/solr/core/src/test-files/solr/filestore" "write")
[junit4] 2> at java.security.AccessControlContext.checkPermission(AccessControlContext.java:472)
[junit4] 2> java.security.AccessControlException: access denied ("java.io.FilePermission" "/home/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-8.x/solr/core/src/test-files/solr/filestore" "write")
[junit4] 2> at java.security.AccessControlContext.checkPermission(AccessControlContext.java:472) ~[?:1.8.0_191]
[junit4] 2> at java.security.AccessController.checkPermission(AccessController.java:884) ~[?:1.8.0_191]
[junit4] 2> at java.lang.SecurityManager.checkPermission(SecurityManager.java:549) ~[?:1.8.0_191]
[junit4] 2> at java.lang.SecurityManager.checkWrite(SecurityManager.java:979) ~[?:1.8.0_191]
[junit4] 2> at java.io.File.mkdir(File.java:1311) ~[?:1.8.0_191]
[junit4] 2> at java.io.File.mkdirs(File.java:1343) ~[?:1.8.0_191]
[junit4] 2> at org.apache.solr.filestore.DistribPackageStore.ensurePackageStoreDir(DistribPackageStore.java:520) ~[java/:?]
[junit4] 2> at org.apache.solr.filestore.DistribPackageStore.<init>(DistribPackageStore.java:77) ~[java/:?]
[junit4] 2> at org.apache.solr.filestore.PackageStoreAPI.<init>(PackageStoreAPI.java:79) ~[java/:?]
[junit4] 2> at org.apache.solr.core.CoreContainer.load(CoreContainer.java:613) ~[java/:?]
[junit4] 2> at org.apache.solr.util.TestHarness.<init>(TestHarness.java:170) ~[java/:?]
[junit4] 2> at org.apache.solr.util.TestHarness.<init>(TestHarness.java:142) ~[java/:?]
[junit4] 2> at org.apache.solr.util.TestHarness.<init>(TestHarness.java:148) ~[java/:?]
[junit4] 2> at org.apache.solr.util.TestHarness.<init>(TestHarness.java:111) ~[java/:?]
[junit4] 2> at org.apache.solr.SolrTestCaseJ4.createCore(SolrTestCaseJ4.java:813) ~[java/:?]
[junit4] 2> at org.apache.solr.SolrTestCaseJ4.initCore(SolrTestCaseJ4.java:803) ~[java/:?]
[junit4] 2> at org.apache.solr.SolrTestCaseJ4.initCore(SolrTestCaseJ4.java:664) ~[java/:?]
[junit4] 2> at org.apache.solr.SolrTestCaseJ4.initCore(SolrTestCaseJ4.java:653) ~[java/:?]
[junit4] 2> at org.apache.solr.update.SoftAutoCommitTest.beforeClass(SoftAutoCommitTest.java:66) ~[test/:?]
[junit4] 2> at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method) ~[?:1.8.0_191]
[junit4] 2> at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62) ~[?:1.8.0_191]
[junit4] 2> at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) ~[?:1.8.0_191]
[junit4] 2> at java.lang.reflect.Method.invoke(Method.java:498) ~[?:1.8.0_191]
[junit4] 2> at com.carrotsearch.randomizedtesting.RandomizedRunner.invoke(RandomizedRunner.java:1750) ~[randomizedtesting-runner-2.7.2.jar:?]
[junit4] 2> at com.carrotsearch.randomizedtesting.RandomizedRunner$6.evaluate(RandomizedRunner.java:878) ~[randomizedtesting-runner-2.7.2.jar:?]
[junit4] 2> at com.carrotsearch.randomizedtesting.RandomizedRunner$7.evaluate(RandomizedRunner.java:894) ~[randomizedtesting-runner-2.7.2.jar:?]
[junit4] 2> at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36) ~[randomizedtesting-runner-2.7.2.jar:?]
[junit4] 2> at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:57) ~[randomizedtesting-runner-2.7.2.jar:?]
[junit4] 2> at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:45) ~[java/:?]
[junit4] 2> at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36) ~[randomizedtesting-runner-2.7.2.jar:?]
[junit4] 2> at org.apache.lucene.util.TestRuleStoreClassName$1.evaluate(TestRuleStoreClassName.java:41) ~[java/:?]
[junit4] 2> at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:40) ~[randomizedtesting-runner-2.7.2.jar:?]
[junit4] 2> at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:40) ~[randomizedtesting-runner-2.7.2.jar:?]
[junit4] 2> at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36) ~[randomizedtesting-runner-2.7.2.jar:?]
[junit4] 2> at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36) ~[randomizedtesting-runner-2.7.2.jar:?]
[junit4] 2> at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36) ~[randomizedtesting-runner-2.7.2.jar:?]
[junit4] 2> at org.apache.lucene.util.TestRuleAssertionsRequired$1.evaluate(TestRuleAssertionsRequired.java:53) ~[java/:?]
[junit4] 2> at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:47) ~[java/:?]
[junit4] 2> at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:64) ~[java/:?]
[junit4] 2> at org.apache.lucene.util.TestRuleIgnoreTestSuites$1.evaluate(TestRuleIgnoreTestSuites.java:54) ~[java/:?]
[junit4] 2> at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36) ~[randomizedtesting-runner-2.7.2.jar:?]
[junit4] 2> at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:368) ~[randomizedtesting-runner-2.7.2.jar:?]
[junit4] 2> at java.lang.Thread.run(Thread.java:748) [?:1.8.0_191]
[junit4] 2> 4533439 INFO (SUITE-SoftAutoCommitTest-seed#[E18D0666487F85D3]-worker) [ ] o.a.s.h.c.HttpShardHandlerFactory Host whitelist initialized: WhitelistHostChecker [whitelistHosts=null, whitelistHostCheckingEnabled=true]
[junit4] 2> 4533439 WARN (SUITE-SoftAutoCommitTest-seed#[E18D0666487F85D3]-worker) [ ] o.a.s.c.s.i.Http2SolrClient Create Http2SolrClient with HTTP/1.1 transport since Java 8 or lower versions does not support SSL + HTTP/2
[junit4] 2> 4533440 WARN (SUITE-SoftAutoCommitTest-seed#[E18D0666487F85D3]-worker) [ ] o.e.j.u.s.S.config Trusting all certificates configured for Client@51e1049c[provider=null,keyStore=null,trustStore=null]
[junit4] 2> 4533440 WARN (SUITE-SoftAutoCommitTest-seed#[E18D0666487F85D3]-worker) [ ] o.e.j.u.s.S.config No Client EndPointIdentificationAlgorithm configured for Client@51e1049c[provider=null,keyStore=null,trustStore=null]
[junit4] 2> 4533442 WARN (SUITE-SoftAutoCommitTest-seed#[E18D0666487F85D3]-worker) [ ] o.a.s.c.s.i.Http2SolrClient Create Http2SolrClient with HTTP/1.1 transport since Java 8 or lower versions does not support SSL + HTTP/2
[junit4] 2> 4533443 WARN (SUITE-SoftAutoCommitTest-seed#[E18D0666487F85D3]-worker) [ ] o.e.j.u.s.S.config Trusting all certificates configured for Client@500daba[provider=null,keyStore=null,trustStore=null]
[junit4] 2> 4533443 WARN (SUITE-SoftAutoCommitTest-seed#[E18D0666487F85D3]-worker) [ ] o.e.j.u.s.S.config No Client EndPointIdentificationAlgorithm configured for Client@500daba[provider=null,keyStore=null,trustStore=null]
[junit4] 2> 4533444 WARN (SUITE-SoftAutoCommitTest-seed#[E18D0666487F85D3]-worker) [ ] o.a.s.c.CoreContainer Not all security plugins configured! authentication=disabled authorization=disabled. Solr is only as secure as you make it. Consider configuring authentication/authorization before exposing Solr to users internal or external. See https://s.apache.org/solrsecurity for more info
[junit4] 2> 4533463 INFO (SUITE-SoftAutoCommitTest-seed#[E18D0666487F85D3]-worker) [ ] o.a.s.c.TransientSolrCoreCacheDefault Allocating transient cache for 2147483647 transient cores
[junit4] 2> 4533463 INFO (SUITE-SoftAutoCommitTest-seed#[E18D0666487F85D3]-worker) [ ] o.a.s.h.a.MetricsHistoryHandler No .system collection, keeping metrics history in memory.
[junit4] 2> 4533488 INFO (SUITE-SoftAutoCommitTest-seed#[E18D0666487F85D3]-worker) [ ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr.node' (registry 'solr.node') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@1ac74495
[junit4] 2> 4533499 INFO (SUITE-SoftAutoCommitTest-seed#[E18D0666487F85D3]-worker) [ ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr.jvm' (registry 'solr.jvm') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@1ac74495
[junit4] 2> 4533499 INFO (SUITE-SoftAutoCommitTest-seed#[E18D0666487F85D3]-worker) [ ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr.jetty' (registry 'solr.jetty') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@1ac74495
[junit4] 2> 4533511 INFO (coreLoadExecutor-28735-thread-1) [ x:collection1 ] o.a.s.c.SolrConfig Using Lucene MatchVersion: 8.6.0
[junit4] 2> 4533545 INFO (coreLoadExecutor-28735-thread-1) [ x:collection1 ] o.a.s.s.IndexSchema Schema name=test
[junit4] 2> 4533682 INFO (coreLoadExecutor-28735-thread-1) [ x:collection1 ] o.a.s.s.IndexSchema Loaded schema test/1.0 with uniqueid field id
[junit4] 2> 4533690 INFO (coreLoadExecutor-28735-thread-1) [ x:collection1 ] o.a.s.c.CoreContainer Creating SolrCore 'collection1' using configuration from instancedir /home/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-8.x/solr/core/src/test-files/solr/collection1, trusted=true
[junit4] 2> 4533691 INFO (coreLoadExecutor-28735-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@1ac74495
[junit4] 2> 4533691 INFO (coreLoadExecutor-28735-thread-1) [ x:collection1 ] o.a.s.c.SolrCore [[collection1] ] Opening new SolrCore at [/home/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-8.x/solr/core/src/test-files/solr/collection1], dataDir=[/home/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-8.x/solr/build/solr-core/test/J1/temp/solr.update.SoftAutoCommitTest_E18D0666487F85D3-001/data-dir-242-001/]
[junit4] 2> 4533692 INFO (coreLoadExecutor-28735-thread-1) [ x:collection1 ] o.a.s.u.RandomMergePolicy RandomMergePolicy wrapping class org.apache.lucene.index.MockRandomMergePolicy: org.apache.lucene.index.MockRandomMergePolicy@30b8f3f1
[junit4] 2> 4533762 INFO (coreLoadExecutor-28735-thread-1) [ x:collection1 ] o.a.s.u.UpdateHandler Using UpdateLog implementation: org.apache.solr.update.UpdateLog
[junit4] 2> 4533762 INFO (coreLoadExecutor-28735-thread-1) [ x:collection1 ] o.a.s.u.UpdateLog Initializing UpdateLog: dataDir= defaultSyncLevel=FLUSH numRecordsToKeep=100 maxNumLogsToKeep=10 numVersionBuckets=65536
[junit4] 2> 4533763 INFO (coreLoadExecutor-28735-thread-1) [ x:collection1 ] o.a.s.u.CommitTracker Hard AutoCommit: disabled
[junit4] 2> 4533763 INFO (coreLoadExecutor-28735-thread-1) [ x:collection1 ] o.a.s.u.CommitTracker Soft AutoCommit: disabled
[junit4] 2> 4533764 INFO (coreLoadExecutor-28735-thread-1) [ x:collection1 ] o.a.s.u.RandomMergePolicy RandomMergePolicy wrapping class org.apache.lucene.index.LogDocMergePolicy: [LogDocMergePolicy: minMergeSize=1000, mergeFactor=36, maxMergeSize=9223372036854775807, maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=false, maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.8868794081942736]
[junit4] 2> 4533765 INFO (coreLoadExecutor-28735-thread-1) [ x:collection1 ] o.a.s.s.SolrIndexSearcher Opening [Searcher@5d055e4b[collection1] main]
[junit4] 2> 4533765 INFO (coreLoadExecutor-28735-thread-1) [ x:collection1 ] o.a.s.h.c.SpellCheckComponent Initializing spell checkers
[junit4] 2> 4533779 INFO (coreLoadExecutor-28735-thread-1) [ x:collection1 ] o.a.s.s.DirectSolrSpellChecker init: {name=direct,classname=DirectSolrSpellChecker,field=lowerfilt,minQueryLength=3}
[junit4] 2> 4533821 INFO (coreLoadExecutor-28735-thread-1) [ x:collection1 ] o.a.s.h.ReplicationHandler Commits will be reserved for 10000 ms
[junit4] 2> 4533821 INFO (coreLoadExecutor-28735-thread-1) [ x:collection1 ] o.a.s.u.UpdateLog Could not find max version in index or recent updates, using new clock 1665825060431069184
[junit4] 2> 4533822 INFO (searcherExecutor-28737-thread-1-processing-x:collection1) [ x:collection1 ] o.a.s.h.c.SpellCheckComponent Loading spell index for spellchecker: default
[junit4] 2> 4533823 INFO (searcherExecutor-28737-thread-1-processing-x:collection1) [ x:collection1 ] o.a.s.h.c.SpellCheckComponent Loading spell index for spellchecker: direct
[junit4] 2> 4533823 INFO (searcherExecutor-28737-thread-1-processing-x:collection1) [ x:collection1 ] o.a.s.h.c.SpellCheckComponent Loading spell index for spellchecker: wordbreak
[junit4] 2> 4533823 INFO (searcherExecutor-28737-thread-1-processing-x:collection1) [ x:collection1 ] o.a.s.h.c.SpellCheckComponent Loading spell index for spellchecker: multipleFields
[junit4] 2> 4533823 INFO (searcherExecutor-28737-thread-1-processing-x:collection1) [ x:collection1 ] o.a.s.h.c.SpellCheckComponent Loading spell index for spellchecker: jarowinkler
[junit4] 2> 4533823 INFO (searcherExecutor-28737-thread-1-processing-x:collection1) [ x:collection1 ] o.a.s.h.c.SpellCheckComponent Loading spell index for spellchecker: external
[junit4] 2> 4533823 INFO (searcherExecutor-28737-thread-1-processing-x:collection1) [ x:collection1 ] o.a.s.h.c.SpellCheckComponent Loading spell index for spellchecker: freq
[junit4] 2> 4533824 INFO (searcherExecutor-28737-thread-1-processing-x:collection1) [ x:collection1 ] o.a.s.h.c.SpellCheckComponent Loading spell index for spellchecker: fqcn
[junit4] 2> 4533824 INFO (searcherExecutor-28737-thread-1-processing-x:collection1) [ x:collection1 ] o.a.s.h.c.SpellCheckComponent Loading spell index for spellchecker: perDict
[junit4] 2> 4533824 INFO (SUITE-SoftAutoCommitTest-seed#[E18D0666487F85D3]-worker) [ ] o.a.s.SolrTestCaseJ4 ####initCore end
[junit4] 2> 4533825 INFO (searcherExecutor-28737-thread-1-processing-x:collection1) [ x:collection1 ] o.a.s.c.SolrCore [collection1] Registered new searcher Searcher@5d055e4b[collection1] main{ExitableDirectoryReader(UninvertingDirectoryReader())}
[junit4] 2> 4533830 INFO (TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeMixedAdds-seed#[E18D0666487F85D3]) [ ] o.a.s.SolrTestCaseJ4 ###Starting testSoftAndHardCommitMaxTimeMixedAdds
[junit4] 2> 4542236 INFO (TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeMixedAdds-seed#[E18D0666487F85D3]) [ x:collection1 ] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=null path=null params={}{add=[529 (1665825069251690496)]} 0 2
[junit4] 2> 4542735 INFO (commitScheduler-28741-thread-1) [ ] o.a.s.u.DirectUpdateHandler2 start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=true,prepareCommit=false}
[junit4] 2> 4542739 INFO (commitScheduler-28741-thread-1) [ ] o.a.s.s.SolrIndexSearcher Opening [Searcher@3fbf28f5[collection1] main]
[junit4] 2> 4542740 INFO (commitScheduler-28741-thread-1) [ ] o.a.s.u.DirectUpdateHandler2 end_commit_flush
[junit4] 2> 4542745 INFO (searcherExecutor-28737-thread-1) [ ] o.a.s.c.SolrCore [collection1] Registered new searcher Searcher@3fbf28f5[collection1] main{ExitableDirectoryReader(UninvertingDirectoryReader(Uninverting(_0(8.6.0):c1:[diagnostics={os=Linux, java.vendor=Oracle Corporation, java.version=1.8.0_191, java.vm.version=25.191-b12, lucene.version=8.6.0, os.arch=amd64, java.runtime.version=1.8.0_191-b12, source=flush, os.version=4.4.0-170-generic, timestamp=1588654584676}]:[attributes={Lucene50StoredFieldsFormat.mode=BEST_SPEED}] :id=1d9hms8zzderb9bzx2xzh4dft)))}
[junit4] 2> 4543436 INFO (commitScheduler-28740-thread-1) [ ] o.a.s.u.DirectUpdateHandler2 start commit{,optimize=false,openSearcher=false,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4] 2> 4543436 INFO (commitScheduler-28740-thread-1) [ ] o.a.s.u.SolrIndexWriter Calling setCommitData with IW:org.apache.solr.update.SolrIndexWriter@73ad1c96 commitCommandVersion:0
[junit4] 2> 4543437 INFO (commitScheduler-28740-thread-1) [ ] o.a.s.s.SolrIndexSearcher Opening [Searcher@40b5c48d[collection1] realtime]
[junit4] 2> 4543438 INFO (commitScheduler-28740-thread-1) [ ] o.a.s.u.DirectUpdateHandler2 end_commit_flush
[junit4] 2> 4543439 INFO (TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeMixedAdds-seed#[E18D0666487F85D3]) [ x:collection1 ] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=null path=null params={}{add=[530 (1665825070515224576)]} 0 1
[junit4] 2> 4543939 INFO (commitScheduler-28741-thread-1) [ ] o.a.s.u.DirectUpdateHandler2 start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=true,prepareCommit=false}
[junit4] 2> 4543942 INFO (commitScheduler-28741-thread-1) [ ] o.a.s.s.SolrIndexSearcher Opening [Searcher@3a08503d[collection1] main]
[junit4] 2> 4543942 INFO (commitScheduler-28741-thread-1) [ ] o.a.s.u.DirectUpdateHandler2 end_commit_flush
[junit4] 2> 4543947 INFO (searcherExecutor-28737-thread-1) [ ] o.a.s.c.SolrCore [collection1] Registered new searcher Searcher@3a08503d[collection1] main{ExitableDirectoryReader(UninvertingDirectoryReader(Uninverting(_0(8.6.0):c1:[diagnostics={os=Linux, java.vendor=Oracle Corporation, java.version=1.8.0_191, java.vm.version=25.191-b12, lucene.version=8.6.0, os.arch=amd64, java.runtime.version=1.8.0_191-b12, source=flush, os.version=4.4.0-170-generic, timestamp=1588654584676}]:[attributes={Lucene50StoredFieldsFormat.mode=BEST_SPEED}] :id=1d9hms8zzderb9bzx2xzh4dft) Uninverting(_1(8.6.0):c1:[diagnostics={os=Linux, java.vendor=Oracle Corporation, java.version=1.8.0_191, java.vm.version=25.191-b12, lucene.version=8.6.0, os.arch=amd64, java.runtime.version=1.8.0_191-b12, source=flush, os.version=4.4.0-170-generic, timestamp=1588654585879}]:[attributes={Lucene50StoredFieldsFormat.mode=BEST_SPEED}] :id=1d9hms8zzderb9bzx2xzh4dfx)))}
[junit4] 2> 4544641 INFO (commitScheduler-28740-thread-1) [ ] o.a.s.u.DirectUpdateHandler2 start commit{,optimize=false,openSearcher=false,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4] 2> 4544641 INFO (commitScheduler-28740-thread-1) [ ] o.a.s.u.SolrIndexWriter Calling setCommitData with IW:org.apache.solr.update.SolrIndexWriter@73ad1c96 commitCommandVersion:0
[junit4] 2> 4544641 INFO (commitScheduler-28740-thread-1) [ ] o.a.s.s.SolrIndexSearcher Opening [Searcher@2d15db7c[collection1] realtime]
[junit4] 2> 4544641 INFO (commitScheduler-28740-thread-1) [ ] o.a.s.u.DirectUpdateHandler2 end_commit_flush
[junit4] 2> 4545642 INFO (TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeMixedAdds-seed#[E18D0666487F85D3]) [ ] o.a.s.SolrTestCaseJ4 ###Ending testSoftAndHardCommitMaxTimeMixedAdds
[junit4] 2> 4545648 INFO (TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxDocs-seed#[E18D0666487F85D3]) [ ] o.a.s.SolrTestCaseJ4 ###Starting testSoftAndHardCommitMaxDocs
[junit4] 2> 4553650 INFO (TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxDocs-seed#[E18D0666487F85D3]) [ x:collection1 ] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=null path=null params={}{add=[8000 (1665825081222234112)]} 0 1
[junit4] 2> 4553651 INFO (TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxDocs-seed#[E18D0666487F85D3]) [ x:collection1 ] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=null path=null params={}{add=[8001 (1665825081224331264)]} 0 0
[junit4] 2> 4553651 INFO (TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxDocs-seed#[E18D0666487F85D3]) [ x:collection1 ] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=null path=null params={}{add=[8002 (1665825081224331265)]} 0 0
[junit4] 2> 4553651 INFO (TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxDocs-seed#[E18D0666487F85D3]) [ x:collection1 ] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=null path=null params={}{add=[8003 (1665825081224331266)]} 0 0
[junit4] 2> 4553652 INFO (TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxDocs-seed#[E18D0666487F85D3]) [ x:collection1 ] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=null path=null params={}{add=[8004 (1665825081225379840)]} 0 0
[junit4] 2> 4553652 INFO (TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxDocs-seed#[E18D0666487F85D3]) [ x:collection1 ] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=null path=null params={}{add=[8005 (1665825081225379841)]} 0 0
[junit4] 2> 4553653 INFO (TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxDocs-seed#[E18D0666487F85D3]) [ x:collection1 ] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=null path=null params={}{add=[8006 (1665825081225379842)]} 0 0
[junit4] 2> 4553653 INFO (TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxDocs-seed#[E18D0666487F85D3]) [ x:collection1 ] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=null path=null params={}{add=[8007 (1665825081226428416)]} 0 0
[junit4] 2> 4553653 INFO (commitScheduler-28741-thread-1) [ ] o.a.s.u.DirectUpdateHandler2 start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=true,prepareCommit=false}
[junit4] 2> 4553654 INFO (commitScheduler-28740-thread-1) [ ] o.a.s.u.DirectUpdateHandler2 start commit{,optimize=false,openSearcher=false,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4] 2> 4553657 INFO (commitScheduler-28741-thread-1) [ ] o.a.s.s.SolrIndexSearcher Opening [Searcher@20dc6237[collection1] main]
[junit4] 2> 4553657 INFO (commitScheduler-28741-thread-1) [ ] o.a.s.u.DirectUpdateHandler2 end_commit_flush
[junit4] 2> 4553657 INFO (commitScheduler-28740-thread-1) [ ] o.a.s.u.SolrIndexWriter Calling setCommitData with IW:org.apache.solr.update.SolrIndexWriter@73ad1c96 commitCommandVersion:0
[junit4] 2> 4553670 INFO (searcherExecutor-28737-thread-1) [ ] o.a.s.c.SolrCore [collection1] Registered new searcher Searcher@20dc6237[collection1] main{ExitableDirectoryReader(UninvertingDirectoryReader(Uninverting(_0(8.6.0):c1:[diagnostics={os=Linux, java.vendor=Oracle Corporation, java.version=1.8.0_191, java.vm.version=25.191-b12, lucene.version=8.6.0, os.arch=amd64, java.runtime.version=1.8.0_191-b12, source=flush, os.version=4.4.0-170-generic, timestamp=1588654584676}]:[attributes={Lucene50StoredFieldsFormat.mode=BEST_SPEED}] :id=1d9hms8zzderb9bzx2xzh4dft) Uninverting(_1(8.6.0):c1:[diagnostics={os=Linux, java.vendor=Oracle Corporation, java.version=1.8.0_191, java.vm.version=25.191-b12, lucene.version=8.6.0, os.arch=amd64, java.runtime.version=1.8.0_191-b12, source=flush, os.version=4.4.0-170-generic, timestamp=1588654585879}]:[attributes={Lucene50StoredFieldsFormat.mode=BEST_SPEED}] :id=1d9hms8zzderb9bzx2xzh4dfx) Uninverting(_2(8.6.0):c8:[diagnostics={os=Linux, java.vendor=Oracle Corporation, java.version=1.8.0_191, java.vm.version=25.191-b12, lucene.version=8.6.0, os.arch=amd64, java.runtime.version=1.8.0_191-b12, source=flush, os.version=4.4.0-170-generic, timestamp=1588654595593}]:[attributes={Lucene50StoredFieldsFormat.mode=BEST_SPEED}] :id=1d9hms8zzderb9bzx2xzh4dg1)))}
[junit4] 2> 4553670 INFO (commitScheduler-28740-thread-1) [ ] o.a.s.s.SolrIndexSearcher Opening [Searcher@52281ec7[collection1] realtime]
[junit4] 2> 4553671 INFO (commitScheduler-28740-thread-1) [ ] o.a.s.u.DirectUpdateHandler2 end_commit_flush
[junit4] 2> 4554658 INFO (TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxDocs-seed#[E18D0666487F85D3]) [ ] o.a.s.SolrTestCaseJ4 ###Ending testSoftAndHardCommitMaxDocs
[junit4] 2> 4554665 INFO (TEST-SoftAutoCommitTest.testSoftCommitWithinAndHardCommitMaxTimeRapidAdds-seed#[E18D0666487F85D3]) [ ] o.a.s.SolrTestCaseJ4 ###Starting testSoftCommitWithinAndHardCommitMaxTimeRapidAdds
[junit4] 2> 4559666 INFO (TEST-SoftAutoCommitTest.testSoftCommitWithinAndHardCommitMaxTimeRapidAdds-seed#[E18D0666487F85D3]) [ x:collection1 ] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=null path=null params={}{add=[5000 (1665825087530467328)]} 0 1
[junit4] 2> 4559667 INFO (TEST-SoftAutoCommitTest.testSoftCommitWithinAndHardCommitMaxTimeRapidAdds-seed#[E18D0666487F85D3]) [ x:collection1 ] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=null path=null params={}{add=[5001 (1665825087532564480)]} 0 0
[junit4] 2> 4559667 INFO (TEST-SoftAutoCommitTest.testSoftCommitWithinAndHardCommitMaxTimeRapidAdds-seed#[E18D0666487F85D3]) [ x:collection1 ] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=null path=null params={}{add=[5002 (1665825087532564481)]} 0 0
[junit4] 2> 4559668 INFO (TEST-SoftAutoCommitTest.testSoftCommitWithinAndHardCommitMaxTimeRapidAdds-seed#[E18D0666487F85D3]) [ x:collection1 ] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=null path=null params={}{add=[5003 (1665825087533613056)]} 0 0
[junit4] 2> 4559668 INFO (TEST-SoftAutoCommitTest.testSoftCommitWithinAndHardCommitMaxTimeRapidAdds-seed#[E18D0666487F85D3]) [ x:collection1 ] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=null path=null params={}{add=[5004 (1665825087533613057)]} 0 0
[junit4] 2> 4559669 INFO (TEST-SoftAutoCommitTest.testSoftCommitWithinAndHardCommitMaxTimeRapidAdds-seed#[E18D0666487F85D3]) [ ] o.a.s.u.SoftAutoCommitTest maxTimeMillis: 10430137190908616ns - 10430137187208858ns == 3ms
[junit4] 2> 4559669 INFO (TEST-SoftAutoCommitTest.testSoftCommitWithinAndHardCommitMaxTimeRapidAdds-seed#[E18D0666487F85D3]) [ ] o.a.s.u.SoftAutoCommitTest maxExpectedSoft=1
[junit4] 2> 4559669 INFO (TEST-SoftAutoCommitTest.testSoftCommitWithinAndHardCommitMaxTimeRapidAdds-seed#[E18D0666487F85D3]) [ ] o.a.s.u.SoftAutoCommitTest maxExpectedHard=1
[junit4] 2> 4560167 INFO (commitScheduler-28741-thread-1) [ ] o.a.s.u.DirectUpdateHandler2 start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=true,prepareCommit=false}
[junit4] 2> 4560170 INFO (commitScheduler-28741-thread-1) [ ] o.a.s.s.SolrIndexSearcher Opening [Searcher@7490b62e[collection1] main]
[junit4] 2> 4560170 INFO (commitScheduler-28741-thread-1) [ ] o.a.s.u.DirectUpdateHandler2 end_commit_flush
[junit4] 2> 4560176 INFO (searcherExecutor-28737-thread-1) [ ] o.a.s.c.SolrCore [collection1] Registered new searcher Searcher@7490b62e[collection1] main{ExitableDirectoryReader(UninvertingDirectoryReader(Uninverting(_0(8.6.0):c1:[diagnostics={os=Linux, java.vendor=Oracle Corporation, java.version=1.8.0_191, java.vm.version=25.191-b12, lucene.version=8.6.0, os.arch=amd64, java.runtime.version=1.8.0_191-b12, source=flush, os.version=4.4.0-170-generic, timestamp=1588654584676}]:[attributes={Lucene50StoredFieldsFormat.mode=BEST_SPEED}] :id=1d9hms8zzderb9bzx2xzh4dft) Uninverting(_1(8.6.0):c1:[diagnostics={os=Linux, java.vendor=Oracle Corporation, java.version=1.8.0_191, java.vm.version=25.191-b12, lucene.version=8.6.0, os.arch=amd64, java.runtime.version=1.8.0_191-b12, source=flush, os.version=4.4.0-170-generic, timestamp=1588654585879}]:[attributes={Lucene50StoredFieldsFormat.mode=BEST_SPEED}] :id=1d9hms8zzderb9bzx2xzh4dfx) Uninverting(_2(8.6.0):c8:[diagnostics={os=Linux, java.vendor=Oracle Corporation, java.version=1.8.0_191, java.vm.version=25.191-b12, lucene.version=8.6.0, os.arch=amd64, java.runtime.version=1.8.0_191-b12, source=flush, os.version=4.4.0-170-generic, timestamp=1588654595593}]:[attributes={Lucene50StoredFieldsFormat.mode=BEST_SPEED}] :id=1d9hms8zzderb9bzx2xzh4dg1) Uninverting(_3(8.6.0):c5:[diagnostics={os=Linux, java.vendor=Oracle Corporation, java.version=1.8.0_191, java.vm.version=25.191-b12, lucene.version=8.6.0, os.arch=amd64, java.runtime.version=1.8.0_191-b12, source=flush, os.version=4.4.0-170-generic, timestamp=1588654602106}]:[attributes={Lucene50StoredFieldsFormat.mode=BEST_SPEED}] :id=1d9hms8zzderb9bzx2xzh4dg5)))}
[junit4] 2> 4560866 INFO (commitScheduler-28740-thread-1) [ ] o.a.s.u.DirectUpdateHandler2 start commit{,optimize=false,openSearcher=false,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4] 2> 4560867 INFO (commitScheduler-28740-thread-1) [ ] o.a.s.u.SolrIndexWriter Calling setCommitData with IW:org.apache.solr.update.SolrIndexWriter@73ad1c96 commitCommandVersion:0
[junit4] 2> 4560867 INFO (commitScheduler-28740-thread-1) [ ] o.a.s.s.SolrIndexSearcher Opening [Searcher@1c8a39e8[collection1] realtime]
[junit4] 2> 4560867 INFO (commitScheduler-28740-thread-1) [ ] o.a.s.u.DirectUpdateHandler2 end_commit_flush
[junit4] 2> 4566272 INFO (TEST-SoftAutoCommitTest.testSoftCommitWithinAndHardCommitMaxTimeRapidAdds-seed#[E18D0666487F85D3]) [ ] o.a.s.SolrTestCaseJ4 ###Ending testSoftCommitWithinAndHardCommitMaxTimeRapidAdds
[junit4] 2> 4566278 INFO (TEST-SoftAutoCommitTest.testHardCommitWithinAndSoftCommitMaxTimeMixedAdds-seed#[E18D0666487F85D3]) [ ] o.a.s.SolrTestCaseJ4 ###Starting testHardCommitWithinAndSoftCommitMaxTimeMixedAdds
[junit4] 2> 4574692 INFO (TEST-SoftAutoCommitTest.testHardCommitWithinAndSoftCommitMaxTimeMixedAdds-seed#[E18D0666487F85D3]) [ x:collection1 ] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=null path=null params={}{add=[529 (1665825103286370304)]} 0 1
[junit4] 2> 4575193 INFO (commitScheduler-28741-thread-1) [ ] o.a.s.u.DirectUpdateHandler2 start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=true,prepareCommit=false}
[junit4] 2> NOTE: reproduce with: ant test -Dtestcase=SoftAutoCommitTest -Dtests.method=testHardCommitWithinAndSoftCommitMaxTimeMixedAdds -Dtests.seed=E18D0666487F85D3 -Dtests.multiplier=2 -Dtests.slow=true -Dtests.locale=en-ZA -Dtests.timezone=Pacific/Easter -Dtests.asserts=true -Dtests.file.encoding=UTF-8
[junit4] FAILURE 11.6s J1 | SoftAutoCommitTest.testHardCommitWithinAndSoftCommitMaxTimeMixedAdds <<<
[junit4] > Throwable #1: java.lang.AssertionError: soft529 wasn't fast enough
[junit4] > at __randomizedtesting.SeedInfo.seed([E18D0666487F85D3:226ADA77794352AE]:0)
[junit4] > at org.apache.solr.update.SoftAutoCommitTest.doTestSoftAndHardCommitMaxTimeMixedAdds(SoftAutoCommitTest.java:209)
[junit4] > at org.apache.solr.update.SoftAutoCommitTest.testHardCommitWithinAndSoftCommitMaxTimeMixedAdds(SoftAutoCommitTest.java:174)
[junit4] > at java.lang.Thread.run(Thread.java:748)
[junit4] 2> 4577908 INFO (TEST-SoftAutoCommitTest.testHardCommitWithinAndSoftCommitMaxTimeMixedAdds-seed#[E18D0666487F85D3]) [ ] o.a.s.SolrTestCaseJ4 ###Ending testHardCommitWithinAndSoftCommitMaxTimeMixedAdds
[junit4] 2> 4577931 INFO (commitScheduler-28741-thread-1) [ ] o.a.s.s.SolrIndexSearcher Opening [Searcher@a1e813e[collection1] main]
[junit4] 2> 4577932 INFO (commitScheduler-28741-thread-1) [ ] o.a.s.u.DirectUpdateHandler2 end_commit_flush
[junit4] 2> 4577935 INFO (commitScheduler-28740-thread-1) [ ] o.a.s.u.DirectUpdateHandler2 start commit{,optimize=false,openSearcher=false,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4] 2> 4577935 INFO (commitScheduler-28740-thread-1) [ ] o.a.s.u.SolrIndexWriter Calling setCommitData with IW:org.apache.solr.update.SolrIndexWriter@73ad1c96 commitCommandVersion:0
[junit4] 2> 4577969 INFO (TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeDelete-seed#[E18D0666487F85D3]) [ ] o.a.s.SolrTestCaseJ4 ###Starting testSoftAndHardCommitMaxTimeDelete
[junit4] 2> 4577970 INFO (searcherExecutor-28737-thread-1) [ ] o.a.s.c.SolrCore [collection1] Registered new searcher Searcher@a1e813e[collection1] main{ExitableDirectoryReader(UninvertingDirectoryReader(Uninverting(_1(8.6.0):c1:[diagnostics={os=Linux, java.vendor=Oracle Corporation, java.version=1.8.0_191, java.vm.version=25.191-b12, lucene.version=8.6.0, os.arch=amd64, java.runtime.version=1.8.0_191-b12, source=flush, os.version=4.4.0-170-generic, timestamp=1588654585879}]:[attributes={Lucene50StoredFieldsFormat.mode=BEST_SPEED}] :id=1d9hms8zzderb9bzx2xzh4dfx) Uninverting(_2(8.6.0):c8:[diagnostics={os=Linux, java.vendor=Oracle Corporation, java.version=1.8.0_191, java.vm.version=25.191-b12, lucene.version=8.6.0, os.arch=amd64, java.runtime.version=1.8.0_191-b12, source=flush, os.version=4.4.0-170-generic, timestamp=1588654595593}]:[attributes={Lucene50StoredFieldsFormat.mode=BEST_SPEED}] :id=1d9hms8zzderb9bzx2xzh4dg1) Uninverting(_3(8.6.0):c5:[diagnostics={os=Linux, java.vendor=Oracle Corporation, java.version=1.8.0_191, java.vm.version=25.191-b12, lucene.version=8.6.0, os.arch=amd64, java.runtime.version=1.8.0_191-b12, source=flush, os.version=4.4.0-170-generic, timestamp=1588654602106}]:[attributes={Lucene50StoredFieldsFormat.mode=BEST_SPEED}] :id=1d9hms8zzderb9bzx2xzh4dg5) Uninverting(_4(8.6.0):c1:[diagnostics={os=Linux, java.vendor=Oracle Corporation, java.version=1.8.0_191, java.vm.version=25.191-b12, lucene.version=8.6.0, os.arch=amd64, java.runtime.version=1.8.0_191-b12, source=flush, os.version=4.4.0-170-generic, timestamp=1588654619846}]:[attributes={Lucene50StoredFieldsFormat.mode=BEST_SPEED}] :id=1d9hms8zzderb9bzx2xzh4dg9)))}
[junit4] 2> 4577970 INFO (commitScheduler-28740-thread-1) [ ] o.a.s.s.SolrIndexSearcher Opening [Searcher@1bea17e1[collection1] realtime]
[junit4] 2> 4577971 INFO (commitScheduler-28740-thread-1) [ ] o.a.s.u.DirectUpdateHandler2 end_commit_flush
[junit4] 2> 4582973 INFO (TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeDelete-seed#[E18D0666487F85D3]) [ x:collection1 ] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=null path=null params={}{add=[529 (1665825111968579584)]} 0 2
[junit4] 2> 4582974 INFO (TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeDelete-seed#[E18D0666487F85D3]) [ x:collection1 ] o.a.s.u.DirectUpdateHandler2 start commit{_version_=1665825111971725312,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4] 2> 4582974 INFO (TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeDelete-seed#[E18D0666487F85D3]) [ x:collection1 ] o.a.s.u.SolrIndexWriter Calling setCommitData with IW:org.apache.solr.update.SolrIndexWriter@73ad1c96 commitCommandVersion:1665825111971725312
[junit4] 2> 4583008 INFO (TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeDelete-seed#[E18D0666487F85D3]) [ x:collection1 ] o.a.s.s.SolrIndexSearcher Opening [Searcher@5a2f8030[collection1] main]
[junit4] 2> 4583008 INFO (TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeDelete-seed#[E18D0666487F85D3]) [ x:collection1 ] o.a.s.u.DirectUpdateHandler2 end_commit_flush
[junit4] 2> 4583014 INFO (searcherExecutor-28737-thread-1-processing-x:collection1) [ x:collection1 ] o.a.s.c.SolrCore [collection1] Registered new searcher Searcher@5a2f8030[collection1] main{ExitableDirectoryReader(UninvertingDirectoryReader(Uninverting(_1(8.6.0):c1:[diagnostics={os=Linux, java.vendor=Oracle Corporation, java.version=1.8.0_191, java.vm.version=25.191-b12, lucene.version=8.6.0, os.arch=amd64, java.runtime.version=1.8.0_191-b12, source=flush, os.version=4.4.0-170-generic, timestamp=1588654585879}]:[attributes={Lucene50StoredFieldsFormat.mode=BEST_SPEED}] :id=1d9hms8zzderb9bzx2xzh4dfx) Uninverting(_2(8.6.0):c8:[diagnostics={os=Linux, java.vendor=Oracle Corporation, java.version=1.8.0_191, java.vm.version=25.191-b12, lucene.version=8.6.0, os.arch=amd64, java.runtime.version=1.8.0_191-b12, source=flush, os.version=4.4.0-170-generic, timestamp=1588654595593}]:[attributes={Lucene50StoredFieldsFormat.mode=BEST_SPEED}] :id=1d9hms8zzderb9bzx2xzh4dg1) Uninverting(_3(8.6.0):c5:[diagnostics={os=Linux, java.vendor=Oracle Corporation, java.version=1.8.0_191, java.vm.version=25.191-b12, lucene.version=8.6.0, os.arch=amd64, java.runtime.version=1.8.0_191-b12, source=flush, os.version=4.4.0-170-generic, timestamp=1588654602106}]:[attributes={Lucene50StoredFieldsFormat.mode=BEST_SPEED}] :id=1d9hms8zzderb9bzx2xzh4dg5) Uninverting(_5(8.6.0):c1:[diagnostics={os=Linux, java.vendor=Oracle Corporation, java.version=1.8.0_191, java.vm.version=25.191-b12, lucene.version=8.6.0, os.arch=amd64, java.runtime.version=1.8.0_191-b12, source=flush, os.version=4.4.0-170-generic, timestamp=1588654624927}]:[attributes={Lucene50StoredFieldsFormat.mode=BEST_SPEED}] :id=1d9hms8zzderb9bzx2xzh4dgd)))}
[junit4] 2> 4583014 INFO (TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeDelete-seed#[E18D0666487F85D3]) [ x:collection1 ] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=null path=null params={}{commit=} 0 39
[junit4] 2> 4583015 INFO (TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeDelete-seed#[E18D0666487F85D3]) [ x:collection1 ] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=null path=null params={}{delete=[529 (-1665825112014716928)]} 0 0
[junit4] 2> 4583515 INFO (commitScheduler-28741-thread-1) [ ] o.a.s.u.DirectUpdateHandler2 start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=true,prepareCommit=false}
[junit4] 2> 4583516 INFO (commitScheduler-28741-thread-1) [ ] o.a.s.s.SolrIndexSearcher Opening [Searcher@45be3bbc[collection1] main]
[junit4] 2> 4583516 INFO (commitScheduler-28741-thread-1) [ ] o.a.s.u.DirectUpdateHandler2 end_commit_flush
[junit4] 2> 4583517 INFO (TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeDelete-seed#[E18D0666487F85D3]) [ x:collection1 ] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=null path=null params={}{add=[550 (1665825112540053504)]} 0 0
[junit4] 2> 4583522 INFO (searcherExecutor-28737-thread-1) [ ] o.a.s.c.SolrCore [collection1] Registered new searcher Searcher@45be3bbc[collection1] main{ExitableDirectoryReader(UninvertingDirectoryReader(Uninverting(_1(8.6.0):c1:[diagnostics={os=Linux, java.vendor=Oracle Corporation, java.version=1.8.0_191, java.vm.version=25.191-b12, lucene.version=8.6.0, os.arch=amd64, java.runtime.version=1.8.0_191-b12, source=flush, os.version=4.4.0-170-generic, timestamp=1588654585879}]:[attributes={Lucene50StoredFieldsFormat.mode=BEST_SPEED}] :id=1d9hms8zzderb9bzx2xzh4dfx) Uninverting(_2(8.6.0):c8:[diagnostics={os=Linux, java.vendor=Oracle Corporation, java.version=1.8.0_191, java.vm.version=25.191-b12, lucene.version=8.6.0, os.arch=amd64, java.runtime.version=1.8.0_191-b12, source=flush, os.version=4.4.0-170-generic, timestamp=1588654595593}]:[attributes={Lucene50StoredFieldsFormat.mode=BEST_SPEED}] :id=1d9hms8zzderb9bzx2xzh4dg1) Uninverting(_3(8.6.0):c5:[diagnostics={os=Linux, java.vendor=Oracle Corporation, java.version=1.8.0_191, java.vm.version=25.191-b12, lucene.version=8.6.0, os.arch=amd64, java.runtime.version=1.8.0_191-b12, source=flush, os.version=4.4.0-170-generic, timestamp=1588654602106}]:[attributes={Lucene50StoredFieldsFormat.mode=BEST_SPEED}] :id=1d9hms8zzderb9bzx2xzh4dg5)))}
[junit4] 2> 4584017 INFO (commitScheduler-28741-thread-1) [ ] o.a.s.u.DirectUpdateHandler2 start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=true,prepareCommit=false}
[junit4] 2> 4584021 INFO (commitScheduler-28741-thread-1) [ ] o.a.s.s.SolrIndexSearcher Opening [Searcher@2ec6f2fc[collection1] main]
[junit4] 2> 4584021 INFO (commitScheduler-28741-thread-1) [ ] o.a.s.u.DirectUpdateHandler2 end_commit_flush
[junit4] 2> 4584026 INFO (searcherExecutor-28737-thread-1) [ ] o.a.s.c.SolrCore [collection1] Registered new searcher Searcher@2ec6f2fc[collection1] main{ExitableDirectoryReader(UninvertingDirectoryReader(Uninverting(_1(8.6.0):c1:[diagnostics={os=Linux, java.vendor=Oracle Corporation, java.version=1.8.0_191, java.vm.version=25.191-b12, lucene.version=8.6.0, os.arch=amd64, java.runtime.version=1.8.0_191-b12, source=flush, os.version=4.4.0-170-generic, timestamp=1588654585879}]:[attributes={Lucene50StoredFieldsFormat.mode=BEST_SPEED}] :id=1d9hms8zzderb9bzx2xzh4dfx) Uninverting(_2(8.6.0):c8:[diagnostics={os=Linux, java.vendor=Oracle Corporation, java.version=1.8.0_191, java.vm.version=25.191-b12, lucene.version=8.6.0, os.arch=amd64, java.runtime.version=1.8.0_191-b12, source=flush, os.version=4.4.0-170-generic, timestamp=1588654595593}]:[attributes={Lucene50StoredFieldsFormat.mode=BEST_SPEED}] :id=1d9hms8zzderb9bzx2xzh4dg1) Uninverting(_3(8.6.0):c5:[diagnostics={os=Linux, java.vendor=Oracle Corporation, java.version=1.8.0_191, java.vm.version=25.191-b12, lucene.version=8.6.0, os.arch=amd64, java.runtime.version=1.8.0_191-b12, source=flush, os.version=4.4.0-170-generic, timestamp=1588654602106}]:[attributes={Lucene50StoredFieldsFormat.mode=BEST_SPEED}] :id=1d9hms8zzderb9bzx2xzh4dg5) Uninverting(_6(8.6.0):c1:[diagnostics={os=Linux, java.vendor=Oracle Corporation, java.version=1.8.0_191, java.vm.version=25.191-b12, lucene.version=8.6.0, os.arch=amd64, java.runtime.version=1.8.0_191-b12, source=flush, os.version=4.4.0-170-generic, timestamp=1588654625957}]:[attributes={Lucene50StoredFieldsFormat.mode=BEST_SPEED}] :id=1d9hms8zzderb9bzx2xzh4dgh)))}
[junit4] 2> 4584215 INFO (commitScheduler-28740-thread-1) [ ] o.a.s.u.DirectUpdateHandler2 start commit{,optimize=false,openSearcher=false,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4] 2> 4584215 INFO (commitScheduler-28740-thread-1) [ ] o.a.s.u.SolrIndexWriter Calling setCommitData with IW:org.apache.solr.update.SolrIndexWriter@73ad1c96 commitCommandVersion:0
[junit4] 2> 4584216 INFO (commitScheduler-28740-thread-1) [ ] o.a.s.s.SolrIndexSearcher Opening [Searcher@1b22538d[collection1] realtime]
[junit4] 2> 4584216 INFO (commitScheduler-28740-thread-1) [ ] o.a.s.u.DirectUpdateHandler2 end_commit_flush
[junit4] 2> 4590217 INFO (TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeDelete-seed#[E18D0666487F85D3]) [ ] o.a.s.SolrTestCaseJ4 ###Ending testSoftAndHardCommitMaxTimeDelete
[junit4] 2> 4590231 INFO (TEST-SoftAutoCommitTest.testHardCommitWithinAndSoftCommitMaxTimeRapidAdds-seed#[E18D0666487F85D3]) [ ] o.a.s.SolrTestCaseJ4 ###Starting testHardCommitWithinAndSoftCommitMaxTimeRapidAdds
[junit4] 2> 4595233 INFO (TEST-SoftAutoCommitTest.testHardCommitWithinAndSoftCommitMaxTimeRapidAdds-seed#[E18D0666487F85D3]) [ x:collection1 ] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=null path=null params={}{add=[5000 (1665825124825169920)]} 0 1
[junit4] 2> 4595234 INFO (TEST-SoftAutoCommitTest.testHardCommitWithinAndSoftCommitMaxTimeRapidAdds-seed#[E18D0666487F85D3]) [ x:collection1 ] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=null path=null params={}{add=[5001 (1665825124827267072)]} 0 0
[junit4] 2> 4595234 INFO (TEST-SoftAutoCommitTest.testHardCommitWithinAndSoftCommitMaxTimeRapidAdds-seed#[E18D0666487F85D3]) [ x:collection1 ] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=null path=null params={}{add=[5002 (1665825124827267073)]} 0 0
[junit4] 2> 4595234 INFO (TEST-SoftAutoCommitTest.testHardCommitWithinAndSoftCommitMaxTimeRapidAdds-seed#[E18D0666487F85D3]) [ x:collection1 ] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=null path=null params={}{add=[5003 (1665825124827267074)]} 0 0
[junit4] 2> 4595235 INFO (TEST-SoftAutoCommitTest.testHardCommitWithinAndSoftCommitMaxTimeRapidAdds-seed#[E18D0666487F85D3]) [ x:collection1 ] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=null path=null params={}{add=[5004 (1665825124828315648)]} 0 0
[junit4] 2> 4595235 INFO (TEST-SoftAutoCommitTest.testHardCommitWithinAndSoftCommitMaxTimeRapidAdds-seed#[E18D0666487F85D3]) [ ] o.a.s.u.SoftAutoCommitTest maxTimeMillis: 10430172757464893ns - 10430172754029368ns == 3ms
[junit4] 2> 4595235 INFO (TEST-SoftAutoCommitTest.testHardCommitWithinAndSoftCommitMaxTimeRapidAdds-seed#[E18D0666487F85D3]) [ ] o.a.s.u.SoftAutoCommitTest maxExpectedSoft=1
[junit4] 2> 4595235 INFO (TEST-SoftAutoCommitTest.testHardCommitWithinAndSoftCommitMaxTimeRapidAdds-seed#[E18D0666487F85D3]) [ ] o.a.s.u.SoftAutoCommitTest maxExpectedHard=1
[junit4] 2> 4595733 INFO (commitScheduler-28741-thread-1) [ ] o.a.s.u.DirectUpdateHandler2 start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=true,prepareCommit=false}
[junit4] 2> 4595737 INFO (commitScheduler-28741-thread-1) [ ] o.a.s.s.SolrIndexSearcher Opening [Searcher@233ed843[collection1] main]
[junit4] 2> 4595737 INFO (commitScheduler-28741-thread-1) [ ] o.a.s.u.DirectUpdateHandler2 end_commit_flush
[junit4] 2> 4595743 INFO (searcherExecutor-28737-thread-1) [ ] o.a.s.c.SolrCore [collection1] Registered new searcher Searcher@233ed843[collection1] main{ExitableDirectoryReader(UninvertingDirectoryReader(Uninverting(_1(8.6.0):c1:[diagnostics={os=Linux, java.vendor=Oracle Corporation, java.version=1.8.0_191, java.vm.version=25.191-b12, lucene.version=8.6.0, os.arch=amd64, java.runtime.version=1.8.0_191-b12, source=flush, os.version=4.4.0-170-generic, timestamp=1588654585879}]:[attributes={Lucene50StoredFieldsFormat.mode=BEST_SPEED}] :id=1d9hms8zzderb9bzx2xzh4dfx) Uninverting(_2(8.6.0):c8:[diagnostics={os=Linux, java.vendor=Oracle Corporation, java.version=1.8.0_191, java.vm.version=25.191-b12, lucene.version=8.6.0, os.arch=amd64, java.runtime.version=1.8.0_191-b12, source=flush, os.version=4.4.0-170-generic, timestamp=1588654595593}]:[attributes={Lucene50StoredFieldsFormat.mode=BEST_SPEED}] :id=1d9hms8zzderb9bzx2xzh4dg1) Uninverting(_6(8.6.0):c1:[diagnostics={os=Linux, java.vendor=Oracle Corporation, java.version=1.8.0_191, java.vm.version=25.191-b12, lucene.version=8.6.0, os.arch=amd64, java.runtime.version=1.8.0_191-b12, source=flush, os.version=4.4.0-170-generic, timestamp=1588654625957}]:[attributes={Lucene50StoredFieldsFormat.mode=BEST_SPEED}] :id=1d9hms8zzderb9bzx2xzh4dgh) Uninverting(_7(8.6.0):c5:[diagnostics={os=Linux, java.vendor=Oracle Corporation, java.version=1.8.0_191, java.vm.version=25.191-b12, lucene.version=8.6.0, os.arch=amd64, java.runtime.version=1.8.0_191-b12, source=flush, os.version=4.4.0-170-generic, timestamp=1588654637673}]:[attributes={Lucene50StoredFieldsFormat.mode=BEST_SPEED}] :id=1d9hms8zzderb9bzx2xzh4dgl)))}
[junit4] 2> 4596433 INFO (commitScheduler-28740-thread-1) [ ] o.a.s.u.DirectUpdateHandler2 start commit{,optimize=false,openSearcher=false,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4] 2> 4596433 INFO (commitScheduler-28740-thread-1) [ ] o.a.s.u.SolrIndexWriter Calling setCommitData with IW:org.apache.solr.update.SolrIndexWriter@73ad1c96 commitCommandVersion:0
[junit4] 2> 4596434 INFO (commitScheduler-28740-thread-1) [ ] o.a.s.s.SolrIndexSearcher Opening [Searcher@492f4efb[collection1] realtime]
[junit4] 2> 4596434 INFO (commitScheduler-28740-thread-1) [ ] o.a.s.u.DirectUpdateHandler2 end_commit_flush
[junit4] 2> 4601867 INFO (TEST-SoftAutoCommitTest.testHardCommitWithinAndSoftCommitMaxTimeRapidAdds-seed#[E18D0666487F85D3]) [ ] o.a.s.SolrTestCaseJ4 ###Ending testHardCommitWithinAndSoftCommitMaxTimeRapidAdds
[junit4] 2> 4601913 INFO (TEST-SoftAutoCommitTest.testSoftCommitWithinAndHardCommitMaxTimeMixedAdds-seed#[E18D0666487F85D3]) [ ] o.a.s.SolrTestCaseJ4 ###Starting testSoftCommitWithinAndHardCommitMaxTimeMixedAdds
[junit4] 2> 4610316 INFO (TEST-SoftAutoCommitTest.testSoftCommitWithinAndHardCommitMaxTimeMixedAdds-seed#[E18D0666487F85D3]) [ x:collection1 ] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=null path=null params={}{add=[529 (1665825140639793152)]} 0 1
[junit4] 2> 4610816 INFO (commitScheduler-28741-thread-1) [ ] o.a.s.u.DirectUpdateHandler2 start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=true,prepareCommit=false}
[junit4] 2> 4610819 INFO (commitScheduler-28741-thread-1) [ ] o.a.s.s.SolrIndexSearcher Opening [Searcher@591ebd56[collection1] main]
[junit4] 2> 4610819 INFO (commitScheduler-28741-thread-1) [ ] o.a.s.u.DirectUpdateHandler2 end_commit_flush
[junit4] 2> 4610825 INFO (searcherExecutor-28737-thread-1) [ ] o.a.s.c.SolrCore [collection1] Registered new searcher Searcher@591ebd56[collection1] main{ExitableDirectoryReader(UninvertingDirectoryReader(Uninverting(_1(8.6.0):c1:[diagnostics={os=Linux, java.vendor=Oracle Corporation, java.version=1.8.0_191, java.vm.version=25.191-b12, lucene.version=8.6.0, os.arch=amd64, java.runtime.version=1.8.0_191-b12, source=flush, os.version=4.4.0-170-generic, timestamp=1588654585879}]:[attributes={Lucene50StoredFieldsFormat.mode=BEST_SPEED}] :id=1d9hms8zzderb9bzx2xzh4dfx) Uninverting(_2(8.6.0):c8:[diagnostics={os=Linux, java.vendor=Oracle Corporation, java.version=1.8.0_191, java.vm.version=25.191-b12, lucene.version=8.6.0, os.arch=amd64, java.runtime.version=1.8.0_191-b12, source=flush, os.version=4.4.0-170-generic, timestamp=1588654595593}]:[attributes={Lucene50StoredFieldsFormat.mode=BEST_SPEED}] :id=1d9hms8zzderb9bzx2xzh4dg1) Uninverting(_6(8.6.0):c1:[diagnostics={os=Linux, java.vendor=Oracle Corporation, java.version=1.8.0_191, java.vm.version=25.191-b12, lucene.version=8.6.0, os.arch=amd64, java.runtime.version=1.8.0_191-b12, source=flush, os.version=4.4.0-170-generic, timestamp=1588654625957}]:[attributes={Lucene50StoredFieldsFormat.mode=BEST_SPEED}] :id=1d9hms8zzderb9bzx2xzh4dgh) Uninverting(_7(8.6.0):c5:[diagnostics={os=Linux, java.vendor=Oracle Corporation, java.version=1.8.0_191, java.vm.version=25.191-b12, lucene.version=8.6.0, os.arch=amd64, java.runtime.version=1.8.0_191-b12, source=flush, os.version=4.4.0-170-generic, timestamp=1588654637673}]:[attributes={Lucene50StoredFieldsFormat.mode=BEST_SPEED}] :id=1d9hms8zzderb9bzx2xzh4dgl) Uninverting(_8(8.6.0):c1:[diagnostics={os=Linux, java.vendor=Oracle Corporation, java.version=1.8.0_191, java.vm.version=25.191-b12, lucene.version=8.6.0, os.arch=amd64, java.runtime.version=1.8.0_191-b12, source=flush, os.version=4.4.0-170-generic, timestamp=1588654652756}]:[attributes={Lucene50StoredFieldsFormat.mode=BEST_SPEED}] :id=1d9hms8zzderb9bzx2xzh4dgp)))}
[junit4] 2> 4611516 INFO (commitScheduler-28740-thread-1) [ ] o.a.s.u.DirectUpdateHandler2 start commit{,optimize=false,openSearcher=false,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4] 2> 4611516 INFO (commitScheduler-28740-thread-1) [ ] o.a.s.u.SolrIndexWriter Calling setCommitData with IW:org.apache.solr.update.SolrIndexWriter@73ad1c96 commitCommandVersion:0
[junit4] 2> 4611516 INFO (commitScheduler-28740-thread-1) [ ] o.a.s.s.SolrIndexSearcher Opening [Searcher@aff4500[collection1] realtime]
[junit4] 2> 4611517 INFO (commitScheduler-28740-thread-1) [ ] o.a.s.u.DirectUpdateHandler2 end_commit_flush
[junit4] 2> 4611518 INFO (TEST-SoftAutoCommitTest.testSoftCommitWithinAndHardCommitMaxTimeMixedAdds-seed#[E18D0666487F85D3]) [ x:collection1 ] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=null path=null params={}{add=[530 (1665825141900181504)]} 0 1
[junit4] 2> 4612018 INFO (commitScheduler-28741-thread-1) [ ] o.a.s.u.DirectUpdateHandler2 start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=true,prepareCommit=false}
[junit4] 2> 4612021 INFO (commitScheduler-28741-thread-1) [ ] o.a.s.s.SolrIndexSearcher Opening [Searcher@50158de3[collection1] main]
[junit4] 2> 4612022 INFO (commitScheduler-28741-thread-1) [ ] o.a.s.u.DirectUpdateHandler2 end_commit_flush
[junit4] 2> 4612027 INFO (searcherExecutor-28737-thread-1) [ ] o.a.s.c.SolrCore [collection1] Registered new searcher Searcher@50158de3[collection1] main{ExitableDirectoryReader(UninvertingDirectoryReader(Uninverting(_2(8.6.0):c8:[diagnostics={os=Linux, java.vendor=Oracle Corporation, java.version=1.8.0_191, java.vm.version=25.191-b12, lucene.version=8.6.0, os.arch=amd64, java.runtime.version=1.8.0_191-b12, source=flush, os.version=4.4.0-170-generic, timestamp=1588654595593}]:[attributes={Lucene50StoredFieldsFormat.mode=BEST_SPEED}] :id=1d9hms8zzderb9bzx2xzh4dg1) Uninverting(_6(8.6.0):c1:[diagnostics={os=Linux, java.vendor=Oracle Corporation, java.version=1.8.0_191, java.vm.version=25.191-b12, lucene.version=8.6.0, os.arch=amd64, java.runtime.version=1.8.0_191-b12, source=flush, os.version=4.4.0-170-generic, timestamp=1588654625957}]:[attributes={Lucene50StoredFieldsFormat.mode=BEST_SPEED}] :id=1d9hms8zzderb9bzx2xzh4dgh) Uninverting(_7(8.6.0):c5:[diagnostics={os=Linux, java.vendor=Oracle Corporation, java.version=1.8.0_191, java.vm.version=25.191-b12, lucene.version=8.6.0, os.arch=amd64, java.runtime.version=1.8.0_191-b12, source=flush, os.version=4.4.0-170-generic, timestamp=1588654637673}]:[attributes={Lucene50StoredFieldsFormat.mode=BEST_SPEED}] :id=1d9hms8zzderb9bzx2xzh4dgl) Uninverting(_8(8.6.0):c1:[diagnostics={os=Linux, java.vendor=Oracle Corporation, java.version=1.8.0_191, java.vm.version=25.191-b12, lucene.version=8.6.0, os.arch=amd64, java.runtime.version=1.8.0_191-b12, source=flush, os.version=4.4.0-170-generic, timestamp=1588654652756}]:[attributes={Lucene50StoredFieldsFormat.mode=BEST_SPEED}] :id=1d9hms8zzderb9bzx2xzh4dgp) Uninverting(_9(8.6.0):c1:[diagnostics={os=Linux, java.vendor=Oracle Corporation, java.version=1.8.0_191, java.vm.version=25.191-b12, lucene.version=8.6.0, os.arch=amd64, java.runtime.version=1.8.0_191-b12, source=flush, os.version=4.4.0-170-generic, timestamp=1588654653958}]:[attributes={Lucene50StoredFieldsFormat.mode=BEST_SPEED}] :id=1d9hms8zzderb9bzx2xzh4dgt)))}
[junit4] 2> 4612718 INFO (commitScheduler-28740-thread-1) [ ] o.a.s.u.DirectUpdateHandler2 start commit{,optimize=false,openSearcher=false,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4] 2> 4612718 INFO (commitScheduler-28740-thread-1) [ ] o.a.s.u.SolrIndexWriter Calling setCommitData with IW:org.apache.solr.update.SolrIndexWriter@73ad1c96 commitCommandVersion:0
[junit4] 2> 4612719 INFO (commitScheduler-28740-thread-1) [ ] o.a.s.s.SolrIndexSearcher Opening [Searcher@abc41cc[collection1] realtime]
[junit4] 2> 4612719 INFO (commitScheduler-28740-thread-1) [ ] o.a.s.u.DirectUpdateHandler2 end_commit_flush
[junit4] 2> 4613729 INFO (TEST-SoftAutoCommitTest.testSoftCommitWithinAndHardCommitMaxTimeMixedAdds-seed#[E18D0666487F85D3]) [ ] o.a.s.SolrTestCaseJ4 ###Ending testSoftCommitWithinAndHardCommitMaxTimeMixedAdds
[junit4] 2> 4613736 INFO (TEST-SoftAutoCommitTest.testHardCommitWithinAndSoftCommitMaxTimeDelete-seed#[E18D0666487F85D3]) [ ] o.a.s.SolrTestCaseJ4 ###Starting testHardCommitWithinAndSoftCommitMaxTimeDelete
[junit4] 2> 4618746 INFO (TEST-SoftAutoCommitTest.testHardCommitWithinAndSoftCommitMaxTimeDelete-seed#[E18D0666487F85D3]) [ x:collection1 ] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=null path=null params={}{add=[529 (1665825149480337408)]} 0 1
[junit4] 2> 4618747 INFO (TEST-SoftAutoCommitTest.testHardCommitWithinAndSoftCommitMaxTimeDelete-seed#[E18D0666487F85D3]) [ x:collection1 ] o.a.s.u.DirectUpdateHandler2 start commit{_version_=1665825149482434560,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4] 2> 4618747 INFO (TEST-SoftAutoCommitTest.testHardCommitWithinAndSoftCommitMaxTimeDelete-seed#[E18D0666487F85D3]) [ x:collection1 ] o.a.s.u.SolrIndexWriter Calling setCommitData with IW:org.apache.solr.update.SolrIndexWriter@73ad1c96 commitCommandVersion:1665825149482434560
[junit4] 2> 4618763 INFO (TEST-SoftAutoCommitTest.testHardCommitWithinAndSoftCommitMaxTimeDelete-seed#[E18D0666487F85D3]) [ x:collection1 ] o.a.s.s.SolrIndexSearcher Opening [Searcher@6e24618a[collection1] main]
[junit4] 2> 4618764 INFO (TEST-SoftAutoCommitTest.testHardCommitWithinAndSoftCommitMaxTimeDelete-seed#[E18D0666487F85D3]) [ x:collection1 ] o.a.s.u.DirectUpdateHandler2 end_commit_flush
[junit4] 2> 4618769 INFO (searcherExecutor-28737-thread-1-processing-x:collection1) [ x:collection1 ] o.a.s.c.SolrCore [collection1] Registered new searcher Searcher@6e24618a[collection1] main{ExitableDirectoryReader(UninvertingDirectoryReader(Uninverting(_2(8.6.0):c8:[diagnostics={os=Linux, java.vendor=Oracle Corporation, java.version=1.8.0_191, java.vm.version=25.191-b12, lucene.version=8.6.0, os.arch=amd64, java.runtime.version=1.8.0_191-b12, source=flush, os.version=4.4.0-170-generic, timestamp=1588654595593}]:[attributes={Lucene50StoredFieldsFormat.mode=BEST_SPEED}] :id=1d9hms8zzderb9bzx2xzh4dg1) Uninverting(_6(8.6.0):c1:[diagnostics={os=Linux, java.vendor=Oracle Corporation, java.version=1.8.0_191, java.vm.version=25.191-b12, lucene.version=8.6.0, os.arch=amd64, java.runtime.version=1.8.0_191-b12, source=flush, os.version=4.4.0-170-generic, timestamp=1588654625957}]:[attributes={Lucene50StoredFieldsFormat.mode=BEST_SPEED}] :id=1d9hms8zzderb9bzx2xzh4dgh) Uninverting(_7(8.6.0):c5:[diagnostics={os=Linux, java.vendor=Oracle Corporation, java.version=1.8.0_191, java.vm.version=25.191-b12, lucene.version=8.6.0, os.arch=amd64, java.runtime.version=1.8.0_191-b12, source=flush, os.version=4.4.0-170-generic, timestamp=1588654637673}]:[attributes={Lucene50StoredFieldsFormat.mode=BEST_SPEED}] :id=1d9hms8zzderb9bzx2xzh4dgl) Uninverting(_9(8.6.0):c1:[diagnostics={os=Linux, java.vendor=Oracle Corporation, java.version=1.8.0_191, java.vm.version=25.191-b12, lucene.version=8.6.0, os.arch=amd64, java.runtime.version=1.8.0_191-b12, source=flush, os.version=4.4.0-170-generic, timestamp=1588654653958}]:[attributes={Lucene50StoredFieldsFormat.mode=BEST_SPEED}] :id=1d9hms8zzderb9bzx2xzh4dgt) Uninverting(_a(8.6.0):c1:[diagnostics={os=Linux, java.vendor=Oracle Corporation, java.version=1.8.0_191, java.vm.version=25.191-b12, lucene.version=8.6.0, os.arch=amd64, java.runtime.version=1.8.0_191-b12, source=flush, os.version=4.4.0-170-generic, timestamp=1588654660687}]:[attributes={Lucene50StoredFieldsFormat.mode=BEST_SPEED}] :id=1d9hms8zzderb9bzx2xzh4dgx)))}
[junit4] 2> 4618773 INFO (TEST-SoftAutoCommitTest.testHardCommitWithinAndSoftCommitMaxTimeDelete-seed#[E18D0666487F85D3]) [ x:collection1 ] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=null path=null params={}{commit=} 0 26
[junit4] 2> 4618774 INFO (TEST-SoftAutoCommitTest.testHardCommitWithinAndSoftCommitMaxTimeDelete-seed#[E18D0666487F85D3]) [ x:collection1 ] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=null path=null params={}{delete=[529 (-1665825149509697536)]} 0 0
[junit4] 2> 4619274 INFO (commitScheduler-28741-thread-1) [ ] o.a.s.u.DirectUpdateHandler2 start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=true,prepareCommit=false}
[junit4] 2> 4619275 INFO (commitScheduler-28741-thread-1) [ ] o.a.s.s.SolrIndexSearcher Opening [Searcher@56dea2d4[collection1] main]
[junit4] 2> 4619275 INFO (commitScheduler-28741-thread-1) [ ] o.a.s.u.DirectUpdateHandler2 end_commit_flush
[junit4] 2> 4619276 INFO (TEST-SoftAutoCommitTest.testHardCommitWithinAndSoftCommitMaxTimeDelete-seed#[E18D0666487F85D3]) [ x:collection1 ] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=null path=null params={}{add=[550 (1665825150036082688)]} 0 0
[junit4] 2> 4619296 INFO (searcherExecutor-28737-thread-1) [ ] o.a.s.c.SolrCore [collection1] Registered new searcher Searcher@56dea2d4[collection1] main{ExitableDirectoryReader(UninvertingDirectoryReader(Uninverting(_2(8.6.0):c8:[diagnostics={os=Linux, java.vendor=Oracle Corporation, java.version=1.8.0_191, java.vm.version=25.191-b12, lucene.version=8.6.0, os.arch=amd64, java.runtime.version=1.8.0_191-b12, source=flush, os.version=4.4.0-170-generic, timestamp=1588654595593}]:[attributes={Lucene50StoredFieldsFormat.mode=BEST_SPEED}] :id=1d9hms8zzderb9bzx2xzh4dg1) Uninverting(_6(8.6.0):c1:[diagnostics={os=Linux, java.vendor=Oracle Corporation, java.version=1.8.0_191, java.vm.version=25.191-b12, lucene.version=8.6.0, os.arch=amd64, java.runtime.version=1.8.0_191-b12, source=flush, os.version=4.4.0-170-generic, timestamp=1588654625957}]:[attributes={Lucene50StoredFieldsFormat.mode=BEST_SPEED}] :id=1d9hms8zzderb9bzx2xzh4dgh) Uninverting(_7(8.6.0):c5:[diagnostics={os=Linux, java.vendor=Oracle Corporation, java.version=1.8.0_191, java.vm.version=25.191-b12, lucene.version=8.6.0, os.arch=amd64, java.runtime.version=1.8.0_191-b12, source=flush, os.version=4.4.0-170-generic, timestamp=1588654637673}]:[attributes={Lucene50StoredFieldsFormat.mode=BEST_SPEED}] :id=1d9hms8zzderb9bzx2xzh4dgl) Uninverting(_9(8.6.0):c1:[diagnostics={os=Linux, java.vendor=Oracle Corporation, java.version=1.8.0_191, java.vm.version=25.191-b12, lucene.version=8.6.0, os.arch=amd64, java.runtime.version=1.8.0_191-b12, source=flush, os.version=4.4.0-170-generic, timestamp=1588654653958}]:[attributes={Lucene50StoredFieldsFormat.mode=BEST_SPEED}] :id=1d9hms8zzderb9bzx2xzh4dgt)))}
[junit4] 2> 4619776 INFO (commitScheduler-28741-thread-1) [ ] o.a.s.u.DirectUpdateHandler2 start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=true,prepareCommit=false}
[junit4] 2> 4619779 INFO (commitScheduler-28741-thread-1) [ ] o.a.s.s.SolrIndexSearcher Opening [Searcher@2c188508[collection1] main]
[junit4] 2> 4619780 INFO (commitScheduler-28741-thread-1) [ ] o.a.s.u.DirectUpdateHandler2 end_commit_flush
[junit4] 2> 4619801 INFO (searcherExecutor-28737-thread-1) [ ] o.a.s.c.SolrCore [collection1] Registered new searcher Searcher@2c188508[collection1] main{ExitableDirectoryReader(UninvertingDirectoryReader(Uninverting(_2(8.6.0):c8:[diagnostics={os=Linux, java.vendor=Oracle Corporation, java.version=1.8.0_191, java.vm.version=25.191-b12, lucene.version=8.6.0, os.arch=amd64, java.runtime.version=1.8.0_191-b12, source=flush, os.version=4.4.0-170-generic, timestamp=1588654595593}]:[attributes={Lucene50StoredFieldsFormat.mode=BEST_SPEED}] :id=1d9hms8zzderb9bzx2xzh4dg1) Uninverting(_7(8.6.0):c5:[diagnostics={os=Linux, java.vendor=Oracle Corporation, java.version=1.8.0_191, java.vm.version=25.191-b12, lucene.version=8.6.0, os.arch=amd64, java.runtime.version=1.8.0_191-b12, source=flush, os.version=4.4.0-170-generic, timestamp=1588654637673}]:[attributes={Lucene50StoredFieldsFormat.mode=BEST_SPEED}] :id=1d9hms8zzderb9bzx2xzh4dgl) Uninverting(_9(8.6.0):c1:[diagnostics={os=Linux, java.vendor=Oracle Corporation, java.version=1.8.0_191, java.vm.version=25.191-b12, lucene.version=8.6.0, os.arch=amd64, java.runtime.version=1.8.0_191-b12, source=flush, os.version=4.4.0-170-generic, timestamp=1588654653958}]:[attributes={Lucene50StoredFieldsFormat.mode=BEST_SPEED}] :id=1d9hms8zzderb9bzx2xzh4dgt) Uninverting(_b(8.6.0):c1:[diagnostics={os=Linux, java.vendor=Oracle Corporation, java.version=1.8.0_191, java.vm.version=25.191-b12, lucene.version=8.6.0, os.arch=amd64, java.runtime.version=1.8.0_191-b12, source=flush, os.version=4.4.0-170-generic, timestamp=1588654661716}]:[attributes={Lucene50StoredFieldsFormat.mode=BEST_SPEED}] :id=1d9hms8zzderb9bzx2xzh4dh1)))}
[junit4] 2> 4619974 INFO (commitScheduler-28740-thread-1) [ ] o.a.s.u.DirectUpdateHandler2 start commit{,optimize=false,openSearcher=false,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4] 2> 4619974 INFO (commitScheduler-28740-thread-1) [ ] o.a.s.u.SolrIndexWriter Calling setCommitData with IW:org.apache.solr.update.SolrIndexWriter@73ad1c96 commitCommandVersion:0
[junit4] 2> 4619975 INFO (commitScheduler-28740-thread-1) [ ] o.a.s.s.SolrIndexSearcher Opening [Searcher@7b45745c[collection1] realtime]
[junit4] 2> 4619975 INFO (commitScheduler-28740-thread-1) [ ] o.a.s.u.DirectUpdateHandler2 end_commit_flush
[junit4] 2> 4625976 INFO (TEST-SoftAutoCommitTest.testHardCommitWithinAndSoftCommitMaxTimeDelete-seed#[E18D0666487F85D3]) [ ] o.a.s.SolrTestCaseJ4 ###Ending testHardCommitWithinAndSoftCommitMaxTimeDelete
[junit4] 2> 4625990 INFO (TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeRapidAdds-seed#[E18D0666487F85D3]) [ ] o.a.s.SolrTestCaseJ4 ###Starting testSoftAndHardCommitMaxTimeRapidAdds
[junit4] 2> 4630992 INFO (TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeRapidAdds-seed#[E18D0666487F85D3]) [ x:collection1 ] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=null path=null params={}{add=[5000 (1665825162321199104)]} 0 1
[junit4] 2> 4630993 INFO (TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeRapidAdds-seed#[E18D0666487F85D3]) [ x:collection1 ] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=null path=null params={}{add=[5001 (1665825162322247680)]} 0 0
[junit4] 2> 4630994 INFO (TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeRapidAdds-seed#[E18D0666487F85D3]) [ x:collection1 ] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=null path=null params={}{add=[5002 (1665825162323296256)]} 0 0
[junit4] 2> 4630994 INFO (TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeRapidAdds-seed#[E18D0666487F85D3]) [ x:collection1 ] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=null path=null params={}{add=[5003 (1665825162324344832)]} 0 0
[junit4] 2> 4630994 INFO (TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeRapidAdds-seed#[E18D0666487F85D3]) [ x:collection1 ] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=null path=null params={}{add=[5004 (1665825162324344833)]} 0 0
[junit4] 2> 4630995 INFO (TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeRapidAdds-seed#[E18D0666487F85D3]) [ ] o.a.s.u.SoftAutoCommitTest maxTimeMillis: 10430208517072561ns - 10430208512936447ns == 4ms
[junit4] 2> 4630995 INFO (TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeRapidAdds-seed#[E18D0666487F85D3]) [ ] o.a.s.u.SoftAutoCommitTest maxExpectedSoft=1
[junit4] 2> 4630995 INFO (TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeRapidAdds-seed#[E18D0666487F85D3]) [ ] o.a.s.u.SoftAutoCommitTest maxExpectedHard=1
[junit4] 2> 4631492 INFO (commitScheduler-28741-thread-1) [ ] o.a.s.u.DirectUpdateHandler2 start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=true,prepareCommit=false}
[junit4] 2> 4631496 INFO (commitScheduler-28741-thread-1) [ ] o.a.s.s.SolrIndexSearcher Opening [Searcher@31404ab1[collection1] main]
[junit4] 2> 4631496 INFO (commitScheduler-28741-thread-1) [ ] o.a.s.u.DirectUpdateHandler2 end_commit_flush
[junit4] 2> 4631501 INFO (searcherExecutor-28737-thread-1) [ ] o.a.s.c.SolrCore [collection1] Registered new searcher Searcher@31404ab1[collection1] main{ExitableDirectoryReader(UninvertingDirectoryReader(Uninverting(_2(8.6.0):c8:[diagnostics={os=Linux, java.vendor=Oracle Corporation, java.version=1.8.0_191, java.vm.version=25.191-b12, lucene.version=8.6.0, os.arch=amd64, java.runtime.version=1.8.0_191-b12, source=flush, os.version=4.4.0-170-generic, timestamp=1588654595593}]:[attributes={Lucene50StoredFieldsFormat.mode=BEST_SPEED}] :id=1d9hms8zzderb9bzx2xzh4dg1) Uninverting(_9(8.6.0):c1:[diagnostics={os=Linux, java.vendor=Oracle Corporation, java.version=1.8.0_191, java.vm.version=25.191-b12, lucene.version=8.6.0, os.arch=amd64, java.runtime.version=1.8.0_191-b12, source=flush, os.version=4.4.0-170-generic, timestamp=1588654653958}]:[attributes={Lucene50StoredFieldsFormat.mode=BEST_SPEED}] :id=1d9hms8zzderb9bzx2xzh4dgt) Uninverting(_b(8.6.0):c1:[diagnostics={os=Linux, java.vendor=Oracle Corporation, java.version=1.8.0_191, java.vm.version=25.191-b12, lucene.version=8.6.0, os.arch=amd64, java.runtime.version=1.8.0_191-b12, source=flush, os.version=4.4.0-170-generic, timestamp=1588654661716}]:[attributes={Lucene50StoredFieldsFormat.mode=BEST_SPEED}] :id=1d9hms8zzderb9bzx2xzh4dh1) Uninverting(_c(8.6.0):c5:[diagnostics={os=Linux, java.vendor=Oracle Corporation, java.version=1.8.0_191, java.vm.version=25.191-b12, lucene.version=8.6.0, os.arch=amd64, java.runtime.version=1.8.0_191-b12, source=flush, os.version=4.4.0-170-generic, timestamp=1588654673432}]:[attributes={Lucene50StoredFieldsFormat.mode=BEST_SPEED}] :id=1d9hms8zzderb9bzx2xzh4dh5)))}
[junit4] 2> 4632192 INFO (commitScheduler-28740-thread-1) [ ] o.a.s.u.DirectUpdateHandler2 start commit{,optimize=false,openSearcher=false,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4] 2> 4632192 INFO (commitScheduler-28740-thread-1) [ ] o.a.s.u.SolrIndexWriter Calling setCommitData with IW:org.apache.solr.update.SolrIndexWriter@73ad1c96 commitCommandVersion:0
[junit4] 2> 4632193 INFO (commitScheduler-28740-thread-1) [ ] o.a.s.s.SolrIndexSearcher Opening [Searcher@7deba38a[collection1] realtime]
[junit4] 2> 4632193 INFO (commitScheduler-28740-thread-1) [ ] o.a.s.u.DirectUpdateHandler2 end_commit_flush
[junit4] 2> 4637602 INFO (TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeRapidAdds-seed#[E18D0666487F85D3]) [ ] o.a.s.SolrTestCaseJ4 ###Ending testSoftAndHardCommitMaxTimeRapidAdds
[junit4] 2> 4637609 INFO (TEST-SoftAutoCommitTest.testSoftCommitWithinAndHardCommitMaxTimeDelete-seed#[E18D0666487F85D3]) [ ] o.a.s.SolrTestCaseJ4 ###Starting testSoftCommitWithinAndHardCommitMaxTimeDelete
[junit4] 2> 4642611 INFO (TEST-SoftAutoCommitTest.testSoftCommitWithinAndHardCommitMaxTimeDelete-seed#[E18D0666487F85D3]) [ x:collection1 ] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=null path=null params={}{add=[529 (1665825174503555072)]} 0 1
[junit4] 2> 4642611 INFO (TEST-SoftAutoCommitTest.testSoftCommitWithinAndHardCommitMaxTimeDelete-seed#[E18D0666487F85D3]) [ x:collection1 ] o.a.s.u.DirectUpdateHandler2 start commit{_version_=1665825174505652224,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4] 2> 4642611 INFO (TEST-SoftAutoCommitTest.testSoftCommitWithinAndHardCommitMaxTimeDelete-seed#[E18D0666487F85D3]) [ x:collection1 ] o.a.s.u.SolrIndexWriter Calling setCommitData with IW:org.apache.solr.update.SolrIndexWriter@73ad1c96 commitCommandVersion:1665825174505652224
[junit4] 2> 4642615 INFO (TEST-SoftAutoCommitTest.testSoftCommitWithinAndHardCommitMaxTimeDelete-seed#[E18D0666487F85D3]) [ x:collection1 ] o.a.s.s.SolrIndexSearcher Opening [Searcher@772928db[collection1] main]
[junit4] 2> 4642616 INFO (TEST-SoftAutoCommitTest.testSoftCommitWithinAndHardCommitMaxTimeDelete-seed#[E18D0666487F85D3]) [ x:collection1 ] o.a.s.u.DirectUpdateHandler2 end_commit_flush
[junit4] 2> 4642621 INFO (searcherExecutor-28737-thread-1-processing-x:collection1) [ x:collection1 ] o.a.s.c.SolrCore [collection1] Registered new searcher Searcher@772928db[collection1] main{ExitableDirectoryReader(UninvertingDirectoryReader(Uninverting(_2(8.6.0):c8:[diagnostics={os=Linux, java.vendor=Oracle Corporation, java.version=1.8.0_191, java.vm.version=25.191-b12, lucene.version=8.6.0, os.arch=amd64, java.runtime.version=1.8.0_191-b12, source=flush, os.version=4.4.0-170-generic, timestamp=1588654595593}]:[attributes={Lucene50StoredFieldsFormat.mode=BEST_SPEED}] :id=1d9hms8zzderb9bzx2xzh4dg1) Uninverting(_9(8.6.0):c1:[diagnostics={os=Linux, java.vendor=Oracle Corporation, java.version=1.8.0_191, java.vm.version=25.191-b12, lucene.version=8.6.0, os.arch=amd64, java.runtime.version=1.8.0_191-b12, source=flush, os.version=4.4.0-170-generic, timestamp=1588654653958}]:[attributes={Lucene50StoredFieldsFormat.mode=BEST_SPEED}] :id=1d9hms8zzderb9bzx2xzh4dgt) Uninverting(_b(8.6.0):c1:[diagnostics={os=Linux, java.vendor=Oracle Corporation, java.version=1.8.0_191, java.vm.version=25.191-b12, lucene.version=8.6.0, os.arch=amd64, java.runtime.version=1.8.0_191-b12, source=flush, os.version=4.4.0-170-generic, timestamp=1588654661716}]:[attributes={Lucene50StoredFieldsFormat.mode=BEST_SPEED}] :id=1d9hms8zzderb9bzx2xzh4dh1) Uninverting(_c(8.6.0):c5:[diagnostics={os=Linux, java.vendor=Oracle Corporation, java.version=1.8.0_191, java.vm.version=25.191-b12, lucene.version=8.6.0, os.arch=amd64, java.runtime.version=1.8.0_191-b12, source=flush, os.version=4.4.0-170-generic, timestamp=1588654673432}]:[attributes={Lucene50StoredFieldsFormat.mode=BEST_SPEED}] :id=1d9hms8zzderb9bzx2xzh4dh5) Uninverting(_d(8.6.0):c1:[diagnostics={os=Linux, java.vendor=Oracle Corporation, java.version=1.8.0_191, java.vm.version=25.191-b12, lucene.version=8.6.0, os.arch=amd64, java.runtime.version=1.8.0_191-b12, source=flush, os.version=4.4.0-170-generic, timestamp=1588654684551}]:[attributes={Lucene50StoredFieldsFormat.mode=BEST_SPEED}] :id=1d9hms8zzderb9bzx2xzh4dh9)))}
[junit4] 2> 4642622 INFO (TEST-SoftAutoCommitTest.testSoftCommitWithinAndHardCommitMaxTimeDelete-seed#[E18D0666487F85D3]) [ x:collection1 ] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=null path=null params={}{commit=} 0 10
[junit4] 2> 4642623 INFO (TEST-SoftAutoCommitTest.testSoftCommitWithinAndHardCommitMaxTimeDelete-seed#[E18D0666487F85D3]) [ x:collection1 ] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=null path=null params={}{delete=[529 (-1665825174517186560)]} 0 0
[junit4] 2> 4643123 INFO (commitScheduler-28741-thread-1) [ ] o.a.s.u.DirectUpdateHandler2 start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=true,prepareCommit=false}
[junit4] 2> 4643123 INFO (commitScheduler-28741-thread-1) [ ] o.a.s.s.SolrIndexSearcher Opening [Searcher@1ec20e66[collection1] main]
[junit4] 2> 4643123 INFO (commitScheduler-28741-thread-1) [ ] o.a.s.u.DirectUpdateHandler2 end_commit_flush
[junit4] 2> 4643124 INFO (TEST-SoftAutoCommitTest.testSoftCommitWithinAndHardCommitMaxTimeDelete-seed#[E18D0666487F85D3]) [ x:collection1 ] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=null path=null params={}{add=[550 (1665825175043571712)]} 0 0
[junit4] 2> 4643129 INFO (searcherExecutor-28737-thread-1) [ ] o.a.s.c.SolrCore [collection1] Registered new searcher Searcher@1ec20e66[collection1] main{ExitableDirectoryReader(UninvertingDirectoryReader(Uninverting(_2(8.6.0):c8:[diagnostics={os=Linux, java.vendor=Oracle Corporation, java.version=1.8.0_191, java.vm.version=25.191-b12, lucene.version=8.6.0, os.arch=amd64, java.runtime.version=1.8.0_191-b12, source=flush, os.version=4.4.0-170-generic, timestamp=1588654595593}]:[attributes={Lucene50StoredFieldsFormat.mode=BEST_SPEED}] :id=1d9hms8zzderb9bzx2xzh4dg1) Uninverting(_9(8.6.0):c1:[diagnostics={os=Linux, java.vendor=Oracle Corporation, java.version=1.8.0_191, java.vm.version=25.191-b12, lucene.version=8.6.0, os.arch=amd64, java.runtime.version=1.8.0_191-b12, source=flush, os.version=4.4.0-170-generic, timestamp=1588654653958}]:[attributes={Lucene50StoredFieldsFormat.mode=BEST_SPEED}] :id=1d9hms8zzderb9bzx2xzh4dgt) Uninverting(_b(8.6.0):c1:[diagnostics={os=Linux, java.vendor=Oracle Corporation, java.version=1.8.0_191, java.vm.version=25.191-b12, lucene.version=8.6.0, os.arch=amd64, java.runtime.version=1.8.0_191-b12, source=flush, os.version=4.4.0-170-generic, timestamp=1588654661716}]:[attributes={Lucene50StoredFieldsFormat.mode=BEST_SPEED}] :id=1d9hms8zzderb9bzx2xzh4dh1) Uninverting(_c(8.6.0):c5:[diagnostics={os=Linux, java.vendor=Oracle Corporation, java.version=1.8.0_191, java.vm.version=25.191-b12, lucene.version=8.6.0, os.arch=amd64, java.runtime.version=1.8.0_191-b12, source=flush, os.version=4.4.0-170-generic, timestamp=1588654673432}]:[attributes={Lucene50StoredFieldsFormat.mode=BEST_SPEED}] :id=1d9hms8zzderb9bzx2xzh4dh5)))}
[junit4] 2> 4643624 INFO (commitScheduler-28741-thread-1) [ ] o.a.s.u.DirectUpdateHandler2 start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=true,prepareCommit=false}
[junit4] 2> 4643627 INFO (commitScheduler-28741-thread-1) [ ] o.a.s.s.SolrIndexSearcher Opening [Searcher@55258ddb[collection1] main]
[junit4] 2> 4643628 INFO (commitScheduler-28741-thread-1) [ ] o.a.s.u.DirectUpdateHandler2 end_commit_flush
[junit4] 2> 4643633 INFO (searcherExecutor-28737-thread-1) [ ] o.a.s.c.SolrCore [collection1] Registered new searcher Searcher@55258ddb[collection1] main{ExitableDirectoryReader(UninvertingDirectoryReader(Uninverting(_2(8.6.0):c8:[diagnostics={os=Linux, java.vendor=Oracle Corporation, java.version=1.8.0_191, java.vm.version=25.191-b12, lucene.version=8.6.0, os.arch=amd64, java.runtime.version=1.8.0_191-b12, source=flush, os.version=4.4.0-170-generic, timestamp=1588654595593}]:[attributes={Lucene50StoredFieldsFormat.mode=BEST_SPEED}] :id=1d9hms8zzderb9bzx2xzh4dg1) Uninverting(_9(8.6.0):c1:[diagnostics={os=Linux, java.vendor=Oracle Corporation, java.version=1.8.0_191, java.vm.version=25.191-b12, lucene.version=8.6.0, os.arch=amd64, java.runtime.version=1.8.0_191-b12, source=flush, os.version=4.4.0-170-generic, timestamp=1588654653958}]:[attributes={Lucene50StoredFieldsFormat.mode=BEST_SPEED}] :id=1d9hms8zzderb9bzx2xzh4dgt) Uninverting(_c(8.6.0):c5:[diagnostics={os=Linux, java.vendor=Oracle Corporation, java.version=1.8.0_191, java.vm.version=25.191-b12, lucene.version=8.6.0, os.arch=amd64, java.runtime.version=1.8.0_191-b12, source=flush, os.version=4.4.0-170-generic, timestamp=1588654673432}]:[attributes={Lucene50StoredFieldsFormat.mode=BEST_SPEED}] :id=1d9hms8zzderb9bzx2xzh4dh5) Uninverting(_e(8.6.0):c1:[diagnostics={os=Linux, java.vendor=Oracle Corporation, java.version=1.8.0_191, java.vm.version=25.191-b12, lucene.version=8.6.0, os.arch=amd64, java.runtime.version=1.8.0_191-b12, source=flush, os.version=4.4.0-170-generic, timestamp=1588654685564}]:[attributes={Lucene50StoredFieldsFormat.mode=BEST_SPEED}] :id=1d9hms8zzderb9bzx2xzh4dhd)))}
[junit4] 2> 4643823 INFO (commitScheduler-28740-thread-1) [ ] o.a.s.u.DirectUpdateHandler2 start commit{,optimize=false,openSearcher=false,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4] 2> 4643823 INFO (commitScheduler-28740-thread-1) [ ] o.a.s.u.SolrIndexWriter Calling setCommitData with IW:org.apache.solr.update.SolrIndexWriter@73ad1c96 commitCommandVersion:0
[junit4] 2> 4643823 INFO (commitScheduler-28740-thread-1) [ ] o.a.s.s.SolrIndexSearcher Opening [Searcher@7f4ac124[collection1] realtime]
[junit4] 2> 4643824 INFO (commitScheduler-28740-thread-1) [ ] o.a.s.u.DirectUpdateHandler2 end_commit_flush
[junit4] 2> 4649824 INFO (TEST-SoftAutoCommitTest.testSoftCommitWithinAndHardCommitMaxTimeDelete-seed#[E18D0666487F85D3]) [ ] o.a.s.SolrTestCaseJ4 ###Ending testSoftCommitWithinAndHardCommitMaxTimeDelete
[junit4] 2> 4649825 INFO (SUITE-SoftAutoCommitTest-seed#[E18D0666487F85D3]-worker) [ ] o.a.s.SolrTestCaseJ4 ###deleteCore
[junit4] 2> 4649825 INFO (SUITE-SoftAutoCommitTest-seed#[E18D0666487F85D3]-worker) [ ] o.a.s.c.CoreContainer Shutting down CoreContainer instance=1560065459
[junit4] 2> 4649825 INFO (coreCloseExecutor-28743-thread-1) [ ] o.a.s.c.SolrCore [collection1] CLOSING SolrCore org.apache.solr.core.SolrCore@759c2fce
[junit4] 2> 4649825 INFO (coreCloseExecutor-28743-thread-1) [ ] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.core.collection1 tag=SolrCore@759c2fce
[junit4] 2> 4649825 INFO (coreCloseExecutor-28743-thread-1) [ ] o.a.s.m.r.SolrJmxReporter Closing reporter [org.apache.solr.metrics.reporters.SolrJmxReporter@1456d38: rootName = null, domain = solr.core.collection1, service url = null, agent id = null] for registry solr.core.collection1/com.codahale.metrics.MetricRegistry@12bc784
[junit4] 2> 4649879 INFO (coreCloseExecutor-28743-thread-1) [ ] o.a.s.u.DirectUpdateHandler2 Committing on IndexWriter.close() ... SKIPPED (unnecessary).
[junit4] 2> 4649889 INFO (SUITE-SoftAutoCommitTest-seed#[E18D0666487F85D3]-worker) [ ] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.node tag=null
[junit4] 2> 4649889 INFO (SUITE-SoftAutoCommitTest-seed#[E18D0666487F85D3]-worker) [ ] o.a.s.m.r.SolrJmxReporter Closing reporter [org.apache.solr.metrics.reporters.SolrJmxReporter@587bc4aa: rootName = null, domain = solr.node, service url = null, agent id = null] for registry solr.node/com.codahale.metrics.MetricRegistry@2e22ecca
[junit4] 2> 4649896 INFO (SUITE-SoftAutoCommitTest-seed#[E18D0666487F85D3]-worker) [ ] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.jvm tag=null
[junit4] 2> 4649896 INFO (SUITE-SoftAutoCommitTest-seed#[E18D0666487F85D3]-worker) [ ] o.a.s.m.r.SolrJmxReporter Closing reporter [org.apache.solr.metrics.reporters.SolrJmxReporter@2dd74876: rootName = null, domain = solr.jvm, service url = null, agent id = null] for registry solr.jvm/com.codahale.metrics.MetricRegistry@31ca38bb
[junit4] 2> 4649911 INFO (SUITE-SoftAutoCommitTest-seed#[E18D0666487F85D3]-worker) [ ] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.jetty tag=null
[junit4] 2> 4649911 INFO (SUITE-SoftAutoCommitTest-seed#[E18D0666487F85D3]-worker) [ ] o.a.s.m.r.SolrJmxReporter Closing reporter [org.apache.solr.metrics.reporters.SolrJmxReporter@7940637e: rootName = null, domain = solr.jetty, service url = null, agent id = null] for registry solr.jetty/com.codahale.metrics.MetricRegistry@9715f1f
[junit4] 2> NOTE: leaving temporary files on disk at: /home/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-8.x/solr/build/solr-core/test/J1/temp/solr.update.SoftAutoCommitTest_E18D0666487F85D3-001
[junit4] 2> NOTE: test params are: codec=Asserting(Lucene84): {multiDefault=Lucene84, subject=Lucene84, _root_=PostingsFormat(name=LuceneVarGapFixedInterval), id=PostingsFormat(name=MockRandom), text=PostingsFormat(name=LuceneVarGapDocFreqInterval)}, docValues:{range_facet_l_dv=DocValuesFormat(name=Asserting), _version_=DocValuesFormat(name=Lucene80), range_facet_i_dv=DocValuesFormat(name=Lucene80), intDvoDefault=DocValuesFormat(name=Asserting), timestamp=DocValuesFormat(name=Lucene80)}, maxPointsInLeafNode=1071, maxMBSortInHeap=6.136441266064604, sim=Asserting(org.apache.lucene.search.similarities.AssertingSimilarity@7a1914e9), locale=en-ZA, timezone=Pacific/Easter
[junit4] 2> NOTE: Linux 4.4.0-170-generic amd64/Oracle Corporation 1.8.0_191 (64-bit)/cpus=8,threads=1,free=319710000,total=534249472
[junit4] 2> NOTE: All tests run in this JVM: [TestInfoStreamLogging, SimplePostToolTest, TestCloudJSONFacetSKG, SchemaApiFailureTest, TermVectorComponentTest, PeerSyncTest, TestDistributedSearch, TestReload, TestRestoreCore, TestSolr4Spatial, IndexSizeTriggerSizeEstimationTest, TestCoreContainer, SolrSlf4jReporterTest, SharedFSAutoReplicaFailoverTest, RollingRestartTest, SimpleFacetsTest, StatsReloadRaceTest, TestCaffeineCache, TestBlobHandler, TestConfigSetImmutable, TestSolrXml, AutoscalingHistoryHandlerTest, TestSolrCloudWithHadoopAuthPlugin, CollectionsAPISolrJTest, HdfsCollectionsAPIDistributedZkTest, ChaosMonkeySafeLeaderWithPullReplicasTest, TestHdfsCloudBackupRestore, HdfsWriteToMultipleCollectionsTest, CloudExitableDirectoryReaderTest, TestTextField, HdfsDirectoryTest, TestSimNodeLostTrigger, TestExactSharedStatsCache, ResponseBuilderTest, JWTAuthPluginTest, OpenExchangeRatesOrgProviderTest, TestFieldCacheSort, TestStressUserVersions, DistanceFunctionTest, MergeStrategyTest, TestCollationField, TestDynamicFieldCollectionResource, TestCloudRecovery, TestComplexPhraseQParserPlugin, TestBulkSchemaConcurrent, TestCoreBackup, AutoScalingHandlerTest, CloneFieldUpdateProcessorFactoryTest, TestTolerantUpdateProcessorRandomCloud, RegexBoostProcessorTest, BasicDistributedZk2Test, ExplicitHLLTest, NestedAtomicUpdateTest, TestFieldResource, ZookeeperReadAPITest, ConfigureRecoveryStrategyTest, BlockCacheTest, ManagedSchemaRoundRobinCloudTest, TestLeaderElectionWithEmptyReplica, CoreAdminOperationTest, TestStressLucene, TestSearcherReuse, TestPullReplica, ZkNodePropsTest, ExternalFileFieldSortTest, AddReplicaTest, ShowFileRequestHandlerTest, SolrCoreTest, TestOmitPositions, TestFieldCacheWithThreads, DistributedMLTComponentTest, SuggesterFSTTest, TestExpandComponent, TestSystemCollAutoCreate, MoveReplicaHDFSFailoverTest, UpdateRequestProcessorFactoryTest, TestTlogReplayVsRecovery, TestIndexingPerformance, ZkCLITest, TestFastLRUCache, OverseerCollectionConfigSetProcessorTest, PropertiesRequestHandlerTest, TestScoreJoinQPScore, CdcrVersionReplicationTest, RestoreTriggerStateTest, ReplaceNodeTest, ScheduledTriggerTest, TestSolrTestCaseJ4, TestWordDelimiterFilterFactory, TestJsonRequest, SplitByPrefixTest, SuggestComponentContextFilterQueryTest, TestQuerySenderListener, TestInPlaceUpdatesDistrib, PeerSyncReplicationTest, TestAuthorizationFramework, SortSpecParsingTest, CircularListTest, SmileWriterTest, MultiDestinationAuditLoggerTest, DistanceUnitsTest, TestJsonFacets, NumberUtilsTest, TestHighlightDedupGrouping, PreAnalyzedFieldTest, TestSimTriggerIntegration, TestMiniSolrCloudClusterSSL, TestJavabinTupleStreamParser, PathHierarchyTokenizerFactoryTest, TestLegacyField, TestDistribDocBasedVersion, HdfsThreadLeakTest, CollectionTooManyReplicasTest, TestDFRSimilarityFactory, TestSimClusterStateProvider, TestXmlQParser, TestSimDistributedQueue, BinaryUpdateRequestHandlerTest, UtilsToolTest, TestLFUCache, ResponseHeaderTest, TriLevelCompositeIdRoutingTest, TestDynamicFieldNamesIndexCorrectly, TestTestInjection, TestSolrQueryResponse, AtomicUpdateRemovalJavabinTest, SyncSliceTest, TestCustomDocTransformer, TemplateUpdateProcessorTest, ClusterStateUpdateTest, SolrRrdBackendFactoryTest, TestRestManager, TestHashQParserPlugin, HighlighterTest, BasicFunctionalityTest, URLClassifyProcessorTest, TestDynamicLoadingUrl, ForceLeaderTest, AnalysisErrorHandlingTest, MinimalSchemaTest, TestSimGenericDistributedQueue, TriggerEventQueueTest, SolrMetricManagerTest, MBeansHandlerTest, TestStreamBody, TestRandomFaceting, TestRequestForwarding, TestReplicationHandlerBackup, TestSolrCloudWithDelegationTokens, MetricsHistoryWithAuthIntegrationTest, DistribDocExpirationUpdateProcessorTest, LeaderElectionContextKeyTest, LeaderElectionTest, LeaderFailoverAfterPartitionTest, LegacyCloudClusterPropTest, MoveReplicaTest, OverseerTest, RemoteQueryErrorTest, ShardRoutingTest, SolrXmlInZkTest, TestCloudConsistency, TestRebalanceLeaders, TestStressCloudBlindAtomicUpdates, TestWaitForStateWithJettyShutdowns, TestWithCollection, TestReplicaProperties, TestRequestStatusCollectionAPI, HdfsAutoAddReplicasIntegrationTest, HttpTriggerListenerTest, MetricTriggerIntegrationTest, MetricTriggerTest, NodeAddedTriggerIntegrationTest, NodeLostTriggerIntegrationTest, NodeLostTriggerTest, SystemLogListenerTest, TestSnapshotCloudManager, BaseCdcrDistributedZkTest, CdcrBidirectionalTest, CdcrOpsAndBoundariesTest, CdcrReplicationHandlerTest, HDFSCollectionsAPITest, ZkStateWriterTest, ZkDynamicConfigTest, AlternateDirectoryTest, BlobRepositoryCloudTest, DirectoryFactoryTest, PluginInfoTest, QueryResultKeyTest, TestDirectoryFactory, TestJmxIntegration, TestLazyCores, TestNRTOpen, TestReloadAndDeleteDocs, TestSolrConfigHandler, JsonLoaderTest, RequestLoggingTest, SearchHandlerTest, TestReplicationHandler, MoreLikeThisComponentTest, PhrasesIdentificationComponentTest, QueryElevationComponentTest, SpellCheckComponentTest, TestTrackingShardHandlerFactory, JavabinLoaderTest, RandomizedTaggerTest, XmlInterpolationTest, HighlighterConfigTest, TestUnifiedSolrHighlighterWithoutStoredId, TestLegacyTerms, TestMultiValuedNumericRangeQuery, TestNumericRangeQuery64, SolrGraphiteReporterTest, TestIntervalFaceting, TestManagedSchemaAPI, TestSchemaManager, TestSchemalessBufferedUpdates, UUIDFieldTest, AnalyticsMergeStrategyTest, AnalyticsQueryTest, CursorMarkTest, RankQueryTest, TestComplexPhraseLeadingWildcard, TestExtendedDismaxParser, TestInitQParser, TestLegacyNumericRangeQueryBuilder, TestMaxScoreQueryParser, TestMultiWordSynonyms, TestOverriddenPrefixQueryForCustomFieldType, TestPayloadCheckQParserPlugin, TestQueryTypes, TestRangeQuery, TestJsonFacetsWithNestedObjects, TestJsonRangeFacets, TestMinMaxOnMultiValuedField, TestNestedDocsSort, TestScoreJoinQPNoScore, TestBM25SimilarityFactory, TestDFISimilarityFactory, TestLegacyBM25SimilarityFactory, TestPerFieldSimilarity, TestDefaultStatsCache, AuditLoggerPluginTest, BasicAuthIntegrationTest, TestImpersonationWithHadoopAuth, CacheHeaderTest, HttpSolrCallGetCoreTest, SpellCheckCollatorTest, SpellingQueryConverterTest, WordBreakSolrSpellCheckerTest, TestAnalyzeInfixSuggestions, TestFuzzyAnalyzedSuggestions, TestDocTermOrdsUninvertLimit, TestFieldCache, TestNumericTerms64, SoftAutoCommitTest]
[junit4] Completed [906/907 (1!)] on J1 in 117.75s, 10 tests, 1 failure <<< FAILURES!
[...truncated 52587 lines...]