You are viewing a plain text version of this content. The canonical link for it is here.
Posted to builds@lucene.apache.org by Policeman Jenkins Server <je...@thetaphi.de> on 2020/07/25 00:17:05 UTC
[JENKINS] Lucene-Solr-master-MacOSX (64bit/jdk-13.0.2) - Build #
6330 - Still Unstable!
Build: https://jenkins.thetaphi.de/job/Lucene-Solr-master-MacOSX/6330/
Java: 64bit/jdk-13.0.2 -XX:+UseCompressedOops -XX:+UseSerialGC
1 tests failed.
FAILED: org.apache.solr.update.SoftAutoCommitTest.testHardCommitWithinAndSoftCommitMaxTimeMixedAdds
Error Message:
soft530 after hard529 but no hard530: 371214736193346 !<= 371214228935877
Stack Trace:
java.lang.AssertionError: soft530 after hard529 but no hard530: 371214736193346 !<= 371214228935877
at __randomizedtesting.SeedInfo.seed([E453A00BA8CF69CC:27B47C1A99F3BEB1]:0)
at org.junit.Assert.fail(Assert.java:88)
at org.junit.Assert.assertTrue(Assert.java:41)
at org.apache.solr.update.SoftAutoCommitTest.doTestSoftAndHardCommitMaxTimeMixedAdds(SoftAutoCommitTest.java:268)
at org.apache.solr.update.SoftAutoCommitTest.testHardCommitWithinAndSoftCommitMaxTimeMixedAdds(SoftAutoCommitTest.java:174)
at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
at java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
at java.base/java.lang.reflect.Method.invoke(Method.java:567)
at com.carrotsearch.randomizedtesting.RandomizedRunner.invoke(RandomizedRunner.java:1754)
at com.carrotsearch.randomizedtesting.RandomizedRunner$8.evaluate(RandomizedRunner.java:942)
at com.carrotsearch.randomizedtesting.RandomizedRunner$9.evaluate(RandomizedRunner.java:978)
at com.carrotsearch.randomizedtesting.RandomizedRunner$10.evaluate(RandomizedRunner.java:992)
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:370)
at com.carrotsearch.randomizedtesting.ThreadLeakControl.forkTimeoutingTask(ThreadLeakControl.java:819)
at com.carrotsearch.randomizedtesting.ThreadLeakControl$3.evaluate(ThreadLeakControl.java:470)
at com.carrotsearch.randomizedtesting.RandomizedRunner.runSingleTest(RandomizedRunner.java:951)
at com.carrotsearch.randomizedtesting.RandomizedRunner$5.evaluate(RandomizedRunner.java:836)
at com.carrotsearch.randomizedtesting.RandomizedRunner$6.evaluate(RandomizedRunner.java:887)
at com.carrotsearch.randomizedtesting.RandomizedRunner$7.evaluate(RandomizedRunner.java:898)
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 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:370)
at com.carrotsearch.randomizedtesting.ThreadLeakControl.lambda$forkTimeoutingTask$0(ThreadLeakControl.java:826)
at java.base/java.lang.Thread.run(Thread.java:830)
Build Log:
[...truncated 13051 lines...]
[junit4] Suite: org.apache.solr.update.SoftAutoCommitTest
[junit4] 2> 550335 INFO (SUITE-SoftAutoCommitTest-seed#[E453A00BA8CF69CC]-worker) [ ] o.a.s.SolrTestCase Setting 'solr.default.confdir' system property to test-framework derived value of '/Users/jenkins/workspace/Lucene-Solr-master-MacOSX/solr/server/solr/configsets/_default/conf'
[junit4] 2> 550338 INFO (SUITE-SoftAutoCommitTest-seed#[E453A00BA8CF69CC]-worker) [ ] o.a.s.SolrTestCaseJ4 Created dataDir: /Users/jenkins/workspace/Lucene-Solr-master-MacOSX/solr/build/solr-core/test/J1/temp/solr.update.SoftAutoCommitTest_E453A00BA8CF69CC-001/data-dir-44-001
[junit4] 2> 550338 WARN (SUITE-SoftAutoCommitTest-seed#[E453A00BA8CF69CC]-worker) [ ] o.a.s.SolrTestCaseJ4 startTrackingSearchers: numOpens=4 numCloses=4
[junit4] 2> 550361 INFO (SUITE-SoftAutoCommitTest-seed#[E453A00BA8CF69CC]-worker) [ ] o.a.s.SolrTestCaseJ4 Using PointFields (NUMERIC_POINTS_SYSPROP=true) w/NUMERIC_DOCVALUES_SYSPROP=false
[junit4] 2> 550362 INFO (SUITE-SoftAutoCommitTest-seed#[E453A00BA8CF69CC]-worker) [ ] o.a.s.SolrTestCaseJ4 Randomized ssl (false) and clientAuth (false) via: @org.apache.solr.util.RandomizeSSL(reason="", value=0.0/0.0, ssl=0.0/0.0, clientAuth=0.0/0.0) w/ MAC_OS_X supressed clientAuth
[junit4] 2> 550362 INFO (SUITE-SoftAutoCommitTest-seed#[E453A00BA8CF69CC]-worker) [ ] o.a.s.SolrTestCaseJ4 SecureRandom sanity checks: test.solr.allowed.securerandom=null & java.security.egd=file:/dev/./urandom
[junit4] 2> 550363 INFO (SUITE-SoftAutoCommitTest-seed#[E453A00BA8CF69CC]-worker) [ ] o.a.s.SolrTestCaseJ4 ####initCore
[junit4] 2> 550382 INFO (SUITE-SoftAutoCommitTest-seed#[E453A00BA8CF69CC]-worker) [ ] o.a.s.c.SolrConfig Using Lucene MatchVersion: 9.0.0
[junit4] 2> 550462 INFO (SUITE-SoftAutoCommitTest-seed#[E453A00BA8CF69CC]-worker) [ ] o.a.s.s.IndexSchema Schema name=test
[junit4] 2> 550763 INFO (SUITE-SoftAutoCommitTest-seed#[E453A00BA8CF69CC]-worker) [ ] o.a.s.s.IndexSchema Loaded schema test/1.0 with uniqueid field id
[junit4] 2> 551203 WARN (SUITE-SoftAutoCommitTest-seed#[E453A00BA8CF69CC]-worker) [ ] o.a.s.c.CoreContainer Unable to create [/Users/jenkins/workspace/Lucene-Solr-master-MacOSX/solr/core/src/test-files/solr/userfiles]. Features requiring this directory may fail.
[junit4] 2> => java.security.AccessControlException: access denied ("java.io.FilePermission" "/Users/jenkins/workspace/Lucene-Solr-master-MacOSX/solr/core/src/test-files/solr/userfiles" "write")
[junit4] 2> at java.base/java.security.AccessControlContext.checkPermission(AccessControlContext.java:472)
[junit4] 2> java.security.AccessControlException: access denied ("java.io.FilePermission" "/Users/jenkins/workspace/Lucene-Solr-master-MacOSX/solr/core/src/test-files/solr/userfiles" "write")
[junit4] 2> at java.security.AccessControlContext.checkPermission(AccessControlContext.java:472) ~[?:?]
[junit4] 2> at java.security.AccessController.checkPermission(AccessController.java:1036) ~[?:?]
[junit4] 2> at java.lang.SecurityManager.checkPermission(SecurityManager.java:408) ~[?:?]
[junit4] 2> at java.lang.SecurityManager.checkWrite(SecurityManager.java:838) ~[?:?]
[junit4] 2> at sun.nio.fs.UnixPath.checkWrite(UnixPath.java:824) ~[?:?]
[junit4] 2> at sun.nio.fs.UnixFileSystemProvider.createDirectory(UnixFileSystemProvider.java:381) ~[?:?]
[junit4] 2> at java.nio.file.Files.createDirectory(Files.java:693) ~[?:?]
[junit4] 2> at java.nio.file.Files.createAndCheckIsDirectory(Files.java:800) ~[?:?]
[junit4] 2> at java.nio.file.Files.createDirectories(Files.java:746) ~[?:?]
[junit4] 2> at org.apache.solr.core.CoreContainer.<init>(CoreContainer.java:364) [java/:?]
[junit4] 2> at org.apache.solr.core.CoreContainer.<init>(CoreContainer.java:325) [java/:?]
[junit4] 2> at org.apache.solr.util.TestHarness.<init>(TestHarness.java:169) [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:810) [java/:?]
[junit4] 2> at org.apache.solr.SolrTestCaseJ4.initCore(SolrTestCaseJ4.java:800) [java/:?]
[junit4] 2> at org.apache.solr.SolrTestCaseJ4.initCore(SolrTestCaseJ4.java:661) [java/:?]
[junit4] 2> at org.apache.solr.SolrTestCaseJ4.initCore(SolrTestCaseJ4.java:650) [java/:?]
[junit4] 2> at org.apache.solr.update.SoftAutoCommitTest.beforeClass(SoftAutoCommitTest.java:66) [test/:?]
[junit4] 2> at jdk.internal.reflect.NativeMethodAccessorImpl.invoke0(Native Method) ~[?:?]
[junit4] 2> at jdk.internal.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62) ~[?:?]
[junit4] 2> at jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) ~[?:?]
[junit4] 2> at java.lang.reflect.Method.invoke(Method.java:567) ~[?:?]
[junit4] 2> at com.carrotsearch.randomizedtesting.RandomizedRunner.invoke(RandomizedRunner.java:1754) [randomizedtesting-runner-2.7.6.jar:?]
[junit4] 2> at com.carrotsearch.randomizedtesting.RandomizedRunner$6.evaluate(RandomizedRunner.java:882) [randomizedtesting-runner-2.7.6.jar:?]
[junit4] 2> at com.carrotsearch.randomizedtesting.RandomizedRunner$7.evaluate(RandomizedRunner.java:898) [randomizedtesting-runner-2.7.6.jar:?]
[junit4] 2> at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36) [randomizedtesting-runner-2.7.6.jar:?]
[junit4] 2> at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:57) [randomizedtesting-runner-2.7.6.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.6.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.6.jar:?]
[junit4] 2> at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:40) [randomizedtesting-runner-2.7.6.jar:?]
[junit4] 2> at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36) [randomizedtesting-runner-2.7.6.jar:?]
[junit4] 2> at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36) [randomizedtesting-runner-2.7.6.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.6.jar:?]
[junit4] 2> at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:370) [randomizedtesting-runner-2.7.6.jar:?]
[junit4] 2> at com.carrotsearch.randomizedtesting.ThreadLeakControl.lambda$forkTimeoutingTask$0(ThreadLeakControl.java:826) [randomizedtesting-runner-2.7.6.jar:?]
[junit4] 2> at java.lang.Thread.run(Thread.java:830) [?:?]
[junit4] 2> 551247 WARN (SUITE-SoftAutoCommitTest-seed#[E453A00BA8CF69CC]-worker) [ ] o.a.s.f.DistribPackageStore Unable to create [/Users/jenkins/workspace/Lucene-Solr-master-MacOSX/solr/core/src/test-files/solr/filestore] directory in SOLR_HOME [/Users/jenkins/workspace/Lucene-Solr-master-MacOSX/solr/core/src/test-files/solr]. Features requiring this directory may fail.
[junit4] 2> => java.security.AccessControlException: access denied ("java.io.FilePermission" "/Users/jenkins/workspace/Lucene-Solr-master-MacOSX/solr/core/src/test-files/solr/filestore" "write")
[junit4] 2> at java.base/java.security.AccessControlContext.checkPermission(AccessControlContext.java:472)
[junit4] 2> java.security.AccessControlException: access denied ("java.io.FilePermission" "/Users/jenkins/workspace/Lucene-Solr-master-MacOSX/solr/core/src/test-files/solr/filestore" "write")
[junit4] 2> at java.security.AccessControlContext.checkPermission(AccessControlContext.java:472) ~[?:?]
[junit4] 2> at java.security.AccessController.checkPermission(AccessController.java:1036) ~[?:?]
[junit4] 2> at java.lang.SecurityManager.checkPermission(SecurityManager.java:408) ~[?:?]
[junit4] 2> at java.lang.SecurityManager.checkWrite(SecurityManager.java:838) ~[?:?]
[junit4] 2> at java.io.File.mkdir(File.java:1323) ~[?:?]
[junit4] 2> at java.io.File.mkdirs(File.java:1355) ~[?:?]
[junit4] 2> at org.apache.solr.filestore.DistribPackageStore.ensurePackageStoreDir(DistribPackageStore.java:523) [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:78) [java/:?]
[junit4] 2> at org.apache.solr.core.CoreContainer.load(CoreContainer.java:664) [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:810) [java/:?]
[junit4] 2> at org.apache.solr.SolrTestCaseJ4.initCore(SolrTestCaseJ4.java:800) [java/:?]
[junit4] 2> at org.apache.solr.SolrTestCaseJ4.initCore(SolrTestCaseJ4.java:661) [java/:?]
[junit4] 2> at org.apache.solr.SolrTestCaseJ4.initCore(SolrTestCaseJ4.java:650) [java/:?]
[junit4] 2> at org.apache.solr.update.SoftAutoCommitTest.beforeClass(SoftAutoCommitTest.java:66) [test/:?]
[junit4] 2> at jdk.internal.reflect.NativeMethodAccessorImpl.invoke0(Native Method) ~[?:?]
[junit4] 2> at jdk.internal.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62) ~[?:?]
[junit4] 2> at jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) ~[?:?]
[junit4] 2> at java.lang.reflect.Method.invoke(Method.java:567) ~[?:?]
[junit4] 2> at com.carrotsearch.randomizedtesting.RandomizedRunner.invoke(RandomizedRunner.java:1754) [randomizedtesting-runner-2.7.6.jar:?]
[junit4] 2> at com.carrotsearch.randomizedtesting.RandomizedRunner$6.evaluate(RandomizedRunner.java:882) [randomizedtesting-runner-2.7.6.jar:?]
[junit4] 2> at com.carrotsearch.randomizedtesting.RandomizedRunner$7.evaluate(RandomizedRunner.java:898) [randomizedtesting-runner-2.7.6.jar:?]
[junit4] 2> at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36) [randomizedtesting-runner-2.7.6.jar:?]
[junit4] 2> at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:57) [randomizedtesting-runner-2.7.6.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.6.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.6.jar:?]
[junit4] 2> at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:40) [randomizedtesting-runner-2.7.6.jar:?]
[junit4] 2> at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36) [randomizedtesting-runner-2.7.6.jar:?]
[junit4] 2> at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36) [randomizedtesting-runner-2.7.6.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.6.jar:?]
[junit4] 2> at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:370) [randomizedtesting-runner-2.7.6.jar:?]
[junit4] 2> at com.carrotsearch.randomizedtesting.ThreadLeakControl.lambda$forkTimeoutingTask$0(ThreadLeakControl.java:826) [randomizedtesting-runner-2.7.6.jar:?]
[junit4] 2> at java.lang.Thread.run(Thread.java:830) [?:?]
[junit4] 2> 551298 INFO (SUITE-SoftAutoCommitTest-seed#[E453A00BA8CF69CC]-worker) [ ] o.a.s.h.c.HttpShardHandlerFactory Host whitelist initialized: WhitelistHostChecker [whitelistHosts=null, whitelistHostCheckingEnabled=true]
[junit4] 2> 551312 WARN (SUITE-SoftAutoCommitTest-seed#[E453A00BA8CF69CC]-worker) [ ] o.e.j.u.s.S.config Trusting all certificates configured for Client@3cb541ca[provider=null,keyStore=null,trustStore=null]
[junit4] 2> 551312 WARN (SUITE-SoftAutoCommitTest-seed#[E453A00BA8CF69CC]-worker) [ ] o.e.j.u.s.S.config No Client EndPointIdentificationAlgorithm configured for Client@3cb541ca[provider=null,keyStore=null,trustStore=null]
[junit4] 2> 551334 WARN (SUITE-SoftAutoCommitTest-seed#[E453A00BA8CF69CC]-worker) [ ] o.e.j.u.s.S.config Trusting all certificates configured for Client@7a18a9f[provider=null,keyStore=null,trustStore=null]
[junit4] 2> 551334 WARN (SUITE-SoftAutoCommitTest-seed#[E453A00BA8CF69CC]-worker) [ ] o.e.j.u.s.S.config No Client EndPointIdentificationAlgorithm configured for Client@7a18a9f[provider=null,keyStore=null,trustStore=null]
[junit4] 2> 551334 WARN (SUITE-SoftAutoCommitTest-seed#[E453A00BA8CF69CC]-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> 551454 INFO (SUITE-SoftAutoCommitTest-seed#[E453A00BA8CF69CC]-worker) [ ] o.a.s.c.TransientSolrCoreCacheDefault Allocating transient cache for 1000 transient cores
[junit4] 2> 551454 INFO (SUITE-SoftAutoCommitTest-seed#[E453A00BA8CF69CC]-worker) [ ] o.a.s.h.a.MetricsHistoryHandler No .system collection, keeping metrics history in memory.
[junit4] 2> 551510 INFO (SUITE-SoftAutoCommitTest-seed#[E453A00BA8CF69CC]-worker) [ ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr.node' (registry 'solr.node') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@332c10b3
[junit4] 2> 551526 INFO (SUITE-SoftAutoCommitTest-seed#[E453A00BA8CF69CC]-worker) [ ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr.jvm' (registry 'solr.jvm') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@332c10b3
[junit4] 2> 551526 INFO (SUITE-SoftAutoCommitTest-seed#[E453A00BA8CF69CC]-worker) [ ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr.jetty' (registry 'solr.jetty') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@332c10b3
[junit4] 2> 551543 INFO (coreLoadExecutor-3587-thread-1) [ x:collection1 ] o.a.s.c.SolrConfig Using Lucene MatchVersion: 9.0.0
[junit4] 2> 551584 INFO (coreLoadExecutor-3587-thread-1) [ x:collection1 ] o.a.s.c.CoreContainer Creating SolrCore 'collection1' using configuration from instancedir /Users/jenkins/workspace/Lucene-Solr-master-MacOSX/solr/core/src/test-files/solr/collection1, trusted=true
[junit4] 2> 551592 INFO (coreLoadExecutor-3587-thread-1) [ x:collection1 ] o.a.s.s.IndexSchema Schema name=test
[junit4] 2> 551857 INFO (coreLoadExecutor-3587-thread-1) [ x:collection1 ] o.a.s.s.IndexSchema Loaded schema test/1.0 with uniqueid field id
[junit4] 2> 551913 INFO (coreLoadExecutor-3587-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@332c10b3
[junit4] 2> 551913 INFO (coreLoadExecutor-3587-thread-1) [ x:collection1 ] o.a.s.c.SolrCore [[collection1] ] Opening new SolrCore at [/Users/jenkins/workspace/Lucene-Solr-master-MacOSX/solr/core/src/test-files/solr/collection1], dataDir=[/Users/jenkins/workspace/Lucene-Solr-master-MacOSX/solr/build/solr-core/test/J1/temp/solr.update.SoftAutoCommitTest_E453A00BA8CF69CC-001/data-dir-44-001/]
[junit4] 2> 551923 INFO (coreLoadExecutor-3587-thread-1) [ x:collection1 ] o.a.s.u.RandomMergePolicy RandomMergePolicy wrapping class org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: maxMergeAtOnce=46, maxMergeAtOnceExplicit=31, maxMergedSegmentMB=92.080078125, floorSegmentMB=0.21875, forceMergeDeletesPctAllowed=28.587403632068558, segmentsPerTier=48.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.7451723430030592, deletesPctAllowed=32.76397807639149
[junit4] 2> 552108 INFO (coreLoadExecutor-3587-thread-1) [ x:collection1 ] o.a.s.u.UpdateHandler Using UpdateLog implementation: org.apache.solr.update.UpdateLog
[junit4] 2> 552109 INFO (coreLoadExecutor-3587-thread-1) [ x:collection1 ] o.a.s.u.UpdateLog Initializing UpdateLog: dataDir= defaultSyncLevel=FLUSH numRecordsToKeep=100 maxNumLogsToKeep=10 numVersionBuckets=65536
[junit4] 2> 552112 INFO (coreLoadExecutor-3587-thread-1) [ x:collection1 ] o.a.s.u.CommitTracker Hard AutoCommit: disabled
[junit4] 2> 552112 INFO (coreLoadExecutor-3587-thread-1) [ x:collection1 ] o.a.s.u.CommitTracker Soft AutoCommit: disabled
[junit4] 2> 552115 INFO (coreLoadExecutor-3587-thread-1) [ x:collection1 ] o.a.s.u.RandomMergePolicy RandomMergePolicy wrapping class org.apache.lucene.index.LogByteSizeMergePolicy: [LogByteSizeMergePolicy: minMergeSize=1677721, mergeFactor=48, maxMergeSize=2147483648, maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=true, maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.5813466194367937]
[junit4] 2> 552118 INFO (coreLoadExecutor-3587-thread-1) [ x:collection1 ] o.a.s.h.c.SpellCheckComponent Initializing spell checkers
[junit4] 2> 552174 INFO (coreLoadExecutor-3587-thread-1) [ x:collection1 ] o.a.s.s.DirectSolrSpellChecker init: {name=direct, classname=DirectSolrSpellChecker, field=lowerfilt, minQueryLength=3}
[junit4] 2> 552447 INFO (coreLoadExecutor-3587-thread-1) [ x:collection1 ] o.a.s.h.ReplicationHandler Commits will be reserved for 10000 ms
[junit4] 2> 552448 INFO (coreLoadExecutor-3587-thread-1) [ x:collection1 ] o.a.s.u.UpdateLog Could not find max version in index or recent updates, using new clock 1673143328673103872
[junit4] 2> 552449 INFO (searcherExecutor-3589-thread-1-processing-x:collection1) [ x:collection1 ] o.a.s.h.c.SpellCheckComponent Loading spell index for spellchecker: default
[junit4] 2> 552451 INFO (searcherExecutor-3589-thread-1-processing-x:collection1) [ x:collection1 ] o.a.s.h.c.SpellCheckComponent Loading spell index for spellchecker: direct
[junit4] 2> 552451 INFO (searcherExecutor-3589-thread-1-processing-x:collection1) [ x:collection1 ] o.a.s.h.c.SpellCheckComponent Loading spell index for spellchecker: wordbreak
[junit4] 2> 552451 INFO (searcherExecutor-3589-thread-1-processing-x:collection1) [ x:collection1 ] o.a.s.h.c.SpellCheckComponent Loading spell index for spellchecker: multipleFields
[junit4] 2> 552453 INFO (searcherExecutor-3589-thread-1-processing-x:collection1) [ x:collection1 ] o.a.s.h.c.SpellCheckComponent Loading spell index for spellchecker: jarowinkler
[junit4] 2> 552454 INFO (SUITE-SoftAutoCommitTest-seed#[E453A00BA8CF69CC]-worker) [ ] o.a.s.SolrTestCaseJ4 ####initCore end
[junit4] 2> 552454 INFO (searcherExecutor-3589-thread-1-processing-x:collection1) [ x:collection1 ] o.a.s.h.c.SpellCheckComponent Loading spell index for spellchecker: external
[junit4] 2> 552454 INFO (searcherExecutor-3589-thread-1-processing-x:collection1) [ x:collection1 ] o.a.s.h.c.SpellCheckComponent Loading spell index for spellchecker: freq
[junit4] 2> 552459 INFO (searcherExecutor-3589-thread-1-processing-x:collection1) [ x:collection1 ] o.a.s.h.c.SpellCheckComponent Loading spell index for spellchecker: fqcn
[junit4] 2> 552461 INFO (searcherExecutor-3589-thread-1-processing-x:collection1) [ x:collection1 ] o.a.s.h.c.SpellCheckComponent Loading spell index for spellchecker: perDict
[junit4] 2> 552464 INFO (searcherExecutor-3589-thread-1-processing-x:collection1) [ x:collection1 ] o.a.s.c.SolrCore [collection1] Registered new searcher autowarm time: 0 ms
[junit4] 2> 552465 INFO (TEST-SoftAutoCommitTest.testSoftCommitWithinAndHardCommitMaxTimeRapidAdds-seed#[E453A00BA8CF69CC]) [ ] o.a.s.SolrTestCaseJ4 ###Starting testSoftCommitWithinAndHardCommitMaxTimeRapidAdds
[junit4] 2> 557475 INFO (TEST-SoftAutoCommitTest.testSoftCommitWithinAndHardCommitMaxTimeRapidAdds-seed#[E453A00BA8CF69CC]) [ x:collection1 ] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=null path=null params={}{add=[5000 (1673143333936955392)]} 0 7
[junit4] 2> 557479 INFO (TEST-SoftAutoCommitTest.testSoftCommitWithinAndHardCommitMaxTimeRapidAdds-seed#[E453A00BA8CF69CC]) [ x:collection1 ] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=null path=null params={}{add=[5001 (1673143333948489728)]} 0 0
[junit4] 2> 557480 INFO (TEST-SoftAutoCommitTest.testSoftCommitWithinAndHardCommitMaxTimeRapidAdds-seed#[E453A00BA8CF69CC]) [ x:collection1 ] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=null path=null params={}{add=[5002 (1673143333949538304)]} 0 0
[junit4] 2> 557481 INFO (TEST-SoftAutoCommitTest.testSoftCommitWithinAndHardCommitMaxTimeRapidAdds-seed#[E453A00BA8CF69CC]) [ x:collection1 ] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=null path=null params={}{add=[5003 (1673143333949538305)]} 0 0
[junit4] 2> 557481 INFO (TEST-SoftAutoCommitTest.testSoftCommitWithinAndHardCommitMaxTimeRapidAdds-seed#[E453A00BA8CF69CC]) [ x:collection1 ] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=null path=null params={}{add=[5004 (1673143333950586880)]} 0 0
[junit4] 2> 557482 INFO (TEST-SoftAutoCommitTest.testSoftCommitWithinAndHardCommitMaxTimeRapidAdds-seed#[E453A00BA8CF69CC]) [ ] o.a.s.u.SoftAutoCommitTest maxTimeMillis: 371197821032922ns - 371197807508277ns == 13ms
[junit4] 2> 557482 INFO (TEST-SoftAutoCommitTest.testSoftCommitWithinAndHardCommitMaxTimeRapidAdds-seed#[E453A00BA8CF69CC]) [ ] o.a.s.u.SoftAutoCommitTest maxExpectedSoft=1
[junit4] 2> 557482 INFO (TEST-SoftAutoCommitTest.testSoftCommitWithinAndHardCommitMaxTimeRapidAdds-seed#[E453A00BA8CF69CC]) [ ] o.a.s.u.SoftAutoCommitTest maxExpectedHard=1
[junit4] 2> 557984 INFO (searcherExecutor-3589-thread-1-processing-x:collection1) [ x:collection1 ] o.a.s.c.SolrCore [collection1] Registered new searcher autowarm time: 0 ms
[junit4] 2> 564235 INFO (TEST-SoftAutoCommitTest.testSoftCommitWithinAndHardCommitMaxTimeRapidAdds-seed#[E453A00BA8CF69CC]) [ ] o.a.s.SolrTestCaseJ4 ###Ending testSoftCommitWithinAndHardCommitMaxTimeRapidAdds
[junit4] 2> 564239 INFO (TEST-SoftAutoCommitTest.testHardCommitWithinAndSoftCommitMaxTimeMixedAdds-seed#[E453A00BA8CF69CC]) [ ] o.a.s.SolrTestCaseJ4 ###Starting testHardCommitWithinAndSoftCommitMaxTimeMixedAdds
[junit4] 2> 572669 INFO (TEST-SoftAutoCommitTest.testHardCommitWithinAndSoftCommitMaxTimeMixedAdds-seed#[E453A00BA8CF69CC]) [ x:collection1 ] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=null path=null params={}{add=[529 (1673143349862727680)]} 0 12
[junit4] 2> 573230 INFO (searcherExecutor-3589-thread-1-processing-x:collection1) [ x:collection1 ] o.a.s.c.SolrCore [collection1] Registered new searcher autowarm time: 0 ms
[junit4] 2> 573895 INFO (TEST-SoftAutoCommitTest.testHardCommitWithinAndSoftCommitMaxTimeMixedAdds-seed#[E453A00BA8CF69CC]) [ x:collection1 ] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=null path=null params={}{add=[530 (1673143351158767616)]} 0 3
[junit4] 2> 574398 INFO (searcherExecutor-3589-thread-1-processing-x:collection1) [ x:collection1 ] o.a.s.c.SolrCore [collection1] Registered new searcher autowarm time: 0 ms
[junit4] 2> 580746 INFO (TEST-SoftAutoCommitTest.testHardCommitWithinAndSoftCommitMaxTimeMixedAdds-seed#[E453A00BA8CF69CC]) [ ] o.a.s.SolrTestCaseJ4 ###Ending testHardCommitWithinAndSoftCommitMaxTimeMixedAdds
[junit4] 2> NOTE: reproduce with: ant test -Dtestcase=SoftAutoCommitTest -Dtests.method=testHardCommitWithinAndSoftCommitMaxTimeMixedAdds -Dtests.seed=E453A00BA8CF69CC -Dtests.slow=true -Dtests.locale=ar-AE -Dtests.timezone=Africa/Nouakchott -Dtests.asserts=true -Dtests.file.encoding=ISO-8859-1
[junit4] FAILURE 16.5s J1 | SoftAutoCommitTest.testHardCommitWithinAndSoftCommitMaxTimeMixedAdds <<<
[junit4] > Throwable #1: java.lang.AssertionError: soft530 after hard529 but no hard530: 371214736193346 !<= 371214228935877
[junit4] > at __randomizedtesting.SeedInfo.seed([E453A00BA8CF69CC:27B47C1A99F3BEB1]:0)
[junit4] > at org.apache.solr.update.SoftAutoCommitTest.doTestSoftAndHardCommitMaxTimeMixedAdds(SoftAutoCommitTest.java:268)
[junit4] > at org.apache.solr.update.SoftAutoCommitTest.testHardCommitWithinAndSoftCommitMaxTimeMixedAdds(SoftAutoCommitTest.java:174)
[junit4] > at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
[junit4] > at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
[junit4] > at java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
[junit4] > at java.base/java.lang.reflect.Method.invoke(Method.java:567)
[junit4] > at java.base/java.lang.Thread.run(Thread.java:830)
[junit4] 2> 580756 INFO (TEST-SoftAutoCommitTest.testHardCommitWithinAndSoftCommitMaxTimeRapidAdds-seed#[E453A00BA8CF69CC]) [ ] o.a.s.SolrTestCaseJ4 ###Starting testHardCommitWithinAndSoftCommitMaxTimeRapidAdds
[junit4] 2> 585763 INFO (TEST-SoftAutoCommitTest.testHardCommitWithinAndSoftCommitMaxTimeRapidAdds-seed#[E453A00BA8CF69CC]) [ x:collection1 ] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=null path=null params={}{add=[5000 (1673143363604316160)]} 0 5
[junit4] 2> 585765 INFO (TEST-SoftAutoCommitTest.testHardCommitWithinAndSoftCommitMaxTimeRapidAdds-seed#[E453A00BA8CF69CC]) [ x:collection1 ] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=null path=null params={}{add=[5001 (1673143363607461888)]} 0 0
[junit4] 2> 585765 INFO (TEST-SoftAutoCommitTest.testHardCommitWithinAndSoftCommitMaxTimeRapidAdds-seed#[E453A00BA8CF69CC]) [ x:collection1 ] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=null path=null params={}{add=[5002 (1673143363608510464)]} 0 0
[junit4] 2> 585766 INFO (TEST-SoftAutoCommitTest.testHardCommitWithinAndSoftCommitMaxTimeRapidAdds-seed#[E453A00BA8CF69CC]) [ x:collection1 ] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=null path=null params={}{add=[5003 (1673143363609559040)]} 0 0
[junit4] 2> 585767 INFO (TEST-SoftAutoCommitTest.testHardCommitWithinAndSoftCommitMaxTimeRapidAdds-seed#[E453A00BA8CF69CC]) [ x:collection1 ] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=null path=null params={}{add=[5004 (1673143363610607616)]} 0 0
[junit4] 2> 585767 INFO (TEST-SoftAutoCommitTest.testHardCommitWithinAndSoftCommitMaxTimeRapidAdds-seed#[E453A00BA8CF69CC]) [ ] o.a.s.u.SoftAutoCommitTest maxTimeMillis: 371226106840115ns - 371226097217174ns == 9ms
[junit4] 2> 585767 INFO (TEST-SoftAutoCommitTest.testHardCommitWithinAndSoftCommitMaxTimeRapidAdds-seed#[E453A00BA8CF69CC]) [ ] o.a.s.u.SoftAutoCommitTest maxExpectedSoft=1
[junit4] 2> 585767 INFO (TEST-SoftAutoCommitTest.testHardCommitWithinAndSoftCommitMaxTimeRapidAdds-seed#[E453A00BA8CF69CC]) [ ] o.a.s.u.SoftAutoCommitTest maxExpectedHard=1
[junit4] 2> 586292 INFO (searcherExecutor-3589-thread-1-processing-x:collection1) [ x:collection1 ] o.a.s.c.SolrCore [collection1] Registered new searcher autowarm time: 0 ms
[junit4] 2> 592415 INFO (TEST-SoftAutoCommitTest.testHardCommitWithinAndSoftCommitMaxTimeRapidAdds-seed#[E453A00BA8CF69CC]) [ ] o.a.s.SolrTestCaseJ4 ###Ending testHardCommitWithinAndSoftCommitMaxTimeRapidAdds
[junit4] 2> 592422 INFO (TEST-SoftAutoCommitTest.testSoftCommitWithinAndHardCommitMaxTimeDelete-seed#[E453A00BA8CF69CC]) [ ] o.a.s.SolrTestCaseJ4 ###Starting testSoftCommitWithinAndHardCommitMaxTimeDelete
[junit4] 2> 597814 INFO (TEST-SoftAutoCommitTest.testSoftCommitWithinAndHardCommitMaxTimeDelete-seed#[E453A00BA8CF69CC]) [ x:collection1 ] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=null path=null params={}{add=[529 (1673143376239656960)]} 0 2
[junit4] 2> 597836 INFO (searcherExecutor-3589-thread-1-processing-x:collection1) [ x:collection1 ] o.a.s.c.SolrCore [collection1] Registered new searcher autowarm time: 0 ms
[junit4] 2> 597848 INFO (TEST-SoftAutoCommitTest.testSoftCommitWithinAndHardCommitMaxTimeDelete-seed#[E453A00BA8CF69CC]) [ x:collection1 ] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=null path=null params={}{commit=} 0 33
[junit4] 2> 597849 INFO (TEST-SoftAutoCommitTest.testSoftCommitWithinAndHardCommitMaxTimeDelete-seed#[E453A00BA8CF69CC]) [ x:collection1 ] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=null path=null params={}{delete=[529 (-1673143376279502848)]} 0 1
[junit4] 2> 598355 INFO (searcherExecutor-3589-thread-1-processing-x:collection1) [ x:collection1 ] o.a.s.c.SolrCore [collection1] Registered new searcher autowarm time: 0 ms
[junit4] 2> 598355 INFO (TEST-SoftAutoCommitTest.testSoftCommitWithinAndHardCommitMaxTimeDelete-seed#[E453A00BA8CF69CC]) [ x:collection1 ] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=null path=null params={}{add=[550 (1673143376807985152)]} 0 2
[junit4] 2> 598870 INFO (searcherExecutor-3589-thread-1-processing-x:collection1) [ x:collection1 ] o.a.s.c.SolrCore [collection1] Registered new searcher autowarm time: 0 ms
[junit4] 2> 608095 INFO (TEST-SoftAutoCommitTest.testSoftCommitWithinAndHardCommitMaxTimeDelete-seed#[E453A00BA8CF69CC]) [ ] o.a.s.SolrTestCaseJ4 ###Ending testSoftCommitWithinAndHardCommitMaxTimeDelete
[junit4] 2> 608104 INFO (TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeDelete-seed#[E453A00BA8CF69CC]) [ ] o.a.s.SolrTestCaseJ4 ###Starting testSoftAndHardCommitMaxTimeDelete
[junit4] 2> 613124 INFO (TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeDelete-seed#[E453A00BA8CF69CC]) [ x:collection1 ] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=null path=null params={}{add=[529 (1673143392293355520)]} 0 3
[junit4] 2> 613139 INFO (searcherExecutor-3589-thread-1-processing-x:collection1) [ x:collection1 ] o.a.s.c.SolrCore [collection1] Registered new searcher autowarm time: 0 ms
[junit4] 2> 613140 INFO (TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeDelete-seed#[E453A00BA8CF69CC]) [ x:collection1 ] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=null path=null params={}{commit=} 0 11
[junit4] 2> 613142 INFO (TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeDelete-seed#[E453A00BA8CF69CC]) [ x:collection1 ] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=null path=null params={}{delete=[529 (-1673143392314327040)]} 0 1
[junit4] 2> 613654 INFO (searcherExecutor-3589-thread-1-processing-x:collection1) [ x:collection1 ] o.a.s.c.SolrCore [collection1] Registered new searcher autowarm time: 0 ms
[junit4] 2> 613658 INFO (TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeDelete-seed#[E453A00BA8CF69CC]) [ x:collection1 ] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=null path=null params={}{add=[550 (1673143392851197952)]} 0 5
[junit4] 2> 614179 INFO (searcherExecutor-3589-thread-1-processing-x:collection1) [ x:collection1 ] o.a.s.c.SolrCore [collection1] Registered new searcher autowarm time: 0 ms
[junit4] 2> 621499 INFO (TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeDelete-seed#[E453A00BA8CF69CC]) [ ] o.a.s.SolrTestCaseJ4 ###Ending testSoftAndHardCommitMaxTimeDelete
[junit4] 2> 621506 INFO (TEST-SoftAutoCommitTest.testSoftCommitWithinAndHardCommitMaxTimeMixedAdds-seed#[E453A00BA8CF69CC]) [ ] o.a.s.SolrTestCaseJ4 ###Starting testSoftCommitWithinAndHardCommitMaxTimeMixedAdds
[junit4] 2> 642128 INFO (TEST-SoftAutoCommitTest.testSoftCommitWithinAndHardCommitMaxTimeMixedAdds-seed#[E453A00BA8CF69CC]) [ x:collection1 ] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=null path=null params={}{add=[529 (1673143422675845120)]} 0 32
[junit4] 2> 642641 INFO (searcherExecutor-3589-thread-1-processing-x:collection1) [ x:collection1 ] o.a.s.c.SolrCore [collection1] Registered new searcher autowarm time: 0 ms
[junit4] 2> 644776 INFO (TEST-SoftAutoCommitTest.testSoftCommitWithinAndHardCommitMaxTimeMixedAdds-seed#[E453A00BA8CF69CC]) [ x:collection1 ] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=null path=null params={}{add=[530 (1673143425482883072)]} 0 3
[junit4] 2> 645292 INFO (searcherExecutor-3589-thread-1-processing-x:collection1) [ x:collection1 ] o.a.s.c.SolrCore [collection1] Registered new searcher autowarm time: 0 ms
[junit4] 2> 648105 INFO (TEST-SoftAutoCommitTest.testSoftCommitWithinAndHardCommitMaxTimeMixedAdds-seed#[E453A00BA8CF69CC]) [ ] o.a.s.SolrTestCaseJ4 ###Ending testSoftCommitWithinAndHardCommitMaxTimeMixedAdds
[junit4] 2> 648111 INFO (TEST-SoftAutoCommitTest.testHardCommitWithinAndSoftCommitMaxTimeDelete-seed#[E453A00BA8CF69CC]) [ ] o.a.s.SolrTestCaseJ4 ###Starting testHardCommitWithinAndSoftCommitMaxTimeDelete
[junit4] 2> 653119 INFO (TEST-SoftAutoCommitTest.testHardCommitWithinAndSoftCommitMaxTimeDelete-seed#[E453A00BA8CF69CC]) [ x:collection1 ] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=null path=null params={}{add=[529 (1673143434233249792)]} 0 1
[junit4] 2> 653129 INFO (searcherExecutor-3589-thread-1-processing-x:collection1) [ x:collection1 ] o.a.s.c.SolrCore [collection1] Registered new searcher autowarm time: 0 ms
[junit4] 2> 653129 INFO (TEST-SoftAutoCommitTest.testHardCommitWithinAndSoftCommitMaxTimeDelete-seed#[E453A00BA8CF69CC]) [ x:collection1 ] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=null path=null params={}{commit=} 0 9
[junit4] 2> 653131 INFO (TEST-SoftAutoCommitTest.testHardCommitWithinAndSoftCommitMaxTimeDelete-seed#[E453A00BA8CF69CC]) [ x:collection1 ] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=null path=null params={}{delete=[529 (-1673143434245832704)]} 0 1
[junit4] 2> 653634 INFO (TEST-SoftAutoCommitTest.testHardCommitWithinAndSoftCommitMaxTimeDelete-seed#[E453A00BA8CF69CC]) [ x:collection1 ] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=null path=null params={}{add=[550 (1673143434773266432)]} 0 0
[junit4] 2> 653635 INFO (searcherExecutor-3589-thread-1-processing-x:collection1) [ x:collection1 ] o.a.s.c.SolrCore [collection1] Registered new searcher autowarm time: 0 ms
[junit4] 2> 654143 INFO (searcherExecutor-3589-thread-1-processing-x:collection1) [ x:collection1 ] o.a.s.c.SolrCore [collection1] Registered new searcher autowarm time: 0 ms
[junit4] 2> 660342 INFO (TEST-SoftAutoCommitTest.testHardCommitWithinAndSoftCommitMaxTimeDelete-seed#[E453A00BA8CF69CC]) [ ] o.a.s.SolrTestCaseJ4 ###Ending testHardCommitWithinAndSoftCommitMaxTimeDelete
[junit4] 2> 660347 INFO (TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeRapidAdds-seed#[E453A00BA8CF69CC]) [ ] o.a.s.SolrTestCaseJ4 ###Starting testSoftAndHardCommitMaxTimeRapidAdds
[junit4] 2> 665357 INFO (TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeRapidAdds-seed#[E453A00BA8CF69CC]) [ x:collection1 ] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=null path=null params={}{add=[5000 (1673143447057334272)]} 0 8
[junit4] 2> 665357 INFO (TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeRapidAdds-seed#[E453A00BA8CF69CC]) [ x:collection1 ] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=null path=null params={}{add=[5001 (1673143447066771456)]} 0 0
[junit4] 2> 665358 INFO (TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeRapidAdds-seed#[E453A00BA8CF69CC]) [ x:collection1 ] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=null path=null params={}{add=[5002 (1673143447067820032)]} 0 0
[junit4] 2> 665358 INFO (TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeRapidAdds-seed#[E453A00BA8CF69CC]) [ x:collection1 ] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=null path=null params={}{add=[5003 (1673143447067820033)]} 0 0
[junit4] 2> 665359 INFO (TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeRapidAdds-seed#[E453A00BA8CF69CC]) [ x:collection1 ] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=null path=null params={}{add=[5004 (1673143447067820034)]} 0 0
[junit4] 2> 665359 INFO (TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeRapidAdds-seed#[E453A00BA8CF69CC]) [ ] o.a.s.u.SoftAutoCommitTest maxTimeMillis: 371305698478048ns - 371305687719721ns == 10ms
[junit4] 2> 665359 INFO (TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeRapidAdds-seed#[E453A00BA8CF69CC]) [ ] o.a.s.u.SoftAutoCommitTest maxExpectedSoft=1
[junit4] 2> 665359 INFO (TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeRapidAdds-seed#[E453A00BA8CF69CC]) [ ] o.a.s.u.SoftAutoCommitTest maxExpectedHard=1
[junit4] 2> 665874 INFO (searcherExecutor-3589-thread-1-processing-x:collection1) [ x:collection1 ] o.a.s.c.SolrCore [collection1] Registered new searcher autowarm time: 0 ms
[junit4] 2> 671975 INFO (TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeRapidAdds-seed#[E453A00BA8CF69CC]) [ ] o.a.s.SolrTestCaseJ4 ###Ending testSoftAndHardCommitMaxTimeRapidAdds
[junit4] 2> 671980 INFO (TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxDocs-seed#[E453A00BA8CF69CC]) [ ] o.a.s.SolrTestCaseJ4 ###Starting testSoftAndHardCommitMaxDocs
[junit4] 2> 679982 INFO (TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxDocs-seed#[E453A00BA8CF69CC]) [ x:collection1 ] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=null path=null params={}{add=[8000 (1673143462401146880)]} 0 1
[junit4] 2> 679983 INFO (TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxDocs-seed#[E453A00BA8CF69CC]) [ x:collection1 ] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=null path=null params={}{add=[8001 (1673143462402195456)]} 0 0
[junit4] 2> 679983 INFO (TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxDocs-seed#[E453A00BA8CF69CC]) [ x:collection1 ] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=null path=null params={}{add=[8002 (1673143462403244032)]} 0 0
[junit4] 2> 679983 INFO (TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxDocs-seed#[E453A00BA8CF69CC]) [ x:collection1 ] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=null path=null params={}{add=[8003 (1673143462403244033)]} 0 0
[junit4] 2> 679983 INFO (TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxDocs-seed#[E453A00BA8CF69CC]) [ x:collection1 ] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=null path=null params={}{add=[8004 (1673143462403244034)]} 0 0
[junit4] 2> 679984 INFO (TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxDocs-seed#[E453A00BA8CF69CC]) [ x:collection1 ] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=null path=null params={}{add=[8005 (1673143462404292608)]} 0 0
[junit4] 2> 679985 INFO (TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxDocs-seed#[E453A00BA8CF69CC]) [ x:collection1 ] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=null path=null params={}{add=[8006 (1673143462405341184)]} 0 0
[junit4] 2> 679985 INFO (TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxDocs-seed#[E453A00BA8CF69CC]) [ x:collection1 ] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=null path=null params={}{add=[8007 (1673143462405341185)]} 0 0
[junit4] 2> 680025 INFO (searcherExecutor-3589-thread-1-processing-x:collection1) [ x:collection1 ] o.a.s.c.SolrCore [collection1] Registered new searcher autowarm time: 0 ms
[junit4] 2> 681038 INFO (TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxDocs-seed#[E453A00BA8CF69CC]) [ ] o.a.s.SolrTestCaseJ4 ###Ending testSoftAndHardCommitMaxDocs
[junit4] 2> 681042 INFO (TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeMixedAdds-seed#[E453A00BA8CF69CC]) [ ] o.a.s.SolrTestCaseJ4 ###Starting testSoftAndHardCommitMaxTimeMixedAdds
[junit4] 2> 689467 INFO (TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeMixedAdds-seed#[E453A00BA8CF69CC]) [ x:collection1 ] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=null path=null params={}{add=[529 (1673143472334307328)]} 0 13
[junit4] 2> 689985 INFO (searcherExecutor-3589-thread-1-processing-x:collection1) [ x:collection1 ] o.a.s.c.SolrCore [collection1] Registered new searcher autowarm time: 0 ms
[junit4] 2> 690796 INFO (TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeMixedAdds-seed#[E453A00BA8CF69CC]) [ x:collection1 ] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=null path=null params={}{add=[530 (1673143473738350592)]} 0 3
[junit4] 2> 691307 INFO (searcherExecutor-3589-thread-1-processing-x:collection1) [ x:collection1 ] o.a.s.c.SolrCore [collection1] Registered new searcher autowarm time: 0 ms
[junit4] 2> 693019 INFO (TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeMixedAdds-seed#[E453A00BA8CF69CC]) [ ] o.a.s.SolrTestCaseJ4 ###Ending testSoftAndHardCommitMaxTimeMixedAdds
[junit4] 2> 693020 INFO (SUITE-SoftAutoCommitTest-seed#[E453A00BA8CF69CC]-worker) [ ] o.a.s.SolrTestCaseJ4 ###deleteCore
[junit4] 2> 693020 INFO (SUITE-SoftAutoCommitTest-seed#[E453A00BA8CF69CC]-worker) [ ] o.a.s.c.CoreContainer Shutting down CoreContainer instance=29059608
[junit4] 2> 693021 INFO (coreCloseExecutor-3595-thread-1) [ ] o.a.s.c.SolrCore [collection1] CLOSING SolrCore org.apache.solr.core.SolrCore@7d31436d
[junit4] 2> 693021 INFO (coreCloseExecutor-3595-thread-1) [ ] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.core.collection1 tag=SolrCore@7d31436d
[junit4] 2> 693021 INFO (coreCloseExecutor-3595-thread-1) [ ] o.a.s.m.r.SolrJmxReporter Closing reporter [org.apache.solr.metrics.reporters.SolrJmxReporter@7e9cae26: rootName = null, domain = solr.core.collection1, service url = null, agent id = null] for registry solr.core.collection1/com.codahale.metrics.MetricRegistry@69b31f86
[junit4] 2> 693039 INFO (coreCloseExecutor-3595-thread-1) [ ] o.a.s.u.DirectUpdateHandler2 Committing on IndexWriter.close() ... SKIPPED (unnecessary).
[junit4] 2> 693042 INFO (SUITE-SoftAutoCommitTest-seed#[E453A00BA8CF69CC]-worker) [ ] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.node tag=null
[junit4] 2> 693042 INFO (SUITE-SoftAutoCommitTest-seed#[E453A00BA8CF69CC]-worker) [ ] o.a.s.m.r.SolrJmxReporter Closing reporter [org.apache.solr.metrics.reporters.SolrJmxReporter@33b60577: rootName = null, domain = solr.node, service url = null, agent id = null] for registry solr.node/com.codahale.metrics.MetricRegistry@c78dc44
[junit4] 2> 693048 INFO (SUITE-SoftAutoCommitTest-seed#[E453A00BA8CF69CC]-worker) [ ] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.jvm tag=null
[junit4] 2> 693048 INFO (SUITE-SoftAutoCommitTest-seed#[E453A00BA8CF69CC]-worker) [ ] o.a.s.m.r.SolrJmxReporter Closing reporter [org.apache.solr.metrics.reporters.SolrJmxReporter@2d64d7ce: rootName = null, domain = solr.jvm, service url = null, agent id = null] for registry solr.jvm/com.codahale.metrics.MetricRegistry@540a41cb
[junit4] 2> 693051 INFO (SUITE-SoftAutoCommitTest-seed#[E453A00BA8CF69CC]-worker) [ ] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.jetty tag=null
[junit4] 2> 693051 INFO (SUITE-SoftAutoCommitTest-seed#[E453A00BA8CF69CC]-worker) [ ] o.a.s.m.r.SolrJmxReporter Closing reporter [org.apache.solr.metrics.reporters.SolrJmxReporter@53d5ff4b: rootName = null, domain = solr.jetty, service url = null, agent id = null] for registry solr.jetty/com.codahale.metrics.MetricRegistry@3da39f
[junit4] 2> NOTE: leaving temporary files on disk at: /Users/jenkins/workspace/Lucene-Solr-master-MacOSX/solr/build/solr-core/test/J1/temp/solr.update.SoftAutoCommitTest_E453A00BA8CF69CC-001
[junit4] 2> NOTE: test params are: codec=Asserting(Lucene86): {multiDefault=PostingsFormat(name=Direct), subject=PostingsFormat(name=Direct), _root_=Lucene84, id=PostingsFormat(name=LuceneVarGapDocFreqInterval), text=PostingsFormat(name=LuceneFixedGap)}, docValues:{range_facet_l_dv=DocValuesFormat(name=Lucene80), _version_=DocValuesFormat(name=Asserting), range_facet_i_dv=DocValuesFormat(name=Asserting), intDvoDefault=DocValuesFormat(name=Lucene80), timestamp=DocValuesFormat(name=Asserting)}, maxPointsInLeafNode=1960, maxMBSortInHeap=6.542250749544779, sim=Asserting(RandomSimilarity(queryNorm=true): {}), locale=ar-AE, timezone=Africa/Nouakchott
[junit4] 2> NOTE: Mac OS X 10.14.6 x86_64/AdoptOpenJDK 13.0.2 (64-bit)/cpus=6,threads=1,free=52332504,total=194707456
[junit4] 2> NOTE: All tests run in this JVM: [SplitShardTest, TestPayloadCheckQParserPlugin, TestFieldSortValues, TransactionLogTest, TestDistribDocBasedVersion, ChaosMonkeySafeLeaderWithPullReplicasTest, TestExactStatsCacheCloud, TestMultiValuedNumericRangeQuery, SplitByPrefixTest, CdcrOpsAndBoundariesTest, BlockCacheTest, HDFSCollectionsAPITest, TestCloudManagedSchema, PeerSyncWithBufferUpdatesTest, MoveReplicaHDFSTest, TestLeaderElectionZkExpiry, TestDistributedSearch, CoreAdminCreateDiscoverTest, SuggestComponentContextFilterQueryTest, DistanceFunctionTest, CurrencyRangeFacetCloudTest, ConnectionReuseTest, ConcurrentCreateRoutedAliasTest, TestConfigOverlay, TestCSVResponseWriter, TestSort, SolrTestCaseJ4Test, OverseerRolesTest, TestHashQParserPlugin, SharedFSAutoReplicaFailoverTest, TestRandomFlRTGCloud, TestNestedDocsSort, CloudMLTQParserTest, LukeRequestHandlerTest, TestDeprecatedFilters, TestNumericTerms64, TestSolrQueryResponse, JavaBinAtomicUpdateMultivalueTest, TolerantUpdateProcessorTest, TestValueSourceCache, TestPHPSerializedResponseWriter, TlogReplayBufferedWhileIndexingTest, TestTlogReplayVsRecovery, TestCoreAdminApis, TestRTGBase, DistributedQueryElevationComponentTest, SpellingQueryConverterTest, NoCacheHeaderTest, RuleEngineTest, InfixSuggestersTest, LeaderElectionTest, RAMDirectoryFactoryTest, TestAtomicUpdateErrorCases, DirectoryFactoryTest, TestDocTermOrds, SoftAutoCommitTest]
[junit4] Completed [297/867 (1!)] on J1 in 142.76s, 10 tests, 1 failure <<< FAILURES!
[...truncated 53807 lines...]
[repro] Jenkins log URL: https://jenkins.thetaphi.de/job/Lucene-Solr-master-MacOSX/6330/consoleText
[repro] Revision: d0642600ff1a09c2f9e1a641f5d49b4974c9523c
[repro] Ant options: "-Dargs=-XX:+UseCompressedOops -XX:+UseSerialGC"
[repro] Repro line: ant test -Dtestcase=SoftAutoCommitTest -Dtests.method=testHardCommitWithinAndSoftCommitMaxTimeMixedAdds -Dtests.seed=E453A00BA8CF69CC -Dtests.slow=true -Dtests.locale=ar-AE -Dtests.timezone=Africa/Nouakchott -Dtests.asserts=true -Dtests.file.encoding=ISO-8859-1
[repro] JUnit rest result XML files will be moved to: ./repro-reports
[repro] ant clean
[...truncated 6 lines...]
[repro] Test suites by module:
[repro] solr/core
[repro] SoftAutoCommitTest
[repro] ant compile-test
[...truncated 2446 lines...]
[repro] ant test-nocompile -Dtests.dups=5 -Dtests.maxfailures=5 -Dtests.class="*.SoftAutoCommitTest" -Dtests.showOutput=onerror "-Dargs=-XX:+UseCompressedOops -XX:+UseSerialGC" -Dtests.seed=E453A00BA8CF69CC -Dtests.slow=true -Dtests.locale=ar-AE -Dtests.timezone=Africa/Nouakchott -Dtests.asserts=true -Dtests.file.encoding=ISO-8859-1
[...truncated 126 lines...]
[repro] Failures w/original seeds:
[repro] 0/5 failed: org.apache.solr.update.SoftAutoCommitTest
[repro] Exiting with code 0
[...truncated 79 lines...]