[JENKINS-EA] Lucene-Solr-master-Linux (64bit/jdk-12-ea+shipilev-fastdebug) - Build # 23759 - Unstable!

[Policeman Jenkins Server]

Build: https://jenkins.thetaphi.de/job/Lucene-Solr-master-Linux/23759/
Java: 64bit/jdk-12-ea+shipilev-fastdebug -XX:+UseCompressedOops -XX:+UseG1GC

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

Error Message:
soft530 after hard530: 1696306341180873 !<= 1696306339843564

Stack Trace:
java.lang.AssertionError: soft530 after hard530: 1696306341180873 !<= 
1696306339843564
        at 
__randomizedtesting.SeedInfo.seed([73B2184A229681F0:2266E1CA93E5B157]: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:264)
        at 
org.apache.solr.update.SoftAutoCommitTest.testSoftAndHardCommitMaxTimeMixedAdds(SoftAutoCommitTest.java:168)
        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: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 
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.base/java.lang.Thread.run(Thread.java:835)




Build Log:
[...truncated 15544 lines...]
   [junit4] Suite: org.apache.solr.update.SoftAutoCommitTest
   [junit4]   2> Creating dataDir: 
/home/jenkins/workspace/Lucene-Solr-master-Linux/solr/build/solr-core/test/J1/temp/solr.update.SoftAutoCommitTest_73B2184A229681F0-001/init-core-data-001
   [junit4]   2> 3577558 INFO  
(SUITE-SoftAutoCommitTest-seed#[73B2184A229681F0]-worker) [    ] 
o.a.s.SolrTestCaseJ4 SecureRandom sanity checks: 
test.solr.allowed.securerandom=null & java.security.egd=file:/dev/./urandom
   [junit4]   2> 3577559 WARN  
(SUITE-SoftAutoCommitTest-seed#[73B2184A229681F0]-worker) [    ] 
o.a.s.SolrTestCaseJ4 startTrackingSearchers: numOpens=24 numCloses=24
   [junit4]   2> 3577559 INFO  
(SUITE-SoftAutoCommitTest-seed#[73B2184A229681F0]-worker) [    ] 
o.a.s.SolrTestCaseJ4 Using TrieFields (NUMERIC_POINTS_SYSPROP=false) 
w/NUMERIC_DOCVALUES_SYSPROP=true
   [junit4]   2> 3577560 INFO  
(SUITE-SoftAutoCommitTest-seed#[73B2184A229681F0]-worker) [    ] 
o.a.s.SolrTestCaseJ4 Randomized ssl (false) and clientAuth (true) via: 
@org.apache.solr.util.RandomizeSSL(reason="", value=0.0/0.0, ssl=0.0/0.0, 
clientAuth=0.0/0.0)
   [junit4]   2> 3577561 INFO  
(SUITE-SoftAutoCommitTest-seed#[73B2184A229681F0]-worker) [    ] 
o.a.s.SolrTestCaseJ4 ####initCore
   [junit4]   2> 3577561 INFO  
(SUITE-SoftAutoCommitTest-seed#[73B2184A229681F0]-worker) [    ] 
o.a.s.c.SolrResourceLoader [null] Added 2 libs to classloader, from paths: 
[/home/jenkins/workspace/Lucene-Solr-master-Linux/solr/core/src/test-files/solr/collection1/lib,
 
/home/jenkins/workspace/Lucene-Solr-master-Linux/solr/core/src/test-files/solr/collection1/lib/classes]
   [junit4]   2> 3577641 INFO  
(SUITE-SoftAutoCommitTest-seed#[73B2184A229681F0]-worker) [    ] 
o.a.s.c.SolrConfig Using Lucene MatchVersion: 9.0.0
   [junit4]   2> 3577744 INFO  
(SUITE-SoftAutoCommitTest-seed#[73B2184A229681F0]-worker) [    ] 
o.a.s.s.IndexSchema [null] Schema name=test
   [junit4]   2> 3577882 INFO  
(SUITE-SoftAutoCommitTest-seed#[73B2184A229681F0]-worker) [    ] 
o.a.s.s.IndexSchema Loaded schema test/1.0 with uniqueid field id
   [junit4]   2> 3578034 INFO  
(SUITE-SoftAutoCommitTest-seed#[73B2184A229681F0]-worker) [    ] 
o.a.s.h.c.HttpShardHandlerFactory Host whitelist initialized: 
WhitelistHostChecker [whitelistHosts=null, whitelistHostCheckingEnabled=true]
   [junit4]   2> 3578078 WARN  
(SUITE-SoftAutoCommitTest-seed#[73B2184A229681F0]-worker) [    ] 
o.e.j.u.s.S.config No Client EndPointIdentificationAlgorithm configured for 
SslContextFactory@5a11c33[provider=null,keyStore=null,trustStore=null]
   [junit4]   2> 3578092 WARN  
(SUITE-SoftAutoCommitTest-seed#[73B2184A229681F0]-worker) [    ] 
o.e.j.u.s.S.config No Client EndPointIdentificationAlgorithm configured for 
SslContextFactory@1065b015[provider=null,keyStore=null,trustStore=null]
   [junit4]   2> 3578111 INFO  
(SUITE-SoftAutoCommitTest-seed#[73B2184A229681F0]-worker) [    ] 
o.a.s.c.TransientSolrCoreCacheDefault Allocating transient cache for 2147483647 
transient cores
   [junit4]   2> 3578111 INFO  
(SUITE-SoftAutoCommitTest-seed#[73B2184A229681F0]-worker) [    ] 
o.a.s.h.a.MetricsHistoryHandler No .system collection, keeping metrics history 
in memory.
   [junit4]   2> 3578132 INFO  
(SUITE-SoftAutoCommitTest-seed#[73B2184A229681F0]-worker) [    ] 
o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr.node' (registry 'solr.node') 
enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@b7b0ed
   [junit4]   2> 3578149 INFO  
(SUITE-SoftAutoCommitTest-seed#[73B2184A229681F0]-worker) [    ] 
o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr.jvm' (registry 'solr.jvm') 
enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@b7b0ed
   [junit4]   2> 3578150 INFO  
(SUITE-SoftAutoCommitTest-seed#[73B2184A229681F0]-worker) [    ] 
o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr.jetty' (registry 
'solr.jetty') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@b7b0ed
   [junit4]   2> 3578152 INFO  (coreLoadExecutor-14808-thread-1) [    
x:collection1] o.a.s.c.SolrResourceLoader [null] Added 2 libs to classloader, 
from paths: 
[/home/jenkins/workspace/Lucene-Solr-master-Linux/solr/core/src/test-files/solr/collection1/lib,
 
/home/jenkins/workspace/Lucene-Solr-master-Linux/solr/core/src/test-files/solr/collection1/lib/classes]
   [junit4]   2> 3578188 INFO  (coreLoadExecutor-14808-thread-1) [    
x:collection1] o.a.s.c.SolrConfig Using Lucene MatchVersion: 9.0.0
   [junit4]   2> 3578215 INFO  (coreLoadExecutor-14808-thread-1) [    
x:collection1] o.a.s.s.IndexSchema [collection1] Schema name=test
   [junit4]   2> 3578356 INFO  (coreLoadExecutor-14808-thread-1) [    
x:collection1] o.a.s.s.IndexSchema Loaded schema test/1.0 with uniqueid field id
   [junit4]   2> 3578369 INFO  (coreLoadExecutor-14808-thread-1) [    
x:collection1] o.a.s.c.CoreContainer Creating SolrCore 'collection1' using 
configuration from instancedir 
/home/jenkins/workspace/Lucene-Solr-master-Linux/solr/core/src/test-files/solr/collection1,
 trusted=true
   [junit4]   2> 3578369 INFO  (coreLoadExecutor-14808-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@b7b0ed
   [junit4]   2> 3578370 INFO  (coreLoadExecutor-14808-thread-1) [    
x:collection1] o.a.s.c.SolrCore [[collection1] ] Opening new SolrCore at 
[/home/jenkins/workspace/Lucene-Solr-master-Linux/solr/core/src/test-files/solr/collection1],
 
dataDir=[/home/jenkins/workspace/Lucene-Solr-master-Linux/solr/build/solr-core/test/J1/temp/solr.update.SoftAutoCommitTest_73B2184A229681F0-001/init-core-data-001/]
   [junit4]   2> 3578373 INFO  (coreLoadExecutor-14808-thread-1) [    
x:collection1] o.a.s.u.RandomMergePolicy RandomMergePolicy wrapping class 
org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: 
maxMergeAtOnce=29, maxMergeAtOnceExplicit=26, maxMergedSegmentMB=26.6318359375, 
floorSegmentMB=0.2197265625, forceMergeDeletesPctAllowed=4.130103806933887, 
segmentsPerTier=39.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=1.0, 
deletesPctAllowed=33.38624233075407
   [junit4]   2> 3578462 INFO  (coreLoadExecutor-14808-thread-1) [    
x:collection1] o.a.s.u.UpdateHandler Using UpdateLog implementation: 
org.apache.solr.update.UpdateLog
   [junit4]   2> 3578462 INFO  (coreLoadExecutor-14808-thread-1) [    
x:collection1] o.a.s.u.UpdateLog Initializing UpdateLog: dataDir= 
defaultSyncLevel=FLUSH numRecordsToKeep=100 maxNumLogsToKeep=10 
numVersionBuckets=65536
   [junit4]   2> 3578465 INFO  (coreLoadExecutor-14808-thread-1) [    
x:collection1] o.a.s.u.CommitTracker Hard AutoCommit: disabled
   [junit4]   2> 3578466 INFO  (coreLoadExecutor-14808-thread-1) [    
x:collection1] o.a.s.u.CommitTracker Soft AutoCommit: disabled
   [junit4]   2> 3578467 INFO  (coreLoadExecutor-14808-thread-1) [    
x:collection1] o.a.s.u.RandomMergePolicy RandomMergePolicy wrapping class 
org.apache.lucene.index.LogDocMergePolicy: [LogDocMergePolicy: 
minMergeSize=1000, mergeFactor=34, maxMergeSize=9223372036854775807, 
maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=true, 
maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12, 
noCFSRatio=0.0]
   [junit4]   2> 3578468 INFO  (coreLoadExecutor-14808-thread-1) [    
x:collection1] o.a.s.s.SolrIndexSearcher Opening 
[Searcher@750490e8[collection1] main]
   [junit4]   2> 3578469 INFO  (coreLoadExecutor-14808-thread-1) [    
x:collection1] o.a.s.h.c.SpellCheckComponent Initializing spell checkers
   [junit4]   2> 3579102 INFO  (coreLoadExecutor-14808-thread-1) [    
x:collection1] o.a.s.s.DirectSolrSpellChecker init: 
{name=direct,classname=DirectSolrSpellChecker,field=lowerfilt,minQueryLength=3}
   [junit4]   2> 3579239 INFO  (coreLoadExecutor-14808-thread-1) [    
x:collection1] o.a.s.h.ReplicationHandler Commits will be reserved for 10000ms.
   [junit4]   2> 3579239 INFO  (coreLoadExecutor-14808-thread-1) [    
x:collection1] o.a.s.u.UpdateLog Could not find max version in index or recent 
updates, using new clock 1627517556136869888
   [junit4]   2> 3579240 INFO  
(searcherExecutor-14809-thread-1-processing-x:collection1) [    x:collection1] 
o.a.s.h.c.SpellCheckComponent Loading spell index for spellchecker: default
   [junit4]   2> 3579241 INFO  
(searcherExecutor-14809-thread-1-processing-x:collection1) [    x:collection1] 
o.a.s.h.c.SpellCheckComponent Loading spell index for spellchecker: direct
   [junit4]   2> 3579241 INFO  
(searcherExecutor-14809-thread-1-processing-x:collection1) [    x:collection1] 
o.a.s.h.c.SpellCheckComponent Loading spell index for spellchecker: wordbreak
   [junit4]   2> 3579241 INFO  
(searcherExecutor-14809-thread-1-processing-x:collection1) [    x:collection1] 
o.a.s.h.c.SpellCheckComponent Loading spell index for spellchecker: 
multipleFields
   [junit4]   2> 3579243 INFO  
(SUITE-SoftAutoCommitTest-seed#[73B2184A229681F0]-worker) [    ] 
o.a.s.SolrTestCaseJ4 ####initCore end
   [junit4]   2> 3579247 INFO  
(searcherExecutor-14809-thread-1-processing-x:collection1) [    x:collection1] 
o.a.s.h.c.SpellCheckComponent Loading spell index for spellchecker: jarowinkler
   [junit4]   2> 3579248 INFO  
(searcherExecutor-14809-thread-1-processing-x:collection1) [    x:collection1] 
o.a.s.h.c.SpellCheckComponent Loading spell index for spellchecker: external
   [junit4]   2> 3579248 INFO  
(searcherExecutor-14809-thread-1-processing-x:collection1) [    x:collection1] 
o.a.s.h.c.SpellCheckComponent Loading spell index for spellchecker: freq
   [junit4]   2> 3579249 INFO  
(searcherExecutor-14809-thread-1-processing-x:collection1) [    x:collection1] 
o.a.s.h.c.SpellCheckComponent Loading spell index for spellchecker: fqcn
   [junit4]   2> 3579251 INFO  
(searcherExecutor-14809-thread-1-processing-x:collection1) [    x:collection1] 
o.a.s.h.c.SpellCheckComponent Loading spell index for spellchecker: perDict
   [junit4]   2> 3579252 INFO  
(searcherExecutor-14809-thread-1-processing-x:collection1) [    x:collection1] 
o.a.s.c.SolrCore [collection1] Registered new searcher 
Searcher@750490e8[collection1] 
main{ExitableDirectoryReader(UninvertingDirectoryReader())}
   [junit4]   2> 3579255 INFO  
(TEST-SoftAutoCommitTest.testHardCommitWithinAndSoftCommitMaxTimeRapidAdds-seed#[73B2184A229681F0])
 [    ] o.a.s.SolrTestCaseJ4 ###Starting 
testHardCommitWithinAndSoftCommitMaxTimeRapidAdds
   [junit4]   2> 3584492 INFO  
(TEST-SoftAutoCommitTest.testHardCommitWithinAndSoftCommitMaxTimeRapidAdds-seed#[73B2184A229681F0])
 [    ] o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=null 
path=null params={}{add=[5000 (1627517561623019520)]} 0 21
   [junit4]   2> 3584495 INFO  
(TEST-SoftAutoCommitTest.testHardCommitWithinAndSoftCommitMaxTimeRapidAdds-seed#[73B2184A229681F0])
 [    ] o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=null 
path=null params={}{add=[5001 (1627517561647136768)]} 0 0
   [junit4]   2> 3584495 INFO  
(TEST-SoftAutoCommitTest.testHardCommitWithinAndSoftCommitMaxTimeRapidAdds-seed#[73B2184A229681F0])
 [    ] o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=null 
path=null params={}{add=[5002 (1627517561648185344)]} 0 0
   [junit4]   2> 3584495 INFO  
(TEST-SoftAutoCommitTest.testHardCommitWithinAndSoftCommitMaxTimeRapidAdds-seed#[73B2184A229681F0])
 [    ] o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=null 
path=null params={}{add=[5003 (1627517561648185345)]} 0 0
   [junit4]   2> 3584496 INFO  
(TEST-SoftAutoCommitTest.testHardCommitWithinAndSoftCommitMaxTimeRapidAdds-seed#[73B2184A229681F0])
 [    ] o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=null 
path=null params={}{add=[5004 (1627517561649233920)]} 0 0
   [junit4]   2> 3584496 INFO  
(TEST-SoftAutoCommitTest.testHardCommitWithinAndSoftCommitMaxTimeRapidAdds-seed#[73B2184A229681F0])
 [    ] o.a.s.u.SoftAutoCommitTest maxTimeMillis: 1696275490507963ns - 
1696275465317585ns == 25ms
   [junit4]   2> 3584496 INFO  
(TEST-SoftAutoCommitTest.testHardCommitWithinAndSoftCommitMaxTimeRapidAdds-seed#[73B2184A229681F0])
 [    ] o.a.s.u.SoftAutoCommitTest maxExpectedSoft=1
   [junit4]   2> 3584496 INFO  
(TEST-SoftAutoCommitTest.testHardCommitWithinAndSoftCommitMaxTimeRapidAdds-seed#[73B2184A229681F0])
 [    ] o.a.s.u.SoftAutoCommitTest maxExpectedHard=1
   [junit4]   2> 3584973 INFO  (commitScheduler-14813-thread-1) [    ] 
o.a.s.u.DirectUpdateHandler2 start 
commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=true,prepareCommit=false}
   [junit4]   2> 3584981 INFO  (commitScheduler-14813-thread-1) [    ] 
o.a.s.s.SolrIndexSearcher Opening [Searcher@b6a99c6[collection1] main]
   [junit4]   2> 3584984 INFO  (searcherExecutor-14809-thread-1) [    ] 
o.a.s.c.SolrCore [collection1] Registered new searcher 
Searcher@b6a99c6[collection1] 
main{ExitableDirectoryReader(UninvertingDirectoryReader(Uninverting(_0(9.0.0):C5:[diagnostics={os=Linux,
 java.vendor=Aleksey Shipilev, java.version=12-testing, 
java.vm.version=12-testing+0-builds.shipilev.net-openjdk-jdk12-b109-20190215-jdk-1229,
 lucene.version=9.0.0, os.arch=amd64, 
java.runtime.version=12-testing+0-builds.shipilev.net-openjdk-jdk12-b109-20190215-jdk-1229,
 source=flush, os.version=4.18.0-15-generic, 
timestamp=1552121698527}]:[attributes={Lucene50StoredFieldsFormat.mode=BEST_SPEED}])))}
   [junit4]   2> 3584984 INFO  (commitScheduler-14813-thread-1) [    ] 
o.a.s.u.DirectUpdateHandler2 end_commit_flush
   [junit4]   2> 3585686 INFO  (commitScheduler-14812-thread-1) [    ] 
o.a.s.u.DirectUpdateHandler2 start 
commit{,optimize=false,openSearcher=false,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
   [junit4]   2> 3585686 INFO  (commitScheduler-14812-thread-1) [    ] 
o.a.s.u.SolrIndexWriter Calling setCommitData with 
IW:org.apache.solr.update.SolrIndexWriter@29c28e83 commitCommandVersion:0
   [junit4]   2> 3585690 INFO  (commitScheduler-14812-thread-1) [    ] 
o.a.s.s.SolrIndexSearcher Opening [Searcher@32685e8f[collection1] realtime]
   [junit4]   2> 3585691 INFO  (commitScheduler-14812-thread-1) [    ] 
o.a.s.u.DirectUpdateHandler2 end_commit_flush
   [junit4]   2> 3591086 INFO  
(TEST-SoftAutoCommitTest.testHardCommitWithinAndSoftCommitMaxTimeRapidAdds-seed#[73B2184A229681F0])
 [    ] o.a.s.SolrTestCaseJ4 ###Ending 
testHardCommitWithinAndSoftCommitMaxTimeRapidAdds
   [junit4]   2> 3591092 INFO  
(TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeDelete-seed#[73B2184A229681F0])
 [    ] o.a.s.SolrTestCaseJ4 ###Starting testSoftAndHardCommitMaxTimeDelete
   [junit4]   2> 3596118 INFO  
(TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeDelete-seed#[73B2184A229681F0])
 [    ] o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=null 
path=null params={}{add=[529 (1627517573812715520)]} 0 22
   [junit4]   2> 3596118 INFO  
(TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeDelete-seed#[73B2184A229681F0])
 [    ] o.a.s.u.DirectUpdateHandler2 start 
commit{_version_=1627517573835784192,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
   [junit4]   2> 3596118 INFO  
(TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeDelete-seed#[73B2184A229681F0])
 [    ] o.a.s.u.SolrIndexWriter Calling setCommitData with 
IW:org.apache.solr.update.SolrIndexWriter@29c28e83 
commitCommandVersion:1627517573835784192
   [junit4]   2> 3596151 INFO  
(TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeDelete-seed#[73B2184A229681F0])
 [    ] o.a.s.s.SolrIndexSearcher Opening [Searcher@31afe001[collection1] main]
   [junit4]   2> 3596152 INFO  
(TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeDelete-seed#[73B2184A229681F0])
 [    ] o.a.s.u.DirectUpdateHandler2 end_commit_flush
   [junit4]   2> 3596172 INFO  (searcherExecutor-14809-thread-1) [    ] 
o.a.s.c.SolrCore [collection1] Registered new searcher 
Searcher@31afe001[collection1] 
main{ExitableDirectoryReader(UninvertingDirectoryReader(Uninverting(_0(9.0.0):C5:[diagnostics={os=Linux,
 java.vendor=Aleksey Shipilev, java.version=12-testing, 
java.vm.version=12-testing+0-builds.shipilev.net-openjdk-jdk12-b109-20190215-jdk-1229,
 lucene.version=9.0.0, os.arch=amd64, 
java.runtime.version=12-testing+0-builds.shipilev.net-openjdk-jdk12-b109-20190215-jdk-1229,
 source=flush, os.version=4.18.0-15-generic, 
timestamp=1552121698527}]:[attributes={Lucene50StoredFieldsFormat.mode=BEST_SPEED}])
 Uninverting(_1(9.0.0):C1:[diagnostics={os=Linux, java.vendor=Aleksey Shipilev, 
java.version=12-testing, 
java.vm.version=12-testing+0-builds.shipilev.net-openjdk-jdk12-b109-20190215-jdk-1229,
 lucene.version=9.0.0, os.arch=amd64, 
java.runtime.version=12-testing+0-builds.shipilev.net-openjdk-jdk12-b109-20190215-jdk-1229,
 source=flush, os.version=4.18.0-15-generic, 
timestamp=1552121709683}]:[attributes={Lucene50StoredFieldsFormat.mode=BEST_SPEED}])))}
   [junit4]   2> 3596172 INFO  
(TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeDelete-seed#[73B2184A229681F0])
 [    ] o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=null 
path=null params={}{commit=} 0 53
   [junit4]   2> 3596173 INFO  
(TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeDelete-seed#[73B2184A229681F0])
 [    ] o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=null 
path=null params={}{delete=[529 (-1627517573892407296)]} 0 1
   [junit4]   2> 3596673 INFO  (commitScheduler-14813-thread-2) [    ] 
o.a.s.u.DirectUpdateHandler2 start 
commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=true,prepareCommit=false}
   [junit4]   2> 3596674 INFO  (commitScheduler-14813-thread-2) [    ] 
o.a.s.s.SolrIndexSearcher Opening [Searcher@2bcdb966[collection1] main]
   [junit4]   2> 3596675 INFO  (commitScheduler-14813-thread-2) [    ] 
o.a.s.u.DirectUpdateHandler2 end_commit_flush
   [junit4]   2> 3596676 INFO  
(TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeDelete-seed#[73B2184A229681F0])
 [    ] o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=null 
path=null params={}{add=[550 (1627517574419841024)]} 0 0
   [junit4]   2> 3596678 INFO  (searcherExecutor-14809-thread-1) [    ] 
o.a.s.c.SolrCore [collection1] Registered new searcher 
Searcher@2bcdb966[collection1] 
main{ExitableDirectoryReader(UninvertingDirectoryReader(Uninverting(_0(9.0.0):C5:[diagnostics={os=Linux,
 java.vendor=Aleksey Shipilev, java.version=12-testing, 
java.vm.version=12-testing+0-builds.shipilev.net-openjdk-jdk12-b109-20190215-jdk-1229,
 lucene.version=9.0.0, os.arch=amd64, 
java.runtime.version=12-testing+0-builds.shipilev.net-openjdk-jdk12-b109-20190215-jdk-1229,
 source=flush, os.version=4.18.0-15-generic, 
timestamp=1552121698527}]:[attributes={Lucene50StoredFieldsFormat.mode=BEST_SPEED}])))}
   [junit4]   2> 3597176 INFO  (commitScheduler-14813-thread-2) [    ] 
o.a.s.u.DirectUpdateHandler2 start 
commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=true,prepareCommit=false}
   [junit4]   2> 3597184 INFO  (commitScheduler-14813-thread-2) [    ] 
o.a.s.s.SolrIndexSearcher Opening [Searcher@7f4ce147[collection1] main]
   [junit4]   2> 3597185 INFO  (commitScheduler-14813-thread-2) [    ] 
o.a.s.u.DirectUpdateHandler2 end_commit_flush
   [junit4]   2> 3597188 INFO  (searcherExecutor-14809-thread-1) [    ] 
o.a.s.c.SolrCore [collection1] Registered new searcher 
Searcher@7f4ce147[collection1] 
main{ExitableDirectoryReader(UninvertingDirectoryReader(Uninverting(_0(9.0.0):C5:[diagnostics={os=Linux,
 java.vendor=Aleksey Shipilev, java.version=12-testing, 
java.vm.version=12-testing+0-builds.shipilev.net-openjdk-jdk12-b109-20190215-jdk-1229,
 lucene.version=9.0.0, os.arch=amd64, 
java.runtime.version=12-testing+0-builds.shipilev.net-openjdk-jdk12-b109-20190215-jdk-1229,
 source=flush, os.version=4.18.0-15-generic, 
timestamp=1552121698527}]:[attributes={Lucene50StoredFieldsFormat.mode=BEST_SPEED}])
 Uninverting(_2(9.0.0):C1:[diagnostics={os=Linux, java.vendor=Aleksey Shipilev, 
java.version=12-testing, 
java.vm.version=12-testing+0-builds.shipilev.net-openjdk-jdk12-b109-20190215-jdk-1229,
 lucene.version=9.0.0, os.arch=amd64, 
java.runtime.version=12-testing+0-builds.shipilev.net-openjdk-jdk12-b109-20190215-jdk-1229,
 source=flush, os.version=4.18.0-15-generic, 
timestamp=1552121710730}]:[attributes={Lucene50StoredFieldsFormat.mode=BEST_SPEED}])))}
   [junit4]   2> 3597377 INFO  (commitScheduler-14812-thread-2) [    ] 
o.a.s.u.DirectUpdateHandler2 start 
commit{,optimize=false,openSearcher=false,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
   [junit4]   2> 3597378 INFO  (commitScheduler-14812-thread-2) [    ] 
o.a.s.u.SolrIndexWriter Calling setCommitData with 
IW:org.apache.solr.update.SolrIndexWriter@29c28e83 commitCommandVersion:0
   [junit4]   2> 3597387 INFO  (commitScheduler-14812-thread-2) [    ] 
o.a.s.s.SolrIndexSearcher Opening [Searcher@d0e55d4[collection1] realtime]
   [junit4]   2> 3597387 INFO  (commitScheduler-14812-thread-2) [    ] 
o.a.s.u.DirectUpdateHandler2 end_commit_flush
   [junit4]   2> 3603388 INFO  
(TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeDelete-seed#[73B2184A229681F0])
 [    ] o.a.s.SolrTestCaseJ4 ###Ending testSoftAndHardCommitMaxTimeDelete
   [junit4]   2> 3603396 INFO  
(TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeMixedAdds-seed#[73B2184A229681F0])
 [    ] o.a.s.SolrTestCaseJ4 ###Starting testSoftAndHardCommitMaxTimeMixedAdds
   [junit4]   2> 3611817 INFO  
(TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeMixedAdds-seed#[73B2184A229681F0])
 [    ] o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=null 
path=null params={}{add=[529 (1627517590277455872)]} 0 19
   [junit4]   2> 3612305 INFO  (commitScheduler-14813-thread-3) [    ] 
o.a.s.u.DirectUpdateHandler2 start 
commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=true,prepareCommit=false}
   [junit4]   2> 3612547 INFO  (commitScheduler-14813-thread-3) [    ] 
o.a.s.s.SolrIndexSearcher Opening [Searcher@3147343b[collection1] main]
   [junit4]   2> 3612550 INFO  (searcherExecutor-14809-thread-1) [    ] 
o.a.s.c.SolrCore [collection1] Registered new searcher 
Searcher@3147343b[collection1] 
main{ExitableDirectoryReader(UninvertingDirectoryReader(Uninverting(_0(9.0.0):C5:[diagnostics={os=Linux,
 java.vendor=Aleksey Shipilev, java.version=12-testing, 
java.vm.version=12-testing+0-builds.shipilev.net-openjdk-jdk12-b109-20190215-jdk-1229,
 lucene.version=9.0.0, os.arch=amd64, 
java.runtime.version=12-testing+0-builds.shipilev.net-openjdk-jdk12-b109-20190215-jdk-1229,
 source=flush, os.version=4.18.0-15-generic, 
timestamp=1552121698527}]:[attributes={Lucene50StoredFieldsFormat.mode=BEST_SPEED}])
 Uninverting(_2(9.0.0):C1:[diagnostics={os=Linux, java.vendor=Aleksey Shipilev, 
java.version=12-testing, 
java.vm.version=12-testing+0-builds.shipilev.net-openjdk-jdk12-b109-20190215-jdk-1229,
 lucene.version=9.0.0, os.arch=amd64, 
java.runtime.version=12-testing+0-builds.shipilev.net-openjdk-jdk12-b109-20190215-jdk-1229,
 source=flush, os.version=4.18.0-15-generic, 
timestamp=1552121710730}]:[attributes={Lucene50StoredFieldsFormat.mode=BEST_SPEED}])
 Uninverting(_3(9.0.0):C1:[diagnostics={os=Linux, java.vendor=Aleksey Shipilev, 
java.version=12-testing, 
java.vm.version=12-testing+0-builds.shipilev.net-openjdk-jdk12-b109-20190215-jdk-1229,
 lucene.version=9.0.0, os.arch=amd64, 
java.runtime.version=12-testing+0-builds.shipilev.net-openjdk-jdk12-b109-20190215-jdk-1229,
 source=flush, os.version=4.18.0-15-generic, 
timestamp=1552121726093}]:[attributes={Lucene50StoredFieldsFormat.mode=BEST_SPEED}])))}
   [junit4]   2> 3612551 INFO  (commitScheduler-14813-thread-3) [    ] 
o.a.s.u.DirectUpdateHandler2 end_commit_flush
   [junit4]   2> 3613014 INFO  (commitScheduler-14812-thread-3) [    ] 
o.a.s.u.DirectUpdateHandler2 start 
commit{,optimize=false,openSearcher=false,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
   [junit4]   2> 3613014 INFO  (commitScheduler-14812-thread-3) [    ] 
o.a.s.u.SolrIndexWriter Calling setCommitData with 
IW:org.apache.solr.update.SolrIndexWriter@29c28e83 commitCommandVersion:0
   [junit4]   2> 3613015 INFO  (commitScheduler-14812-thread-3) [    ] 
o.a.s.s.SolrIndexSearcher Opening [Searcher@42fbf260[collection1] realtime]
   [junit4]   2> 3613015 INFO  (commitScheduler-14812-thread-3) [    ] 
o.a.s.u.DirectUpdateHandler2 end_commit_flush
   [junit4]   2> 3613050 INFO  
(TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeMixedAdds-seed#[73B2184A229681F0])
 [    ] o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=null 
path=null params={}{add=[530 (1627517591553572864)]} 0 34
   [junit4]   2> 3615332 INFO  (commitScheduler-14812-thread-4) [    ] 
o.a.s.u.DirectUpdateHandler2 start 
commit{,optimize=false,openSearcher=false,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
   [junit4]   2> 3615332 INFO  (commitScheduler-14812-thread-4) [    ] 
o.a.s.u.SolrIndexWriter Calling setCommitData with 
IW:org.apache.solr.update.SolrIndexWriter@29c28e83 commitCommandVersion:0
   [junit4]   2> 3615332 INFO  (commitScheduler-14813-thread-4) [    ] 
o.a.s.u.DirectUpdateHandler2 start 
commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=true,prepareCommit=false}
   [junit4]   2> 3615346 INFO  (commitScheduler-14813-thread-4) [    ] 
o.a.s.s.SolrIndexSearcher Opening [Searcher@2096e9b5[collection1] main]
   [junit4]   2> 3615347 INFO  (commitScheduler-14813-thread-4) [    ] 
o.a.s.u.DirectUpdateHandler2 end_commit_flush
   [junit4]   2> 3615349 INFO  (searcherExecutor-14809-thread-1) [    ] 
o.a.s.c.SolrCore [collection1] Registered new searcher 
Searcher@2096e9b5[collection1] 
main{ExitableDirectoryReader(UninvertingDirectoryReader(Uninverting(_0(9.0.0):C5:[diagnostics={os=Linux,
 java.vendor=Aleksey Shipilev, java.version=12-testing, 
java.vm.version=12-testing+0-builds.shipilev.net-openjdk-jdk12-b109-20190215-jdk-1229,
 lucene.version=9.0.0, os.arch=amd64, 
java.runtime.version=12-testing+0-builds.shipilev.net-openjdk-jdk12-b109-20190215-jdk-1229,
 source=flush, os.version=4.18.0-15-generic, 
timestamp=1552121698527}]:[attributes={Lucene50StoredFieldsFormat.mode=BEST_SPEED}])
 Uninverting(_2(9.0.0):C1:[diagnostics={os=Linux, java.vendor=Aleksey Shipilev, 
java.version=12-testing, 
java.vm.version=12-testing+0-builds.shipilev.net-openjdk-jdk12-b109-20190215-jdk-1229,
 lucene.version=9.0.0, os.arch=amd64, 
java.runtime.version=12-testing+0-builds.shipilev.net-openjdk-jdk12-b109-20190215-jdk-1229,
 source=flush, os.version=4.18.0-15-generic, 
timestamp=1552121710730}]:[attributes={Lucene50StoredFieldsFormat.mode=BEST_SPEED}])
 Uninverting(_3(9.0.0):C1:[diagnostics={os=Linux, java.vendor=Aleksey Shipilev, 
java.version=12-testing, 
java.vm.version=12-testing+0-builds.shipilev.net-openjdk-jdk12-b109-20190215-jdk-1229,
 lucene.version=9.0.0, os.arch=amd64, 
java.runtime.version=12-testing+0-builds.shipilev.net-openjdk-jdk12-b109-20190215-jdk-1229,
 source=flush, os.version=4.18.0-15-generic, 
timestamp=1552121726093}]:[attributes={Lucene50StoredFieldsFormat.mode=BEST_SPEED}])
 Uninverting(_4(9.0.0):C1:[diagnostics={os=Linux, java.vendor=Aleksey Shipilev, 
java.version=12-testing, 
java.vm.version=12-testing+0-builds.shipilev.net-openjdk-jdk12-b109-20190215-jdk-1229,
 lucene.version=9.0.0, os.arch=amd64, 
java.runtime.version=12-testing+0-builds.shipilev.net-openjdk-jdk12-b109-20190215-jdk-1229,
 source=flush, os.version=4.18.0-15-generic, 
timestamp=1552121728888}]:[attributes={Lucene50StoredFieldsFormat.mode=BEST_SPEED}])))}
   [junit4]   2> 3615349 INFO  (commitScheduler-14812-thread-4) [    ] 
o.a.s.u.DirectUpdateHandler2 end_commit_flush
   [junit4]   2> 3615370 INFO  
(TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeMixedAdds-seed#[73B2184A229681F0])
 [    ] o.a.s.SolrTestCaseJ4 ###Ending testSoftAndHardCommitMaxTimeMixedAdds
   [junit4]   2> NOTE: reproduce with: ant test  -Dtestcase=SoftAutoCommitTest 
-Dtests.method=testSoftAndHardCommitMaxTimeMixedAdds 
-Dtests.seed=73B2184A229681F0 -Dtests.multiplier=3 -Dtests.slow=true 
-Dtests.locale=vo-001 -Dtests.timezone=Singapore -Dtests.asserts=true 
-Dtests.file.encoding=UTF-8
   [junit4] FAILURE 12.1s J1 | 
SoftAutoCommitTest.testSoftAndHardCommitMaxTimeMixedAdds <<<
   [junit4]    > Throwable #1: java.lang.AssertionError: soft530 after hard530: 
1696306341180873 !<= 1696306339843564
   [junit4]    >        at 
__randomizedtesting.SeedInfo.seed([73B2184A229681F0:2266E1CA93E5B157]:0)
   [junit4]    >        at 
org.apache.solr.update.SoftAutoCommitTest.doTestSoftAndHardCommitMaxTimeMixedAdds(SoftAutoCommitTest.java:264)
   [junit4]    >        at 
org.apache.solr.update.SoftAutoCommitTest.testSoftAndHardCommitMaxTimeMixedAdds(SoftAutoCommitTest.java:168)
   [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:835)
   [junit4]   2> 3615490 INFO  
(TEST-SoftAutoCommitTest.testHardCommitWithinAndSoftCommitMaxTimeDelete-seed#[73B2184A229681F0])
 [    ] o.a.s.SolrTestCaseJ4 ###Starting 
testHardCommitWithinAndSoftCommitMaxTimeDelete
   [junit4]   2> 3620506 INFO  
(TEST-SoftAutoCommitTest.testHardCommitWithinAndSoftCommitMaxTimeDelete-seed#[73B2184A229681F0])
 [    ] o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=null 
path=null params={}{add=[529 (1627517599391678464)]} 0 16
   [junit4]   2> 3620507 INFO  
(TEST-SoftAutoCommitTest.testHardCommitWithinAndSoftCommitMaxTimeDelete-seed#[73B2184A229681F0])
 [    ] o.a.s.u.DirectUpdateHandler2 start 
commit{_version_=1627517599409504256,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
   [junit4]   2> 3620507 INFO  
(TEST-SoftAutoCommitTest.testHardCommitWithinAndSoftCommitMaxTimeDelete-seed#[73B2184A229681F0])
 [    ] o.a.s.u.SolrIndexWriter Calling setCommitData with 
IW:org.apache.solr.update.SolrIndexWriter@29c28e83 
commitCommandVersion:1627517599409504256
   [junit4]   2> 3620523 INFO  
(TEST-SoftAutoCommitTest.testHardCommitWithinAndSoftCommitMaxTimeDelete-seed#[73B2184A229681F0])
 [    ] o.a.s.s.SolrIndexSearcher Opening [Searcher@29d60815[collection1] main]
   [junit4]   2> 3620524 INFO  
(TEST-SoftAutoCommitTest.testHardCommitWithinAndSoftCommitMaxTimeDelete-seed#[73B2184A229681F0])
 [    ] o.a.s.u.DirectUpdateHandler2 end_commit_flush
   [junit4]   2> 3620527 INFO  (searcherExecutor-14809-thread-1) [    ] 
o.a.s.c.SolrCore [collection1] Registered new searcher 
Searcher@29d60815[collection1] 
main{ExitableDirectoryReader(UninvertingDirectoryReader(Uninverting(_0(9.0.0):C5:[diagnostics={os=Linux,
 java.vendor=Aleksey Shipilev, java.version=12-testing, 
java.vm.version=12-testing+0-builds.shipilev.net-openjdk-jdk12-b109-20190215-jdk-1229,
 lucene.version=9.0.0, os.arch=amd64, 
java.runtime.version=12-testing+0-builds.shipilev.net-openjdk-jdk12-b109-20190215-jdk-1229,
 source=flush, os.version=4.18.0-15-generic, 
timestamp=1552121698527}]:[attributes={Lucene50StoredFieldsFormat.mode=BEST_SPEED}])
 Uninverting(_2(9.0.0):C1:[diagnostics={os=Linux, java.vendor=Aleksey Shipilev, 
java.version=12-testing, 
java.vm.version=12-testing+0-builds.shipilev.net-openjdk-jdk12-b109-20190215-jdk-1229,
 lucene.version=9.0.0, os.arch=amd64, 
java.runtime.version=12-testing+0-builds.shipilev.net-openjdk-jdk12-b109-20190215-jdk-1229,
 source=flush, os.version=4.18.0-15-generic, 
timestamp=1552121710730}]:[attributes={Lucene50StoredFieldsFormat.mode=BEST_SPEED}])
 Uninverting(_4(9.0.0):C1:[diagnostics={os=Linux, java.vendor=Aleksey Shipilev, 
java.version=12-testing, 
java.vm.version=12-testing+0-builds.shipilev.net-openjdk-jdk12-b109-20190215-jdk-1229,
 lucene.version=9.0.0, os.arch=amd64, 
java.runtime.version=12-testing+0-builds.shipilev.net-openjdk-jdk12-b109-20190215-jdk-1229,
 source=flush, os.version=4.18.0-15-generic, 
timestamp=1552121728888}]:[attributes={Lucene50StoredFieldsFormat.mode=BEST_SPEED}])
 Uninverting(_5(9.0.0):C1:[diagnostics={os=Linux, java.vendor=Aleksey Shipilev, 
java.version=12-testing, 
java.vm.version=12-testing+0-builds.shipilev.net-openjdk-jdk12-b109-20190215-jdk-1229,
 lucene.version=9.0.0, os.arch=amd64, 
java.runtime.version=12-testing+0-builds.shipilev.net-openjdk-jdk12-b109-20190215-jdk-1229,
 source=flush, os.version=4.18.0-15-generic, 
timestamp=1552121734065}]:[attributes={Lucene50StoredFieldsFormat.mode=BEST_SPEED}])))}
   [junit4]   2> 3620534 INFO  
(TEST-SoftAutoCommitTest.testHardCommitWithinAndSoftCommitMaxTimeDelete-seed#[73B2184A229681F0])
 [    ] o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=null 
path=null params={}{commit=} 0 26
   [junit4]   2> 3620535 INFO  
(TEST-SoftAutoCommitTest.testHardCommitWithinAndSoftCommitMaxTimeDelete-seed#[73B2184A229681F0])
 [    ] o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=null 
path=null params={}{delete=[529 (-1627517599437815808)]} 0 1
   [junit4]   2> 3621035 INFO  (commitScheduler-14813-thread-5) [    ] 
o.a.s.u.DirectUpdateHandler2 start 
commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=true,prepareCommit=false}
   [junit4]   2> 3621037 INFO  (commitScheduler-14813-thread-5) [    ] 
o.a.s.s.SolrIndexSearcher Opening [Searcher@6df30b3a[collection1] main]
   [junit4]   2> 3621037 INFO  (commitScheduler-14813-thread-5) [    ] 
o.a.s.u.DirectUpdateHandler2 end_commit_flush
   [junit4]   2> 3621040 INFO  (searcherExecutor-14809-thread-1) [    ] 
o.a.s.c.SolrCore [collection1] Registered new searcher 
Searcher@6df30b3a[collection1] 
main{ExitableDirectoryReader(UninvertingDirectoryReader(Uninverting(_0(9.0.0):C5:[diagnostics={os=Linux,
 java.vendor=Aleksey Shipilev, java.version=12-testing, 
java.vm.version=12-testing+0-builds.shipilev.net-openjdk-jdk12-b109-20190215-jdk-1229,
 lucene.version=9.0.0, os.arch=amd64, 
java.runtime.version=12-testing+0-builds.shipilev.net-openjdk-jdk12-b109-20190215-jdk-1229,
 source=flush, os.version=4.18.0-15-generic, 
timestamp=1552121698527}]:[attributes={Lucene50StoredFieldsFormat.mode=BEST_SPEED}])
 Uninverting(_2(9.0.0):C1:[diagnostics={os=Linux, java.vendor=Aleksey Shipilev, 
java.version=12-testing, 
java.vm.version=12-testing+0-builds.shipilev.net-openjdk-jdk12-b109-20190215-jdk-1229,
 lucene.version=9.0.0, os.arch=amd64, 
java.runtime.version=12-testing+0-builds.shipilev.net-openjdk-jdk12-b109-20190215-jdk-1229,
 source=flush, os.version=4.18.0-15-generic, 
timestamp=1552121710730}]:[attributes={Lucene50StoredFieldsFormat.mode=BEST_SPEED}])
 Uninverting(_4(9.0.0):C1:[diagnostics={os=Linux, java.vendor=Aleksey Shipilev, 
java.version=12-testing, 
java.vm.version=12-testing+0-builds.shipilev.net-openjdk-jdk12-b109-20190215-jdk-1229,
 lucene.version=9.0.0, os.arch=amd64, 
java.runtime.version=12-testing+0-builds.shipilev.net-openjdk-jdk12-b109-20190215-jdk-1229,
 source=flush, os.version=4.18.0-15-generic, 
timestamp=1552121728888}]:[attributes={Lucene50StoredFieldsFormat.mode=BEST_SPEED}])))}
   [junit4]   2> 3621042 INFO  
(TEST-SoftAutoCommitTest.testHardCommitWithinAndSoftCommitMaxTimeDelete-seed#[73B2184A229681F0])
 [    ] o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=null 
path=null params={}{add=[550 (1627517599969443840)]} 0 0
   [junit4]   2> 3621542 INFO  (commitScheduler-14813-thread-5) [    ] 
o.a.s.u.DirectUpdateHandler2 start 
commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=true,prepareCommit=false}
   [junit4]   2> 3621553 INFO  (commitScheduler-14813-thread-5) [    ] 
o.a.s.s.SolrIndexSearcher Opening [Searcher@2d8d6003[collection1] main]
   [junit4]   2> 3621557 INFO  (searcherExecutor-14809-thread-1) [    ] 
o.a.s.c.SolrCore [collection1] Registered new searcher 
Searcher@2d8d6003[collection1] 
main{ExitableDirectoryReader(UninvertingDirectoryReader(Uninverting(_0(9.0.0):C5:[diagnostics={os=Linux,
 java.vendor=Aleksey Shipilev, java.version=12-testing, 
java.vm.version=12-testing+0-builds.shipilev.net-openjdk-jdk12-b109-20190215-jdk-1229,
 lucene.version=9.0.0, os.arch=amd64, 
java.runtime.version=12-testing+0-builds.shipilev.net-openjdk-jdk12-b109-20190215-jdk-1229,
 source=flush, os.version=4.18.0-15-generic, 
timestamp=1552121698527}]:[attributes={Lucene50StoredFieldsFormat.mode=BEST_SPEED}])
 Uninverting(_4(9.0.0):C1:[diagnostics={os=Linux, java.vendor=Aleksey Shipilev, 
java.version=12-testing, 
java.vm.version=12-testing+0-builds.shipilev.net-openjdk-jdk12-b109-20190215-jdk-1229,
 lucene.version=9.0.0, os.arch=amd64, 
java.runtime.version=12-testing+0-builds.shipilev.net-openjdk-jdk12-b109-20190215-jdk-1229,
 source=flush, os.version=4.18.0-15-generic, 
timestamp=1552121728888}]:[attributes={Lucene50StoredFieldsFormat.mode=BEST_SPEED}])
 Uninverting(_6(9.0.0):C1:[diagnostics={os=Linux, java.vendor=Aleksey Shipilev, 
java.version=12-testing, 
java.vm.version=12-testing+0-builds.shipilev.net-openjdk-jdk12-b109-20190215-jdk-1229,
 lucene.version=9.0.0, os.arch=amd64, 
java.runtime.version=12-testing+0-builds.shipilev.net-openjdk-jdk12-b109-20190215-jdk-1229,
 source=flush, os.version=4.18.0-15-generic, 
timestamp=1552121735096}]:[attributes={Lucene50StoredFieldsFormat.mode=BEST_SPEED}])))}
   [junit4]   2> 3621557 INFO  (commitScheduler-14813-thread-5) [    ] 
o.a.s.u.DirectUpdateHandler2 end_commit_flush
   [junit4]   2> 3621735 INFO  (commitScheduler-14812-thread-5) [    ] 
o.a.s.u.DirectUpdateHandler2 start 
commit{,optimize=false,openSearcher=false,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
   [junit4]   2> 3621735 INFO  (commitScheduler-14812-thread-5) [    ] 
o.a.s.u.SolrIndexWriter Calling setCommitData with 
IW:org.apache.solr.update.SolrIndexWriter@29c28e83 commitCommandVersion:0
   [junit4]   2> 3621737 INFO  (commitScheduler-14812-thread-5) [    ] 
o.a.s.s.SolrIndexSearcher Opening [Searcher@37725873[collection1] realtime]
   [junit4]   2> 3621737 INFO  (commitScheduler-14812-thread-5) [    ] 
o.a.s.u.DirectUpdateHandler2 end_commit_flush
   [junit4]   2> 3627738 INFO  
(TEST-SoftAutoCommitTest.testHardCommitWithinAndSoftCommitMaxTimeDelete-seed#[73B2184A229681F0])
 [    ] o.a.s.SolrTestCaseJ4 ###Ending 
testHardCommitWithinAndSoftCommitMaxTimeDelete
   [junit4]   2> 3627743 INFO  
(TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxDocs-seed#[73B2184A229681F0]) 
[    ] o.a.s.SolrTestCaseJ4 ###Starting testSoftAndHardCommitMaxDocs
   [junit4]   2> 3635745 INFO  
(TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxDocs-seed#[73B2184A229681F0]) 
[    ] o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=null path=null 
params={}{add=[8000 (1627517615385608192)]} 0 1
   [junit4]   2> 3635745 INFO  
(TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxDocs-seed#[73B2184A229681F0]) 
[    ] o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=null path=null 
params={}{add=[8001 (1627517615387705344)]} 0 0
   [junit4]   2> 3635746 INFO  
(TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxDocs-seed#[73B2184A229681F0]) 
[    ] o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=null path=null 
params={}{add=[8002 (1627517615387705345)]} 0 0
   [junit4]   2> 3635746 INFO  
(TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxDocs-seed#[73B2184A229681F0]) 
[    ] o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=null path=null 
params={}{add=[8003 (1627517615388753920)]} 0 0
   [junit4]   2> 3635746 INFO  
(TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxDocs-seed#[73B2184A229681F0]) 
[    ] o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=null path=null 
params={}{add=[8004 (1627517615388753921)]} 0 0
   [junit4]   2> 3635747 INFO  
(TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxDocs-seed#[73B2184A229681F0]) 
[    ] o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=null path=null 
params={}{add=[8005 (1627517615388753922)]} 0 0
   [junit4]   2> 3635747 INFO  
(TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxDocs-seed#[73B2184A229681F0]) 
[    ] o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=null path=null 
params={}{add=[8006 (1627517615389802496)]} 0 0
   [junit4]   2> 3635747 INFO  
(TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxDocs-seed#[73B2184A229681F0]) 
[    ] o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=null path=null 
params={}{add=[8007 (1627517615389802497)]} 0 0
   [junit4]   2> 3635748 INFO  (commitScheduler-14813-thread-6) [    ] 
o.a.s.u.DirectUpdateHandler2 start 
commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=true,prepareCommit=false}
   [junit4]   2> 3635748 INFO  (commitScheduler-14812-thread-6) [    ] 
o.a.s.u.DirectUpdateHandler2 start 
commit{,optimize=false,openSearcher=false,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
   [junit4]   2> 3635779 INFO  (commitScheduler-14813-thread-6) [    ] 
o.a.s.s.SolrIndexSearcher Opening [Searcher@7c9fa9cd[collection1] main]
   [junit4]   2> 3635783 INFO  (searcherExecutor-14809-thread-1) [    ] 
o.a.s.c.SolrCore [collection1] Registered new searcher 
Searcher@7c9fa9cd[collection1] 
main{ExitableDirectoryReader(UninvertingDirectoryReader(Uninverting(_0(9.0.0):C5:[diagnostics={os=Linux,
 java.vendor=Aleksey Shipilev, java.version=12-testing, 
java.vm.version=12-testing+0-builds.shipilev.net-openjdk-jdk12-b109-20190215-jdk-1229,
 lucene.version=9.0.0, os.arch=amd64, 
java.runtime.version=12-testing+0-builds.shipilev.net-openjdk-jdk12-b109-20190215-jdk-1229,
 source=flush, os.version=4.18.0-15-generic, 
timestamp=1552121698527}]:[attributes={Lucene50StoredFieldsFormat.mode=BEST_SPEED}])
 Uninverting(_4(9.0.0):C1:[diagnostics={os=Linux, java.vendor=Aleksey Shipilev, 
java.version=12-testing, 
java.vm.version=12-testing+0-builds.shipilev.net-openjdk-jdk12-b109-20190215-jdk-1229,
 lucene.version=9.0.0, os.arch=amd64, 
java.runtime.version=12-testing+0-builds.shipilev.net-openjdk-jdk12-b109-20190215-jdk-1229,
 source=flush, os.version=4.18.0-15-generic, 
timestamp=1552121728888}]:[attributes={Lucene50StoredFieldsFormat.mode=BEST_SPEED}])
 Uninverting(_6(9.0.0):C1:[diagnostics={os=Linux, java.vendor=Aleksey Shipilev, 
java.version=12-testing, 
java.vm.version=12-testing+0-builds.shipilev.net-openjdk-jdk12-b109-20190215-jdk-1229,
 lucene.version=9.0.0, os.arch=amd64, 
java.runtime.version=12-testing+0-builds.shipilev.net-openjdk-jdk12-b109-20190215-jdk-1229,
 source=flush, os.version=4.18.0-15-generic, 
timestamp=1552121735096}]:[attributes={Lucene50StoredFieldsFormat.mode=BEST_SPEED}])
 Uninverting(_7(9.0.0):C8:[diagnostics={os=Linux, java.vendor=Aleksey Shipilev, 
java.version=12-testing, 
java.vm.version=12-testing+0-builds.shipilev.net-openjdk-jdk12-b109-20190215-jdk-1229,
 lucene.version=9.0.0, os.arch=amd64, 
java.runtime.version=12-testing+0-builds.shipilev.net-openjdk-jdk12-b109-20190215-jdk-1229,
 source=flush, os.version=4.18.0-15-generic, 
timestamp=1552121749302}]:[attributes={Lucene50StoredFieldsFormat.mode=BEST_SPEED}])))}
   [junit4]   2> 3635783 INFO  (commitScheduler-14812-thread-6) [    ] 
o.a.s.u.SolrIndexWriter Calling setCommitData with 
IW:org.apache.solr.update.SolrIndexWriter@29c28e83 commitCommandVersion:0
   [junit4]   2> 3635784 INFO  (commitScheduler-14813-thread-6) [    ] 
o.a.s.u.DirectUpdateHandler2 end_commit_flush
   [junit4]   2> 3635785 INFO  (commitScheduler-14812-thread-6) [    ] 
o.a.s.s.SolrIndexSearcher Opening [Searcher@1f2b5a79[collection1] realtime]
   [junit4]   2> 3635785 INFO  (commitScheduler-14812-thread-6) [    ] 
o.a.s.u.DirectUpdateHandler2 end_commit_flush
   [junit4]   2> 3636786 INFO  
(TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxDocs-seed#[73B2184A229681F0]) 
[    ] o.a.s.SolrTestCaseJ4 ###Ending testSoftAndHardCommitMaxDocs
   [junit4]   2> 3636792 INFO  
(TEST-SoftAutoCommitTest.testSoftCommitWithinAndHardCommitMaxTimeDelete-seed#[73B2184A229681F0])
 [    ] o.a.s.SolrTestCaseJ4 ###Starting 
testSoftCommitWithinAndHardCommitMaxTimeDelete
   [junit4]   2> 3641796 INFO  
(TEST-SoftAutoCommitTest.testSoftCommitWithinAndHardCommitMaxTimeDelete-seed#[73B2184A229681F0])
 [    ] o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=null 
path=null params={}{add=[529 (1627517621728444416)]} 0 4
   [junit4]   2> 3641796 INFO  
(TEST-SoftAutoCommitTest.testSoftCommitWithinAndHardCommitMaxTimeDelete-seed#[73B2184A229681F0])
 [    ] o.a.s.u.DirectUpdateHandler2 start 
commit{_version_=1627517621732638720,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
   [junit4]   2> 3641796 INFO  
(TEST-SoftAutoCommitTest.testSoftCommitWithinAndHardCommitMaxTimeDelete-seed#[73B2184A229681F0])
 [    ] o.a.s.u.SolrIndexWriter Calling setCommitData with 
IW:org.apache.solr.update.SolrIndexWriter@29c28e83 
commitCommandVersion:1627517621732638720
   [junit4]   2> 3641808 INFO  
(TEST-SoftAutoCommitTest.testSoftCommitWithinAndHardCommitMaxTimeDelete-seed#[73B2184A229681F0])
 [    ] o.a.s.s.SolrIndexSearcher Opening [Searcher@426a493d[collection1] main]
   [junit4]   2> 3641813 INFO  (searcherExecutor-14809-thread-1) [    ] 
o.a.s.c.SolrCore [collection1] Registered new searcher 
Searcher@426a493d[collection1] 
main{ExitableDirectoryReader(UninvertingDirectoryReader(Uninverting(_0(9.0.0):C5:[diagnostics={os=Linux,
 java.vendor=Aleksey Shipilev, java.version=12-testing, 
java.vm.version=12-testing+0-builds.shipilev.net-openjdk-jdk12-b109-20190215-jdk-1229,
 lucene.version=9.0.0, os.arch=amd64, 
java.runtime.version=12-testing+0-builds.shipilev.net-openjdk-jdk12-b109-20190215-jdk-1229,
 source=flush, os.version=4.18.0-15-generic, 
timestamp=1552121698527}]:[attributes={Lucene50StoredFieldsFormat.mode=BEST_SPEED}])
 Uninverting(_4(9.0.0):C1:[diagnostics={os=Linux, java.vendor=Aleksey Shipilev, 
java.version=12-testing, 
java.vm.version=12-testing+0-builds.shipilev.net-openjdk-jdk12-b109-20190215-jdk-1229,
 lucene.version=9.0.0, os.arch=amd64, 
java.runtime.version=12-testing+0-builds.shipilev.net-openjdk-jdk12-b109-20190215-jdk-1229,
 source=flush, os.version=4.18.0-15-generic, 
timestamp=1552121728888}]:[attributes={Lucene50StoredFieldsFormat.mode=BEST_SPEED}])
 Uninverting(_6(9.0.0):C1:[diagnostics={os=Linux, java.vendor=Aleksey Shipilev, 
java.version=12-testing, 
java.vm.version=12-testing+0-builds.shipilev.net-openjdk-jdk12-b109-20190215-jdk-1229,
 lucene.version=9.0.0, os.arch=amd64, 
java.runtime.version=12-testing+0-builds.shipilev.net-openjdk-jdk12-b109-20190215-jdk-1229,
 source=flush, os.version=4.18.0-15-generic, 
timestamp=1552121735096}]:[attributes={Lucene50StoredFieldsFormat.mode=BEST_SPEED}])
 Uninverting(_7(9.0.0):C8:[diagnostics={os=Linux, java.vendor=Aleksey Shipilev, 
java.version=12-testing, 
java.vm.version=12-testing+0-builds.shipilev.net-openjdk-jdk12-b109-20190215-jdk-1229,
 lucene.version=9.0.0, os.arch=amd64, 
java.runtime.version=12-testing+0-builds.shipilev.net-openjdk-jdk12-b109-20190215-jdk-1229,
 source=flush, os.version=4.18.0-15-generic, 
timestamp=1552121749302}]:[attributes={Lucene50StoredFieldsFormat.mode=BEST_SPEED}])
 Uninverting(_8(9.0.0):C1:[diagnostics={os=Linux, java.vendor=Aleksey Shipilev, 
java.version=12-testing, 
java.vm.version=12-testing+0-builds.shipilev.net-openjdk-jdk12-b109-20190215-jdk-1229,
 lucene.version=9.0.0, os.arch=amd64, 
java.runtime.version=12-testing+0-builds.shipilev.net-openjdk-jdk12-b109-20190215-jdk-1229,
 source=flush, os.version=4.18.0-15-generic, 
timestamp=1552121755351}]:[attributes={Lucene50StoredFieldsFormat.mode=BEST_SPEED}])))}
   [junit4]   2> 3641813 INFO  
(TEST-SoftAutoCommitTest.testSoftCommitWithinAndHardCommitMaxTimeDelete-seed#[73B2184A229681F0])
 [    ] o.a.s.u.DirectUpdateHandler2 end_commit_flush
   [junit4]   2> 3641813 INFO  
(TEST-SoftAutoCommitTest.testSoftCommitWithinAndHardCommitMaxTimeDelete-seed#[73B2184A229681F0])
 [    ] o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=null 
path=null params={}{commit=} 0 16
   [junit4]   2> 3641815 INFO  
(TEST-SoftAutoCommitTest.testSoftCommitWithinAndHardCommitMaxTimeDelete-seed#[73B2184A229681F0])
 [    ] o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=null 
path=null params={}{delete=[529 (-1627517621751513088)]} 0 1
   [junit4]   2> 3642315 INFO  (commitScheduler-14813-thread-7) [    ] 
o.a.s.u.DirectUpdateHandler2 start 
commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=true,prepareCommit=false}
   [junit4]   2> 3642317 INFO  (commitScheduler-14813-thread-7) [    ] 
o.a.s.s.SolrIndexSearcher Opening [Searcher@cbc4b85[collection1] main]
   [junit4]   2> 3642318 INFO  (commitScheduler-14813-thread-7) [    ] 
o.a.s.u.DirectUpdateHandler2 end_commit_flush
   [junit4]   2> 3642321 INFO  (searcherExecutor-14809-thread-1) [    ] 
o.a.s.c.SolrCore [collection1] Registered new searcher 
Searcher@cbc4b85[collection1] 
main{ExitableDirectoryReader(UninvertingDirectoryReader(Uninverting(_0(9.0.0):C5:[diagnostics={os=Linux,
 java.vendor=Aleksey Shipilev, java.version=12-testing, 
java.vm.version=12-testing+0-builds.shipilev.net-openjdk-jdk12-b109-20190215-jdk-1229,
 lucene.version=9.0.0, os.arch=amd64, 
java.runtime.version=12-testing+0-builds.shipilev.net-openjdk-jdk12-b109-20190215-jdk-1229,
 source=flush, os.version=4.18.0-15-generic, 
timestamp=1552121698527}]:[attributes={Lucene50StoredFieldsFormat.mode=BEST_SPEED}])
 Uninverting(_4(9.0.0):C1:[diagnostics={os=Linux, java.vendor=Aleksey Shipilev, 
java.version=12-testing, 
java.vm.version=12-testing+0-builds.shipilev.net-openjdk-jdk12-b109-20190215-jdk-1229,
 lucene.version=9.0.0, os.arch=amd64, 
java.runtime.version=12-testing+0-builds.shipilev.net-openjdk-jdk12-b109-20190215-jdk-1229,
 source=flush, os.version=4.18.0-15-generic, 
timestamp=1552121728888}]:[attributes={Lucene50StoredFieldsFormat.mode=BEST_SPEED}])
 Uninverting(_6(9.0.0):C1:[diagnostics={os=Linux, java.vendor=Aleksey Shipilev, 
java.version=12-testing, 
java.vm.version=12-testing+0-builds.shipilev.net-openjdk-jdk12-b109-20190215-jdk-1229,
 lucene.version=9.0.0, os.arch=amd64, 
java.runtime.version=12-testing+0-builds.shipilev.net-openjdk-jdk12-b109-20190215-jdk-1229,
 source=flush, os.version=4.18.0-15-generic, 
timestamp=1552121735096}]:[attributes={Lucene50StoredFieldsFormat.mode=BEST_SPEED}])
 Uninverting(_7(9.0.0):C8:[diagnostics={os=Linux, java.vendor=Aleksey Shipilev, 
java.version=12-testing, 
java.vm.version=12-testing+0-builds.shipilev.net-openjdk-jdk12-b109-20190215-jdk-1229,
 lucene.version=9.0.0, os.arch=amd64, 
java.runtime.version=12-testing+0-builds.shipilev.net-openjdk-jdk12-b109-20190215-jdk-1229,
 source=flush, os.version=4.18.0-15-generic, 
timestamp=1552121749302}]:[attributes={Lucene50StoredFieldsFormat.mode=BEST_SPEED}])))}
   [junit4]   2> 3642323 INFO  
(TEST-SoftAutoCommitTest.testSoftCommitWithinAndHardCommitMaxTimeDelete-seed#[73B2184A229681F0])
 [    ] o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=null 
path=null params={}{add=[550 (1627517622284189696)]} 0 1
   [junit4]   2> 3642825 INFO  (commitScheduler-14813-thread-7) [    ] 
o.a.s.u.DirectUpdateHandler2 start 
commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=true,prepareCommit=false}
   [junit4]   2> 3642838 INFO  (commitScheduler-14813-thread-7) [    ] 
o.a.s.s.SolrIndexSearcher Opening [Searcher@423de907[collection1] main]
   [junit4]   2> 3642839 INFO  (commitScheduler-14813-thread-7) [    ] 
o.a.s.u.DirectUpdateHandler2 end_commit_flush
   [junit4]   2> 3642842 INFO  (searcherExecutor-14809-thread-1) [    ] 
o.a.s.c.SolrCore [collection1] Registered new searcher 
Searcher@423de907[collection1] 
main{ExitableDirectoryReader(UninvertingDirectoryReader(Uninverting(_0(9.0.0):C5:[diagnostics={os=Linux,
 java.vendor=Aleksey Shipilev, java.version=12-testing, 
java.vm.version=12-testing+0-builds.shipilev.net-openjdk-jdk12-b109-20190215-jdk-1229,
 lucene.version=9.0.0, os.arch=amd64, 
java.runtime.version=12-testing+0-builds.shipilev.net-openjdk-jdk12-b109-20190215-jdk-1229,
 source=flush, os.version=4.18.0-15-generic, 
timestamp=1552121698527}]:[attributes={Lucene50StoredFieldsFormat.mode=BEST_SPEED}])
 Uninverting(_4(9.0.0):C1:[diagnostics={os=Linux, java.vendor=Aleksey Shipilev, 
java.version=12-testing, 
java.vm.version=12-testing+0-builds.shipilev.net-openjdk-jdk12-b109-20190215-jdk-1229,
 lucene.version=9.0.0, os.arch=amd64, 
java.runtime.version=12-testing+0-builds.shipilev.net-openjdk-jdk12-b109-20190215-jdk-1229,
 source=flush, os.version=4.18.0-15-generic, 
timestamp=1552121728888}]:[attributes={Lucene50StoredFieldsFormat.mode=BEST_SPEED}])
 Uninverting(_7(9.0.0):C8:[diagnostics={os=Linux, java.vendor=Aleksey Shipilev, 
java.version=12-testing, 
java.vm.version=12-testing+0-builds.shipilev.net-openjdk-jdk12-b109-20190215-jdk-1229,
 lucene.version=9.0.0, os.arch=amd64, 
java.runtime.version=12-testing+0-builds.shipilev.net-openjdk-jdk12-b109-20190215-jdk-1229,
 source=flush, os.version=4.18.0-15-generic, 
timestamp=1552121749302}]:[attributes={Lucene50StoredFieldsFormat.mode=BEST_SPEED}])
 Uninverting(_9(9.0.0):C1:[diagnostics={os=Linux, java.vendor=Aleksey Shipilev, 
java.version=12-testing, 
java.vm.version=12-testing+0-builds.shipilev.net-openjdk-jdk12-b109-20190215-jdk-1229,
 lucene.version=9.0.0, os.arch=amd64, 
java.runtime.version=12-testing+0-builds.shipilev.net-openjdk-jdk12-b109-20190215-jdk-1229,
 source=flush, os.version=4.18.0-15-generic, 
timestamp=1552121756383}]:[attributes={Lucene50StoredFieldsFormat.mode=BEST_SPEED}])))}
   [junit4]   2> 3643023 INFO  (commitScheduler-14812-thread-7) [    ] 
o.a.s.u.DirectUpdateHandler2 start 
commit{,optimize=false,openSearcher=false,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
   [junit4]   2> 3643023 INFO  (commitScheduler-14812-thread-7) [    ] 
o.a.s.u.SolrIndexWriter Calling setCommitData with 
IW:org.apache.solr.update.SolrIndexWriter@29c28e83 commitCommandVersion:0
   [junit4]   2> 3643027 INFO  (commitScheduler-14812-thread-7) [    ] 
o.a.s.s.SolrIndexSearcher Opening [Searcher@48dfeab2[collection1] realtime]
   [junit4]   2> 3643027 INFO  (commitScheduler-14812-thread-7) [    ] 
o.a.s.u.DirectUpdateHandler2 end_commit_flush
   [junit4]   2> 3649035 INFO  
(TEST-SoftAutoCommitTest.testSoftCommitWithinAndHardCommitMaxTimeDelete-seed#[73B2184A229681F0])
 [    ] o.a.s.SolrTestCaseJ4 ###Ending 
testSoftCommitWithinAndHardCommitMaxTimeDelete
   [junit4]   2> 3649041 INFO  
(TEST-SoftAutoCommitTest.testSoftCommitWithinAndHardCommitMaxTimeMixedAdds-seed#[73B2184A229681F0])
 [    ] o.a.s.SolrTestCaseJ4 ###Starting 
testSoftCommitWithinAndHardCommitMaxTimeMixedAdds
   [junit4]   2> 3657443 INFO  
(TEST-SoftAutoCommitTest.testSoftCommitWithinAndHardCommitMaxTimeMixedAdds-seed#[73B2184A229681F0])
 [    ] o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=null 
path=null params={}{add=[529 (1627517638138658816)]} 0 1
   [junit4]   2> 3657943 INFO  (commitScheduler-14813-thread-8) [    ] 
o.a.s.u.DirectUpdateHandler2 start 
commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=true,prepareCommit=false}
   [junit4]   2> 3657949 INFO  (commitScheduler-14813-thread-8) [    ] 
o.a.s.s.SolrIndexSearcher Opening [Searcher@63d616e1[collection1] main]
   [junit4]   2> 3657949 INFO  (commitScheduler-14813-thread-8) [    ] 
o.a.s.u.DirectUpdateHandler2 end_commit_flush
   [junit4]   2> 3657952 INFO  (searcherExecutor-14809-thread-1) [    ] 
o.a.s.c.SolrCore [collection1] Registered new searcher 
Searcher@63d616e1[collection1] 
main{ExitableDirectoryReader(UninvertingDirectoryReader(Uninverting(_0(9.0.0):C5:[diagnostics={os=Linux,
 java.vendor=Aleksey Shipilev, java.version=12-testing, 
java.vm.version=12-testing+0-builds.shipilev.net-openjdk-jdk12-b109-20190215-jdk-1229,
 lucene.version=9.0.0, os.arch=amd64, 
java.runtime.version=12-testing+0-builds.shipilev.net-openjdk-jdk12-b109-20190215-jdk-1229,
 source=flush, os.version=4.18.0-15-generic, 
timestamp=1552121698527}]:[attributes={Lucene50StoredFieldsFormat.mode=BEST_SPEED}])
 Uninverting(_4(9.0.0):C1:[diagnostics={os=Linux, java.vendor=Aleksey Shipilev, 
java.version=12-testing, 
java.vm.version=12-testing+0-builds.shipilev.net-openjdk-jdk12-b109-20190215-jdk-1229,
 lucene.version=9.0.0, os.arch=amd64, 
java.runtime.version=12-testing+0-builds.shipilev.net-openjdk-jdk12-b109-20190215-jdk-1229,
 source=flush, os.version=4.18.0-15-generic, 
timestamp=1552121728888}]:[attributes={Lucene50StoredFieldsFormat.mode=BEST_SPEED}])
 Uninverting(_7(9.0.0):C8:[diagnostics={os=Linux, java.vendor=Aleksey Shipilev, 
java.version=12-testing, 
java.vm.version=12-testing+0-builds.shipilev.net-openjdk-jdk12-b109-20190215-jdk-1229,
 lucene.version=9.0.0, os.arch=amd64, 
java.runtime.version=12-testing+0-builds.shipilev.net-openjdk-jdk12-b109-20190215-jdk-1229,
 source=flush, os.version=4.18.0-15-generic, 
timestamp=1552121749302}]:[attributes={Lucene50StoredFieldsFormat.mode=BEST_SPEED}])
 Uninverting(_9(9.0.0):C1:[diagnostics={os=Linux, java.vendor=Aleksey Shipilev, 
java.version=12-testing, 
java.vm.version=12-testing+0-builds.shipilev.net-openjdk-jdk12-b109-20190215-jdk-1229,
 lucene.version=9.0.0, os.arch=amd64, 
java.runtime.version=12-testing+0-builds.shipilev.net-openjdk-jdk12-b109-20190215-jdk-1229,
 source=flush, os.version=4.18.0-15-generic, 
timestamp=1552121756383}]:[attributes={Lucene50StoredFieldsFormat.mode=BEST_SPEED}])
 Uninverting(_a(9.0.0):C1:[diagnostics={os=Linux, java.vendor=Aleksey Shipilev, 
java.version=12-testing, 
java.vm.version=12-testing+0-builds.shipilev.net-openjdk-jdk12-b109-20190215-jdk-1229,
 lucene.version=9.0.0, os.arch=amd64, 
java.runtime.version=12-testing+0-builds.shipilev.net-openjdk-jdk12-b109-20190215-jdk-1229,
 source=flush, os.version=4.18.0-15-generic, 
timestamp=1552121771496}]:[attributes={Lucene50StoredFieldsFormat.mode=BEST_SPEED}])))}
   [junit4]   2> 3658643 INFO  (commitScheduler-14812-thread-8) [    ] 
o.a.s.u.DirectUpdateHandler2 start 
commit{,optimize=false,openSearcher=false,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
   [junit4]   2> 3658643 INFO  (commitScheduler-14812-thread-8) [    ] 
o.a.s.u.SolrIndexWriter Calling setCommitData with 
IW:org.apache.solr.update.SolrIndexWriter@29c28e83 commitCommandVersion:0
   [junit4]   2> 3658645 INFO  (commitScheduler-14812-thread-8) [    ] 
o.a.s.s.SolrIndexSearcher Opening [Searcher@77873703[collection1] realtime]
   [junit4]   2> 3658645 INFO  (commitScheduler-14812-thread-8) [    ] 
o.a.s.u.DirectUpdateHandler2 end_commit_flush
   [junit4]   2> 3658646 INFO  
(TEST-SoftAutoCommitTest.testSoftCommitWithinAndHardCommitMaxTimeMixedAdds-seed#[73B2184A229681F0])
 [    ] o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=null 
path=null params={}{add=[530 (1627517639399047168)]} 0 1
   [junit4]   2> 3659146 INFO  (commitScheduler-14813-thread-9) [    ] 
o.a.s.u.DirectUpdateHandler2 start 
commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=true,prepareCommit=false}
   [junit4]   2> 3659158 INFO  (commitScheduler-14813-thread-9) [    ] 
o.a.s.s.SolrIndexSearcher Opening [Searcher@6845ad1[collection1] main]
   [junit4]   2> 3659159 INFO  (commitScheduler-14813-thread-9) [    ] 
o.a.s.u.DirectUpdateHandler2 end_commit_flush
   [junit4]   2> 3659162 INFO  (searcherExecutor-14809-thread-1) [    ] 
o.a.s.c.SolrCore [collection1] Registered new searcher 
Searcher@6845ad1[collection1] 
main{ExitableDirectoryReader(UninvertingDirectoryReader(Uninverting(_0(9.0.0):C5:[diagnostics={os=Linux,
 java.vendor=Aleksey Shipilev, java.version=12-testing, 
java.vm.version=12-testing+0-builds.shipilev.net-openjdk-jdk12-b109-20190215-jdk-1229,
 lucene.version=9.0.0, os.arch=amd64, 
java.runtime.version=12-testing+0-builds.shipilev.net-openjdk-jdk12-b109-20190215-jdk-1229,
 source=flush, os.version=4.18.0-15-generic, 
timestamp=1552121698527}]:[attributes={Lucene50StoredFieldsFormat.mode=BEST_SPEED}])
 Uninverting(_7(9.0.0):C8:[diagnostics={os=Linux, java.vendor=Aleksey Shipilev, 
java.version=12-testing, 
java.vm.version=12-testing+0-builds.shipilev.net-openjdk-jdk12-b109-20190215-jdk-1229,
 lucene.version=9.0.0, os.arch=amd64, 
java.runtime.version=12-testing+0-builds.shipilev.net-openjdk-jdk12-b109-20190215-jdk-1229,
 source=flush, os.version=4.18.0-15-generic, 
timestamp=1552121749302}]:[attributes={Lucene50StoredFieldsFormat.mode=BEST_SPEED}])
 Uninverting(_9(9.0.0):C1:[diagnostics={os=Linux, java.vendor=Aleksey Shipilev, 
java.version=12-testing, 
java.vm.version=12-testing+0-builds.shipilev.net-openjdk-jdk12-b109-20190215-jdk-1229,
 lucene.version=9.0.0, os.arch=amd64, 
java.runtime.version=12-testing+0-builds.shipilev.net-openjdk-jdk12-b109-20190215-jdk-1229,
 source=flush, os.version=4.18.0-15-generic, 
timestamp=1552121756383}]:[attributes={Lucene50StoredFieldsFormat.mode=BEST_SPEED}])
 Uninverting(_a(9.0.0):C1:[diagnostics={os=Linux, java.vendor=Aleksey Shipilev, 
java.version=12-testing, 
java.vm.version=12-testing+0-builds.shipilev.net-openjdk-jdk12-b109-20190215-jdk-1229,
 lucene.version=9.0.0, os.arch=amd64, 
java.runtime.version=12-testing+0-builds.shipilev.net-openjdk-jdk12-b109-20190215-jdk-1229,
 source=flush, os.version=4.18.0-15-generic, 
timestamp=1552121771496}]:[attributes={Lucene50StoredFieldsFormat.mode=BEST_SPEED}])
 Uninverting(_b(9.0.0):C1:[diagnostics={os=Linux, java.vendor=Aleksey Shipilev, 
java.version=12-testing, 
java.vm.version=12-testing+0-builds.shipilev.net-openjdk-jdk12-b109-20190215-jdk-1229,
 lucene.version=9.0.0, os.arch=amd64, 
java.runtime.version=12-testing+0-builds.shipilev.net-openjdk-jdk12-b109-20190215-jdk-1229,
 source=flush, os.version=4.18.0-15-generic, 
timestamp=1552121772701}]:[attributes={Lucene50StoredFieldsFormat.mode=BEST_SPEED}])))}
   [junit4]   2> 3659845 INFO  (commitScheduler-14812-thread-8) [    ] 
o.a.s.u.DirectUpdateHandler2 start 
commit{,optimize=false,openSearcher=false,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
   [junit4]   2> 3659846 INFO  (commitScheduler-14812-thread-8) [    ] 
o.a.s.u.SolrIndexWriter Calling setCommitData with 
IW:org.apache.solr.update.SolrIndexWriter@29c28e83 commitCommandVersion:0
   [junit4]   2> 3659847 INFO  (commitScheduler-14812-thread-8) [    ] 
o.a.s.s.SolrIndexSearcher Opening [Searcher@7c4ffc3e[collection1] realtime]
   [junit4]   2> 3659848 INFO  (commitScheduler-14812-thread-8) [    ] 
o.a.s.u.DirectUpdateHandler2 end_commit_flush
   [junit4]   2> 3660848 INFO  
(TEST-SoftAutoCommitTest.testSoftCommitWithinAndHardCommitMaxTimeMixedAdds-seed#[73B2184A229681F0])
 [    ] o.a.s.SolrTestCaseJ4 ###Ending 
testSoftCommitWithinAndHardCommitMaxTimeMixedAdds
   [junit4]   2> 3660861 INFO  
(TEST-SoftAutoCommitTest.testHardCommitWithinAndSoftCommitMaxTimeMixedAdds-seed#[73B2184A229681F0])
 [    ] o.a.s.SolrTestCaseJ4 ###Starting 
testHardCommitWithinAndSoftCommitMaxTimeMixedAdds
   [junit4]   2> 3669264 INFO  
(TEST-SoftAutoCommitTest.testHardCommitWithinAndSoftCommitMaxTimeMixedAdds-seed#[73B2184A229681F0])
 [    ] o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=null 
path=null params={}{add=[529 (1627517650532827136)]} 0 2
   [junit4]   2> 3669764 INFO  (commitScheduler-14813-thread-10) [    ] 
o.a.s.u.DirectUpdateHandler2 start 
commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=true,prepareCommit=false}
   [junit4]   2> 3669775 INFO  (commitScheduler-14813-thread-10) [    ] 
o.a.s.s.SolrIndexSearcher Opening [Searcher@61b1cbd1[collection1] main]
   [junit4]   2> 3669776 INFO  (commitScheduler-14813-thread-10) [    ] 
o.a.s.u.DirectUpdateHandler2 end_commit_flush
   [junit4]   2> 3669779 INFO  (searcherExecutor-14809-thread-1) [    ] 
o.a.s.c.SolrCore [collection1] Registered new searcher 
Searcher@61b1cbd1[collection1] 
main{ExitableDirectoryReader(UninvertingDirectoryReader(Uninverting(_0(9.0.0):C5:[diagnostics={os=Linux,
 java.vendor=Aleksey Shipilev, java.version=12-testing, 
java.vm.version=12-testing+0-builds.shipilev.net-openjdk-jdk12-b109-20190215-jdk-1229,
 lucene.version=9.0.0, os.arch=amd64, 
java.runtime.version=12-testing+0-builds.shipilev.net-openjdk-jdk12-b109-20190215-jdk-1229,
 source=flush, os.version=4.18.0-15-generic, 
timestamp=1552121698527}]:[attributes={Lucene50StoredFieldsFormat.mode=BEST_SPEED}])
 Uninverting(_7(9.0.0):C8:[diagnostics={os=Linux, java.vendor=Aleksey Shipilev, 
java.version=12-testing, 
java.vm.version=12-testing+0-builds.shipilev.net-openjdk-jdk12-b109-20190215-jdk-1229,
 lucene.version=9.0.0, os.arch=amd64, 
java.runtime.version=12-testing+0-builds.shipilev.net-openjdk-jdk12-b109-20190215-jdk-1229,
 source=flush, os.version=4.18.0-15-generic, 
timestamp=1552121749302}]:[attributes={Lucene50StoredFieldsFormat.mode=BEST_SPEED}])
 Uninverting(_9(9.0.0):C1:[diagnostics={os=Linux, java.vendor=Aleksey Shipilev, 
java.version=12-testing, 
java.vm.version=12-testing+0-builds.shipilev.net-openjdk-jdk12-b109-20190215-jdk-1229,
 lucene.version=9.0.0, os.arch=amd64, 
java.runtime.version=12-testing+0-builds.shipilev.net-openjdk-jdk12-b109-20190215-jdk-1229,
 source=flush, os.version=4.18.0-15-generic, 
timestamp=1552121756383}]:[attributes={Lucene50StoredFieldsFormat.mode=BEST_SPEED}])
 Uninverting(_b(9.0.0):C1:[diagnostics={os=Linux, java.vendor=Aleksey Shipilev, 
java.version=12-testing, 
java.vm.version=12-testing+0-builds.shipilev.net-openjdk-jdk12-b109-20190215-jdk-1229,
 lucene.version=9.0.0, os.arch=amd64, 
java.runtime.version=12-testing+0-builds.shipilev.net-openjdk-jdk12-b109-20190215-jdk-1229,
 source=flush, os.version=4.18.0-15-generic, 
timestamp=1552121772701}]:[attributes={Lucene50StoredFieldsFormat.mode=BEST_SPEED}])
 Uninverting(_c(9.0.0):C1:[diagnostics={os=Linux, java.vendor=Aleksey Shipilev, 
java.version=12-testing, 
java.vm.version=12-testing+0-builds.shipilev.net-openjdk-jdk12-b109-20190215-jdk-1229,
 lucene.version=9.0.0, os.arch=amd64, 
java.runtime.version=12-testing+0-builds.shipilev.net-openjdk-jdk12-b109-20190215-jdk-1229,
 source=flush, os.version=4.18.0-15-generic, 
timestamp=1552121783319}]:[attributes={Lucene50StoredFieldsFormat.mode=BEST_SPEED}])))}
   [junit4]   2> 3670464 INFO  (commitScheduler-14812-thread-9) [    ] 
o.a.s.u.DirectUpdateHandler2 start 
commit{,optimize=false,openSearcher=false,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
   [junit4]   2> 3670464 INFO  (commitScheduler-14812-thread-9) [    ] 
o.a.s.u.SolrIndexWriter Calling setCommitData with 
IW:org.apache.solr.update.SolrIndexWriter@29c28e83 commitCommandVersion:0
   [junit4]   2> 3670465 INFO  (commitScheduler-14812-thread-9) [    ] 
o.a.s.s.SolrIndexSearcher Opening [Searcher@78aeb7c2[collection1] realtime]
   [junit4]   2> 3670465 INFO  (commitScheduler-14812-thread-9) [    ] 
o.a.s.u.DirectUpdateHandler2 end_commit_flush
   [junit4]   2> 3670468 INFO  
(TEST-SoftAutoCommitTest.testHardCommitWithinAndSoftCommitMaxTimeMixedAdds-seed#[73B2184A229681F0])
 [    ] o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=null 
path=null params={}{add=[530 (1627517651793215488)]} 0 3
   [junit4]   2> 3670968 INFO  (commitScheduler-14813-thread-11) [    ] 
o.a.s.u.DirectUpdateHandler2 start 
commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=true,prepareCommit=false}
   [junit4]   2> 3670989 INFO  (commitScheduler-14813-thread-11) [    ] 
o.a.s.s.SolrIndexSearcher Opening [Searcher@30a9e5c9[collection1] main]
   [junit4]   2> 3670993 INFO  (searcherExecutor-14809-thread-1) [    ] 
o.a.s.c.SolrCore [collection1] Registered new searcher 
Searcher@30a9e5c9[collection1] 
main{ExitableDirectoryReader(UninvertingDirectoryReader(Uninverting(_0(9.0.0):C5:[diagnostics={os=Linux,
 java.vendor=Aleksey Shipilev, java.version=12-testing, 
java.vm.version=12-testing+0-builds.shipilev.net-openjdk-jdk12-b109-20190215-jdk-1229,
 lucene.version=9.0.0, os.arch=amd64, 
java.runtime.version=12-testing+0-builds.shipilev.net-openjdk-jdk12-b109-20190215-jdk-1229,
 source=flush, os.version=4.18.0-15-generic, 
timestamp=1552121698527}]:[attributes={Lucene50StoredFieldsFormat.mode=BEST_SPEED}])
 Uninverting(_7(9.0.0):C8:[diagnostics={os=Linux, java.vendor=Aleksey Shipilev, 
java.version=12-testing, 
java.vm.version=12-testing+0-builds.shipilev.net-openjdk-jdk12-b109-20190215-jdk-1229,
 lucene.version=9.0.0, os.arch=amd64, 
java.runtime.version=12-testing+0-builds.shipilev.net-openjdk-jdk12-b109-20190215-jdk-1229,
 source=flush, os.version=4.18.0-15-generic, 
timestamp=1552121749302}]:[attributes={Lucene50StoredFieldsFormat.mode=BEST_SPEED}])
 Uninverting(_9(9.0.0):C1:[diagnostics={os=Linux, java.vendor=Aleksey Shipilev, 
java.version=12-testing, 
java.vm.version=12-testing+0-builds.shipilev.net-openjdk-jdk12-b109-20190215-jdk-1229,
 lucene.version=9.0.0, os.arch=amd64, 
java.runtime.version=12-testing+0-builds.shipilev.net-openjdk-jdk12-b109-20190215-jdk-1229,
 source=flush, os.version=4.18.0-15-generic, 
timestamp=1552121756383}]:[attributes={Lucene50StoredFieldsFormat.mode=BEST_SPEED}])
 Uninverting(_c(9.0.0):C1:[diagnostics={os=Linux, java.vendor=Aleksey Shipilev, 
java.version=12-testing, 
java.vm.version=12-testing+0-builds.shipilev.net-openjdk-jdk12-b109-20190215-jdk-1229,
 lucene.version=9.0.0, os.arch=amd64, 
java.runtime.version=12-testing+0-builds.shipilev.net-openjdk-jdk12-b109-20190215-jdk-1229,
 source=flush, os.version=4.18.0-15-generic, 
timestamp=1552121783319}]:[attributes={Lucene50StoredFieldsFormat.mode=BEST_SPEED}])
 Uninverting(_d(9.0.0):C1:[diagnostics={os=Linux, java.vendor=Aleksey Shipilev, 
java.version=12-testing, 
java.vm.version=12-testing+0-builds.shipilev.net-openjdk-jdk12-b109-20190215-jdk-1229,
 lucene.version=9.0.0, os.arch=amd64, 
java.runtime.version=12-testing+0-builds.shipilev.net-openjdk-jdk12-b109-20190215-jdk-1229,
 source=flush, os.version=4.18.0-15-generic, 
timestamp=1552121784523}]:[attributes={Lucene50StoredFieldsFormat.mode=BEST_SPEED}])))}
   [junit4]   2> 3670994 INFO  (commitScheduler-14813-thread-11) [    ] 
o.a.s.u.DirectUpdateHandler2 end_commit_flush
   [junit4]   2> 3671668 INFO  (commitScheduler-14812-thread-9) [    ] 
o.a.s.u.DirectUpdateHandler2 start 
commit{,optimize=false,openSearcher=false,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
   [junit4]   2> 3671668 INFO  (commitScheduler-14812-thread-9) [    ] 
o.a.s.u.SolrIndexWriter Calling setCommitData with 
IW:org.apache.solr.update.SolrIndexWriter@29c28e83 commitCommandVersion:0
   [junit4]   2> 3671673 INFO  (commitScheduler-14812-thread-9) [    ] 
o.a.s.s.SolrIndexSearcher Opening [Searcher@52f28270[collection1] realtime]
   [junit4]   2> 3671673 INFO  (commitScheduler-14812-thread-9) [    ] 
o.a.s.u.DirectUpdateHandler2 end_commit_flush
   [junit4]   2> 3672674 INFO  
(TEST-SoftAutoCommitTest.testHardCommitWithinAndSoftCommitMaxTimeMixedAdds-seed#[73B2184A229681F0])
 [    ] o.a.s.SolrTestCaseJ4 ###Ending 
testHardCommitWithinAndSoftCommitMaxTimeMixedAdds
   [junit4]   2> 3672688 INFO  
(TEST-SoftAutoCommitTest.testSoftCommitWithinAndHardCommitMaxTimeRapidAdds-seed#[73B2184A229681F0])
 [    ] o.a.s.SolrTestCaseJ4 ###Starting 
testSoftCommitWithinAndHardCommitMaxTimeRapidAdds
   [junit4]   2> 3677690 INFO  
(TEST-SoftAutoCommitTest.testSoftCommitWithinAndHardCommitMaxTimeRapidAdds-seed#[73B2184A229681F0])
 [    ] o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=null 
path=null params={}{add=[5000 (1627517659368128512)]} 0 1
   [junit4]   2> 3677691 INFO  
(TEST-SoftAutoCommitTest.testSoftCommitWithinAndHardCommitMaxTimeRapidAdds-seed#[73B2184A229681F0])
 [    ] o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=null 
path=null params={}{add=[5001 (1627517659370225664)]} 0 0
   [junit4]   2> 3677691 INFO  
(TEST-SoftAutoCommitTest.testSoftCommitWithinAndHardCommitMaxTimeRapidAdds-seed#[73B2184A229681F0])
 [    ] o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=null 
path=null params={}{add=[5002 (1627517659371274240)]} 0 0
   [junit4]   2> 3677691 INFO  
(TEST-SoftAutoCommitTest.testSoftCommitWithinAndHardCommitMaxTimeRapidAdds-seed#[73B2184A229681F0])
 [    ] o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=null 
path=null params={}{add=[5003 (1627517659371274241)]} 0 0
   [junit4]   2> 3677692 INFO  
(TEST-SoftAutoCommitTest.testSoftCommitWithinAndHardCommitMaxTimeRapidAdds-seed#[73B2184A229681F0])
 [    ] o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=null 
path=null params={}{add=[5004 (1627517659372322816)]} 0 0
   [junit4]   2> 3677692 INFO  
(TEST-SoftAutoCommitTest.testSoftCommitWithinAndHardCommitMaxTimeRapidAdds-seed#[73B2184A229681F0])
 [    ] o.a.s.u.SoftAutoCommitTest maxTimeMillis: 1696368686449715ns - 
1696368682626840ns == 3ms
   [junit4]   2> 3677692 INFO  
(TEST-SoftAutoCommitTest.testSoftCommitWithinAndHardCommitMaxTimeRapidAdds-seed#[73B2184A229681F0])
 [    ] o.a.s.u.SoftAutoCommitTest maxExpectedSoft=1
   [junit4]   2> 3677692 INFO  
(TEST-SoftAutoCommitTest.testSoftCommitWithinAndHardCommitMaxTimeRapidAdds-seed#[73B2184A229681F0])
 [    ] o.a.s.u.SoftAutoCommitTest maxExpectedHard=1
   [junit4]   2> 3678192 INFO  (commitScheduler-14813-thread-12) [    ] 
o.a.s.u.DirectUpdateHandler2 start 
commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=true,prepareCommit=false}
   [junit4]   2> 3678204 INFO  (commitScheduler-14813-thread-12) [    ] 
o.a.s.s.SolrIndexSearcher Opening [Searcher@2033dbbf[collection1] main]
   [junit4]   2> 3678204 INFO  (commitScheduler-14813-thread-12) [    ] 
o.a.s.u.DirectUpdateHandler2 end_commit_flush
   [junit4]   2> 3678208 INFO  (searcherExecutor-14809-thread-1) [    ] 
o.a.s.c.SolrCore [collection1] Registered new searcher 
Searcher@2033dbbf[collection1] 
main{ExitableDirectoryReader(UninvertingDirectoryReader(Uninverting(_7(9.0.0):C8:[diagnostics={os=Linux,
 java.vendor=Aleksey Shipilev, java.version=12-testing, 
java.vm.version=12-testing+0-builds.shipilev.net-openjdk-jdk12-b109-20190215-jdk-1229,
 lucene.version=9.0.0, os.arch=amd64, 
java.runtime.version=12-testing+0-builds.shipilev.net-openjdk-jdk12-b109-20190215-jdk-1229,
 source=flush, os.version=4.18.0-15-generic, 
timestamp=1552121749302}]:[attributes={Lucene50StoredFieldsFormat.mode=BEST_SPEED}])
 Uninverting(_9(9.0.0):C1:[diagnostics={os=Linux, java.vendor=Aleksey Shipilev, 
java.version=12-testing, 
java.vm.version=12-testing+0-builds.shipilev.net-openjdk-jdk12-b109-20190215-jdk-1229,
 lucene.version=9.0.0, os.arch=amd64, 
java.runtime.version=12-testing+0-builds.shipilev.net-openjdk-jdk12-b109-20190215-jdk-1229,
 source=flush, os.version=4.18.0-15-generic, 
timestamp=1552121756383}]:[attributes={Lucene50StoredFieldsFormat.mode=BEST_SPEED}])
 Uninverting(_c(9.0.0):C1:[diagnostics={os=Linux, java.vendor=Aleksey Shipilev, 
java.version=12-testing, 
java.vm.version=12-testing+0-builds.shipilev.net-openjdk-jdk12-b109-20190215-jdk-1229,
 lucene.version=9.0.0, os.arch=amd64, 
java.runtime.version=12-testing+0-builds.shipilev.net-openjdk-jdk12-b109-20190215-jdk-1229,
 source=flush, os.version=4.18.0-15-generic, 
timestamp=1552121783319}]:[attributes={Lucene50StoredFieldsFormat.mode=BEST_SPEED}])
 Uninverting(_d(9.0.0):C1:[diagnostics={os=Linux, java.vendor=Aleksey Shipilev, 
java.version=12-testing, 
java.vm.version=12-testing+0-builds.shipilev.net-openjdk-jdk12-b109-20190215-jdk-1229,
 lucene.version=9.0.0, os.arch=amd64, 
java.runtime.version=12-testing+0-builds.shipilev.net-openjdk-jdk12-b109-20190215-jdk-1229,
 source=flush, os.version=4.18.0-15-generic, 
timestamp=1552121784523}]:[attributes={Lucene50StoredFieldsFormat.mode=BEST_SPEED}])
 Uninverting(_e(9.0.0):C5:[diagnostics={os=Linux, java.vendor=Aleksey Shipilev, 
java.version=12-testing, 
java.vm.version=12-testing+0-builds.shipilev.net-openjdk-jdk12-b109-20190215-jdk-1229,
 lucene.version=9.0.0, os.arch=amd64, 
java.runtime.version=12-testing+0-builds.shipilev.net-openjdk-jdk12-b109-20190215-jdk-1229,
 source=flush, os.version=4.18.0-15-generic, 
timestamp=1552121791748}]:[attributes={Lucene50StoredFieldsFormat.mode=BEST_SPEED}])))}
   [junit4]   2> 3678890 INFO  (commitScheduler-14812-thread-10) [    ] 
o.a.s.u.DirectUpdateHandler2 start 
commit{,optimize=false,openSearcher=false,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
   [junit4]   2> 3678890 INFO  (commitScheduler-14812-thread-10) [    ] 
o.a.s.u.SolrIndexWriter Calling setCommitData with 
IW:org.apache.solr.update.SolrIndexWriter@29c28e83 commitCommandVersion:0
   [junit4]   2> 3678891 INFO  (commitScheduler-14812-thread-10) [    ] 
o.a.s.s.SolrIndexSearcher Opening [Searcher@5f30e672[collection1] realtime]
   [junit4]   2> 3678891 INFO  (commitScheduler-14812-thread-10) [    ] 
o.a.s.u.DirectUpdateHandler2 end_commit_flush
   [junit4]   2> 3684305 INFO  
(TEST-SoftAutoCommitTest.testSoftCommitWithinAndHardCommitMaxTimeRapidAdds-seed#[73B2184A229681F0])
 [    ] o.a.s.SolrTestCaseJ4 ###Ending 
testSoftCommitWithinAndHardCommitMaxTimeRapidAdds
   [junit4]   2> 3684309 INFO  
(TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeRapidAdds-seed#[73B2184A229681F0])
 [    ] o.a.s.SolrTestCaseJ4 ###Starting testSoftAndHardCommitMaxTimeRapidAdds
   [junit4]   2> 3689312 INFO  
(TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeRapidAdds-seed#[73B2184A229681F0])
 [    ] o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=null 
path=null params={}{add=[5000 (1627517671554678784)]} 0 2
   [junit4]   2> 3689312 INFO  
(TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeRapidAdds-seed#[73B2184A229681F0])
 [    ] o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=null 
path=null params={}{add=[5001 (1627517671556775936)]} 0 0
   [junit4]   2> 3689313 INFO  
(TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeRapidAdds-seed#[73B2184A229681F0])
 [    ] o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=null 
path=null params={}{add=[5002 (1627517671557824512)]} 0 0
   [junit4]   2> 3689313 INFO  
(TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeRapidAdds-seed#[73B2184A229681F0])
 [    ] o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=null 
path=null params={}{add=[5003 (1627517671557824513)]} 0 0
   [junit4]   2> 3689314 INFO  
(TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeRapidAdds-seed#[73B2184A229681F0])
 [    ] o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=null 
path=null params={}{add=[5004 (1627517671557824514)]} 0 0
   [junit4]   2> 3689314 INFO  
(TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeRapidAdds-seed#[73B2184A229681F0])
 [    ] o.a.s.u.SoftAutoCommitTest maxTimeMillis: 1696380308423598ns - 
1696380304179461ns == 4ms
   [junit4]   2> 3689314 INFO  
(TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeRapidAdds-seed#[73B2184A229681F0])
 [    ] o.a.s.u.SoftAutoCommitTest maxExpectedSoft=1
   [junit4]   2> 3689314 INFO  
(TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeRapidAdds-seed#[73B2184A229681F0])
 [    ] o.a.s.u.SoftAutoCommitTest maxExpectedHard=1
   [junit4]   2> 3689811 INFO  (commitScheduler-14813-thread-13) [    ] 
o.a.s.u.DirectUpdateHandler2 start 
commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=true,prepareCommit=false}
   [junit4]   2> 3689821 INFO  (commitScheduler-14813-thread-13) [    ] 
o.a.s.s.SolrIndexSearcher Opening [Searcher@3ae6701d[collection1] main]
   [junit4]   2> 3689822 INFO  (commitScheduler-14813-thread-13) [    ] 
o.a.s.u.DirectUpdateHandler2 end_commit_flush
   [junit4]   2> 3689826 INFO  (searcherExecutor-14809-thread-1) [    ] 
o.a.s.c.SolrCore [collection1] Registered new searcher 
Searcher@3ae6701d[collection1] 
main{ExitableDirectoryReader(UninvertingDirectoryReader(Uninverting(_7(9.0.0):C8:[diagnostics={os=Linux,
 java.vendor=Aleksey Shipilev, java.version=12-testing, 
java.vm.version=12-testing+0-builds.shipilev.net-openjdk-jdk12-b109-20190215-jdk-1229,
 lucene.version=9.0.0, os.arch=amd64, 
java.runtime.version=12-testing+0-builds.shipilev.net-openjdk-jdk12-b109-20190215-jdk-1229,
 source=flush, os.version=4.18.0-15-generic, 
timestamp=1552121749302}]:[attributes={Lucene50StoredFieldsFormat.mode=BEST_SPEED}])
 Uninverting(_9(9.0.0):C1:[diagnostics={os=Linux, java.vendor=Aleksey Shipilev, 
java.version=12-testing, 
java.vm.version=12-testing+0-builds.shipilev.net-openjdk-jdk12-b109-20190215-jdk-1229,
 lucene.version=9.0.0, os.arch=amd64, 
java.runtime.version=12-testing+0-builds.shipilev.net-openjdk-jdk12-b109-20190215-jdk-1229,
 source=flush, os.version=4.18.0-15-generic, 
timestamp=1552121756383}]:[attributes={Lucene50StoredFieldsFormat.mode=BEST_SPEED}])
 Uninverting(_c(9.0.0):C1:[diagnostics={os=Linux, java.vendor=Aleksey Shipilev, 
java.version=12-testing, 
java.vm.version=12-testing+0-builds.shipilev.net-openjdk-jdk12-b109-20190215-jdk-1229,
 lucene.version=9.0.0, os.arch=amd64, 
java.runtime.version=12-testing+0-builds.shipilev.net-openjdk-jdk12-b109-20190215-jdk-1229,
 source=flush, os.version=4.18.0-15-generic, 
timestamp=1552121783319}]:[attributes={Lucene50StoredFieldsFormat.mode=BEST_SPEED}])
 Uninverting(_d(9.0.0):C1:[diagnostics={os=Linux, java.vendor=Aleksey Shipilev, 
java.version=12-testing, 
java.vm.version=12-testing+0-builds.shipilev.net-openjdk-jdk12-b109-20190215-jdk-1229,
 lucene.version=9.0.0, os.arch=amd64, 
java.runtime.version=12-testing+0-builds.shipilev.net-openjdk-jdk12-b109-20190215-jdk-1229,
 source=flush, os.version=4.18.0-15-generic, 
timestamp=1552121784523}]:[attributes={Lucene50StoredFieldsFormat.mode=BEST_SPEED}])
 Uninverting(_f(9.0.0):C5:[diagnostics={os=Linux, java.vendor=Aleksey Shipilev, 
java.version=12-testing, 
java.vm.version=12-testing+0-builds.shipilev.net-openjdk-jdk12-b109-20190215-jdk-1229,
 lucene.version=9.0.0, os.arch=amd64, 
java.runtime.version=12-testing+0-builds.shipilev.net-openjdk-jdk12-b109-20190215-jdk-1229,
 source=flush, os.version=4.18.0-15-generic, 
timestamp=1552121803366}]:[attributes={Lucene50StoredFieldsFormat.mode=BEST_SPEED}])))}
   [junit4]   2> 3690512 INFO  (commitScheduler-14812-thread-11) [    ] 
o.a.s.u.DirectUpdateHandler2 start 
commit{,optimize=false,openSearcher=false,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
   [junit4]   2> 3690512 INFO  (commitScheduler-14812-thread-11) [    ] 
o.a.s.u.SolrIndexWriter Calling setCommitData with 
IW:org.apache.solr.update.SolrIndexWriter@29c28e83 commitCommandVersion:0
   [junit4]   2> 3690513 INFO  (commitScheduler-14812-thread-11) [    ] 
o.a.s.s.SolrIndexSearcher Opening [Searcher@cc0a629[collection1] realtime]
   [junit4]   2> 3690514 INFO  (commitScheduler-14812-thread-11) [    ] 
o.a.s.u.DirectUpdateHandler2 end_commit_flush
   [junit4]   2> 3695923 INFO  
(TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeRapidAdds-seed#[73B2184A229681F0])
 [    ] o.a.s.SolrTestCaseJ4 ###Ending testSoftAndHardCommitMaxTimeRapidAdds
   [junit4]   2> 3695924 INFO  
(SUITE-SoftAutoCommitTest-seed#[73B2184A229681F0]-worker) [    ] 
o.a.s.SolrTestCaseJ4 ###deleteCore
   [junit4]   2> 3695924 INFO  
(SUITE-SoftAutoCommitTest-seed#[73B2184A229681F0]-worker) [    ] 
o.a.s.c.CoreContainer Shutting down CoreContainer instance=529716312
   [junit4]   2> 3695924 INFO  (coreCloseExecutor-14814-thread-1) [    
x:collection1] o.a.s.c.SolrCore [collection1]  CLOSING SolrCore 
org.apache.solr.core.SolrCore@6632a90e
   [junit4]   2> 3695924 INFO  (coreCloseExecutor-14814-thread-1) [    
x:collection1] o.a.s.m.SolrMetricManager Closing metric reporters for 
registry=solr.core.collection1, tag=6632a90e
   [junit4]   2> 3695924 INFO  (coreCloseExecutor-14814-thread-1) [    
x:collection1] o.a.s.m.r.SolrJmxReporter Closing reporter 
[org.apache.solr.metrics.reporters.SolrJmxReporter@295d091c: rootName = null, 
domain = solr.core.collection1, service url = null, agent id = null] for 
registry solr.core.collection1 / com.codahale.metrics.MetricRegistry@35fff5aa
   [junit4]   2> 3695964 INFO  
(SUITE-SoftAutoCommitTest-seed#[73B2184A229681F0]-worker) [    ] 
o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.node, 
tag=null
   [junit4]   2> 3695964 INFO  
(SUITE-SoftAutoCommitTest-seed#[73B2184A229681F0]-worker) [    ] 
o.a.s.m.r.SolrJmxReporter Closing reporter 
[org.apache.solr.metrics.reporters.SolrJmxReporter@3db1030b: rootName = null, 
domain = solr.node, service url = null, agent id = null] for registry solr.node 
/ com.codahale.metrics.MetricRegistry@7dd0c3ad
   [junit4]   2> 3695975 INFO  
(SUITE-SoftAutoCommitTest-seed#[73B2184A229681F0]-worker) [    ] 
o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.jvm, 
tag=null
   [junit4]   2> 3695976 INFO  
(SUITE-SoftAutoCommitTest-seed#[73B2184A229681F0]-worker) [    ] 
o.a.s.m.r.SolrJmxReporter Closing reporter 
[org.apache.solr.metrics.reporters.SolrJmxReporter@34359f7: rootName = null, 
domain = solr.jvm, service url = null, agent id = null] for registry solr.jvm / 
com.codahale.metrics.MetricRegistry@7026da49
   [junit4]   2> 3695982 INFO  
(SUITE-SoftAutoCommitTest-seed#[73B2184A229681F0]-worker) [    ] 
o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.jetty, 
tag=null
   [junit4]   2> 3695982 INFO  
(SUITE-SoftAutoCommitTest-seed#[73B2184A229681F0]-worker) [    ] 
o.a.s.m.r.SolrJmxReporter Closing reporter 
[org.apache.solr.metrics.reporters.SolrJmxReporter@9d6e48a: rootName = null, 
domain = solr.jetty, service url = null, agent id = null] for registry 
solr.jetty / com.codahale.metrics.MetricRegistry@e49ea3f
   [junit4]   2> NOTE: leaving temporary files on disk at: 
/home/jenkins/workspace/Lucene-Solr-master-Linux/solr/build/solr-core/test/J1/temp/solr.update.SoftAutoCommitTest_73B2184A229681F0-001
   [junit4]   2> NOTE: test params are: codec=Asserting(Lucene80): 
{range_facet_l_dv=FSTOrd50, multiDefault=PostingsFormat(name=MockRandom), 
subject=PostingsFormat(name=MockRandom), 
_root_=PostingsFormat(name=LuceneFixedGap), 
intDefault=PostingsFormat(name=LuceneFixedGap), 
id_i1=PostingsFormat(name=MockRandom), id=FSTOrd50, 
range_facet_i_dv=PostingsFormat(name=LuceneFixedGap), 
text=PostingsFormat(name=LuceneVarGapDocFreqInterval), 
range_facet_l=PostingsFormat(name=LuceneFixedGap), 
timestamp=PostingsFormat(name=LuceneFixedGap)}, 
docValues:{range_facet_l_dv=DocValuesFormat(name=Direct), 
_version_=DocValuesFormat(name=Lucene80), 
intDefault=DocValuesFormat(name=Lucene80), 
id_i1=DocValuesFormat(name=Asserting), 
range_facet_i_dv=DocValuesFormat(name=Lucene80), 
intDvoDefault=DocValuesFormat(name=Lucene80), 
range_facet_l=DocValuesFormat(name=Lucene80), 
timestamp=DocValuesFormat(name=Lucene80)}, maxPointsInLeafNode=777, 
maxMBSortInHeap=5.858878493812199, 
sim=Asserting(org.apache.lucene.search.similarities.AssertingSimilarity@3b102835),
 locale=vo-001, timezone=Singapore
   [junit4]   2> NOTE: Linux 4.18.0-15-generic amd64/Aleksey Shipilev 
12-testing (64-bit)/cpus=8,threads=1,free=117255816,total=450887680
   [junit4]   2> NOTE: All tests run in this JVM: [AliasIntegrationTest, 
TestComplexPhraseQParserPlugin, TestSimTriggerIntegration, 
BasicFunctionalityTest, TestRemoteStreaming, TestRandomCollapseQParserPlugin, 
MoveReplicaHDFSTest, ZkCLITest, TestSchemaNameResource, 
ManagedSchemaRoundRobinCloudTest, TestConfigSetsAPIExclusivity, 
QueryParsingTest, OverseerRolesTest, TestDistributedSearch, TestManagedSchema, 
ClassificationUpdateProcessorIntegrationTest, 
UniqFieldsUpdateProcessorFactoryTest, ReplaceNodeTest, 
DistributedDebugComponentTest, TestSchemaVersionResource, 
LeaderVoteWaitTimeoutTest, TestRealTimeGet, ConnectionReuseTest, BJQParserTest, 
RandomizedTaggerTest, PreAnalyzedFieldTest, CustomCollectionTest, 
UpdateParamsTest, HDFSCollectionsAPITest, CloudExitableDirectoryReaderTest, 
TestFiltering, HighlighterConfigTest, TestRTimerTree, MultiThreadedOCPTest, 
TestFacetMethods, TestSQLHandlerNonCloud, SearchHandlerTest, 
SolrJmxReporterCloudTest, QueryElevationComponentTest, 
AutoscalingHistoryHandlerTest, ChaosMonkeyNothingIsSafeTest, TestCoreDiscovery, 
SolrXmlInZkTest, TestSolrConfigHandler, DeleteLastCustomShardedReplicaTest, 
TestCloudInspectUtil, TestManagedStopFilterFactory, TestDirectoryFactory, 
TestLegacyNumericUtils, TestCloudSearcherWarming, FacetPivotSmallTest, 
UninvertDocValuesMergePolicyTest, ImplicitSnitchTest, TestValueSourceCache, 
TestConfigReload, TestLMJelinekMercerSimilarityFactory, TestJmxIntegration, 
NodeAddedTriggerTest, SpatialRPTFieldTypeTest, DistributedFacetPivotSmallTest, 
ShowFileRequestHandlerTest, NodeMarkersRegistrationTest, 
TestRetrieveFieldsOptimizer, TriLevelCompositeIdRoutingTest, SOLR749Test, 
TestSSLRandomization, MBeansHandlerTest, DOMUtilTest, TokenizerChainTest, 
StatelessScriptUpdateProcessorFactoryTest, TestHttpShardHandlerFactory, 
CdcrUpdateLogTest, TriggerSetPropertiesIntegrationTest, 
TestBulkSchemaConcurrent, RollingRestartTest, TestExportWriter, 
TestNamedUpdateProcessors, HdfsAutoAddReplicasIntegrationTest, TestPushWriter, 
DefaultValueUpdateProcessorTest, OpenExchangeRatesOrgProviderTest, 
PeerSyncWithLeaderTest, DistributedFacetSimpleRefinementLongTailTest, 
BasicDistributedZk2Test, SpellCheckCollatorWithCollapseTest, 
TestBackupRepositoryFactory, TestStressInPlaceUpdates, 
TestHighlightDedupGrouping, HdfsDirectoryFactoryTest, RAMDirectoryFactoryTest, 
TestUninvertingReader, TestFieldResource, CdcrBootstrapTest, 
TestTolerantSearch, TestDelegationWithHadoopAuth, 
ChaosMonkeySafeLeaderWithPullReplicasTest, ChangedSchemaMergeTest, 
TestSizeLimitedDistributedMap, TolerantUpdateProcessorTest, 
DocumentBuilderTest, TestSuggestSpellingConverter, AssignTest, 
TermsComponentTest, AlternateDirectoryTest, TestOrdValues, TestLogWatcher, 
SolrMetricsIntegrationTest, TestPayloadCheckQParserPlugin, 
TestClusterStateMutator, TestGraphMLResponseWriter, 
ParsingFieldUpdateProcessorsTest, TestLuceneMatchVersion, JSONWriterTest, 
ProtectedTermFilterFactoryTest, TestSolr4Spatial, MigrateRouteKeyTest, 
CollectionsAPIAsyncDistributedZkTest, DistributedSpellCheckComponentTest, 
TestWriterPerf, CoreSorterTest, PropertiesRequestHandlerTest, 
TestSearcherReuse, TestSolrFieldCacheBean, TestCloudPseudoReturnFields, 
TestJsonRequest, TestZkAclsWithHadoopAuth, SearchRateTriggerTest, 
ScriptEngineTest, TestSystemCollAutoCreate, InfoHandlerTest, 
TestDynamicFieldCollectionResource, TestRestManager, 
TestTolerantUpdateProcessorCloud, TestRequestStatusCollectionAPI, 
TestReqParamsAPI, FieldMutatingUpdateProcessorTest, TestRandomFaceting, 
TestTrie, TestCharFilters, TestReversedWildcardFilterFactory, 
TestLuceneIndexBackCompat, TestEmbeddedSolrServerAdminHandler, 
TestEmbeddedSolrServerConstructors, TestEmbeddedSolrServerSchemaAPI, 
ActionThrottleTest, ChaosMonkeyNothingIsSafeWithPullReplicasTest, 
ConcurrentCreateRoutedAliasTest, ConfigSetsAPITest, ConnectionManagerTest, 
CreateCollectionCleanupTest, CreateRoutedAliasTest, DeleteReplicaTest, 
DistribJoinFromCollectionTest, ForceLeaderTest, 
ForceLeaderWithTlogReplicasTest, HealthCheckHandlerTest, 
HttpPartitionOnCommitTest, LeaderElectionTest, 
LeaderFailoverAfterPartitionTest, SaslZkACLProviderTest, 
ShardRoutingCustomTest, SolrCLIZkUtilsTest, TestAuthenticationFramework, 
TestClusterProperties, TestConfigSetsAPIZkFailure, TestCryptoKeys, 
TestDistributedMap, TestDownShardTolerantSearch, 
TestLeaderElectionWithEmptyReplica, TestRandomFlRTGCloud, 
TestTolerantUpdateProcessorRandomCloud, ZkFailoverTest, ZkNodePropsTest, 
CollectionsAPIDistributedZkTest, TestCollectionsAPIViaSolrCloudCluster, 
AutoAddReplicasPlanActionTest, AutoScalingHandlerTest, HttpTriggerListenerTest, 
IndexSizeTriggerTest, MetricTriggerIntegrationTest, ScheduledTriggerTest, 
TestPolicyCloud, TestSimGenericDistributedQueue, TestSimNodeAddedTrigger, 
TestSimNodeLostTrigger, CdcrReplicationHandlerTest, CdcrRequestHandlerTest, 
CdcrVersionReplicationTest, HdfsBasicDistributedZkTest, 
HdfsChaosMonkeyNothingIsSafeTest, HdfsNNFailoverTest, HdfsRecoverLeaseTest, 
HdfsRestartWhileUpdatingTest, HdfsSyncSliceTest, 
HdfsTlogReplayBufferedWhileIndexingTest, HdfsUnloadDistributedZkTest, 
HdfsWriteToMultipleCollectionsTest, ByteBuffersDirectoryFactoryTest, 
CachingDirectoryFactoryTest, DirectoryFactoryTest, PluginInfoTest, 
RequestHandlersTest, TestCodecSupport, TestConfig, TestConfigOverlay, 
TestConfigSetImmutable, TestConfigSetProperties, TestDynamicURP, 
TestImplicitCoreProperties, TestInfoStreamLogging, TestLazyCores, 
TestReloadAndDeleteDocs, TestSolrIndexConfig, TestSolrCoreSnapshots, 
MoreLikeThisHandlerTest, ResponseBuilderTest, TestHdfsBackupRestoreCore, 
V2StandaloneTest, XmlUpdateRequestHandlerTest, XsltUpdateRequestHandlerTest, 
CoreAdminCreateDiscoverTest, CoreAdminHandlerTest, CoreAdminOperationTest, 
SecurityConfHandlerTest, SystemInfoHandlerTest, TestApiFramework, 
TestCollectionAPIs, TestConfigsApi, TestCoreAdminApis, BadComponentTest, 
CustomHighlightComponentTest, CustomTermsComponentTest, 
DistributedFacetPivotLargeTest, DistributedFacetPivotWhiteBoxTest, 
InfixSuggestersTest, SuggestComponentContextFilterQueryTest, JavabinLoaderTest, 
Tagger2Test, TaggerTest, TaggingAttributeTest, XmlInterpolationTest, 
TestPostingsSolrHighlighter, TestNumericRangeQuery64, RegexBytesRefFilterTest, 
TestStreamBody, TestCustomDocTransformer, TestChildDocTransformerHierarchy, 
TestSchemaResource, BadCopyFieldTest, BadIndexSchemaTest, DateFieldTest, 
DocValuesMissingTest, EnumFieldTest, NotRequiredUniqueKeyTest, 
RequiredFieldsTest, TestCloudSchemaless, TestGraphTermsQParserPlugin, 
TestInitQParser, TestLRUCache, TestMissingGroups, TestNoOpRegenerator, 
TestPseudoReturnFields, TestRecovery, TestReloadDeadlock, 
TestSimpleQParserPlugin, TestSolr4Spatial2, TestStandardQParsers, 
TestStressLucene, TestStressRecovery, TestStressReorder, TestStressVersions, 
SpatialHeatmapFacetsTest, TestCloudJSONFacetSKG, 
TestJsonFacetsWithNestedObjects, SortByFunctionTest, TestFunctionQuery, 
BlockJoinFacetRandomTest, BlockJoinFacetSimpleTest, GraphQueryTest, 
TestCloudNestedDocsSort, TestDistribIDF, BasicAuthIntegrationTest, 
JWTAuthPluginTest, PKIAuthenticationIntegrationTest, 
TestAuthorizationFramework, FileBasedSpellCheckerTest, SuggesterFSTTest, 
SuggesterTest, TestAnalyzeInfixSuggestions, TestBlendedInfixSuggestions, 
TestFuzzyAnalyzedSuggestions, TestPhraseSuggestions, HdfsDirectoryTest, 
TestFieldCacheWithThreads, TestLegacyFieldCache, AddBlockUpdateTest, 
DataDrivenBlockJoinTest, PeerSyncTest, PeerSyncWithBufferUpdatesTest, 
SoftAutoCommitTest]
   [junit4] Completed [825/845 (1!)] on J1 in 118.59s, 10 tests, 1 failure <<< 
FAILURES!

[...truncated 42568 lines...]
[repro] Jenkins log URL: 
https://jenkins.thetaphi.de/job/Lucene-Solr-master-Linux/23759/consoleText

[repro] Revision: 8c6e30536562413639eaf8bab1087da700733b33

[repro] Ant options: "-Dargs=-XX:+UseCompressedOops -XX:+UseG1GC"
[repro] Repro line:  ant test  -Dtestcase=SoftAutoCommitTest 
-Dtests.method=testSoftAndHardCommitMaxTimeMixedAdds 
-Dtests.seed=73B2184A229681F0 -Dtests.multiplier=3 -Dtests.slow=true 
-Dtests.locale=vo-001 -Dtests.timezone=Singapore -Dtests.asserts=true 
-Dtests.file.encoding=UTF-8

[repro] ant clean

[...truncated 6 lines...]
[repro] Test suites by module:
[repro]    solr/core
[repro]       SoftAutoCommitTest
[repro] ant compile-test

[...truncated 3570 lines...]
[repro] ant test-nocompile -Dtests.dups=5 -Dtests.maxfailures=5 
-Dtests.class="*.SoftAutoCommitTest" -Dtests.showOutput=onerror 
"-Dargs=-XX:+UseCompressedOops -XX:+UseG1GC" -Dtests.seed=73B2184A229681F0 
-Dtests.multiplier=3 -Dtests.slow=true -Dtests.locale=vo-001 
-Dtests.timezone=Singapore -Dtests.asserts=true -Dtests.file.encoding=UTF-8

[...truncated 120 lines...]
[repro] Failures:
[repro]   0/5 failed: org.apache.solr.update.SoftAutoCommitTest
[repro] Exiting with code 0

[...truncated 43 lines...]

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