You are viewing a plain text version of this content. The canonical link for it is here.

Posted to dev@lucene.apache.org by Apache Jenkins Server <je...@builds.apache.org> on 2018/12/25 13:36:06 UTC

[JENKINS] Lucene-Solr-Tests-master - Build # 3089 - Unstable

Build: https://builds.apache.org/job/Lucene-Solr-Tests-master/3089/

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

Error Message:
soft529 wasn't fast enough

Stack Trace:
java.lang.AssertionError: soft529 wasn't fast enough
	at __randomizedtesting.SeedInfo.seed([709ECA08866D55E0:B3791619B751829D]:0)
	at org.junit.Assert.fail(Assert.java:88)
	at org.junit.Assert.assertTrue(Assert.java:41)
	at org.junit.Assert.assertNotNull(Assert.java:712)
	at org.apache.solr.update.SoftAutoCommitTest.doTestSoftAndHardCommitMaxTimeMixedAdds(SoftAutoCommitTest.java:209)
	at org.apache.solr.update.SoftAutoCommitTest.testHardCommitWithinAndSoftCommitMaxTimeMixedAdds(SoftAutoCommitTest.java:174)
	at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
	at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
	at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
	at java.lang.reflect.Method.invoke(Method.java:498)
	at com.carrotsearch.randomizedtesting.RandomizedRunner.invoke(RandomizedRunner.java:1750)
	at com.carrotsearch.randomizedtesting.RandomizedRunner$8.evaluate(RandomizedRunner.java:938)
	at com.carrotsearch.randomizedtesting.RandomizedRunner$9.evaluate(RandomizedRunner.java:974)
	at com.carrotsearch.randomizedtesting.RandomizedRunner$10.evaluate(RandomizedRunner.java:988)
	at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:57)
	at org.apache.lucene.util.TestRuleSetupTeardownChained$1.evaluate(TestRuleSetupTeardownChained.java:49)
	at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:45)
	at org.apache.lucene.util.TestRuleThreadAndTestName$1.evaluate(TestRuleThreadAndTestName.java:48)
	at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:64)
	at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:47)
	at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
	at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:368)
	at com.carrotsearch.randomizedtesting.ThreadLeakControl.forkTimeoutingTask(ThreadLeakControl.java:817)
	at com.carrotsearch.randomizedtesting.ThreadLeakControl$3.evaluate(ThreadLeakControl.java:468)
	at com.carrotsearch.randomizedtesting.RandomizedRunner.runSingleTest(RandomizedRunner.java:947)
	at com.carrotsearch.randomizedtesting.RandomizedRunner$5.evaluate(RandomizedRunner.java:832)
	at com.carrotsearch.randomizedtesting.RandomizedRunner$6.evaluate(RandomizedRunner.java:883)
	at com.carrotsearch.randomizedtesting.RandomizedRunner$7.evaluate(RandomizedRunner.java:894)
	at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
	at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:57)
	at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:45)
	at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
	at org.apache.lucene.util.TestRuleStoreClassName$1.evaluate(TestRuleStoreClassName.java:41)
	at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:40)
	at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:40)
	at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
	at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
	at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
	at org.apache.lucene.util.TestRuleAssertionsRequired$1.evaluate(TestRuleAssertionsRequired.java:53)
	at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:47)
	at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:64)
	at org.apache.lucene.util.TestRuleIgnoreTestSuites$1.evaluate(TestRuleIgnoreTestSuites.java:54)
	at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
	at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:368)
	at java.lang.Thread.run(Thread.java:748)




Build Log:
[...truncated 12615 lines...]
   [junit4] Suite: org.apache.solr.update.SoftAutoCommitTest
   [junit4]   2> Creating dataDir: /home/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-master/solr/build/solr-core/test/J0/temp/solr.update.SoftAutoCommitTest_709ECA08866D55E0-001/init-core-data-001
   [junit4]   2> 14214 INFO  (SUITE-SoftAutoCommitTest-seed#[709ECA08866D55E0]-worker) [    ] o.a.s.SolrTestCaseJ4 Using PointFields (NUMERIC_POINTS_SYSPROP=true) w/NUMERIC_DOCVALUES_SYSPROP=false
   [junit4]   2> 14594 INFO  (SUITE-SoftAutoCommitTest-seed#[709ECA08866D55E0]-worker) [    ] o.e.j.u.log Logging initialized @14676ms to org.eclipse.jetty.util.log.Slf4jLog
   [junit4]   2> 14671 INFO  (SUITE-SoftAutoCommitTest-seed#[709ECA08866D55E0]-worker) [    ] o.a.s.SolrTestCaseJ4 Randomized ssl (false) and clientAuth (false) via: @org.apache.solr.util.RandomizeSSL(reason=, ssl=NaN, value=NaN, clientAuth=NaN)
   [junit4]   2> 14868 INFO  (SUITE-SoftAutoCommitTest-seed#[709ECA08866D55E0]-worker) [    ] o.a.s.SolrTestCaseJ4 SecureRandom sanity checks: test.solr.allowed.securerandom=null & java.security.egd=file:/dev/./urandom
   [junit4]   2> 14906 INFO  (SUITE-SoftAutoCommitTest-seed#[709ECA08866D55E0]-worker) [    ] o.a.s.SolrTestCaseJ4 ####initCore
   [junit4]   2> 15608 INFO  (SUITE-SoftAutoCommitTest-seed#[709ECA08866D55E0]-worker) [    ] o.a.s.c.SolrResourceLoader Using system property solr.solr.home: /home/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-master/solr/core/src/test-files/solr
   [junit4]   2> 15664 INFO  (SUITE-SoftAutoCommitTest-seed#[709ECA08866D55E0]-worker) [    ] o.a.s.c.SolrResourceLoader [null] Added 2 libs to classloader, from paths: [/home/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-master/solr/core/src/test-files/solr/collection1/lib, /home/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-master/solr/core/src/test-files/solr/collection1/lib/classes]
   [junit4]   2> 19809 INFO  (SUITE-SoftAutoCommitTest-seed#[709ECA08866D55E0]-worker) [    ] o.a.s.c.SolrConfig Using Lucene MatchVersion: 8.0.0
   [junit4]   2> 21304 INFO  (SUITE-SoftAutoCommitTest-seed#[709ECA08866D55E0]-worker) [    ] o.a.s.s.IndexSchema [null] Schema name=test
   [junit4]   2> 25525 WARN  (SUITE-SoftAutoCommitTest-seed#[709ECA08866D55E0]-worker) [    ] o.a.s.c.SolrResourceLoader Solr loaded a deprecated plugin/analysis class [solr.WordDelimiterFilterFactory]. Please consult documentation how to replace it accordingly.
   [junit4]   2> 26799 WARN  (SUITE-SoftAutoCommitTest-seed#[709ECA08866D55E0]-worker) [    ] o.a.s.c.SolrResourceLoader Solr loaded a deprecated plugin/analysis class [solr.GeoHashField]. Please consult documentation how to replace it accordingly.
   [junit4]   2> 26870 WARN  (SUITE-SoftAutoCommitTest-seed#[709ECA08866D55E0]-worker) [    ] o.a.s.c.SolrResourceLoader Solr loaded a deprecated plugin/analysis class [solr.LatLonType]. Please consult documentation how to replace it accordingly.
   [junit4]   2> 26965 WARN  (SUITE-SoftAutoCommitTest-seed#[709ECA08866D55E0]-worker) [    ] o.a.s.c.SolrResourceLoader Solr loaded a deprecated plugin/analysis class [solr.CurrencyField]. Please consult documentation how to replace it accordingly.
   [junit4]   2> 28054 INFO  (SUITE-SoftAutoCommitTest-seed#[709ECA08866D55E0]-worker) [    ] o.a.s.s.IndexSchema Loaded schema test/1.0 with uniqueid field id
   [junit4]   2> 37031 WARN  (SUITE-SoftAutoCommitTest-seed#[709ECA08866D55E0]-worker) [    ] o.e.j.u.s.S.config No Client EndPointIdentificationAlgorithm configured for SslContextFactory@292bc5b0[provider=null,keyStore=null,trustStore=null]
   [junit4]   2> 38700 WARN  (SUITE-SoftAutoCommitTest-seed#[709ECA08866D55E0]-worker) [    ] o.e.j.u.s.S.config No Client EndPointIdentificationAlgorithm configured for SslContextFactory@31435bce[provider=null,keyStore=null,trustStore=null]
   [junit4]   2> 41335 INFO  (SUITE-SoftAutoCommitTest-seed#[709ECA08866D55E0]-worker) [    ] o.a.s.c.TransientSolrCoreCacheDefault Allocating transient cache for 2147483647 transient cores
   [junit4]   2> 41405 INFO  (SUITE-SoftAutoCommitTest-seed#[709ECA08866D55E0]-worker) [    ] o.a.s.h.a.MetricsHistoryHandler No .system collection, keeping metrics history in memory.
   [junit4]   2> 43139 INFO  (SUITE-SoftAutoCommitTest-seed#[709ECA08866D55E0]-worker) [    ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr.node' (registry 'solr.node') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@32b8a122
   [junit4]   2> 43141 INFO  (SUITE-SoftAutoCommitTest-seed#[709ECA08866D55E0]-worker) [    ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr.jvm' (registry 'solr.jvm') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@32b8a122
   [junit4]   2> 43141 INFO  (SUITE-SoftAutoCommitTest-seed#[709ECA08866D55E0]-worker) [    ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr.jetty' (registry 'solr.jetty') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@32b8a122
   [junit4]   2> 43606 INFO  (coreLoadExecutor-9-thread-1) [    x:collection1] o.a.s.c.SolrResourceLoader [null] Added 2 libs to classloader, from paths: [/home/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-master/solr/core/src/test-files/solr/collection1/lib, /home/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-master/solr/core/src/test-files/solr/collection1/lib/classes]
   [junit4]   2> 44332 INFO  (coreLoadExecutor-9-thread-1) [    x:collection1] o.a.s.c.SolrConfig Using Lucene MatchVersion: 8.0.0
   [junit4]   2> 44896 INFO  (coreLoadExecutor-9-thread-1) [    x:collection1] o.a.s.s.IndexSchema [collection1] Schema name=test
   [junit4]   2> 46870 INFO  (coreLoadExecutor-9-thread-1) [    x:collection1] o.a.s.s.IndexSchema Loaded schema test/1.0 with uniqueid field id
   [junit4]   2> 47128 INFO  (coreLoadExecutor-9-thread-1) [    x:collection1] o.a.s.c.CoreContainer Creating SolrCore 'collection1' using configuration from instancedir /home/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-master/solr/core/src/test-files/solr/collection1, trusted=true
   [junit4]   2> 47555 INFO  (coreLoadExecutor-9-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@32b8a122
   [junit4]   2> 47667 INFO  (coreLoadExecutor-9-thread-1) [    x:collection1] o.a.s.c.SolrCore [[collection1] ] Opening new SolrCore at [/home/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-master/solr/core/src/test-files/solr/collection1], dataDir=[/home/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-master/solr/build/solr-core/test/J0/temp/solr.update.SoftAutoCommitTest_709ECA08866D55E0-001/init-core-data-001/]
   [junit4]   2> 48084 INFO  (coreLoadExecutor-9-thread-1) [    x:collection1] o.a.s.u.RandomMergePolicy RandomMergePolicy wrapping class org.apache.lucene.index.LogDocMergePolicy: [LogDocMergePolicy: minMergeSize=1000, mergeFactor=47, maxMergeSize=9223372036854775807, maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=true, maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.7031738305480503]
   [junit4]   2> 57010 INFO  (coreLoadExecutor-9-thread-1) [    x:collection1] o.a.s.u.UpdateHandler Using UpdateLog implementation: org.apache.solr.update.UpdateLog
   [junit4]   2> 57010 INFO  (coreLoadExecutor-9-thread-1) [    x:collection1] o.a.s.u.UpdateLog Initializing UpdateLog: dataDir= defaultSyncLevel=FLUSH numRecordsToKeep=100 maxNumLogsToKeep=10 numVersionBuckets=65536
   [junit4]   2> 57085 INFO  (coreLoadExecutor-9-thread-1) [    x:collection1] o.a.s.u.CommitTracker Hard AutoCommit: disabled
   [junit4]   2> 57085 INFO  (coreLoadExecutor-9-thread-1) [    x:collection1] o.a.s.u.CommitTracker Soft AutoCommit: disabled
   [junit4]   2> 57101 INFO  (coreLoadExecutor-9-thread-1) [    x:collection1] o.a.s.u.RandomMergePolicy RandomMergePolicy wrapping class org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: maxMergeAtOnce=47, maxMergeAtOnceExplicit=43, maxMergedSegmentMB=63.3349609375, floorSegmentMB=1.078125, forceMergeDeletesPctAllowed=7.136964010060918, segmentsPerTier=29.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.32221035965128914, deletesPctAllowed=24.761996953705175
   [junit4]   2> 57193 INFO  (coreLoadExecutor-9-thread-1) [    x:collection1] o.a.s.s.SolrIndexSearcher Opening [Searcher@1d0c720f[collection1] main]
   [junit4]   2> 57922 INFO  (coreLoadExecutor-9-thread-1) [    x:collection1] o.a.s.h.c.SpellCheckComponent Initializing spell checkers
   [junit4]   2> 58864 INFO  (coreLoadExecutor-9-thread-1) [    x:collection1] o.a.s.s.DirectSolrSpellChecker init: {name=direct,classname=DirectSolrSpellChecker,field=lowerfilt,minQueryLength=3}
   [junit4]   2> 60044 INFO  (coreLoadExecutor-9-thread-1) [    x:collection1] o.a.s.h.ReplicationHandler Commits will be reserved for 10000ms.
   [junit4]   2> 60117 INFO  (coreLoadExecutor-9-thread-1) [    x:collection1] o.a.s.u.UpdateLog Could not find max version in index or recent updates, using new clock 1620822950467862528
   [junit4]   2> 60155 INFO  (SUITE-SoftAutoCommitTest-seed#[709ECA08866D55E0]-worker) [    ] o.a.s.SolrTestCaseJ4 ####initCore end
   [junit4]   2> 60157 INFO  (searcherExecutor-10-thread-1-processing-x:collection1) [    x:collection1] o.a.s.h.c.SpellCheckComponent Loading spell index for spellchecker: default
   [junit4]   2> 60326 INFO  (searcherExecutor-10-thread-1-processing-x:collection1) [    x:collection1] o.a.s.h.c.SpellCheckComponent Loading spell index for spellchecker: direct
   [junit4]   2> 60326 INFO  (searcherExecutor-10-thread-1-processing-x:collection1) [    x:collection1] o.a.s.h.c.SpellCheckComponent Loading spell index for spellchecker: wordbreak
   [junit4]   2> 60326 INFO  (searcherExecutor-10-thread-1-processing-x:collection1) [    x:collection1] o.a.s.h.c.SpellCheckComponent Loading spell index for spellchecker: multipleFields
   [junit4]   2> 60615 INFO  (TEST-SoftAutoCommitTest.testHardCommitWithinAndSoftCommitMaxTimeMixedAdds-seed#[709ECA08866D55E0]) [    ] o.a.s.SolrTestCaseJ4 ###Starting testHardCommitWithinAndSoftCommitMaxTimeMixedAdds
   [junit4]   2> 60643 INFO  (searcherExecutor-10-thread-1-processing-x:collection1) [    x:collection1] o.a.s.h.c.SpellCheckComponent Loading spell index for spellchecker: jarowinkler
   [junit4]   2> 60663 INFO  (searcherExecutor-10-thread-1-processing-x:collection1) [    x:collection1] o.a.s.h.c.SpellCheckComponent Loading spell index for spellchecker: external
   [junit4]   2> 60664 INFO  (searcherExecutor-10-thread-1-processing-x:collection1) [    x:collection1] o.a.s.h.c.SpellCheckComponent Loading spell index for spellchecker: freq
   [junit4]   2> 60665 INFO  (searcherExecutor-10-thread-1-processing-x:collection1) [    x:collection1] o.a.s.h.c.SpellCheckComponent Loading spell index for spellchecker: fqcn
   [junit4]   2> 60666 INFO  (searcherExecutor-10-thread-1-processing-x:collection1) [    x:collection1] o.a.s.h.c.SpellCheckComponent Loading spell index for spellchecker: perDict
   [junit4]   2> 61199 INFO  (searcherExecutor-10-thread-1-processing-x:collection1) [    x:collection1] o.a.s.c.SolrCore [collection1] Registered new searcher Searcher@1d0c720f[collection1] main{ExitableDirectoryReader(UninvertingDirectoryReader())}
   [junit4]   2> 72195 INFO  (TEST-SoftAutoCommitTest.testHardCommitWithinAndSoftCommitMaxTimeMixedAdds-seed#[709ECA08866D55E0]) [    ] o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=null path=null params={}{add=[529 (1620822961179066368)]} 0 3077
   [junit4]   2> 72803 INFO  (commitScheduler-14-thread-1) [    ] o.a.s.u.DirectUpdateHandler2 start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=true,prepareCommit=false}
   [junit4]   2> 73443 INFO  (commitScheduler-13-thread-1) [    ] o.a.s.u.DirectUpdateHandler2 start commit{,optimize=false,openSearcher=false,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
   [junit4]   2> 74901 INFO  (TEST-SoftAutoCommitTest.testHardCommitWithinAndSoftCommitMaxTimeMixedAdds-seed#[709ECA08866D55E0]) [    ] o.a.s.SolrTestCaseJ4 ###Ending testHardCommitWithinAndSoftCommitMaxTimeMixedAdds
   [junit4]   2> NOTE: reproduce with: ant test  -Dtestcase=SoftAutoCommitTest -Dtests.method=testHardCommitWithinAndSoftCommitMaxTimeMixedAdds -Dtests.seed=709ECA08866D55E0 -Dtests.multiplier=2 -Dtests.slow=true -Dtests.locale=ru -Dtests.timezone=America/Argentina/Rio_Gallegos -Dtests.asserts=true -Dtests.file.encoding=ISO-8859-1
   [junit4] FAILURE 14.9s J0 | SoftAutoCommitTest.testHardCommitWithinAndSoftCommitMaxTimeMixedAdds <<<
   [junit4]    > Throwable #1: java.lang.AssertionError: soft529 wasn't fast enough
   [junit4]    > 	at __randomizedtesting.SeedInfo.seed([709ECA08866D55E0:B3791619B751829D]:0)
   [junit4]    > 	at org.apache.solr.update.SoftAutoCommitTest.doTestSoftAndHardCommitMaxTimeMixedAdds(SoftAutoCommitTest.java:209)
   [junit4]    > 	at org.apache.solr.update.SoftAutoCommitTest.testHardCommitWithinAndSoftCommitMaxTimeMixedAdds(SoftAutoCommitTest.java:174)
   [junit4]    > 	at java.lang.Thread.run(Thread.java:748)
   [junit4]   2> 75049 INFO  (TEST-SoftAutoCommitTest.testSoftCommitWithinAndHardCommitMaxTimeMixedAdds-seed#[709ECA08866D55E0]) [    ] o.a.s.SolrTestCaseJ4 ###Starting testSoftCommitWithinAndHardCommitMaxTimeMixedAdds
   [junit4]   2> 75085 INFO  (commitScheduler-14-thread-1) [    ] o.a.s.s.SolrIndexSearcher Opening [Searcher@5cbddf50[collection1] main]
   [junit4]   2> 75119 INFO  (commitScheduler-13-thread-1) [    ] o.a.s.u.SolrIndexWriter Calling setCommitData with IW:org.apache.solr.update.SolrIndexWriter@bbe468d commitCommandVersion:0
   [junit4]   2> 75119 INFO  (commitScheduler-14-thread-1) [    ] o.a.s.u.DirectUpdateHandler2 end_commit_flush
   [junit4]   2> 75229 INFO  (TEST-SoftAutoCommitTest.testSoftCommitWithinAndHardCommitMaxTimeMixedAdds-seed#[709ECA08866D55E0]) [    ] o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=null path=null params={}{add=[529 (1620822966275145728)]} 0 37
   [junit4]   2> 75254 INFO  (searcherExecutor-10-thread-1) [    ] o.a.s.c.SolrCore [collection1] Registered new searcher Searcher@5cbddf50[collection1] main{ExitableDirectoryReader(UninvertingDirectoryReader(Uninverting(_0(8.0.0):C1:[diagnostics={os=Linux, java.vendor=Oracle Corporation, java.version=1.8.0_191, java.vm.version=25.191-b12, lucene.version=8.0.0, os.arch=amd64, java.runtime.version=1.8.0_191-b12, source=flush, os.version=4.4.0-112-generic, timestamp=1545737233431}]:[attributes={Lucene50StoredFieldsFormat.mode=BEST_SPEED}])))}
   [junit4]   2> 75699 INFO  (commitScheduler-13-thread-1) [    ] o.a.s.s.SolrIndexSearcher Opening [Searcher@4fc897bc[collection1] realtime]
   [junit4]   2> 75735 INFO  (commitScheduler-14-thread-1) [    ] o.a.s.u.DirectUpdateHandler2 start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=true,prepareCommit=false}
   [junit4]   2> 75735 INFO  (commitScheduler-13-thread-1) [    ] o.a.s.u.DirectUpdateHandler2 end_commit_flush
   [junit4]   2> 75914 INFO  (commitScheduler-14-thread-1) [    ] o.a.s.s.SolrIndexSearcher Opening [Searcher@2752212f[collection1] main]
   [junit4]   2> 75915 INFO  (commitScheduler-14-thread-1) [    ] o.a.s.u.DirectUpdateHandler2 end_commit_flush
   [junit4]   2> 75950 INFO  (searcherExecutor-10-thread-1) [    ] o.a.s.c.SolrCore [collection1] Registered new searcher Searcher@2752212f[collection1] main{ExitableDirectoryReader(UninvertingDirectoryReader(Uninverting(_1(8.0.0):C1:[diagnostics={os=Linux, java.vendor=Oracle Corporation, java.version=1.8.0_191, java.vm.version=25.191-b12, lucene.version=8.0.0, os.arch=amd64, java.runtime.version=1.8.0_191-b12, source=flush, os.version=4.4.0-112-generic, timestamp=1545737234722}]:[attributes={Lucene50StoredFieldsFormat.mode=BEST_SPEED}])))}
   [junit4]   2> 76439 INFO  (commitScheduler-13-thread-1) [    ] o.a.s.u.DirectUpdateHandler2 start commit{,optimize=false,openSearcher=false,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
   [junit4]   2> 76439 INFO  (commitScheduler-13-thread-1) [    ] o.a.s.u.SolrIndexWriter Calling setCommitData with IW:org.apache.solr.update.SolrIndexWriter@bbe468d commitCommandVersion:0
   [junit4]   2> 76457 INFO  (TEST-SoftAutoCommitTest.testSoftCommitWithinAndHardCommitMaxTimeMixedAdds-seed#[709ECA08866D55E0]) [    ] o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=null path=null params={}{add=[530 (1620822967585865728)]} 0 15
   [junit4]   2> 77014 INFO  (commitScheduler-14-thread-2) [    ] o.a.s.u.DirectUpdateHandler2 start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=true,prepareCommit=false}
   [junit4]   2> 77071 INFO  (commitScheduler-13-thread-1) [    ] o.a.s.s.SolrIndexSearcher Opening [Searcher@27446007[collection1] realtime]
   [junit4]   2> 77073 INFO  (commitScheduler-14-thread-2) [    ] o.a.s.s.SolrIndexSearcher Opening [Searcher@7e41d163[collection1] main]
   [junit4]   2> 77073 INFO  (commitScheduler-14-thread-2) [    ] o.a.s.u.DirectUpdateHandler2 end_commit_flush
   [junit4]   2> 77075 INFO  (commitScheduler-13-thread-1) [    ] o.a.s.u.DirectUpdateHandler2 end_commit_flush
   [junit4]   2> 77133 INFO  (searcherExecutor-10-thread-1) [    ] o.a.s.c.SolrCore [collection1] Registered new searcher Searcher@7e41d163[collection1] main{ExitableDirectoryReader(UninvertingDirectoryReader(Uninverting(_1(8.0.0):C1:[diagnostics={os=Linux, java.vendor=Oracle Corporation, java.version=1.8.0_191, java.vm.version=25.191-b12, lucene.version=8.0.0, os.arch=amd64, java.runtime.version=1.8.0_191-b12, source=flush, os.version=4.4.0-112-generic, timestamp=1545737234722}]:[attributes={Lucene50StoredFieldsFormat.mode=BEST_SPEED}]) Uninverting(_2(8.0.0):C1:[diagnostics={os=Linux, java.vendor=Oracle Corporation, java.version=1.8.0_191, java.vm.version=25.191-b12, lucene.version=8.0.0, os.arch=amd64, java.runtime.version=1.8.0_191-b12, source=flush, os.version=4.4.0-112-generic, timestamp=1545737236114}]:[attributes={Lucene50StoredFieldsFormat.mode=BEST_SPEED}])))}
   [junit4]   2> 77671 INFO  (commitScheduler-13-thread-1) [    ] o.a.s.u.DirectUpdateHandler2 start commit{,optimize=false,openSearcher=false,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
   [junit4]   2> 77671 INFO  (commitScheduler-13-thread-1) [    ] o.a.s.u.SolrIndexWriter Calling setCommitData with IW:org.apache.solr.update.SolrIndexWriter@bbe468d commitCommandVersion:0
   [junit4]   2> 77673 INFO  (commitScheduler-13-thread-1) [    ] o.a.s.s.SolrIndexSearcher Opening [Searcher@d24b9c1[collection1] realtime]
   [junit4]   2> 77679 INFO  (commitScheduler-13-thread-1) [    ] o.a.s.u.DirectUpdateHandler2 end_commit_flush
   [junit4]   2> 78688 INFO  (TEST-SoftAutoCommitTest.testSoftCommitWithinAndHardCommitMaxTimeMixedAdds-seed#[709ECA08866D55E0]) [    ] o.a.s.SolrTestCaseJ4 ###Ending testSoftCommitWithinAndHardCommitMaxTimeMixedAdds
   [junit4]   2> 78710 INFO  (TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeRapidAdds-seed#[709ECA08866D55E0]) [    ] o.a.s.SolrTestCaseJ4 ###Starting testSoftAndHardCommitMaxTimeRapidAdds
   [junit4]   2> 83775 INFO  (TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeRapidAdds-seed#[709ECA08866D55E0]) [    ] o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=null path=null params={}{add=[5000 (1620822975216353280)]} 0 56
   [junit4]   2> 83778 INFO  (TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeRapidAdds-seed#[709ECA08866D55E0]) [    ] o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=null path=null params={}{add=[5001 (1620822975277170688)]} 0 1
   [junit4]   2> 83791 INFO  (TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeRapidAdds-seed#[709ECA08866D55E0]) [    ] o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=null path=null params={}{add=[5002 (1620822975278219264)]} 0 13
   [junit4]   2> 83793 INFO  (TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeRapidAdds-seed#[709ECA08866D55E0]) [    ] o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=null path=null params={}{add=[5003 (1620822975292899328)]} 0 0
   [junit4]   2> 83795 INFO  (TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeRapidAdds-seed#[709ECA08866D55E0]) [    ] o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=null path=null params={}{add=[5004 (1620822975294996480)]} 0 0
   [junit4]   2> 83828 INFO  (TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeRapidAdds-seed#[709ECA08866D55E0]) [    ] o.a.s.u.SoftAutoCommitTest maxTimeMillis: 28074643951352787ns - 28074643841798862ns == 109ms
   [junit4]   2> 83829 INFO  (TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeRapidAdds-seed#[709ECA08866D55E0]) [    ] o.a.s.u.SoftAutoCommitTest maxExpectedSoft=1
   [junit4]   2> 83829 INFO  (TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeRapidAdds-seed#[709ECA08866D55E0]) [    ] o.a.s.u.SoftAutoCommitTest maxExpectedHard=1
   [junit4]   2> 84225 INFO  (commitScheduler-14-thread-3) [    ] o.a.s.u.DirectUpdateHandler2 start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=true,prepareCommit=false}
   [junit4]   2> 84528 INFO  (commitScheduler-14-thread-3) [    ] o.a.s.s.SolrIndexSearcher Opening [Searcher@2490ed0c[collection1] main]
   [junit4]   2> 84561 INFO  (commitScheduler-14-thread-3) [    ] o.a.s.u.DirectUpdateHandler2 end_commit_flush
   [junit4]   2> 84563 INFO  (searcherExecutor-10-thread-1) [    ] o.a.s.c.SolrCore [collection1] Registered new searcher Searcher@2490ed0c[collection1] main{ExitableDirectoryReader(UninvertingDirectoryReader(Uninverting(_1(8.0.0):C1:[diagnostics={os=Linux, java.vendor=Oracle Corporation, java.version=1.8.0_191, java.vm.version=25.191-b12, lucene.version=8.0.0, os.arch=amd64, java.runtime.version=1.8.0_191-b12, source=flush, os.version=4.4.0-112-generic, timestamp=1545737234722}]:[attributes={Lucene50StoredFieldsFormat.mode=BEST_SPEED}]) Uninverting(_2(8.0.0):C1:[diagnostics={os=Linux, java.vendor=Oracle Corporation, java.version=1.8.0_191, java.vm.version=25.191-b12, lucene.version=8.0.0, os.arch=amd64, java.runtime.version=1.8.0_191-b12, source=flush, os.version=4.4.0-112-generic, timestamp=1545737236114}]:[attributes={Lucene50StoredFieldsFormat.mode=BEST_SPEED}]) Uninverting(_3(8.0.0):C5:[diagnostics={os=Linux, java.vendor=Oracle Corporation, java.version=1.8.0_191, java.vm.version=25.191-b12, lucene.version=8.0.0, os.arch=amd64, java.runtime.version=1.8.0_191-b12, source=flush, os.version=4.4.0-112-generic, timestamp=1545737243711}]:[attributes={Lucene50StoredFieldsFormat.mode=BEST_SPEED}])))}
   [junit4]   2> 84979 INFO  (commitScheduler-13-thread-2) [    ] o.a.s.u.DirectUpdateHandler2 start commit{,optimize=false,openSearcher=false,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
   [junit4]   2> 84979 INFO  (commitScheduler-13-thread-2) [    ] o.a.s.u.SolrIndexWriter Calling setCommitData with IW:org.apache.solr.update.SolrIndexWriter@bbe468d commitCommandVersion:0
   [junit4]   2> 84981 INFO  (commitScheduler-13-thread-2) [    ] o.a.s.s.SolrIndexSearcher Opening [Searcher@414a54b0[collection1] realtime]
   [junit4]   2> 84981 INFO  (commitScheduler-13-thread-2) [    ] o.a.s.u.DirectUpdateHandler2 end_commit_flush
   [junit4]   2> 90699 INFO  (TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeRapidAdds-seed#[709ECA08866D55E0]) [    ] o.a.s.SolrTestCaseJ4 ###Ending testSoftAndHardCommitMaxTimeRapidAdds
   [junit4]   2> 90717 INFO  (TEST-SoftAutoCommitTest.testHardCommitWithinAndSoftCommitMaxTimeRapidAdds-seed#[709ECA08866D55E0]) [    ] o.a.s.SolrTestCaseJ4 ###Starting testHardCommitWithinAndSoftCommitMaxTimeRapidAdds
   [junit4]   2> 95885 INFO  (TEST-SoftAutoCommitTest.testHardCommitWithinAndSoftCommitMaxTimeRapidAdds-seed#[709ECA08866D55E0]) [    ] o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=null path=null params={}{add=[5000 (1620822987799265280)]} 0 166
   [junit4]   2> 95887 INFO  (TEST-SoftAutoCommitTest.testHardCommitWithinAndSoftCommitMaxTimeRapidAdds-seed#[709ECA08866D55E0]) [    ] o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=null path=null params={}{add=[5001 (1620822987974377472)]} 0 1
   [junit4]   2> 95903 INFO  (TEST-SoftAutoCommitTest.testHardCommitWithinAndSoftCommitMaxTimeRapidAdds-seed#[709ECA08866D55E0]) [    ] o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=null path=null params={}{add=[5002 (1620822987976474624)]} 0 14
   [junit4]   2> 95923 INFO  (TEST-SoftAutoCommitTest.testHardCommitWithinAndSoftCommitMaxTimeRapidAdds-seed#[709ECA08866D55E0]) [    ] o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=null path=null params={}{add=[5003 (1620822988012126208)]} 0 1
   [junit4]   2> 95924 INFO  (TEST-SoftAutoCommitTest.testHardCommitWithinAndSoftCommitMaxTimeRapidAdds-seed#[709ECA08866D55E0]) [    ] o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=null path=null params={}{add=[5004 (1620822988014223360)]} 0 0
   [junit4]   2> 95925 INFO  (TEST-SoftAutoCommitTest.testHardCommitWithinAndSoftCommitMaxTimeRapidAdds-seed#[709ECA08866D55E0]) [    ] o.a.s.u.SoftAutoCommitTest maxTimeMillis: 28074656048514150ns - 28074655842143744ns == 206ms
   [junit4]   2> 95958 INFO  (TEST-SoftAutoCommitTest.testHardCommitWithinAndSoftCommitMaxTimeRapidAdds-seed#[709ECA08866D55E0]) [    ] o.a.s.u.SoftAutoCommitTest maxExpectedSoft=1
   [junit4]   2> 95974 INFO  (TEST-SoftAutoCommitTest.testHardCommitWithinAndSoftCommitMaxTimeRapidAdds-seed#[709ECA08866D55E0]) [    ] o.a.s.u.SoftAutoCommitTest maxExpectedHard=1
   [junit4]   2> 96229 INFO  (commitScheduler-14-thread-4) [    ] o.a.s.u.DirectUpdateHandler2 start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=true,prepareCommit=false}
   [junit4]   2> 96377 INFO  (commitScheduler-14-thread-4) [    ] o.a.s.s.SolrIndexSearcher Opening [Searcher@21d942c9[collection1] main]
   [junit4]   2> 96395 INFO  (commitScheduler-14-thread-4) [    ] o.a.s.u.DirectUpdateHandler2 end_commit_flush
   [junit4]   2> 96399 INFO  (searcherExecutor-10-thread-1) [    ] o.a.s.c.SolrCore [collection1] Registered new searcher Searcher@21d942c9[collection1] main{ExitableDirectoryReader(UninvertingDirectoryReader(Uninverting(_1(8.0.0):C1:[diagnostics={os=Linux, java.vendor=Oracle Corporation, java.version=1.8.0_191, java.vm.version=25.191-b12, lucene.version=8.0.0, os.arch=amd64, java.runtime.version=1.8.0_191-b12, source=flush, os.version=4.4.0-112-generic, timestamp=1545737234722}]:[attributes={Lucene50StoredFieldsFormat.mode=BEST_SPEED}]) Uninverting(_2(8.0.0):C1:[diagnostics={os=Linux, java.vendor=Oracle Corporation, java.version=1.8.0_191, java.vm.version=25.191-b12, lucene.version=8.0.0, os.arch=amd64, java.runtime.version=1.8.0_191-b12, source=flush, os.version=4.4.0-112-generic, timestamp=1545737236114}]:[attributes={Lucene50StoredFieldsFormat.mode=BEST_SPEED}]) Uninverting(_4(8.0.0):C5:[diagnostics={os=Linux, java.vendor=Oracle Corporation, java.version=1.8.0_191, java.vm.version=25.191-b12, lucene.version=8.0.0, os.arch=amd64, java.runtime.version=1.8.0_191-b12, source=flush, os.version=4.4.0-112-generic, timestamp=1545737255488}]:[attributes={Lucene50StoredFieldsFormat.mode=BEST_SPEED}])))}
   [junit4]   2> 97054 INFO  (commitScheduler-13-thread-3) [    ] o.a.s.u.DirectUpdateHandler2 start commit{,optimize=false,openSearcher=false,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
   [junit4]   2> 97054 INFO  (commitScheduler-13-thread-3) [    ] o.a.s.u.SolrIndexWriter Calling setCommitData with IW:org.apache.solr.update.SolrIndexWriter@bbe468d commitCommandVersion:0
   [junit4]   2> 97107 INFO  (commitScheduler-13-thread-3) [    ] o.a.s.s.SolrIndexSearcher Opening [Searcher@480f2d25[collection1] realtime]
   [junit4]   2> 97127 INFO  (commitScheduler-13-thread-3) [    ] o.a.s.u.DirectUpdateHandler2 end_commit_flush
   [junit4]   2> 102509 INFO  (TEST-SoftAutoCommitTest.testHardCommitWithinAndSoftCommitMaxTimeRapidAdds-seed#[709ECA08866D55E0]) [    ] o.a.s.SolrTestCaseJ4 ###Ending testHardCommitWithinAndSoftCommitMaxTimeRapidAdds
   [junit4]   2> 102662 INFO  (TEST-SoftAutoCommitTest.testSoftCommitWithinAndHardCommitMaxTimeRapidAdds-seed#[709ECA08866D55E0]) [    ] o.a.s.SolrTestCaseJ4 ###Starting testSoftCommitWithinAndHardCommitMaxTimeRapidAdds
   [junit4]   2> 107699 INFO  (TEST-SoftAutoCommitTest.testSoftCommitWithinAndHardCommitMaxTimeRapidAdds-seed#[709ECA08866D55E0]) [    ] o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=null path=null params={}{add=[5000 (1620823000323457024)]} 0 36
   [junit4]   2> 107737 INFO  (TEST-SoftAutoCommitTest.testSoftCommitWithinAndHardCommitMaxTimeRapidAdds-seed#[709ECA08866D55E0]) [    ] o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=null path=null params={}{add=[5001 (1620823000362254336)]} 0 37
   [junit4]   2> 107790 INFO  (TEST-SoftAutoCommitTest.testSoftCommitWithinAndHardCommitMaxTimeRapidAdds-seed#[709ECA08866D55E0]) [    ] o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=null path=null params={}{add=[5002 (1620823000455577600)]} 0 1
   [junit4]   2> 107842 INFO  (TEST-SoftAutoCommitTest.testSoftCommitWithinAndHardCommitMaxTimeRapidAdds-seed#[709ECA08866D55E0]) [    ] o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=null path=null params={}{add=[5003 (1620823000510103552)]} 0 50
   [junit4]   2> 107843 INFO  (TEST-SoftAutoCommitTest.testSoftCommitWithinAndHardCommitMaxTimeRapidAdds-seed#[709ECA08866D55E0]) [    ] o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=null path=null params={}{add=[5004 (1620823000512200704)]} 0 0
   [junit4]   2> 107844 INFO  (TEST-SoftAutoCommitTest.testSoftCommitWithinAndHardCommitMaxTimeRapidAdds-seed#[709ECA08866D55E0]) [    ] o.a.s.u.SoftAutoCommitTest maxTimeMillis: 28074667967595766ns - 28074667785824416ns == 181ms
   [junit4]   2> 107844 INFO  (TEST-SoftAutoCommitTest.testSoftCommitWithinAndHardCommitMaxTimeRapidAdds-seed#[709ECA08866D55E0]) [    ] o.a.s.u.SoftAutoCommitTest maxExpectedSoft=1
   [junit4]   2> 107844 INFO  (TEST-SoftAutoCommitTest.testSoftCommitWithinAndHardCommitMaxTimeRapidAdds-seed#[709ECA08866D55E0]) [    ] o.a.s.u.SoftAutoCommitTest maxExpectedHard=1
   [junit4]   2> 108185 INFO  (commitScheduler-14-thread-5) [    ] o.a.s.u.DirectUpdateHandler2 start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=true,prepareCommit=false}
   [junit4]   2> 108320 INFO  (commitScheduler-14-thread-5) [    ] o.a.s.s.SolrIndexSearcher Opening [Searcher@1b380b81[collection1] main]
   [junit4]   2> 108321 INFO  (commitScheduler-14-thread-5) [    ] o.a.s.u.DirectUpdateHandler2 end_commit_flush
   [junit4]   2> 108335 INFO  (searcherExecutor-10-thread-1) [    ] o.a.s.c.SolrCore [collection1] Registered new searcher Searcher@1b380b81[collection1] main{ExitableDirectoryReader(UninvertingDirectoryReader(Uninverting(_1(8.0.0):C1:[diagnostics={os=Linux, java.vendor=Oracle Corporation, java.version=1.8.0_191, java.vm.version=25.191-b12, lucene.version=8.0.0, os.arch=amd64, java.runtime.version=1.8.0_191-b12, source=flush, os.version=4.4.0-112-generic, timestamp=1545737234722}]:[attributes={Lucene50StoredFieldsFormat.mode=BEST_SPEED}]) Uninverting(_2(8.0.0):C1:[diagnostics={os=Linux, java.vendor=Oracle Corporation, java.version=1.8.0_191, java.vm.version=25.191-b12, lucene.version=8.0.0, os.arch=amd64, java.runtime.version=1.8.0_191-b12, source=flush, os.version=4.4.0-112-generic, timestamp=1545737236114}]:[attributes={Lucene50StoredFieldsFormat.mode=BEST_SPEED}]) Uninverting(_5(8.0.0):C5:[diagnostics={os=Linux, java.vendor=Oracle Corporation, java.version=1.8.0_191, java.vm.version=25.191-b12, lucene.version=8.0.0, os.arch=amd64, java.runtime.version=1.8.0_191-b12, source=flush, os.version=4.4.0-112-generic, timestamp=1545737267470}]:[attributes={Lucene50StoredFieldsFormat.mode=BEST_SPEED}])))}
   [junit4]   2> 108866 INFO  (commitScheduler-13-thread-4) [    ] o.a.s.u.DirectUpdateHandler2 start commit{,optimize=false,openSearcher=false,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
   [junit4]   2> 108866 INFO  (commitScheduler-13-thread-4) [    ] o.a.s.u.SolrIndexWriter Calling setCommitData with IW:org.apache.solr.update.SolrIndexWriter@bbe468d commitCommandVersion:0
   [junit4]   2> 108868 INFO  (commitScheduler-13-thread-4) [    ] o.a.s.s.SolrIndexSearcher Opening [Searcher@25f26658[collection1] realtime]
   [junit4]   2> 108869 INFO  (commitScheduler-13-thread-4) [    ] o.a.s.u.DirectUpdateHandler2 end_commit_flush
   [junit4]   2> 114465 INFO  (TEST-SoftAutoCommitTest.testSoftCommitWithinAndHardCommitMaxTimeRapidAdds-seed#[709ECA08866D55E0]) [    ] o.a.s.SolrTestCaseJ4 ###Ending testSoftCommitWithinAndHardCommitMaxTimeRapidAdds
   [junit4]   2> 114509 INFO  (TEST-SoftAutoCommitTest.testSoftCommitWithinAndHardCommitMaxTimeDelete-seed#[709ECA08866D55E0]) [    ] o.a.s.SolrTestCaseJ4 ###Starting testSoftCommitWithinAndHardCommitMaxTimeDelete
   [junit4]   2> 119569 INFO  (TEST-SoftAutoCommitTest.testSoftCommitWithinAndHardCommitMaxTimeDelete-seed#[709ECA08866D55E0]) [    ] o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=null path=null params={}{add=[529 (1620823012749082624)]} 0 56
   [junit4]   2> 119571 INFO  (TEST-SoftAutoCommitTest.testSoftCommitWithinAndHardCommitMaxTimeDelete-seed#[709ECA08866D55E0]) [    ] o.a.s.u.DirectUpdateHandler2 start commit{_version_=1620823012809900032,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
   [junit4]   2> 119571 INFO  (TEST-SoftAutoCommitTest.testSoftCommitWithinAndHardCommitMaxTimeDelete-seed#[709ECA08866D55E0]) [    ] o.a.s.u.SolrIndexWriter Calling setCommitData with IW:org.apache.solr.update.SolrIndexWriter@bbe468d commitCommandVersion:1620823012809900032
   [junit4]   2> 119680 INFO  (TEST-SoftAutoCommitTest.testSoftCommitWithinAndHardCommitMaxTimeDelete-seed#[709ECA08866D55E0]) [    ] o.a.s.s.SolrIndexSearcher Opening [Searcher@421b59a3[collection1] main]
   [junit4]   2> 119702 INFO  (searcherExecutor-10-thread-1) [    ] o.a.s.c.SolrCore [collection1] Registered new searcher Searcher@421b59a3[collection1] main{ExitableDirectoryReader(UninvertingDirectoryReader(Uninverting(_2(8.0.0):C1:[diagnostics={os=Linux, java.vendor=Oracle Corporation, java.version=1.8.0_191, java.vm.version=25.191-b12, lucene.version=8.0.0, os.arch=amd64, java.runtime.version=1.8.0_191-b12, source=flush, os.version=4.4.0-112-generic, timestamp=1545737236114}]:[attributes={Lucene50StoredFieldsFormat.mode=BEST_SPEED}]) Uninverting(_5(8.0.0):C5:[diagnostics={os=Linux, java.vendor=Oracle Corporation, java.version=1.8.0_191, java.vm.version=25.191-b12, lucene.version=8.0.0, os.arch=amd64, java.runtime.version=1.8.0_191-b12, source=flush, os.version=4.4.0-112-generic, timestamp=1545737267470}]:[attributes={Lucene50StoredFieldsFormat.mode=BEST_SPEED}]) Uninverting(_6(8.0.0):C1:[diagnostics={os=Linux, java.vendor=Oracle Corporation, java.version=1.8.0_191, java.vm.version=25.191-b12, lucene.version=8.0.0, os.arch=amd64, java.runtime.version=1.8.0_191-b12, source=flush, os.version=4.4.0-112-generic, timestamp=1545737278814}]:[attributes={Lucene50StoredFieldsFormat.mode=BEST_SPEED}])))}
   [junit4]   2> 119828 INFO  (TEST-SoftAutoCommitTest.testSoftCommitWithinAndHardCommitMaxTimeDelete-seed#[709ECA08866D55E0]) [    ] o.a.s.u.DirectUpdateHandler2 end_commit_flush
   [junit4]   2> 120437 INFO  (TEST-SoftAutoCommitTest.testSoftCommitWithinAndHardCommitMaxTimeDelete-seed#[709ECA08866D55E0]) [    ] o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=null path=null params={}{commit=} 0 867
   [junit4]   2> 120529 INFO  (TEST-SoftAutoCommitTest.testSoftCommitWithinAndHardCommitMaxTimeDelete-seed#[709ECA08866D55E0]) [    ] o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=null path=null params={}{delete=[529 (-1620823013720064000)]} 0 90
   [junit4]   2> 121060 INFO  (commitScheduler-14-thread-7) [    ] o.a.s.u.DirectUpdateHandler2 start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=true,prepareCommit=false}
   [junit4]   2> 121113 INFO  (commitScheduler-14-thread-7) [    ] o.a.s.s.SolrIndexSearcher Opening [Searcher@68663e5c[collection1] main]
   [junit4]   2> 121114 INFO  (commitScheduler-14-thread-7) [    ] o.a.s.u.DirectUpdateHandler2 end_commit_flush
   [junit4]   2> 121130 INFO  (TEST-SoftAutoCommitTest.testSoftCommitWithinAndHardCommitMaxTimeDelete-seed#[709ECA08866D55E0]) [    ] o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=null path=null params={}{add=[550 (1620823014443581440)]} 0 1
   [junit4]   2> 121295 INFO  (searcherExecutor-10-thread-1) [    ] o.a.s.c.SolrCore [collection1] Registered new searcher Searcher@68663e5c[collection1] main{ExitableDirectoryReader(UninvertingDirectoryReader(Uninverting(_2(8.0.0):C1:[diagnostics={os=Linux, java.vendor=Oracle Corporation, java.version=1.8.0_191, java.vm.version=25.191-b12, lucene.version=8.0.0, os.arch=amd64, java.runtime.version=1.8.0_191-b12, source=flush, os.version=4.4.0-112-generic, timestamp=1545737236114}]:[attributes={Lucene50StoredFieldsFormat.mode=BEST_SPEED}]) Uninverting(_5(8.0.0):C5:[diagnostics={os=Linux, java.vendor=Oracle Corporation, java.version=1.8.0_191, java.vm.version=25.191-b12, lucene.version=8.0.0, os.arch=amd64, java.runtime.version=1.8.0_191-b12, source=flush, os.version=4.4.0-112-generic, timestamp=1545737267470}]:[attributes={Lucene50StoredFieldsFormat.mode=BEST_SPEED}])))}
   [junit4]   2> 121711 INFO  (commitScheduler-13-thread-5) [    ] o.a.s.u.DirectUpdateHandler2 start commit{,optimize=false,openSearcher=false,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
   [junit4]   2> 121711 INFO  (commitScheduler-13-thread-5) [    ] o.a.s.u.SolrIndexWriter Calling setCommitData with IW:org.apache.solr.update.SolrIndexWriter@bbe468d commitCommandVersion:0
   [junit4]   2> 121732 INFO  (commitScheduler-14-thread-7) [    ] o.a.s.u.DirectUpdateHandler2 start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=true,prepareCommit=false}
   [junit4]   2> 121880 INFO  (commitScheduler-14-thread-7) [    ] o.a.s.s.SolrIndexSearcher Opening [Searcher@13727e4b[collection1] main]
   [junit4]   2> 121880 INFO  (commitScheduler-14-thread-7) [    ] o.a.s.u.DirectUpdateHandler2 end_commit_flush
   [junit4]   2> 121904 INFO  (searcherExecutor-10-thread-1) [    ] o.a.s.c.SolrCore [collection1] Registered new searcher Searcher@13727e4b[collection1] main{ExitableDirectoryReader(UninvertingDirectoryReader(Uninverting(_2(8.0.0):C1:[diagnostics={os=Linux, java.vendor=Oracle Corporation, java.version=1.8.0_191, java.vm.version=25.191-b12, lucene.version=8.0.0, os.arch=amd64, java.runtime.version=1.8.0_191-b12, source=flush, os.version=4.4.0-112-generic, timestamp=1545737236114}]:[attributes={Lucene50StoredFieldsFormat.mode=BEST_SPEED}]) Uninverting(_5(8.0.0):C5:[diagnostics={os=Linux, java.vendor=Oracle Corporation, java.version=1.8.0_191, java.vm.version=25.191-b12, lucene.version=8.0.0, os.arch=amd64, java.runtime.version=1.8.0_191-b12, source=flush, os.version=4.4.0-112-generic, timestamp=1545737267470}]:[attributes={Lucene50StoredFieldsFormat.mode=BEST_SPEED}]) Uninverting(_7(8.0.0):C1:[diagnostics={os=Linux, java.vendor=Oracle Corporation, java.version=1.8.0_191, java.vm.version=25.191-b12, lucene.version=8.0.0, os.arch=amd64, java.runtime.version=1.8.0_191-b12, source=flush, os.version=4.4.0-112-generic, timestamp=1545737280919}]:[attributes={Lucene50StoredFieldsFormat.mode=BEST_SPEED}])))}
   [junit4]   2> 122077 INFO  (commitScheduler-13-thread-5) [    ] o.a.s.u.DirectUpdateHandler2 end_commit_flush
   [junit4]   2> 127915 INFO  (TEST-SoftAutoCommitTest.testSoftCommitWithinAndHardCommitMaxTimeDelete-seed#[709ECA08866D55E0]) [    ] o.a.s.SolrTestCaseJ4 ###Ending testSoftCommitWithinAndHardCommitMaxTimeDelete
   [junit4]   2> 128252 INFO  (TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeDelete-seed#[709ECA08866D55E0]) [    ] o.a.s.SolrTestCaseJ4 ###Starting testSoftAndHardCommitMaxTimeDelete
   [junit4]   2> 133295 INFO  (TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeDelete-seed#[709ECA08866D55E0]) [    ] o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=null path=null params={}{add=[529 (1620823027167002624)]} 0 32
   [junit4]   2> 133296 INFO  (TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeDelete-seed#[709ECA08866D55E0]) [    ] o.a.s.u.DirectUpdateHandler2 start commit{_version_=1620823027201605632,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
   [junit4]   2> 133296 INFO  (TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeDelete-seed#[709ECA08866D55E0]) [    ] o.a.s.u.SolrIndexWriter Calling setCommitData with IW:org.apache.solr.update.SolrIndexWriter@bbe468d commitCommandVersion:1620823027201605632
   [junit4]   2> 133370 INFO  (TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeDelete-seed#[709ECA08866D55E0]) [    ] o.a.s.s.SolrIndexSearcher Opening [Searcher@625ddb00[collection1] main]
   [junit4]   2> 133370 INFO  (TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeDelete-seed#[709ECA08866D55E0]) [    ] o.a.s.u.DirectUpdateHandler2 end_commit_flush
   [junit4]   2> 133425 INFO  (searcherExecutor-10-thread-1) [    ] o.a.s.c.SolrCore [collection1] Registered new searcher Searcher@625ddb00[collection1] main{ExitableDirectoryReader(UninvertingDirectoryReader(Uninverting(_2(8.0.0):C1:[diagnostics={os=Linux, java.vendor=Oracle Corporation, java.version=1.8.0_191, java.vm.version=25.191-b12, lucene.version=8.0.0, os.arch=amd64, java.runtime.version=1.8.0_191-b12, source=flush, os.version=4.4.0-112-generic, timestamp=1545737236114}]:[attributes={Lucene50StoredFieldsFormat.mode=BEST_SPEED}]) Uninverting(_5(8.0.0):C5:[diagnostics={os=Linux, java.vendor=Oracle Corporation, java.version=1.8.0_191, java.vm.version=25.191-b12, lucene.version=8.0.0, os.arch=amd64, java.runtime.version=1.8.0_191-b12, source=flush, os.version=4.4.0-112-generic, timestamp=1545737267470}]:[attributes={Lucene50StoredFieldsFormat.mode=BEST_SPEED}]) Uninverting(_7(8.0.0):C1:[diagnostics={os=Linux, java.vendor=Oracle Corporation, java.version=1.8.0_191, java.vm.version=25.191-b12, lucene.version=8.0.0, os.arch=amd64, java.runtime.version=1.8.0_191-b12, source=flush, os.version=4.4.0-112-generic, timestamp=1545737280919}]:[attributes={Lucene50StoredFieldsFormat.mode=BEST_SPEED}]) Uninverting(_8(8.0.0):C1:[diagnostics={os=Linux, java.vendor=Oracle Corporation, java.version=1.8.0_191, java.vm.version=25.191-b12, lucene.version=8.0.0, os.arch=amd64, java.runtime.version=1.8.0_191-b12, source=flush, os.version=4.4.0-112-generic, timestamp=1545737292500}]:[attributes={Lucene50StoredFieldsFormat.mode=BEST_SPEED}])))}
   [junit4]   2> 133441 INFO  (TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeDelete-seed#[709ECA08866D55E0]) [    ] o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=null path=null params={}{commit=} 0 144
   [junit4]   2> 133443 INFO  (TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeDelete-seed#[709ECA08866D55E0]) [    ] o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=null path=null params={}{delete=[529 (-1620823027354697728)]} 0 1
   [junit4]   2> 133955 INFO  (commitScheduler-14-thread-8) [    ] o.a.s.u.DirectUpdateHandler2 start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=true,prepareCommit=false}
   [junit4]   2> 134139 INFO  (commitScheduler-14-thread-8) [    ] o.a.s.s.SolrIndexSearcher Opening [Searcher@6454d100[collection1] main]
   [junit4]   2> 134140 INFO  (commitScheduler-14-thread-8) [    ] o.a.s.u.DirectUpdateHandler2 end_commit_flush
   [junit4]   2> 134151 INFO  (TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeDelete-seed#[709ECA08866D55E0]) [    ] o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=null path=null params={}{add=[550 (1620823028097089536)]} 0 1
   [junit4]   2> 134189 INFO  (searcherExecutor-10-thread-1) [    ] o.a.s.c.SolrCore [collection1] Registered new searcher Searcher@6454d100[collection1] main{ExitableDirectoryReader(UninvertingDirectoryReader(Uninverting(_2(8.0.0):C1:[diagnostics={os=Linux, java.vendor=Oracle Corporation, java.version=1.8.0_191, java.vm.version=25.191-b12, lucene.version=8.0.0, os.arch=amd64, java.runtime.version=1.8.0_191-b12, source=flush, os.version=4.4.0-112-generic, timestamp=1545737236114}]:[attributes={Lucene50StoredFieldsFormat.mode=BEST_SPEED}]) Uninverting(_5(8.0.0):C5:[diagnostics={os=Linux, java.vendor=Oracle Corporation, java.version=1.8.0_191, java.vm.version=25.191-b12, lucene.version=8.0.0, os.arch=amd64, java.runtime.version=1.8.0_191-b12, source=flush, os.version=4.4.0-112-generic, timestamp=1545737267470}]:[attributes={Lucene50StoredFieldsFormat.mode=BEST_SPEED}]) Uninverting(_7(8.0.0):C1:[diagnostics={os=Linux, java.vendor=Oracle Corporation, java.version=1.8.0_191, java.vm.version=25.191-b12, lucene.version=8.0.0, os.arch=amd64, java.runtime.version=1.8.0_191-b12, source=flush, os.version=4.4.0-112-generic, timestamp=1545737280919}]:[attributes={Lucene50StoredFieldsFormat.mode=BEST_SPEED}])))}
   [junit4]   2> 134643 INFO  (commitScheduler-13-thread-6) [    ] o.a.s.u.DirectUpdateHandler2 start commit{,optimize=false,openSearcher=false,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
   [junit4]   2> 134696 INFO  (commitScheduler-13-thread-6) [    ] o.a.s.u.SolrIndexWriter Calling setCommitData with IW:org.apache.solr.update.SolrIndexWriter@bbe468d commitCommandVersion:0
   [junit4]   2> 134670 INFO  (commitScheduler-14-thread-8) [    ] o.a.s.u.DirectUpdateHandler2 start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=true,prepareCommit=false}
   [junit4]   2> 134751 INFO  (commitScheduler-14-thread-8) [    ] o.a.s.s.SolrIndexSearcher Opening [Searcher@192c3e8a[collection1] main]
   [junit4]   2> 134752 INFO  (commitScheduler-14-thread-8) [    ] o.a.s.u.DirectUpdateHandler2 end_commit_flush
   [junit4]   2> 134796 INFO  (searcherExecutor-10-thread-1) [    ] o.a.s.c.SolrCore [collection1] Registered new searcher Searcher@192c3e8a[collection1] main{ExitableDirectoryReader(UninvertingDirectoryReader(Uninverting(_2(8.0.0):C1:[diagnostics={os=Linux, java.vendor=Oracle Corporation, java.version=1.8.0_191, java.vm.version=25.191-b12, lucene.version=8.0.0, os.arch=amd64, java.runtime.version=1.8.0_191-b12, source=flush, os.version=4.4.0-112-generic, timestamp=1545737236114}]:[attributes={Lucene50StoredFieldsFormat.mode=BEST_SPEED}]) Uninverting(_5(8.0.0):C5:[diagnostics={os=Linux, java.vendor=Oracle Corporation, java.version=1.8.0_191, java.vm.version=25.191-b12, lucene.version=8.0.0, os.arch=amd64, java.runtime.version=1.8.0_191-b12, source=flush, os.version=4.4.0-112-generic, timestamp=1545737267470}]:[attributes={Lucene50StoredFieldsFormat.mode=BEST_SPEED}]) Uninverting(_9(8.0.0):C1:[diagnostics={os=Linux, java.vendor=Oracle Corporation, java.version=1.8.0_191, java.vm.version=25.191-b12, lucene.version=8.0.0, os.arch=amd64, java.runtime.version=1.8.0_191-b12, source=flush, os.version=4.4.0-112-generic, timestamp=1545737293901}]:[attributes={Lucene50StoredFieldsFormat.mode=BEST_SPEED}])))}
   [junit4]   2> 134843 INFO  (commitScheduler-13-thread-6) [    ] o.a.s.u.DirectUpdateHandler2 end_commit_flush
   [junit4]   2> 140798 INFO  (TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeDelete-seed#[709ECA08866D55E0]) [    ] o.a.s.SolrTestCaseJ4 ###Ending testSoftAndHardCommitMaxTimeDelete
   [junit4]   2> 140815 INFO  (TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeMixedAdds-seed#[709ECA08866D55E0]) [    ] o.a.s.SolrTestCaseJ4 ###Starting testSoftAndHardCommitMaxTimeMixedAdds
   [junit4]   2> 149291 INFO  (TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeMixedAdds-seed#[709ECA08866D55E0]) [    ] o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=null path=null params={}{add=[529 (1620823043913809920)]} 0 56
   [junit4]   2> 149801 INFO  (commitScheduler-14-thread-9) [    ] o.a.s.u.DirectUpdateHandler2 start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=true,prepareCommit=false}
   [junit4]   2> 150115 INFO  (commitScheduler-14-thread-9) [    ] o.a.s.s.SolrIndexSearcher Opening [Searcher@5581507e[collection1] main]
   [junit4]   2> 150136 INFO  (searcherExecutor-10-thread-1) [    ] o.a.s.c.SolrCore [collection1] Registered new searcher Searcher@5581507e[collection1] main{ExitableDirectoryReader(UninvertingDirectoryReader(Uninverting(_2(8.0.0):C1:[diagnostics={os=Linux, java.vendor=Oracle Corporation, java.version=1.8.0_191, java.vm.version=25.191-b12, lucene.version=8.0.0, os.arch=amd64, java.runtime.version=1.8.0_191-b12, source=flush, os.version=4.4.0-112-generic, timestamp=1545737236114}]:[attributes={Lucene50StoredFieldsFormat.mode=BEST_SPEED}]) Uninverting(_5(8.0.0):C5:[diagnostics={os=Linux, java.vendor=Oracle Corporation, java.version=1.8.0_191, java.vm.version=25.191-b12, lucene.version=8.0.0, os.arch=amd64, java.runtime.version=1.8.0_191-b12, source=flush, os.version=4.4.0-112-generic, timestamp=1545737267470}]:[attributes={Lucene50StoredFieldsFormat.mode=BEST_SPEED}]) Uninverting(_9(8.0.0):C1:[diagnostics={os=Linux, java.vendor=Oracle Corporation, java.version=1.8.0_191, java.vm.version=25.191-b12, lucene.version=8.0.0, os.arch=amd64, java.runtime.version=1.8.0_191-b12, source=flush, os.version=4.4.0-112-generic, timestamp=1545737293901}]:[attributes={Lucene50StoredFieldsFormat.mode=BEST_SPEED}]) Uninverting(_a(8.0.0):C1:[diagnostics={os=Linux, java.vendor=Oracle Corporation, java.version=1.8.0_191, java.vm.version=25.191-b12, lucene.version=8.0.0, os.arch=amd64, java.runtime.version=1.8.0_191-b12, source=flush, os.version=4.4.0-112-generic, timestamp=1545737309279}]:[attributes={Lucene50StoredFieldsFormat.mode=BEST_SPEED}])))}
   [junit4]   2> 150150 INFO  (commitScheduler-14-thread-9) [    ] o.a.s.u.DirectUpdateHandler2 end_commit_flush
   [junit4]   2> 150494 INFO  (commitScheduler-13-thread-7) [    ] o.a.s.u.DirectUpdateHandler2 start commit{,optimize=false,openSearcher=false,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
   [junit4]   2> 150494 INFO  (commitScheduler-13-thread-7) [    ] o.a.s.u.SolrIndexWriter Calling setCommitData with IW:org.apache.solr.update.SolrIndexWriter@bbe468d commitCommandVersion:0
   [junit4]   2> 150581 INFO  (TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeMixedAdds-seed#[709ECA08866D55E0]) [    ] o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=null path=null params={}{add=[530 (1620823045248647168)]} 0 74
   [junit4]   2> 150637 INFO  (commitScheduler-13-thread-7) [    ] o.a.s.s.SolrIndexSearcher Opening [Searcher@7eabad4e[collection1] realtime]
   [junit4]   2> 150818 INFO  (commitScheduler-13-thread-7) [    ] o.a.s.u.DirectUpdateHandler2 end_commit_flush
   [junit4]   2> 151041 INFO  (commitScheduler-14-thread-10) [    ] o.a.s.u.DirectUpdateHandler2 start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=true,prepareCommit=false}
   [junit4]   2> 151187 INFO  (commitScheduler-14-thread-10) [    ] o.a.s.s.SolrIndexSearcher Opening [Searcher@677aac9e[collection1] main]
   [junit4]   2> 151188 INFO  (commitScheduler-14-thread-10) [    ] o.a.s.u.DirectUpdateHandler2 end_commit_flush
   [junit4]   2> 151202 INFO  (searcherExecutor-10-thread-1) [    ] o.a.s.c.SolrCore [collection1] Registered new searcher Searcher@677aac9e[collection1] main{ExitableDirectoryReader(UninvertingDirectoryReader(Uninverting(_5(8.0.0):C5:[diagnostics={os=Linux, java.vendor=Oracle Corporation, java.version=1.8.0_191, java.vm.version=25.191-b12, lucene.version=8.0.0, os.arch=amd64, java.runtime.version=1.8.0_191-b12, source=flush, os.version=4.4.0-112-generic, timestamp=1545737267470}]:[attributes={Lucene50StoredFieldsFormat.mode=BEST_SPEED}]) Uninverting(_9(8.0.0):C1:[diagnostics={os=Linux, java.vendor=Oracle Corporation, java.version=1.8.0_191, java.vm.version=25.191-b12, lucene.version=8.0.0, os.arch=amd64, java.runtime.version=1.8.0_191-b12, source=flush, os.version=4.4.0-112-generic, timestamp=1545737293901}]:[attributes={Lucene50StoredFieldsFormat.mode=BEST_SPEED}]) Uninverting(_a(8.0.0):C1:[diagnostics={os=Linux, java.vendor=Oracle Corporation, java.version=1.8.0_191, java.vm.version=25.191-b12, lucene.version=8.0.0, os.arch=amd64, java.runtime.version=1.8.0_191-b12, source=flush, os.version=4.4.0-112-generic, timestamp=1545737309279}]:[attributes={Lucene50StoredFieldsFormat.mode=BEST_SPEED}]) Uninverting(_b(8.0.0):C1:[diagnostics={os=Linux, java.vendor=Oracle Corporation, java.version=1.8.0_191, java.vm.version=25.191-b12, lucene.version=8.0.0, os.arch=amd64, java.runtime.version=1.8.0_191-b12, source=flush, os.version=4.4.0-112-generic, timestamp=1545737309731}]:[attributes={Lucene50StoredFieldsFormat.mode=BEST_SPEED}])))}
   [junit4]   2> 151811 INFO  (commitScheduler-13-thread-7) [    ] o.a.s.u.DirectUpdateHandler2 start commit{,optimize=false,openSearcher=false,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
   [junit4]   2> 151811 INFO  (commitScheduler-13-thread-7) [    ] o.a.s.u.SolrIndexWriter Calling setCommitData with IW:org.apache.solr.update.SolrIndexWriter@bbe468d commitCommandVersion:0
   [junit4]   2> 151813 INFO  (commitScheduler-13-thread-7) [    ] o.a.s.s.SolrIndexSearcher Opening [Searcher@4ebbf6ed[collection1] realtime]
   [junit4]   2> 151831 INFO  (commitScheduler-13-thread-7) [    ] o.a.s.u.DirectUpdateHandler2 end_commit_flush
   [junit4]   2> 152820 INFO  (TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeMixedAdds-seed#[709ECA08866D55E0]) [    ] o.a.s.SolrTestCaseJ4 ###Ending testSoftAndHardCommitMaxTimeMixedAdds
   [junit4]   2> 152829 INFO  (TEST-SoftAutoCommitTest.testHardCommitWithinAndSoftCommitMaxTimeDelete-seed#[709ECA08866D55E0]) [    ] o.a.s.SolrTestCaseJ4 ###Starting testHardCommitWithinAndSoftCommitMaxTimeDelete
   [junit4]   2> 157876 INFO  (TEST-SoftAutoCommitTest.testHardCommitWithinAndSoftCommitMaxTimeDelete-seed#[709ECA08866D55E0]) [    ] o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=null path=null params={}{add=[529 (1620823052936806400)]} 0 36
   [junit4]   2> 157877 INFO  (TEST-SoftAutoCommitTest.testHardCommitWithinAndSoftCommitMaxTimeDelete-seed#[709ECA08866D55E0]) [    ] o.a.s.u.DirectUpdateHandler2 start commit{_version_=1620823052976652288,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
   [junit4]   2> 157877 INFO  (TEST-SoftAutoCommitTest.testHardCommitWithinAndSoftCommitMaxTimeDelete-seed#[709ECA08866D55E0]) [    ] o.a.s.u.SolrIndexWriter Calling setCommitData with IW:org.apache.solr.update.SolrIndexWriter@bbe468d commitCommandVersion:1620823052976652288
   [junit4]   2> 158058 INFO  (TEST-SoftAutoCommitTest.testHardCommitWithinAndSoftCommitMaxTimeDelete-seed#[709ECA08866D55E0]) [    ] o.a.s.s.SolrIndexSearcher Opening [Searcher@62405fcf[collection1] main]
   [junit4]   2> 158065 INFO  (searcherExecutor-10-thread-1) [    ] o.a.s.c.SolrCore [collection1] Registered new searcher Searcher@62405fcf[collection1] main{ExitableDirectoryReader(UninvertingDirectoryReader(Uninverting(_5(8.0.0):C5:[diagnostics={os=Linux, java.vendor=Oracle Corporation, java.version=1.8.0_191, java.vm.version=25.191-b12, lucene.version=8.0.0, os.arch=amd64, java.runtime.version=1.8.0_191-b12, source=flush, os.version=4.4.0-112-generic, timestamp=1545737267470}]:[attributes={Lucene50StoredFieldsFormat.mode=BEST_SPEED}]) Uninverting(_9(8.0.0):C1:[diagnostics={os=Linux, java.vendor=Oracle Corporation, java.version=1.8.0_191, java.vm.version=25.191-b12, lucene.version=8.0.0, os.arch=amd64, java.runtime.version=1.8.0_191-b12, source=flush, os.version=4.4.0-112-generic, timestamp=1545737293901}]:[attributes={Lucene50StoredFieldsFormat.mode=BEST_SPEED}]) Uninverting(_b(8.0.0):C1:[diagnostics={os=Linux, java.vendor=Oracle Corporation, java.version=1.8.0_191, java.vm.version=25.191-b12, lucene.version=8.0.0, os.arch=amd64, java.runtime.version=1.8.0_191-b12, source=flush, os.version=4.4.0-112-generic, timestamp=1545737309731}]:[attributes={Lucene50StoredFieldsFormat.mode=BEST_SPEED}]) Uninverting(_c(8.0.0):C1:[diagnostics={os=Linux, java.vendor=Oracle Corporation, java.version=1.8.0_191, java.vm.version=25.191-b12, lucene.version=8.0.0, os.arch=amd64, java.runtime.version=1.8.0_191-b12, source=flush, os.version=4.4.0-112-generic, timestamp=1545737317136}]:[attributes={Lucene50StoredFieldsFormat.mode=BEST_SPEED}])))}
   [junit4]   2> 158061 INFO  (TEST-SoftAutoCommitTest.testHardCommitWithinAndSoftCommitMaxTimeDelete-seed#[709ECA08866D55E0]) [    ] o.a.s.u.DirectUpdateHandler2 end_commit_flush
   [junit4]   2> 158188 INFO  (TEST-SoftAutoCommitTest.testHardCommitWithinAndSoftCommitMaxTimeDelete-seed#[709ECA08866D55E0]) [    ] o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=null path=null params={}{commit=} 0 310
   [junit4]   2> 158371 INFO  (TEST-SoftAutoCommitTest.testHardCommitWithinAndSoftCommitMaxTimeDelete-seed#[709ECA08866D55E0]) [    ] o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=null path=null params={}{delete=[529 (-1620823053305905152)]} 0 180
   [junit4]   2> 158917 INFO  (commitScheduler-14-thread-11) [    ] o.a.s.u.DirectUpdateHandler2 start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=true,prepareCommit=false}
   [junit4]   2> 158955 INFO  (commitScheduler-14-thread-11) [    ] o.a.s.s.SolrIndexSearcher Opening [Searcher@6d5eb29a[collection1] main]
   [junit4]   2> 158974 INFO  (commitScheduler-14-thread-11) [    ] o.a.s.u.DirectUpdateHandler2 end_commit_flush
   [junit4]   2> 158981 INFO  (searcherExecutor-10-thread-1) [    ] o.a.s.c.SolrCore [collection1] Registered new searcher Searcher@6d5eb29a[collection1] main{ExitableDirectoryReader(UninvertingDirectoryReader(Uninverting(_5(8.0.0):C5:[diagnostics={os=Linux, java.vendor=Oracle Corporation, java.version=1.8.0_191, java.vm.version=25.191-b12, lucene.version=8.0.0, os.arch=amd64, java.runtime.version=1.8.0_191-b12, source=flush, os.version=4.4.0-112-generic, timestamp=1545737267470}]:[attributes={Lucene50StoredFieldsFormat.mode=BEST_SPEED}]) Uninverting(_9(8.0.0):C1:[diagnostics={os=Linux, java.vendor=Oracle Corporation, java.version=1.8.0_191, java.vm.version=25.191-b12, lucene.version=8.0.0, os.arch=amd64, java.runtime.version=1.8.0_191-b12, source=flush, os.version=4.4.0-112-generic, timestamp=1545737293901}]:[attributes={Lucene50StoredFieldsFormat.mode=BEST_SPEED}]) Uninverting(_b(8.0.0):C1:[diagnostics={os=Linux, java.vendor=Oracle Corporation, java.version=1.8.0_191, java.vm.version=25.191-b12, lucene.version=8.0.0, os.arch=amd64, java.runtime.version=1.8.0_191-b12, source=flush, os.version=4.4.0-112-generic, timestamp=1545737309731}]:[attributes={Lucene50StoredFieldsFormat.mode=BEST_SPEED}])))}
   [junit4]   2> 159266 INFO  (TEST-SoftAutoCommitTest.testHardCommitWithinAndSoftCommitMaxTimeDelete-seed#[709ECA08866D55E0]) [    ] o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=null path=null params={}{add=[550 (1620823054221312000)]} 0 202
   [junit4]   2> 159593 INFO  (commitScheduler-13-thread-8) [    ] o.a.s.u.DirectUpdateHandler2 start commit{,optimize=false,openSearcher=false,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
   [junit4]   2> 159593 INFO  (commitScheduler-13-thread-8) [    ] o.a.s.u.SolrIndexWriter Calling setCommitData with IW:org.apache.solr.update.SolrIndexWriter@bbe468d commitCommandVersion:0
   [junit4]   2> 159594 INFO  (commitScheduler-14-thread-12) [    ] o.a.s.u.DirectUpdateHandler2 start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=true,prepareCommit=false}
   [junit4]   2> 159649 INFO  (commitScheduler-14-thread-12) [    ] o.a.s.s.SolrIndexSearcher Opening [Searcher@7d35213f[collection1] main]
   [junit4]   2> 159649 INFO  (commitScheduler-14-thread-12) [    ] o.a.s.u.DirectUpdateHandler2 end_commit_flush
   [junit4]   2> 159650 INFO  (commitScheduler-13-thread-8) [    ] o.a.s.u.DirectUpdateHandler2 end_commit_flush
   [junit4]   2> 159711 INFO  (searcherExecutor-10-thread-1) [    ] o.a.s.c.SolrCore [collection1] Registered new searcher Searcher@7d35213f[collection1] main{ExitableDirectoryReader(UninvertingDirectoryReader(Uninverting(_5(8.0.0):C5:[diagnostics={os=Linux, java.vendor=Oracle Corporation, java.version=1.8.0_191, java.vm.version=25.191-b12, lucene.version=8.0.0, os.arch=amd64, java.runtime.version=1.8.0_191-b12, source=flush, os.version=4.4.0-112-generic, timestamp=1545737267470}]:[attributes={Lucene50StoredFieldsFormat.mode=BEST_SPEED}]) Uninverting(_b(8.0.0):C1:[diagnostics={os=Linux, java.vendor=Oracle Corporation, java.version=1.8.0_191, java.vm.version=25.191-b12, lucene.version=8.0.0, os.arch=amd64, java.runtime.version=1.8.0_191-b12, source=flush, os.version=4.4.0-112-generic, timestamp=1545737309731}]:[attributes={Lucene50StoredFieldsFormat.mode=BEST_SPEED}]) Uninverting(_d(8.0.0):C1:[diagnostics={os=Linux, java.vendor=Oracle Corporation, java.version=1.8.0_191, java.vm.version=25.191-b12, lucene.version=8.0.0, os.arch=amd64, java.runtime.version=1.8.0_191-b12, source=flush, os.version=4.4.0-112-generic, timestamp=1545737318799}]:[attributes={Lucene50StoredFieldsFormat.mode=BEST_SPEED}])))}
   [junit4]   2> 165721 INFO  (TEST-SoftAutoCommitTest.testHardCommitWithinAndSoftCommitMaxTimeDelete-seed#[709ECA08866D55E0]) [    ] o.a.s.SolrTestCaseJ4 ###Ending testHardCommitWithinAndSoftCommitMaxTimeDelete
   [junit4]   2> 165836 INFO  (TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxDocs-seed#[709ECA08866D55E0]) [    ] o.a.s.SolrTestCaseJ4 ###Starting testSoftAndHardCommitMaxDocs
   [junit4]   2> 173855 INFO  (TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxDocs-seed#[709ECA08866D55E0]) [    ] o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=null path=null params={}{add=[8000 (1620823069726605312)]} 0 3
   [junit4]   2> 173945 INFO  (TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxDocs-seed#[709ECA08866D55E0]) [    ] o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=null path=null params={}{add=[8001 (1620823069806297088)]} 0 17
   [junit4]   2> 173946 INFO  (TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxDocs-seed#[709ECA08866D55E0]) [    ] o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=null path=null params={}{add=[8002 (1620823069826220032)]} 0 0
   [junit4]   2> 173961 INFO  (TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxDocs-seed#[709ECA08866D55E0]) [    ] o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=null path=null params={}{add=[8003 (1620823069840900096)]} 0 13
   [junit4]   2> 173962 INFO  (TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxDocs-seed#[709ECA08866D55E0]) [    ] o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=null path=null params={}{add=[8004 (1620823069842997248)]} 0 0
   [junit4]   2> 173981 INFO  (TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxDocs-seed#[709ECA08866D55E0]) [    ] o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=null path=null params={}{add=[8005 (1620823069844045824)]} 0 17
   [junit4]   2> 173981 INFO  (commitScheduler-14-thread-13) [    ] o.a.s.u.DirectUpdateHandler2 start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=true,prepareCommit=false}
   [junit4]   2> 173982 INFO  (TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxDocs-seed#[709ECA08866D55E0]) [    ] o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=null path=null params={}{add=[8006 (1620823069862920192)]} 0 1
   [junit4]   2> 173997 INFO  (TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxDocs-seed#[709ECA08866D55E0]) [    ] o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=null path=null params={}{add=[8007 (1620823069865017344)]} 0 14
   [junit4]   2> 173997 INFO  (commitScheduler-13-thread-9) [    ] o.a.s.u.DirectUpdateHandler2 start commit{,optimize=false,openSearcher=false,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
   [junit4]   2> 174020 INFO  (commitScheduler-14-thread-13) [    ] o.a.s.s.SolrIndexSearcher Opening [Searcher@1fca2811[collection1] main]
   [junit4]   2> 174033 INFO  (commitScheduler-13-thread-9) [    ] o.a.s.u.SolrIndexWriter Calling setCommitData with IW:org.apache.solr.update.SolrIndexWriter@bbe468d commitCommandVersion:0
   [junit4]   2> 174036 INFO  (commitScheduler-14-thread-13) [    ] o.a.s.u.DirectUpdateHandler2 end_commit_flush
   [junit4]   2> 174079 INFO  (searcherExecutor-10-thread-1) [    ] o.a.s.c.SolrCore [collection1] Registered new searcher Searcher@1fca2811[collection1] main{ExitableDirectoryReader(UninvertingDirectoryReader(Uninverting(_5(8.0.0):C5:[diagnostics={os=Linux, java.vendor=Oracle Corporation, java.version=1.8.0_191, java.vm.version=25.191-b12, lucene.version=8.0.0, os.arch=amd64, java.runtime.version=1.8.0_191-b12, source=flush, os.version=4.4.0-112-generic, timestamp=1545737267470}]:[attributes={Lucene50StoredFieldsFormat.mode=BEST_SPEED}]) Uninverting(_b(8.0.0):C1:[diagnostics={os=Linux, java.vendor=Oracle Corporation, java.version=1.8.0_191, java.vm.version=25.191-b12, lucene.version=8.0.0, os.arch=amd64, java.runtime.version=1.8.0_191-b12, source=flush, os.version=4.4.0-112-generic, timestamp=1545737309731}]:[attributes={Lucene50StoredFieldsFormat.mode=BEST_SPEED}]) Uninverting(_d(8.0.0):C1:[diagnostics={os=Linux, java.vendor=Oracle Corporation, java.version=1.8.0_191, java.vm.version=25.191-b12, lucene.version=8.0.0, os.arch=amd64, java.runtime.version=1.8.0_191-b12, source=flush, os.version=4.4.0-112-generic, timestamp=1545737318799}]:[attributes={Lucene50StoredFieldsFormat.mode=BEST_SPEED}]) Uninverting(_e(8.0.0):C6:[diagnostics={os=Linux, java.vendor=Oracle Corporation, java.version=1.8.0_191, java.vm.version=25.191-b12, lucene.version=8.0.0, os.arch=amd64, java.runtime.version=1.8.0_191-b12, source=flush, os.version=4.4.0-112-generic, timestamp=1545737333186}]:[attributes={Lucene50StoredFieldsFormat.mode=BEST_SPEED}])))}
   [junit4]   2> 174101 INFO  (commitScheduler-13-thread-9) [    ] o.a.s.s.SolrIndexSearcher Opening [Searcher@4c3c81f[collection1] realtime]
   [junit4]   2> 174115 INFO  (commitScheduler-13-thread-9) [    ] o.a.s.u.DirectUpdateHandler2 end_commit_flush
   [junit4]   2> 175091 INFO  (TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxDocs-seed#[709ECA08866D55E0]) [    ] o.a.s.SolrTestCaseJ4 ###Ending testSoftAndHardCommitMaxDocs
   [junit4]   2> 175092 INFO  (SUITE-SoftAutoCommitTest-seed#[709ECA08866D55E0]-worker) [    ] o.a.s.SolrTestCaseJ4 ###deleteCore
   [junit4]   2> 175092 INFO  (SUITE-SoftAutoCommitTest-seed#[709ECA08866D55E0]-worker) [    ] o.a.s.c.CoreContainer Shutting down CoreContainer instance=1500753082
   [junit4]   2> 175143 INFO  (coreCloseExecutor-15-thread-1) [    x:collection1] o.a.s.c.SolrCore [collection1]  CLOSING SolrCore org.apache.solr.core.SolrCore@3e0bb5d9
   [junit4]   2> 175144 INFO  (coreCloseExecutor-15-thread-1) [    x:collection1] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.core.collection1, tag=3e0bb5d9
   [junit4]   2> 175144 INFO  (coreCloseExecutor-15-thread-1) [    x:collection1] o.a.s.m.r.SolrJmxReporter Closing reporter [org.apache.solr.metrics.reporters.SolrJmxReporter@2c3d89ee: rootName = null, domain = solr.core.collection1, service url = null, agent id = null] for registry solr.core.collection1 / com.codahale.metrics.MetricRegistry@4f51329a
   [junit4]   2> 175747 INFO  (SUITE-SoftAutoCommitTest-seed#[709ECA08866D55E0]-worker) [    ] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.node, tag=null
   [junit4]   2> 175747 INFO  (SUITE-SoftAutoCommitTest-seed#[709ECA08866D55E0]-worker) [    ] o.a.s.m.r.SolrJmxReporter Closing reporter [org.apache.solr.metrics.reporters.SolrJmxReporter@83d582c: rootName = null, domain = solr.node, service url = null, agent id = null] for registry solr.node / com.codahale.metrics.MetricRegistry@d243da5
   [junit4]   2> 175765 INFO  (SUITE-SoftAutoCommitTest-seed#[709ECA08866D55E0]-worker) [    ] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.jvm, tag=null
   [junit4]   2> 175766 INFO  (SUITE-SoftAutoCommitTest-seed#[709ECA08866D55E0]-worker) [    ] o.a.s.m.r.SolrJmxReporter Closing reporter [org.apache.solr.metrics.reporters.SolrJmxReporter@27e984f5: rootName = null, domain = solr.jvm, service url = null, agent id = null] for registry solr.jvm / com.codahale.metrics.MetricRegistry@20fbad0c
   [junit4]   2> 175766 INFO  (SUITE-SoftAutoCommitTest-seed#[709ECA08866D55E0]-worker) [    ] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.jetty, tag=null
   [junit4]   2> 175766 INFO  (SUITE-SoftAutoCommitTest-seed#[709ECA08866D55E0]-worker) [    ] o.a.s.m.r.SolrJmxReporter Closing reporter [org.apache.solr.metrics.reporters.SolrJmxReporter@6d81d048: rootName = null, domain = solr.jetty, service url = null, agent id = null] for registry solr.jetty / com.codahale.metrics.MetricRegistry@55deda03
   [junit4]   1> Done close org.apache.solr.common.util.ExecutorUtil$MDCAwareThreadPoolExecutor@33579098[Terminated, pool size = 0, active threads = 0, queued tasks = 0, completed tasks = 1]
   [junit4]   1> Done close org.apache.solr.common.util.ExecutorUtil$MDCAwareThreadPoolExecutor@4c4b1a44[Terminated, pool size = 0, active threads = 0, queued tasks = 0, completed tasks = 1]
   [junit4]   2> NOTE: leaving temporary files on disk at: /home/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-master/solr/build/solr-core/test/J0/temp/solr.update.SoftAutoCommitTest_709ECA08866D55E0-001
   [junit4]   2> NOTE: test params are: codec=Asserting(Lucene80): {multiDefault=PostingsFormat(name=LuceneVarGapFixedInterval), subject=PostingsFormat(name=LuceneVarGapFixedInterval), _root_=PostingsFormat(name=LuceneVarGapDocFreqInterval), id=FST50, text=PostingsFormat(name=LuceneFixedGap)}, docValues:{range_facet_l_dv=DocValuesFormat(name=Lucene70), _version_=DocValuesFormat(name=Lucene70), range_facet_i_dv=DocValuesFormat(name=Direct), intDvoDefault=DocValuesFormat(name=Lucene70), timestamp=DocValuesFormat(name=Direct)}, maxPointsInLeafNode=1696, maxMBSortInHeap=7.146061684467593, sim=Asserting(org.apache.lucene.search.similarities.AssertingSimilarity@795b96e3), locale=ru, timezone=America/Argentina/Rio_Gallegos
   [junit4]   2> NOTE: Linux 4.4.0-112-generic amd64/Oracle Corporation 1.8.0_191 (64-bit)/cpus=4,threads=1,free=181026576,total=307232768
   [junit4]   2> NOTE: All tests run in this JVM: [SoftAutoCommitTest]
   [junit4] Completed [5/838 (1!)] on J0 in 173.27s, 10 tests, 1 failure <<< FAILURES!

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

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

jar-checksums:

resolve:

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

-ivy-fail-disallowed-ivy-version:

ivy-fail:

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

resolve:

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

-ivy-fail-disallowed-ivy-version:

ivy-fail:

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

resolve:

resolve:

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

-ivy-fail-disallowed-ivy-version:

ivy-fail:

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

resolve:

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

-ivy-fail-disallowed-ivy-version:

ivy-fail:

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

resolve:

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

-ivy-fail-disallowed-ivy-version:

ivy-fail:

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

resolve:

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

-ivy-fail-disallowed-ivy-version:

ivy-fail:

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

resolve:

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

-ivy-fail-disallowed-ivy-version:

ivy-fail:

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

resolve:

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

-ivy-fail-disallowed-ivy-version:

ivy-fail:

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

resolve:

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

-ivy-fail-disallowed-ivy-version:

ivy-fail:

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

resolve:

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

-ivy-fail-disallowed-ivy-version:

ivy-fail:

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

resolve:

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

-ivy-fail-disallowed-ivy-version:

ivy-fail:

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

resolve:

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

-ivy-fail-disallowed-ivy-version:

ivy-fail:

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

resolve:

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

-ivy-fail-disallowed-ivy-version:

ivy-fail:

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

resolve:

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

-ivy-fail-disallowed-ivy-version:

ivy-fail:

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

resolve:

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

-ivy-fail-disallowed-ivy-version:

ivy-fail:

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

resolve:

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

-ivy-fail-disallowed-ivy-version:

ivy-fail:

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

resolve:

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

-ivy-fail-disallowed-ivy-version:

ivy-fail:

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

resolve:

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

-ivy-fail-disallowed-ivy-version:

ivy-fail:

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

resolve:

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

-ivy-fail-disallowed-ivy-version:

ivy-fail:

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

resolve:

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

-ivy-fail-disallowed-ivy-version:

ivy-fail:

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

resolve:

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

-ivy-fail-disallowed-ivy-version:

ivy-fail:

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

resolve:

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

-ivy-fail-disallowed-ivy-version:

ivy-fail:

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

resolve:

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

-ivy-fail-disallowed-ivy-version:

ivy-fail:

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

resolve:

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

-ivy-fail-disallowed-ivy-version:

ivy-fail:

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

resolve:

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

-ivy-fail-disallowed-ivy-version:

ivy-fail:

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

resolve:

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

-ivy-fail-disallowed-ivy-version:

ivy-fail:

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

common.resolve:

resolve:

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

-ivy-fail-disallowed-ivy-version:

ivy-fail:

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

resolve:

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

-ivy-fail-disallowed-ivy-version:

ivy-fail:

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

resolve:

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

-ivy-fail-disallowed-ivy-version:

ivy-fail:

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

resolve:

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

-ivy-fail-disallowed-ivy-version:

ivy-fail:

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

resolve:

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

-ivy-fail-disallowed-ivy-version:

ivy-fail:

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

resolve:

jar-checksums:
    [mkdir] Created dir: /home/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-master/lucene/null1811348371
     [copy] Copying 36 files to /home/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-master/lucene/null1811348371
   [delete] Deleting directory /home/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-master/lucene/null1811348371

resolve-example:

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

-ivy-fail-disallowed-ivy-version:

ivy-fail:

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

resolve:

resolve-server:

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

-ivy-fail-disallowed-ivy-version:

ivy-fail:

ivy-fail:

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

resolve:

resolve:

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

-ivy-fail-disallowed-ivy-version:

ivy-fail:

ivy-fail:

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

resolve:

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

-ivy-fail-disallowed-ivy-version:

ivy-fail:

ivy-fail:

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

resolve:

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

-ivy-fail-disallowed-ivy-version:

ivy-fail:

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

resolve:

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

-ivy-fail-disallowed-ivy-version:

ivy-fail:

ivy-fail:

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

resolve:

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

-ivy-fail-disallowed-ivy-version:

ivy-fail:

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

resolve:

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

-ivy-fail-disallowed-ivy-version:

ivy-fail:

ivy-fail:

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

resolve:

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

-ivy-fail-disallowed-ivy-version:

ivy-fail:

ivy-fail:

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

resolve:

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

-ivy-fail-disallowed-ivy-version:

ivy-fail:

ivy-fail:

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

resolve:

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

-ivy-fail-disallowed-ivy-version:

ivy-fail:

ivy-fail:

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

resolve:

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

-ivy-fail-disallowed-ivy-version:

ivy-fail:

ivy-fail:

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

resolve:

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

-ivy-fail-disallowed-ivy-version:

ivy-fail:

ivy-fail:

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

resolve:

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

-ivy-fail-disallowed-ivy-version:

ivy-fail:

ivy-fail:

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

resolve:

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

-ivy-fail-disallowed-ivy-version:

ivy-fail:

ivy-fail:

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

resolve:

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

-ivy-fail-disallowed-ivy-version:

ivy-fail:

ivy-fail:

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

resolve:

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

-ivy-fail-disallowed-ivy-version:

ivy-fail:

ivy-fail:

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

resolve:

jar-checksums:
    [mkdir] Created dir: /home/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-master/solr/null1389913944
     [copy] Copying 256 files to /home/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-master/solr/null1389913944
   [delete] Deleting directory /home/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-master/solr/null1389913944

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

-jenkins-base:

BUILD SUCCESSFUL
Total time: 211 minutes 29 seconds
Archiving artifacts
java.lang.InterruptedException: no matches found within 10000
	at hudson.FilePath$34.hasMatch(FilePath.java:2678)
	at hudson.FilePath$34.invoke(FilePath.java:2557)
	at hudson.FilePath$34.invoke(FilePath.java:2547)
	at hudson.FilePath$FileCallableWrapper.call(FilePath.java:2918)
Also:   hudson.remoting.Channel$CallSiteStackTrace: Remote call to lucene2
		at hudson.remoting.Channel.attachCallSiteStackTrace(Channel.java:1741)
		at hudson.remoting.UserRequest$ExceptionResponse.retrieve(UserRequest.java:357)
		at hudson.remoting.Channel.call(Channel.java:955)
		at hudson.FilePath.act(FilePath.java:1036)
		at hudson.FilePath.act(FilePath.java:1025)
		at hudson.FilePath.validateAntFileMask(FilePath.java:2547)
		at hudson.tasks.ArtifactArchiver.perform(ArtifactArchiver.java:243)
		at hudson.tasks.BuildStepCompatibilityLayer.perform(BuildStepCompatibilityLayer.java:81)
		at hudson.tasks.BuildStepMonitor$1.perform(BuildStepMonitor.java:20)
		at hudson.model.AbstractBuild$AbstractBuildExecution.perform(AbstractBuild.java:744)
		at hudson.model.AbstractBuild$AbstractBuildExecution.performAllBuildSteps(AbstractBuild.java:690)
		at hudson.model.Build$BuildExecution.post2(Build.java:186)
		at hudson.model.AbstractBuild$AbstractBuildExecution.post(AbstractBuild.java:635)
		at hudson.model.Run.execute(Run.java:1819)
		at hudson.model.FreeStyleBuild.run(FreeStyleBuild.java:43)
		at hudson.model.ResourceController.execute(ResourceController.java:97)
		at hudson.model.Executor.run(Executor.java:429)
Caused: hudson.FilePath$TunneledInterruptedException
	at hudson.FilePath$FileCallableWrapper.call(FilePath.java:2920)
	at hudson.remoting.UserRequest.perform(UserRequest.java:212)
	at hudson.remoting.UserRequest.perform(UserRequest.java:54)
	at hudson.remoting.Request$2.run(Request.java:369)
	at hudson.remoting.InterceptingExecutorService$1.call(InterceptingExecutorService.java:72)
	at java.util.concurrent.FutureTask.run(FutureTask.java:266)
	at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142)
	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
	at java.lang.Thread.run(Thread.java:748)
Caused: java.lang.InterruptedException: java.lang.InterruptedException: no matches found within 10000
	at hudson.FilePath.act(FilePath.java:1038)
	at hudson.FilePath.act(FilePath.java:1025)
	at hudson.FilePath.validateAntFileMask(FilePath.java:2547)
	at hudson.tasks.ArtifactArchiver.perform(ArtifactArchiver.java:243)
	at hudson.tasks.BuildStepCompatibilityLayer.perform(BuildStepCompatibilityLayer.java:81)
	at hudson.tasks.BuildStepMonitor$1.perform(BuildStepMonitor.java:20)
	at hudson.model.AbstractBuild$AbstractBuildExecution.perform(AbstractBuild.java:744)
	at hudson.model.AbstractBuild$AbstractBuildExecution.performAllBuildSteps(AbstractBuild.java:690)
	at hudson.model.Build$BuildExecution.post2(Build.java:186)
	at hudson.model.AbstractBuild$AbstractBuildExecution.post(AbstractBuild.java:635)
	at hudson.model.Run.execute(Run.java:1819)
	at hudson.model.FreeStyleBuild.run(FreeStyleBuild.java:43)
	at hudson.model.ResourceController.execute(ResourceController.java:97)
	at hudson.model.Executor.run(Executor.java:429)
No artifacts found that match the file pattern "**/*.events,heapdumps/**,**/hs_err_pid*". Configuration error?
Recording test results
Build step 'Publish JUnit test result report' changed build result to UNSTABLE
Email was triggered for: Unstable (Test Failures)
Sending email for trigger: Unstable (Test Failures)

[JENKINS] Lucene-Solr-Tests-master - Build # 3090 - Still Unstable

Posted by Apache Jenkins Server <je...@builds.apache.org>.

Build: https://builds.apache.org/job/Lucene-Solr-Tests-master/3090/

1 tests failed.
FAILED:  org.apache.solr.cloud.TestPullReplicaErrorHandling.testPullReplicaDisconnectsFromZooKeeper

Error Message:
Didn't get expected doc count. Expected: 10, Found: 0

Stack Trace:
java.lang.AssertionError: Didn't get expected doc count. Expected: 10, Found: 0
	at __randomizedtesting.SeedInfo.seed([5C4F9DE5439B7443:4306BD6666717B23]:0)
	at org.junit.Assert.fail(Assert.java:88)
	at org.apache.solr.cloud.TestPullReplicaErrorHandling.assertNumDocs(TestPullReplicaErrorHandling.java:253)
	at org.apache.solr.cloud.TestPullReplicaErrorHandling.assertNumDocs(TestPullReplicaErrorHandling.java:258)
	at org.apache.solr.cloud.TestPullReplicaErrorHandling.testPullReplicaDisconnectsFromZooKeeper(TestPullReplicaErrorHandling.java:229)
	at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
	at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
	at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
	at java.lang.reflect.Method.invoke(Method.java:498)
	at com.carrotsearch.randomizedtesting.RandomizedRunner.invoke(RandomizedRunner.java:1750)
	at com.carrotsearch.randomizedtesting.RandomizedRunner$8.evaluate(RandomizedRunner.java:938)
	at com.carrotsearch.randomizedtesting.RandomizedRunner$9.evaluate(RandomizedRunner.java:974)
	at com.carrotsearch.randomizedtesting.RandomizedRunner$10.evaluate(RandomizedRunner.java:988)
	at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:57)
	at org.apache.lucene.util.TestRuleSetupTeardownChained$1.evaluate(TestRuleSetupTeardownChained.java:49)
	at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:45)
	at org.apache.lucene.util.TestRuleThreadAndTestName$1.evaluate(TestRuleThreadAndTestName.java:48)
	at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:64)
	at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:47)
	at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
	at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:368)
	at com.carrotsearch.randomizedtesting.ThreadLeakControl.forkTimeoutingTask(ThreadLeakControl.java:817)
	at com.carrotsearch.randomizedtesting.ThreadLeakControl$3.evaluate(ThreadLeakControl.java:468)
	at com.carrotsearch.randomizedtesting.RandomizedRunner.runSingleTest(RandomizedRunner.java:947)
	at com.carrotsearch.randomizedtesting.RandomizedRunner$5.evaluate(RandomizedRunner.java:832)
	at com.carrotsearch.randomizedtesting.RandomizedRunner$6.evaluate(RandomizedRunner.java:883)
	at com.carrotsearch.randomizedtesting.RandomizedRunner$7.evaluate(RandomizedRunner.java:894)
	at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
	at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:57)
	at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:45)
	at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
	at org.apache.lucene.util.TestRuleStoreClassName$1.evaluate(TestRuleStoreClassName.java:41)
	at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:40)
	at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:40)
	at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
	at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
	at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
	at org.apache.lucene.util.TestRuleAssertionsRequired$1.evaluate(TestRuleAssertionsRequired.java:53)
	at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:47)
	at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:64)
	at org.apache.lucene.util.TestRuleIgnoreTestSuites$1.evaluate(TestRuleIgnoreTestSuites.java:54)
	at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
	at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:368)
	at java.lang.Thread.run(Thread.java:748)




Build Log:
[...truncated 14390 lines...]
   [junit4] Suite: org.apache.solr.cloud.TestPullReplicaErrorHandling
   [junit4]   2> Creating dataDir: /home/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-master/solr/build/solr-core/test/J0/temp/solr.cloud.TestPullReplicaErrorHandling_5C4F9DE5439B7443-001/init-core-data-001
   [junit4]   2> 3324891 WARN  (SUITE-TestPullReplicaErrorHandling-seed#[5C4F9DE5439B7443]-worker) [    ] o.a.s.SolrTestCaseJ4 startTrackingSearchers: numOpens=34 numCloses=34
   [junit4]   2> 3324891 INFO  (SUITE-TestPullReplicaErrorHandling-seed#[5C4F9DE5439B7443]-worker) [    ] o.a.s.SolrTestCaseJ4 Using TrieFields (NUMERIC_POINTS_SYSPROP=false) w/NUMERIC_DOCVALUES_SYSPROP=true
   [junit4]   2> 3324893 INFO  (SUITE-TestPullReplicaErrorHandling-seed#[5C4F9DE5439B7443]-worker) [    ] o.a.s.SolrTestCaseJ4 Randomized ssl (false) and clientAuth (false) via: @org.apache.solr.SolrTestCaseJ4$SuppressSSL(bugUrl=https://issues.apache.org/jira/browse/SOLR-5776)
   [junit4]   2> 3324893 INFO  (SUITE-TestPullReplicaErrorHandling-seed#[5C4F9DE5439B7443]-worker) [    ] o.a.s.SolrTestCaseJ4 SecureRandom sanity checks: test.solr.allowed.securerandom=null & java.security.egd=file:/dev/./urandom
   [junit4]   2> 3324893 INFO  (SUITE-TestPullReplicaErrorHandling-seed#[5C4F9DE5439B7443]-worker) [    ] o.a.s.c.MiniSolrCloudCluster Starting cluster of 4 servers in /home/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-master/solr/build/solr-core/test/J0/temp/solr.cloud.TestPullReplicaErrorHandling_5C4F9DE5439B7443-001/tempDir-001
   [junit4]   2> 3324893 INFO  (SUITE-TestPullReplicaErrorHandling-seed#[5C4F9DE5439B7443]-worker) [    ] o.a.s.c.ZkTestServer STARTING ZK TEST SERVER
   [junit4]   2> 3324894 INFO  (ZkTestServer Run Thread) [    ] o.a.s.c.ZkTestServer client port:0.0.0.0/0.0.0.0:0
   [junit4]   2> 3324894 INFO  (ZkTestServer Run Thread) [    ] o.a.s.c.ZkTestServer Starting server
   [junit4]   2> 3324994 INFO  (SUITE-TestPullReplicaErrorHandling-seed#[5C4F9DE5439B7443]-worker) [    ] o.a.s.c.ZkTestServer start zk server on port:37948
   [junit4]   2> 3324994 INFO  (SUITE-TestPullReplicaErrorHandling-seed#[5C4F9DE5439B7443]-worker) [    ] o.a.s.c.ZkTestServer parse host and port list: 127.0.0.1:37948
   [junit4]   2> 3324994 INFO  (SUITE-TestPullReplicaErrorHandling-seed#[5C4F9DE5439B7443]-worker) [    ] o.a.s.c.ZkTestServer connecting to 127.0.0.1 37948
   [junit4]   2> 3324997 INFO  (zkConnectionManagerCallback-9163-thread-1) [    ] o.a.s.c.c.ConnectionManager zkClient has connected
   [junit4]   2> 3324999 INFO  (zkConnectionManagerCallback-9165-thread-1) [    ] o.a.s.c.c.ConnectionManager zkClient has connected
   [junit4]   2> 3325000 INFO  (zkConnectionManagerCallback-9167-thread-1) [    ] o.a.s.c.c.ConnectionManager zkClient has connected
   [junit4]   2> 3325001 WARN  (jetty-launcher-9168-thread-1) [    ] o.e.j.s.AbstractConnector Ignoring deprecated socket close linger time
   [junit4]   2> 3325002 WARN  (jetty-launcher-9168-thread-4) [    ] o.e.j.s.AbstractConnector Ignoring deprecated socket close linger time
   [junit4]   2> 3325002 WARN  (jetty-launcher-9168-thread-3) [    ] o.e.j.s.AbstractConnector Ignoring deprecated socket close linger time
   [junit4]   2> 3325002 INFO  (jetty-launcher-9168-thread-1) [    ] o.a.s.c.s.e.JettySolrRunner Start Jetty (original configured port=0)
   [junit4]   2> 3325002 INFO  (jetty-launcher-9168-thread-1) [    ] o.a.s.c.s.e.JettySolrRunner Trying to start Jetty on port 0 try number 1 ...
   [junit4]   2> 3325002 INFO  (jetty-launcher-9168-thread-4) [    ] o.a.s.c.s.e.JettySolrRunner Start Jetty (original configured port=0)
   [junit4]   2> 3325002 INFO  (jetty-launcher-9168-thread-3) [    ] o.a.s.c.s.e.JettySolrRunner Start Jetty (original configured port=0)
   [junit4]   2> 3325002 INFO  (jetty-launcher-9168-thread-4) [    ] o.a.s.c.s.e.JettySolrRunner Trying to start Jetty on port 0 try number 1 ...
   [junit4]   2> 3325002 INFO  (jetty-launcher-9168-thread-3) [    ] o.a.s.c.s.e.JettySolrRunner Trying to start Jetty on port 0 try number 1 ...
   [junit4]   2> 3325002 INFO  (jetty-launcher-9168-thread-1) [    ] o.e.j.s.Server jetty-9.4.14.v20181114; built: 2018-11-14T21:20:31.478Z; git: c4550056e785fb5665914545889f21dc136ad9e6; jvm 1.8.0_191-b12
   [junit4]   2> 3325002 INFO  (jetty-launcher-9168-thread-4) [    ] o.e.j.s.Server jetty-9.4.14.v20181114; built: 2018-11-14T21:20:31.478Z; git: c4550056e785fb5665914545889f21dc136ad9e6; jvm 1.8.0_191-b12
   [junit4]   2> 3325002 INFO  (jetty-launcher-9168-thread-3) [    ] o.e.j.s.Server jetty-9.4.14.v20181114; built: 2018-11-14T21:20:31.478Z; git: c4550056e785fb5665914545889f21dc136ad9e6; jvm 1.8.0_191-b12
   [junit4]   2> 3325002 WARN  (jetty-launcher-9168-thread-2) [    ] o.e.j.s.AbstractConnector Ignoring deprecated socket close linger time
   [junit4]   2> 3325002 INFO  (jetty-launcher-9168-thread-2) [    ] o.a.s.c.s.e.JettySolrRunner Start Jetty (original configured port=0)
   [junit4]   2> 3325002 INFO  (jetty-launcher-9168-thread-2) [    ] o.a.s.c.s.e.JettySolrRunner Trying to start Jetty on port 0 try number 1 ...
   [junit4]   2> 3325002 INFO  (jetty-launcher-9168-thread-2) [    ] o.e.j.s.Server jetty-9.4.14.v20181114; built: 2018-11-14T21:20:31.478Z; git: c4550056e785fb5665914545889f21dc136ad9e6; jvm 1.8.0_191-b12
   [junit4]   2> 3325004 INFO  (jetty-launcher-9168-thread-4) [    ] o.e.j.s.session DefaultSessionIdManager workerName=node0
   [junit4]   2> 3325004 INFO  (jetty-launcher-9168-thread-4) [    ] o.e.j.s.session No SessionScavenger set, using defaults
   [junit4]   2> 3325004 INFO  (jetty-launcher-9168-thread-4) [    ] o.e.j.s.session node0 Scavenging every 600000ms
   [junit4]   2> 3325004 INFO  (jetty-launcher-9168-thread-2) [    ] o.e.j.s.session DefaultSessionIdManager workerName=node0
   [junit4]   2> 3325004 INFO  (jetty-launcher-9168-thread-2) [    ] o.e.j.s.session No SessionScavenger set, using defaults
   [junit4]   2> 3325004 INFO  (jetty-launcher-9168-thread-2) [    ] o.e.j.s.session node0 Scavenging every 600000ms
   [junit4]   2> 3325004 INFO  (jetty-launcher-9168-thread-4) [    ] o.e.j.s.h.ContextHandler Started o.e.j.s.ServletContextHandler@4d2a6974{/solr,null,AVAILABLE}
   [junit4]   2> 3325005 INFO  (jetty-launcher-9168-thread-1) [    ] o.e.j.s.session DefaultSessionIdManager workerName=node0
   [junit4]   2> 3325005 INFO  (jetty-launcher-9168-thread-1) [    ] o.e.j.s.session No SessionScavenger set, using defaults
   [junit4]   2> 3325005 INFO  (jetty-launcher-9168-thread-1) [    ] o.e.j.s.session node0 Scavenging every 660000ms
   [junit4]   2> 3325005 INFO  (jetty-launcher-9168-thread-2) [    ] o.e.j.s.h.ContextHandler Started o.e.j.s.ServletContextHandler@34105ff2{/solr,null,AVAILABLE}
   [junit4]   2> 3325005 INFO  (jetty-launcher-9168-thread-3) [    ] o.e.j.s.session DefaultSessionIdManager workerName=node0
   [junit4]   2> 3325005 INFO  (jetty-launcher-9168-thread-3) [    ] o.e.j.s.session No SessionScavenger set, using defaults
   [junit4]   2> 3325005 INFO  (jetty-launcher-9168-thread-3) [    ] o.e.j.s.session node0 Scavenging every 660000ms
   [junit4]   2> 3325005 INFO  (jetty-launcher-9168-thread-1) [    ] o.e.j.s.h.ContextHandler Started o.e.j.s.ServletContextHandler@626d8839{/solr,null,AVAILABLE}
   [junit4]   2> 3325005 INFO  (jetty-launcher-9168-thread-3) [    ] o.e.j.s.h.ContextHandler Started o.e.j.s.ServletContextHandler@249be9cd{/solr,null,AVAILABLE}
   [junit4]   2> 3325005 INFO  (jetty-launcher-9168-thread-2) [    ] o.e.j.s.AbstractConnector Started ServerConnector@728c4468{HTTP/1.1,[http/1.1, h2c]}{127.0.0.1:41059}
   [junit4]   2> 3325005 INFO  (jetty-launcher-9168-thread-2) [    ] o.e.j.s.Server Started @3325109ms
   [junit4]   2> 3325005 INFO  (jetty-launcher-9168-thread-2) [    ] o.a.s.c.s.e.JettySolrRunner Jetty properties: {hostContext=/solr, hostPort=41059}
   [junit4]   2> 3325005 INFO  (jetty-launcher-9168-thread-3) [    ] o.e.j.s.AbstractConnector Started ServerConnector@4b96c83b{HTTP/1.1,[http/1.1, h2c]}{127.0.0.1:43408}
   [junit4]   2> 3325005 INFO  (jetty-launcher-9168-thread-3) [    ] o.e.j.s.Server Started @3325109ms
   [junit4]   2> 3325006 INFO  (jetty-launcher-9168-thread-3) [    ] o.a.s.c.s.e.JettySolrRunner Jetty properties: {hostContext=/solr, hostPort=43408}
   [junit4]   2> 3325006 ERROR (jetty-launcher-9168-thread-2) [    ] o.a.s.u.StartupLoggingUtils Missing Java Option solr.log.dir. Logging may be missing or incomplete.
   [junit4]   2> 3325006 INFO  (jetty-launcher-9168-thread-2) [    ] o.a.s.s.SolrDispatchFilter Using logger factory org.apache.logging.slf4j.Log4jLoggerFactory
   [junit4]   2> 3325006 INFO  (jetty-launcher-9168-thread-4) [    ] o.e.j.s.AbstractConnector Started ServerConnector@629acb36{HTTP/1.1,[http/1.1, h2c]}{127.0.0.1:43292}
   [junit4]   2> 3325006 INFO  (jetty-launcher-9168-thread-4) [    ] o.e.j.s.Server Started @3325109ms
   [junit4]   2> 3325006 ERROR (jetty-launcher-9168-thread-3) [    ] o.a.s.u.StartupLoggingUtils Missing Java Option solr.log.dir. Logging may be missing or incomplete.
   [junit4]   2> 3325006 INFO  (jetty-launcher-9168-thread-4) [    ] o.a.s.c.s.e.JettySolrRunner Jetty properties: {hostContext=/solr, hostPort=43292}
   [junit4]   2> 3325006 INFO  (jetty-launcher-9168-thread-3) [    ] o.a.s.s.SolrDispatchFilter Using logger factory org.apache.logging.slf4j.Log4jLoggerFactory
   [junit4]   2> 3325006 INFO  (jetty-launcher-9168-thread-2) [    ] o.a.s.s.SolrDispatchFilter  ___      _       Welcome to Apache Solr™ version 8.0.0
   [junit4]   2> 3325006 ERROR (jetty-launcher-9168-thread-4) [    ] o.a.s.u.StartupLoggingUtils Missing Java Option solr.log.dir. Logging may be missing or incomplete.
   [junit4]   2> 3325006 INFO  (jetty-launcher-9168-thread-2) [    ] o.a.s.s.SolrDispatchFilter / __| ___| |_ _   Starting in cloud mode on port null
   [junit4]   2> 3325006 INFO  (jetty-launcher-9168-thread-4) [    ] o.a.s.s.SolrDispatchFilter Using logger factory org.apache.logging.slf4j.Log4jLoggerFactory
   [junit4]   2> 3325006 INFO  (jetty-launcher-9168-thread-2) [    ] o.a.s.s.SolrDispatchFilter \__ \/ _ \ | '_|  Install dir: null
   [junit4]   2> 3325006 INFO  (jetty-launcher-9168-thread-2) [    ] o.a.s.s.SolrDispatchFilter |___/\___/_|_|    Start time: 2018-12-25T19:41:15.517Z
   [junit4]   2> 3325006 INFO  (jetty-launcher-9168-thread-4) [    ] o.a.s.s.SolrDispatchFilter  ___      _       Welcome to Apache Solr™ version 8.0.0
   [junit4]   2> 3325006 INFO  (jetty-launcher-9168-thread-4) [    ] o.a.s.s.SolrDispatchFilter / __| ___| |_ _   Starting in cloud mode on port null
   [junit4]   2> 3325006 INFO  (jetty-launcher-9168-thread-4) [    ] o.a.s.s.SolrDispatchFilter \__ \/ _ \ | '_|  Install dir: null
   [junit4]   2> 3325006 INFO  (jetty-launcher-9168-thread-4) [    ] o.a.s.s.SolrDispatchFilter |___/\___/_|_|    Start time: 2018-12-25T19:41:15.517Z
   [junit4]   2> 3325006 INFO  (jetty-launcher-9168-thread-3) [    ] o.a.s.s.SolrDispatchFilter  ___      _       Welcome to Apache Solr™ version 8.0.0
   [junit4]   2> 3325006 INFO  (jetty-launcher-9168-thread-3) [    ] o.a.s.s.SolrDispatchFilter / __| ___| |_ _   Starting in cloud mode on port null
   [junit4]   2> 3325006 INFO  (jetty-launcher-9168-thread-3) [    ] o.a.s.s.SolrDispatchFilter \__ \/ _ \ | '_|  Install dir: null
   [junit4]   2> 3325006 INFO  (jetty-launcher-9168-thread-3) [    ] o.a.s.s.SolrDispatchFilter |___/\___/_|_|    Start time: 2018-12-25T19:41:15.517Z
   [junit4]   2> 3325015 INFO  (jetty-launcher-9168-thread-1) [    ] o.e.j.s.AbstractConnector Started ServerConnector@396c1c67{HTTP/1.1,[http/1.1, h2c]}{127.0.0.1:35665}
   [junit4]   2> 3325015 INFO  (jetty-launcher-9168-thread-1) [    ] o.e.j.s.Server Started @3325119ms
   [junit4]   2> 3325015 INFO  (jetty-launcher-9168-thread-1) [    ] o.a.s.c.s.e.JettySolrRunner Jetty properties: {hostContext=/solr, hostPort=35665}
   [junit4]   2> 3325015 ERROR (jetty-launcher-9168-thread-1) [    ] o.a.s.u.StartupLoggingUtils Missing Java Option solr.log.dir. Logging may be missing or incomplete.
   [junit4]   2> 3325015 INFO  (jetty-launcher-9168-thread-1) [    ] o.a.s.s.SolrDispatchFilter Using logger factory org.apache.logging.slf4j.Log4jLoggerFactory
   [junit4]   2> 3325015 INFO  (jetty-launcher-9168-thread-1) [    ] o.a.s.s.SolrDispatchFilter  ___      _       Welcome to Apache Solr™ version 8.0.0
   [junit4]   2> 3325015 INFO  (jetty-launcher-9168-thread-1) [    ] o.a.s.s.SolrDispatchFilter / __| ___| |_ _   Starting in cloud mode on port null
   [junit4]   2> 3325015 INFO  (jetty-launcher-9168-thread-1) [    ] o.a.s.s.SolrDispatchFilter \__ \/ _ \ | '_|  Install dir: null
   [junit4]   2> 3325015 INFO  (jetty-launcher-9168-thread-1) [    ] o.a.s.s.SolrDispatchFilter |___/\___/_|_|    Start time: 2018-12-25T19:41:15.526Z
   [junit4]   2> 3325016 INFO  (zkConnectionManagerCallback-9172-thread-1) [    ] o.a.s.c.c.ConnectionManager zkClient has connected
   [junit4]   2> 3325016 INFO  (zkConnectionManagerCallback-9170-thread-1) [    ] o.a.s.c.c.ConnectionManager zkClient has connected
   [junit4]   2> 3325017 INFO  (jetty-launcher-9168-thread-2) [    ] o.a.s.s.SolrDispatchFilter solr.xml found in ZooKeeper. Loading...
   [junit4]   2> 3325017 INFO  (zkConnectionManagerCallback-9176-thread-1) [    ] o.a.s.c.c.ConnectionManager zkClient has connected
   [junit4]   2> 3325020 INFO  (zkConnectionManagerCallback-9174-thread-1) [    ] o.a.s.c.c.ConnectionManager zkClient has connected
   [junit4]   2> 3325020 INFO  (jetty-launcher-9168-thread-4) [    ] o.a.s.s.SolrDispatchFilter solr.xml found in ZooKeeper. Loading...
   [junit4]   2> 3325059 INFO  (jetty-launcher-9168-thread-3) [    ] o.a.s.s.SolrDispatchFilter solr.xml found in ZooKeeper. Loading...
   [junit4]   2> 3325060 INFO  (jetty-launcher-9168-thread-1) [    ] o.a.s.s.SolrDispatchFilter solr.xml found in ZooKeeper. Loading...
   [junit4]   2> 3325300 WARN  (jetty-launcher-9168-thread-3) [    ] o.e.j.u.s.S.config No Client EndPointIdentificationAlgorithm configured for SslContextFactory@30f6f596[provider=null,keyStore=null,trustStore=null]
   [junit4]   2> 3325355 WARN  (jetty-launcher-9168-thread-3) [    ] o.e.j.u.s.S.config No Client EndPointIdentificationAlgorithm configured for SslContextFactory@6560652[provider=null,keyStore=null,trustStore=null]
   [junit4]   2> 3325356 INFO  (jetty-launcher-9168-thread-3) [    ] o.a.s.c.ZkContainer Zookeeper client=127.0.0.1:37948/solr
   [junit4]   2> 3325411 INFO  (zkConnectionManagerCallback-9183-thread-1) [    ] o.a.s.c.c.ConnectionManager zkClient has connected
   [junit4]   2> 3325424 WARN  (jetty-launcher-9168-thread-2) [    ] o.e.j.u.s.S.config No Client EndPointIdentificationAlgorithm configured for SslContextFactory@2fe4121d[provider=null,keyStore=null,trustStore=null]
   [junit4]   2> 3325426 WARN  (jetty-launcher-9168-thread-1) [    ] o.e.j.u.s.S.config No Client EndPointIdentificationAlgorithm configured for SslContextFactory@691349b5[provider=null,keyStore=null,trustStore=null]
   [junit4]   2> 3325428 WARN  (jetty-launcher-9168-thread-2) [    ] o.e.j.u.s.S.config No Client EndPointIdentificationAlgorithm configured for SslContextFactory@4e7ab944[provider=null,keyStore=null,trustStore=null]
   [junit4]   2> 3325429 INFO  (jetty-launcher-9168-thread-2) [    ] o.a.s.c.ZkContainer Zookeeper client=127.0.0.1:37948/solr
   [junit4]   2> 3325477 WARN  (jetty-launcher-9168-thread-1) [    ] o.e.j.u.s.S.config No Client EndPointIdentificationAlgorithm configured for SslContextFactory@60bbc495[provider=null,keyStore=null,trustStore=null]
   [junit4]   2> 3325478 INFO  (jetty-launcher-9168-thread-1) [    ] o.a.s.c.ZkContainer Zookeeper client=127.0.0.1:37948/solr
   [junit4]   2> 3325516 INFO  (zkConnectionManagerCallback-9190-thread-1) [    ] o.a.s.c.c.ConnectionManager zkClient has connected
   [junit4]   2> 3325532 INFO  (zkConnectionManagerCallback-9196-thread-1) [    ] o.a.s.c.c.ConnectionManager zkClient has connected
   [junit4]   2> 3325541 WARN  (NIOServerCxn.Factory:0.0.0.0/0.0.0.0:0) [    ] o.a.z.s.NIOServerCnxn Unable to read additional data from client sessionid 0x1068b2539790008, likely client has closed socket
   [junit4]   2> 3325541 WARN  (jetty-launcher-9168-thread-4) [    ] o.e.j.u.s.S.config No Client EndPointIdentificationAlgorithm configured for SslContextFactory@ad503ad[provider=null,keyStore=null,trustStore=null]
   [junit4]   2> 3325548 INFO  (zkConnectionManagerCallback-9199-thread-1) [    ] o.a.s.c.c.ConnectionManager zkClient has connected
   [junit4]   2> 3325549 INFO  (zkConnectionManagerCallback-9193-thread-1) [    ] o.a.s.c.c.ConnectionManager zkClient has connected
   [junit4]   2> 3325550 WARN  (jetty-launcher-9168-thread-4) [    ] o.e.j.u.s.S.config No Client EndPointIdentificationAlgorithm configured for SslContextFactory@e0c74a2[provider=null,keyStore=null,trustStore=null]
   [junit4]   2> 3325550 INFO  (zkConnectionManagerCallback-9203-thread-1) [    ] o.a.s.c.c.ConnectionManager zkClient has connected
   [junit4]   2> 3325551 INFO  (jetty-launcher-9168-thread-4) [    ] o.a.s.c.ZkContainer Zookeeper client=127.0.0.1:37948/solr
   [junit4]   2> 3325552 INFO  (zkConnectionManagerCallback-9208-thread-1) [    ] o.a.s.c.c.ConnectionManager zkClient has connected
   [junit4]   2> 3325597 INFO  (zkConnectionManagerCallback-9212-thread-1) [    ] o.a.s.c.c.ConnectionManager zkClient has connected
   [junit4]   2> 3325638 INFO  (jetty-launcher-9168-thread-4) [n:127.0.0.1:43292_solr    ] o.a.s.c.OverseerElectionContext I am going to be the leader 127.0.0.1:43292_solr
   [junit4]   2> 3325650 INFO  (jetty-launcher-9168-thread-4) [n:127.0.0.1:43292_solr    ] o.a.s.c.Overseer Overseer (id=73899435892473870-127.0.0.1:43292_solr-n_0000000000) starting
   [junit4]   2> 3325666 INFO  (zkConnectionManagerCallback-9221-thread-1) [    ] o.a.s.c.c.ConnectionManager zkClient has connected
   [junit4]   2> 3325673 INFO  (jetty-launcher-9168-thread-4) [n:127.0.0.1:43292_solr    ] o.a.s.c.s.i.ZkClientClusterStateProvider Cluster at 127.0.0.1:37948/solr ready
   [junit4]   2> 3325674 INFO  (OverseerStateUpdate-73899435892473870-127.0.0.1:43292_solr-n_0000000000) [n:127.0.0.1:43292_solr    ] o.a.s.c.Overseer Starting to work on the main queue : 127.0.0.1:43292_solr
   [junit4]   2> 3325675 INFO  (jetty-launcher-9168-thread-4) [n:127.0.0.1:43292_solr    ] o.a.s.c.ZkController Register node as live in ZooKeeper:/live_nodes/127.0.0.1:43292_solr
   [junit4]   2> 3325676 DEBUG (OverseerAutoScalingTriggerThread-73899435892473870-127.0.0.1:43292_solr-n_0000000000) [    ] o.a.s.c.a.OverseerTriggerThread Adding .auto_add_replicas and .scheduled_maintenance triggers
   [junit4]   2> 3325681 INFO  (zkCallback-9220-thread-1) [    ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (1)
   [junit4]   2> 3325682 INFO  (OverseerStateUpdate-73899435892473870-127.0.0.1:43292_solr-n_0000000000) [n:127.0.0.1:43292_solr    ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (1)
   [junit4]   2> 3325699 DEBUG (OverseerAutoScalingTriggerThread-73899435892473870-127.0.0.1:43292_solr-n_0000000000) [    ] o.a.s.c.a.OverseerTriggerThread Refreshing /autoscaling.json with znode version 1
   [junit4]   2> 3325699 DEBUG (OverseerAutoScalingTriggerThread-73899435892473870-127.0.0.1:43292_solr-n_0000000000) [    ] o.a.s.c.a.OverseerTriggerThread Current znodeVersion 1, lastZnodeVersion 0
   [junit4]   2> 3325699 DEBUG (OverseerAutoScalingTriggerThread-73899435892473870-127.0.0.1:43292_solr-n_0000000000) [    ] o.a.s.c.a.OverseerTriggerThread Processed trigger updates upto znodeVersion 1
   [junit4]   2> 3325699 INFO  (zkCallback-9198-thread-1) [    ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (1)
   [junit4]   2> 3325700 INFO  (jetty-launcher-9168-thread-1) [n:127.0.0.1:35665_solr    ] o.a.s.c.ZkController Publish node=127.0.0.1:35665_solr as DOWN
   [junit4]   2> 3325701 INFO  (jetty-launcher-9168-thread-1) [n:127.0.0.1:35665_solr    ] o.a.s.c.TransientSolrCoreCacheDefault Allocating transient cache for 2147483647 transient cores
   [junit4]   2> 3325701 INFO  (jetty-launcher-9168-thread-1) [n:127.0.0.1:35665_solr    ] o.a.s.c.ZkController Register node as live in ZooKeeper:/live_nodes/127.0.0.1:35665_solr
   [junit4]   2> 3325702 INFO  (zkCallback-9220-thread-1) [    ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (1) -> (2)
   [junit4]   2> 3325703 INFO  (zkCallback-9198-thread-1) [    ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (1) -> (2)
   [junit4]   2> 3325719 INFO  (zkCallback-9211-thread-1) [    ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (1) -> (2)
   [junit4]   2> 3325719 DEBUG (OverseerStateUpdate-73899435892473870-127.0.0.1:43292_solr-n_0000000000) [n:127.0.0.1:43292_solr    ] o.a.s.c.Overseer processMessage: queueSize: 1, message = {
   [junit4]   2>   "operation":"downnode",
   [junit4]   2>   "node_name":"127.0.0.1:35665_solr"} current state version: 0
   [junit4]   2> 3325723 DEBUG (OverseerAutoScalingTriggerThread-73899435892473870-127.0.0.1:43292_solr-n_0000000000) [    ] o.a.s.c.a.NodeLostTrigger NodeLostTrigger .auto_add_replicas - Initial livenodes: [127.0.0.1:43292_solr, 127.0.0.1:35665_solr]
   [junit4]   2> 3325727 DEBUG (OverseerAutoScalingTriggerThread-73899435892473870-127.0.0.1:43292_solr-n_0000000000) [    ] o.a.s.c.a.OverseerTriggerThread -- cleaning old nodeLost / nodeAdded markers
   [junit4]   2> 3325740 INFO  (jetty-launcher-9168-thread-4) [n:127.0.0.1:43292_solr    ] o.a.s.h.a.MetricsHistoryHandler No .system collection, keeping metrics history in memory.
   [junit4]   2> 3325748 DEBUG (ScheduledTrigger-7305-thread-2) [    ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 2 and last live nodes: 2
   [junit4]   2> 3325748 DEBUG (OverseerAutoScalingTriggerThread-73899435892473870-127.0.0.1:43292_solr-n_0000000000) [    ] o.a.s.c.a.OverseerTriggerThread Current znodeVersion 1, lastZnodeVersion 1
   [junit4]   2> 3325782 INFO  (zkConnectionManagerCallback-9227-thread-1) [    ] o.a.s.c.c.ConnectionManager zkClient has connected
   [junit4]   2> 3325798 INFO  (jetty-launcher-9168-thread-4) [n:127.0.0.1:43292_solr    ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_43292.solr.node' (registry 'solr.node') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@61c5f0a1
   [junit4]   2> 3325812 INFO  (jetty-launcher-9168-thread-1) [n:127.0.0.1:35665_solr    ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (2)
   [junit4]   2> 3325813 INFO  (jetty-launcher-9168-thread-4) [n:127.0.0.1:43292_solr    ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_43292.solr.jvm' (registry 'solr.jvm') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@61c5f0a1
   [junit4]   2> 3325813 INFO  (jetty-launcher-9168-thread-4) [n:127.0.0.1:43292_solr    ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_43292.solr.jetty' (registry 'solr.jetty') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@61c5f0a1
   [junit4]   2> 3325813 INFO  (jetty-launcher-9168-thread-1) [n:127.0.0.1:35665_solr    ] o.a.s.c.s.i.ZkClientClusterStateProvider Cluster at 127.0.0.1:37948/solr ready
   [junit4]   2> 3325814 INFO  (jetty-launcher-9168-thread-4) [n:127.0.0.1:43292_solr    ] o.a.s.c.CorePropertiesLocator Found 0 core definitions underneath /home/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-master/solr/build/solr-core/test/J0/temp/solr.cloud.TestPullReplicaErrorHandling_5C4F9DE5439B7443-001/tempDir-001/node3/.
   [junit4]   2> 3325814 INFO  (jetty-launcher-9168-thread-1) [n:127.0.0.1:35665_solr    ] o.a.s.h.a.MetricsHistoryHandler No .system collection, keeping metrics history in memory.
   [junit4]   2> 3325882 INFO  (jetty-launcher-9168-thread-1) [n:127.0.0.1:35665_solr    ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_35665.solr.node' (registry 'solr.node') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@61c5f0a1
   [junit4]   2> 3325887 INFO  (jetty-launcher-9168-thread-3) [n:127.0.0.1:43408_solr    ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (2)
   [junit4]   2> 3325897 INFO  (jetty-launcher-9168-thread-1) [n:127.0.0.1:35665_solr    ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_35665.solr.jvm' (registry 'solr.jvm') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@61c5f0a1
   [junit4]   2> 3325897 INFO  (jetty-launcher-9168-thread-1) [n:127.0.0.1:35665_solr    ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_35665.solr.jetty' (registry 'solr.jetty') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@61c5f0a1
   [junit4]   2> 3325898 INFO  (jetty-launcher-9168-thread-1) [n:127.0.0.1:35665_solr    ] o.a.s.c.CorePropertiesLocator Found 0 core definitions underneath /home/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-master/solr/build/solr-core/test/J0/temp/solr.cloud.TestPullReplicaErrorHandling_5C4F9DE5439B7443-001/tempDir-001/node1/.
   [junit4]   2> 3325898 INFO  (jetty-launcher-9168-thread-3) [n:127.0.0.1:43408_solr    ] o.a.s.c.ZkController Publish node=127.0.0.1:43408_solr as DOWN
   [junit4]   2> 3325899 INFO  (jetty-launcher-9168-thread-3) [n:127.0.0.1:43408_solr    ] o.a.s.c.TransientSolrCoreCacheDefault Allocating transient cache for 2147483647 transient cores
   [junit4]   2> 3325899 INFO  (jetty-launcher-9168-thread-3) [n:127.0.0.1:43408_solr    ] o.a.s.c.ZkController Register node as live in ZooKeeper:/live_nodes/127.0.0.1:43408_solr
   [junit4]   2> 3325900 DEBUG (OverseerStateUpdate-73899435892473870-127.0.0.1:43292_solr-n_0000000000) [n:127.0.0.1:43292_solr    ] o.a.s.c.Overseer processMessage: queueSize: 1, message = {
   [junit4]   2>   "operation":"downnode",
   [junit4]   2>   "node_name":"127.0.0.1:43408_solr"} current state version: 0
   [junit4]   2> 3325900 INFO  (jetty-launcher-9168-thread-2) [n:127.0.0.1:41059_solr    ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (2)
   [junit4]   2> 3325901 INFO  (zkCallback-9220-thread-1) [    ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (2) -> (3)
   [junit4]   2> 3325901 INFO  (zkCallback-9198-thread-1) [    ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (2) -> (3)
   [junit4]   2> 3325901 INFO  (zkCallback-9211-thread-1) [    ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (2) -> (3)
   [junit4]   2> 3325901 INFO  (zkCallback-9226-thread-1) [    ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (2) -> (3)
   [junit4]   2> 3325902 INFO  (zkCallback-9202-thread-1) [    ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (2) -> (3)
   [junit4]   2> 3325903 INFO  (jetty-launcher-9168-thread-2) [n:127.0.0.1:41059_solr    ] o.a.s.c.ZkController Publish node=127.0.0.1:41059_solr as DOWN
   [junit4]   2> 3325904 INFO  (jetty-launcher-9168-thread-2) [n:127.0.0.1:41059_solr    ] o.a.s.c.TransientSolrCoreCacheDefault Allocating transient cache for 2147483647 transient cores
   [junit4]   2> 3325904 INFO  (jetty-launcher-9168-thread-2) [n:127.0.0.1:41059_solr    ] o.a.s.c.ZkController Register node as live in ZooKeeper:/live_nodes/127.0.0.1:41059_solr
   [junit4]   2> 3325904 DEBUG (OverseerStateUpdate-73899435892473870-127.0.0.1:43292_solr-n_0000000000) [n:127.0.0.1:43292_solr    ] o.a.s.c.Overseer processMessage: queueSize: 2, message = {
   [junit4]   2>   "operation":"downnode",
   [junit4]   2>   "node_name":"127.0.0.1:41059_solr"} current state version: 0
   [junit4]   2> 3325905 INFO  (zkCallback-9211-thread-1) [    ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (3) -> (4)
   [junit4]   2> 3325905 INFO  (zkCallback-9226-thread-1) [    ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (3) -> (4)
   [junit4]   2> 3325912 INFO  (zkCallback-9202-thread-1) [    ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (3) -> (4)
   [junit4]   2> 3325917 INFO  (zkCallback-9220-thread-1) [    ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (3) -> (4)
   [junit4]   2> 3325917 INFO  (zkCallback-9198-thread-1) [    ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (3) -> (4)
   [junit4]   2> 3325917 INFO  (zkCallback-9192-thread-1) [    ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (2) -> (3)
   [junit4]   2> 3325933 INFO  (zkCallback-9192-thread-2) [    ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (3) -> (4)
   [junit4]   2> 3325934 INFO  (zkConnectionManagerCallback-9238-thread-1) [    ] o.a.s.c.c.ConnectionManager zkClient has connected
   [junit4]   2> 3325934 INFO  (zkConnectionManagerCallback-9237-thread-1) [    ] o.a.s.c.c.ConnectionManager zkClient has connected
   [junit4]   2> 3325936 INFO  (jetty-launcher-9168-thread-3) [n:127.0.0.1:43408_solr    ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (4)
   [junit4]   2> 3325936 INFO  (jetty-launcher-9168-thread-2) [n:127.0.0.1:41059_solr    ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (4)
   [junit4]   2> 3325937 INFO  (jetty-launcher-9168-thread-3) [n:127.0.0.1:43408_solr    ] o.a.s.c.s.i.ZkClientClusterStateProvider Cluster at 127.0.0.1:37948/solr ready
   [junit4]   2> 3325937 INFO  (jetty-launcher-9168-thread-2) [n:127.0.0.1:41059_solr    ] o.a.s.c.s.i.ZkClientClusterStateProvider Cluster at 127.0.0.1:37948/solr ready
   [junit4]   2> 3325937 INFO  (jetty-launcher-9168-thread-3) [n:127.0.0.1:43408_solr    ] o.a.s.h.a.MetricsHistoryHandler No .system collection, keeping metrics history in memory.
   [junit4]   2> 3325937 INFO  (jetty-launcher-9168-thread-2) [n:127.0.0.1:41059_solr    ] o.a.s.h.a.MetricsHistoryHandler No .system collection, keeping metrics history in memory.
   [junit4]   2> 3325969 INFO  (jetty-launcher-9168-thread-3) [n:127.0.0.1:43408_solr    ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_43408.solr.node' (registry 'solr.node') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@61c5f0a1
   [junit4]   2> 3325969 INFO  (jetty-launcher-9168-thread-2) [n:127.0.0.1:41059_solr    ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_41059.solr.node' (registry 'solr.node') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@61c5f0a1
   [junit4]   2> 3325976 INFO  (jetty-launcher-9168-thread-2) [n:127.0.0.1:41059_solr    ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_41059.solr.jvm' (registry 'solr.jvm') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@61c5f0a1
   [junit4]   2> 3325976 INFO  (jetty-launcher-9168-thread-3) [n:127.0.0.1:43408_solr    ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_43408.solr.jvm' (registry 'solr.jvm') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@61c5f0a1
   [junit4]   2> 3325976 INFO  (jetty-launcher-9168-thread-2) [n:127.0.0.1:41059_solr    ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_41059.solr.jetty' (registry 'solr.jetty') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@61c5f0a1
   [junit4]   2> 3325976 INFO  (jetty-launcher-9168-thread-3) [n:127.0.0.1:43408_solr    ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_43408.solr.jetty' (registry 'solr.jetty') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@61c5f0a1
   [junit4]   2> 3325977 INFO  (jetty-launcher-9168-thread-3) [n:127.0.0.1:43408_solr    ] o.a.s.c.CorePropertiesLocator Found 0 core definitions underneath /home/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-master/solr/build/solr-core/test/J0/temp/solr.cloud.TestPullReplicaErrorHandling_5C4F9DE5439B7443-001/tempDir-001/node2/.
   [junit4]   2> 3325977 INFO  (jetty-launcher-9168-thread-2) [n:127.0.0.1:41059_solr    ] o.a.s.c.CorePropertiesLocator Found 0 core definitions underneath /home/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-master/solr/build/solr-core/test/J0/temp/solr.cloud.TestPullReplicaErrorHandling_5C4F9DE5439B7443-001/tempDir-001/node4/.
   [junit4]   2> 3326065 INFO  (zkConnectionManagerCallback-9245-thread-1) [    ] o.a.s.c.c.ConnectionManager zkClient has connected
   [junit4]   2> 3326067 INFO  (SUITE-TestPullReplicaErrorHandling-seed#[5C4F9DE5439B7443]-worker) [    ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (4)
   [junit4]   2> 3326076 INFO  (SUITE-TestPullReplicaErrorHandling-seed#[5C4F9DE5439B7443]-worker) [    ] o.a.s.c.s.i.ZkClientClusterStateProvider Cluster at 127.0.0.1:37948/solr ready
   [junit4]   2> 3326082 INFO  (SUITE-TestPullReplicaErrorHandling-seed#[5C4F9DE5439B7443]-worker) [    ] o.a.s.c.CoreContainer Shutting down CoreContainer instance=2124695683
   [junit4]   2> 3326082 INFO  (SUITE-TestPullReplicaErrorHandling-seed#[5C4F9DE5439B7443]-worker) [    ] o.a.s.c.ZkController Remove node as live in ZooKeeper:/live_nodes/127.0.0.1:43292_solr
   [junit4]   2> 3326082 INFO  (SUITE-TestPullReplicaErrorHandling-seed#[5C4F9DE5439B7443]-worker) [    ] o.a.s.c.CoreContainer Publish this node as DOWN...
   [junit4]   2> 3326082 INFO  (SUITE-TestPullReplicaErrorHandling-seed#[5C4F9DE5439B7443]-worker) [    ] o.a.s.c.ZkController Publish node=127.0.0.1:43292_solr as DOWN
   [junit4]   2> 3326083 INFO  (SUITE-TestPullReplicaErrorHandling-seed#[5C4F9DE5439B7443]-worker) [    ] o.a.s.c.TransientSolrCoreCacheDefault Allocating transient cache for 2147483647 transient cores
   [junit4]   2> 3326084 INFO  (SUITE-TestPullReplicaErrorHandling-seed#[5C4F9DE5439B7443]-worker) [    ] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.node, tag=null
   [junit4]   2> 3326084 INFO  (SUITE-TestPullReplicaErrorHandling-seed#[5C4F9DE5439B7443]-worker) [    ] o.a.s.m.r.SolrJmxReporter Closing reporter [org.apache.solr.metrics.reporters.SolrJmxReporter@23002c74: rootName = solr_43292, domain = solr.node, service url = null, agent id = null] for registry solr.node / com.codahale.metrics.MetricRegistry@e3468d2
   [junit4]   2> 3326086 DEBUG (OverseerStateUpdate-73899435892473870-127.0.0.1:43292_solr-n_0000000000) [n:127.0.0.1:43292_solr    ] o.a.s.c.Overseer processMessage: queueSize: 1, message = {
   [junit4]   2>   "operation":"downnode",
   [junit4]   2>   "node_name":"127.0.0.1:43292_solr"} current state version: 0
   [junit4]   2> 3326088 INFO  (SUITE-TestPullReplicaErrorHandling-seed#[5C4F9DE5439B7443]-worker) [    ] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.jvm, tag=null
   [junit4]   2> 3326088 INFO  (SUITE-TestPullReplicaErrorHandling-seed#[5C4F9DE5439B7443]-worker) [    ] o.a.s.m.r.SolrJmxReporter Closing reporter [org.apache.solr.metrics.reporters.SolrJmxReporter@238ae061: rootName = solr_43292, domain = solr.jvm, service url = null, agent id = null] for registry solr.jvm / com.codahale.metrics.MetricRegistry@7925b85e
   [junit4]   2> 3326091 INFO  (SUITE-TestPullReplicaErrorHandling-seed#[5C4F9DE5439B7443]-worker) [    ] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.jetty, tag=null
   [junit4]   2> 3326091 INFO  (SUITE-TestPullReplicaErrorHandling-seed#[5C4F9DE5439B7443]-worker) [    ] o.a.s.m.r.SolrJmxReporter Closing reporter [org.apache.solr.metrics.reporters.SolrJmxReporter@6a5a563c: rootName = solr_43292, domain = solr.jetty, service url = null, agent id = null] for registry solr.jetty / com.codahale.metrics.MetricRegistry@584cda2d
   [junit4]   2> 3326091 INFO  (SUITE-TestPullReplicaErrorHandling-seed#[5C4F9DE5439B7443]-worker) [    ] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.cluster, tag=null
   [junit4]   2> 3326092 INFO  (closeThreadPool-9248-thread-2) [    ] o.a.s.c.Overseer Overseer (id=73899435892473870-127.0.0.1:43292_solr-n_0000000000) closing
   [junit4]   2> 3326092 INFO  (OverseerStateUpdate-73899435892473870-127.0.0.1:43292_solr-n_0000000000) [n:127.0.0.1:43292_solr    ] o.a.s.c.Overseer Overseer Loop exiting : 127.0.0.1:43292_solr
   [junit4]   1> Done close org.apache.solr.common.util.ExecutorUtil$MDCAwareThreadPoolExecutor@3b1bf82e[Terminated, pool size = 0, active threads = 0, queued tasks = 0, completed tasks = 1]
   [junit4]   1> Done close org.apache.solr.common.util.ExecutorUtil$MDCAwareThreadPoolExecutor@6ebc716f[Terminated, pool size = 1, active threads = 0, queued tasks = 0, completed tasks = 1]
   [junit4]   2> 3326094 INFO  (OverseerAutoScalingTriggerThread-73899435892473870-127.0.0.1:43292_solr-n_0000000000) [    ] o.a.s.c.a.OverseerTriggerThread OverseerTriggerThread woken up but we are closed, exiting.
   [junit4]   2> 3326105 INFO  (zkCallback-9192-thread-2) [    ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (4) -> (3)
   [junit4]   2> 3326105 INFO  (zkCallback-9226-thread-1) [    ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (4) -> (3)
   [junit4]   2> 3326105 INFO  (zkCallback-9198-thread-1) [    ] o.a.s.c.OverseerElectionContext I am going to be the leader 127.0.0.1:35665_solr
   [junit4]   2> 3326105 DEBUG (closeThreadPool-9248-thread-2) [    ] o.a.s.c.a.ScheduledTriggers Shutting down scheduled thread pool executor now
   [junit4]   2> 3326105 INFO  (zkCallback-9202-thread-1) [    ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (4) -> (3)
   [junit4]   2> 3326106 INFO  (zkCallback-9198-thread-1) [n:127.0.0.1:35665_solr    ] o.a.s.c.Overseer Overseer (id=73899435892473867-127.0.0.1:35665_solr-n_0000000001) starting
   [junit4]   2> 3326106 INFO  (zkCallback-9236-thread-1) [    ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (4) -> (3)
   [junit4]   2> 3326106 DEBUG (closeThreadPool-9248-thread-2) [    ] o.a.s.c.a.ScheduledTriggers Shutting down action executor now
   [junit4]   2> 3326106 DEBUG (closeThreadPool-9248-thread-2) [    ] o.a.s.c.a.ScheduledTriggers Awaiting termination for action executor
   [junit4]   2> 3326106 DEBUG (closeThreadPool-9248-thread-2) [    ] o.a.s.c.a.ScheduledTriggers Awaiting termination for scheduled thread pool executor
   [junit4]   2> 3326106 INFO  (zkCallback-9198-thread-2) [    ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (4) -> (3)
   [junit4]   2> 3326107 INFO  (zkCallback-9235-thread-1) [    ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (4) -> (3)
   [junit4]   2> 3326107 INFO  (zkCallback-9244-thread-1) [    ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (4) -> (3)
   [junit4]   2> 3326109 INFO  (OverseerStateUpdate-73899435892473867-127.0.0.1:35665_solr-n_0000000001) [n:127.0.0.1:35665_solr    ] o.a.s.c.Overseer Starting to work on the main queue : 127.0.0.1:35665_solr
   [junit4]   2> 3326109 DEBUG (OverseerAutoScalingTriggerThread-73899435892473867-127.0.0.1:35665_solr-n_0000000001) [    ] o.a.s.c.a.OverseerTriggerThread Refreshing /autoscaling.json with znode version 1
   [junit4]   2> 3326109 DEBUG (OverseerAutoScalingTriggerThread-73899435892473867-127.0.0.1:35665_solr-n_0000000001) [    ] o.a.s.c.a.OverseerTriggerThread Current znodeVersion 1, lastZnodeVersion 0
   [junit4]   2> 3326109 DEBUG (OverseerAutoScalingTriggerThread-73899435892473867-127.0.0.1:35665_solr-n_0000000001) [    ] o.a.s.c.a.OverseerTriggerThread Processed trigger updates upto znodeVersion 1
   [junit4]   2> 3326110 DEBUG (OverseerStateUpdate-73899435892473867-127.0.0.1:35665_solr-n_0000000001) [n:127.0.0.1:35665_solr    ] o.a.s.c.Overseer processMessage: queueSize: 1, message = {
   [junit4]   2>   "operation":"downnode",
   [junit4]   2>   "node_name":"127.0.0.1:43292_solr"} current state version: 0
   [junit4]   2> 3326110 DEBUG (OverseerAutoScalingTriggerThread-73899435892473867-127.0.0.1:35665_solr-n_0000000001) [    ] o.a.s.c.a.NodeLostTrigger NodeLostTrigger .auto_add_replicas - Initial livenodes: [127.0.0.1:41059_solr, 127.0.0.1:43408_solr, 127.0.0.1:35665_solr]
   [junit4]   2> 3326111 DEBUG (OverseerAutoScalingTriggerThread-73899435892473867-127.0.0.1:35665_solr-n_0000000001) [    ] o.a.s.c.a.NodeLostTrigger Adding lost node from marker path: 127.0.0.1:43292_solr
   [junit4]   2> 3326111 DEBUG (OverseerAutoScalingTriggerThread-73899435892473867-127.0.0.1:35665_solr-n_0000000001) [    ] o.a.s.c.a.OverseerTriggerThread -- cleaning old nodeLost / nodeAdded markers
   [junit4]   2> 3326112 DEBUG (closeThreadPool-9248-thread-2) [    ] o.a.s.c.a.ScheduledTriggers ScheduledTriggers closed completely
   [junit4]   2> 3326112 DEBUG (ScheduledTrigger-7326-thread-2) [    ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 3 and last live nodes: 2
   [junit4]   2> 3326112 DEBUG (closeThreadPool-9248-thread-2) [    ] o.a.s.c.a.OverseerTriggerThread OverseerTriggerThread has been closed explicitly
   [junit4]   2> 3326112 DEBUG (ScheduledTrigger-7326-thread-2) [    ] o.a.s.c.a.NodeLostTrigger Tracking lost node: 127.0.0.1:43292_solr
   [junit4]   2> 3326112 INFO  (SUITE-TestPullReplicaErrorHandling-seed#[5C4F9DE5439B7443]-worker) [    ] o.a.s.c.Overseer Overseer (id=73899435892473870-127.0.0.1:43292_solr-n_0000000000) closing
   [junit4]   2> 3326112 INFO  (closeThreadPool-9248-thread-1) [    ] o.a.s.c.Overseer Overseer (id=73899435892473870-127.0.0.1:43292_solr-n_0000000000) closing
   [junit4]   2> 3326112 DEBUG (OverseerAutoScalingTriggerThread-73899435892473867-127.0.0.1:35665_solr-n_0000000001) [    ] o.a.s.c.a.OverseerTriggerThread Current znodeVersion 1, lastZnodeVersion 1
   [junit4]   2> 3326113 INFO  (SUITE-TestPullReplicaErrorHandling-seed#[5C4F9DE5439B7443]-worker) [    ] o.e.j.s.AbstractConnector Stopped ServerConnector@629acb36{HTTP/1.1,[http/1.1, h2c]}{127.0.0.1:0}
   [junit4]   2> 3326113 INFO  (SUITE-TestPullReplicaErrorHandling-seed#[5C4F9DE5439B7443]-worker) [    ] o.e.j.s.h.ContextHandler Stopped o.e.j.s.ServletContextHandler@4d2a6974{/solr,null,UNAVAILABLE}
   [junit4]   2> 3326113 INFO  (SUITE-TestPullReplicaErrorHandling-seed#[5C4F9DE5439B7443]-worker) [    ] o.e.j.s.session node0 Stopped scavenging
   [junit4]   2> 3326113 INFO  (SUITE-TestPullReplicaErrorHandling-seed#[5C4F9DE5439B7443]-worker) [    ] o.a.s.c.s.e.JettySolrRunner Start Jetty (original configured port=0)
   [junit4]   2> 3326113 WARN  (SUITE-TestPullReplicaErrorHandling-seed#[5C4F9DE5439B7443]-worker) [    ] o.e.j.s.AbstractConnector Ignoring deprecated socket close linger time
   [junit4]   2> 3326114 INFO  (SUITE-TestPullReplicaErrorHandling-seed#[5C4F9DE5439B7443]-worker) [    ] o.a.s.c.s.e.JettySolrRunner Trying to start Jetty on port 0 try number 1 ...
   [junit4]   2> 3326114 INFO  (SUITE-TestPullReplicaErrorHandling-seed#[5C4F9DE5439B7443]-worker) [    ] o.e.j.s.Server jetty-9.4.14.v20181114; built: 2018-11-14T21:20:31.478Z; git: c4550056e785fb5665914545889f21dc136ad9e6; jvm 1.8.0_191-b12
   [junit4]   2> 3326114 INFO  (SUITE-TestPullReplicaErrorHandling-seed#[5C4F9DE5439B7443]-worker) [    ] o.e.j.s.session DefaultSessionIdManager workerName=node0
   [junit4]   2> 3326114 INFO  (SUITE-TestPullReplicaErrorHandling-seed#[5C4F9DE5439B7443]-worker) [    ] o.e.j.s.session No SessionScavenger set, using defaults
   [junit4]   2> 3326114 INFO  (SUITE-TestPullReplicaErrorHandling-seed#[5C4F9DE5439B7443]-worker) [    ] o.e.j.s.session node0 Scavenging every 600000ms
   [junit4]   2> 3326115 INFO  (SUITE-TestPullReplicaErrorHandling-seed#[5C4F9DE5439B7443]-worker) [    ] o.e.j.s.h.ContextHandler Started o.e.j.s.ServletContextHandler@4d4854c1{/solr,null,AVAILABLE}
   [junit4]   2> 3326115 INFO  (SUITE-TestPullReplicaErrorHandling-seed#[5C4F9DE5439B7443]-worker) [    ] o.e.j.s.AbstractConnector Started ServerConnector@2fc3dc47{HTTP/1.1,[http/1.1, h2c]}{127.0.0.1:44179}
   [junit4]   2> 3326115 INFO  (SUITE-TestPullReplicaErrorHandling-seed#[5C4F9DE5439B7443]-worker) [    ] o.e.j.s.Server Started @3326219ms
   [junit4]   2> 3326115 INFO  (SUITE-TestPullReplicaErrorHandling-seed#[5C4F9DE5439B7443]-worker) [    ] o.a.s.c.s.e.JettySolrRunner Jetty properties: {hostContext=/solr, hostPort=37917}
   [junit4]   2> 3326115 ERROR (SUITE-TestPullReplicaErrorHandling-seed#[5C4F9DE5439B7443]-worker) [    ] o.a.s.u.StartupLoggingUtils Missing Java Option solr.log.dir. Logging may be missing or incomplete.
   [junit4]   2> 3326115 INFO  (SUITE-TestPullReplicaErrorHandling-seed#[5C4F9DE5439B7443]-worker) [    ] o.a.s.s.SolrDispatchFilter Using logger factory org.apache.logging.slf4j.Log4jLoggerFactory
   [junit4]   2> 3326115 INFO  (SUITE-TestPullReplicaErrorHandling-seed#[5C4F9DE5439B7443]-worker) [    ] o.a.s.s.SolrDispatchFilter  ___      _       Welcome to Apache Solr™ version 8.0.0
   [junit4]   2> 3326115 INFO  (SUITE-TestPullReplicaErrorHandling-seed#[5C4F9DE5439B7443]-worker) [    ] o.a.s.s.SolrDispatchFilter / __| ___| |_ _   Starting in cloud mode on port null
   [junit4]   2> 3326115 INFO  (SUITE-TestPullReplicaErrorHandling-seed#[5C4F9DE5439B7443]-worker) [    ] o.a.s.s.SolrDispatchFilter \__ \/ _ \ | '_|  Install dir: null
   [junit4]   2> 3326115 INFO  (SUITE-TestPullReplicaErrorHandling-seed#[5C4F9DE5439B7443]-worker) [    ] o.a.s.s.SolrDispatchFilter |___/\___/_|_|    Start time: 2018-12-25T19:41:16.626Z
   [junit4]   2> 3326125 INFO  (zkConnectionManagerCallback-9250-thread-1) [    ] o.a.s.c.c.ConnectionManager zkClient has connected
   [junit4]   2> 3326125 INFO  (SUITE-TestPullReplicaErrorHandling-seed#[5C4F9DE5439B7443]-worker) [    ] o.a.s.s.SolrDispatchFilter solr.xml found in ZooKeeper. Loading...
   [junit4]   2> 3326319 WARN  (SUITE-TestPullReplicaErrorHandling-seed#[5C4F9DE5439B7443]-worker) [    ] o.e.j.u.s.S.config No Client EndPointIdentificationAlgorithm configured for SslContextFactory@8fca7ae[provider=null,keyStore=null,trustStore=null]
   [junit4]   2> 3326322 WARN  (SUITE-TestPullReplicaErrorHandling-seed#[5C4F9DE5439B7443]-worker) [    ] o.e.j.u.s.S.config No Client EndPointIdentificationAlgorithm configured for SslContextFactory@343e16b3[provider=null,keyStore=null,trustStore=null]
   [junit4]   2> 3326323 INFO  (SUITE-TestPullReplicaErrorHandling-seed#[5C4F9DE5439B7443]-worker) [    ] o.a.s.c.ZkContainer Zookeeper client=127.0.0.1:37948/solr
   [junit4]   2> 3326324 INFO  (zkConnectionManagerCallback-9256-thread-1) [    ] o.a.s.c.c.ConnectionManager zkClient has connected
   [junit4]   2> 3326326 INFO  (zkConnectionManagerCallback-9258-thread-1) [    ] o.a.s.c.c.ConnectionManager zkClient has connected
   [junit4]   2> 3326330 INFO  (SUITE-TestPullReplicaErrorHandling-seed#[5C4F9DE5439B7443]-worker) [n:127.0.0.1:37917_solr    ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (3)
   [junit4]   2> 3326333 INFO  (SUITE-TestPullReplicaErrorHandling-seed#[5C4F9DE5439B7443]-worker) [n:127.0.0.1:37917_solr    ] o.a.s.c.ZkController Publish node=127.0.0.1:37917_solr as DOWN
   [junit4]   2> 3326333 INFO  (SUITE-TestPullReplicaErrorHandling-seed#[5C4F9DE5439B7443]-worker) [n:127.0.0.1:37917_solr    ] o.a.s.c.TransientSolrCoreCacheDefault Allocating transient cache for 2147483647 transient cores
   [junit4]   2> 3326333 INFO  (SUITE-TestPullReplicaErrorHandling-seed#[5C4F9DE5439B7443]-worker) [n:127.0.0.1:37917_solr    ] o.a.s.c.ZkController Register node as live in ZooKeeper:/live_nodes/127.0.0.1:37917_solr
   [junit4]   2> 3326334 DEBUG (OverseerStateUpdate-73899435892473867-127.0.0.1:35665_solr-n_0000000001) [n:127.0.0.1:35665_solr    ] o.a.s.c.Overseer processMessage: queueSize: 1, message = {
   [junit4]   2>   "operation":"downnode",
   [junit4]   2>   "node_name":"127.0.0.1:37917_solr"} current state version: 0
   [junit4]   2> 3326335 INFO  (zkCallback-9244-thread-1) [    ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (3) -> (4)
   [junit4]   2> 3326335 INFO  (zkCallback-9226-thread-1) [    ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (3) -> (4)
   [junit4]   2> 3326335 INFO  (zkCallback-9257-thread-1) [    ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (3) -> (4)
   [junit4]   2> 3326342 INFO  (zkCallback-9202-thread-1) [    ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (3) -> (4)
   [junit4]   2> 3326343 INFO  (zkCallback-9192-thread-2) [    ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (3) -> (4)
   [junit4]   2> 3326343 INFO  (zkCallback-9235-thread-1) [    ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (3) -> (4)
   [junit4]   2> 3326343 INFO  (zkCallback-9198-thread-1) [    ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (3) -> (4)
   [junit4]   2> 3326343 INFO  (zkCallback-9236-thread-1) [    ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (3) -> (4)
   [junit4]   2> 3326359 INFO  (zkConnectionManagerCallback-9265-thread-1) [    ] o.a.s.c.c.ConnectionManager zkClient has connected
   [junit4]   2> 3326361 INFO  (SUITE-TestPullReplicaErrorHandling-seed#[5C4F9DE5439B7443]-worker) [n:127.0.0.1:37917_solr    ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (4)
   [junit4]   2> 3326362 INFO  (SUITE-TestPullReplicaErrorHandling-seed#[5C4F9DE5439B7443]-worker) [n:127.0.0.1:37917_solr    ] o.a.s.c.s.i.ZkClientClusterStateProvider Cluster at 127.0.0.1:37948/solr ready
   [junit4]   2> 3326362 INFO  (SUITE-TestPullReplicaErrorHandling-seed#[5C4F9DE5439B7443]-worker) [n:127.0.0.1:37917_solr    ] o.a.s.h.a.MetricsHistoryHandler No .system collection, keeping metrics history in memory.
   [junit4]   2> 3326377 INFO  (SUITE-TestPullReplicaErrorHandling-seed#[5C4F9DE5439B7443]-worker) [n:127.0.0.1:37917_solr    ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_37917.solr.node' (registry 'solr.node') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@61c5f0a1
   [junit4]   2> 3326384 INFO  (SUITE-TestPullReplicaErrorHandling-seed#[5C4F9DE5439B7443]-worker) [n:127.0.0.1:37917_solr    ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_37917.solr.jvm' (registry 'solr.jvm') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@61c5f0a1
   [junit4]   2> 3326385 INFO  (SUITE-TestPullReplicaErrorHandling-seed#[5C4F9DE5439B7443]-worker) [n:127.0.0.1:37917_solr    ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_37917.solr.jetty' (registry 'solr.jetty') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@61c5f0a1
   [junit4]   2> 3326385 INFO  (SUITE-TestPullReplicaErrorHandling-seed#[5C4F9DE5439B7443]-worker) [n:127.0.0.1:37917_solr    ] o.a.s.c.CorePropertiesLocator Found 0 core definitions underneath /home/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-master/solr/build/solr-core/test/J0/temp/solr.cloud.TestPullReplicaErrorHandling_5C4F9DE5439B7443-001/tempDir-001/node3/.
   [junit4]   2> 3326464 INFO  (SUITE-TestPullReplicaErrorHandling-seed#[5C4F9DE5439B7443]-worker) [    ] o.a.s.c.TestPullReplicaErrorHandling Adding proxy for URL: http://127.0.0.1:44179/solr. Proxy: http://127.0.0.1:37917/solr
   [junit4]   2> 3326465 INFO  (SUITE-TestPullReplicaErrorHandling-seed#[5C4F9DE5439B7443]-worker) [    ] o.a.s.c.CoreContainer Shutting down CoreContainer instance=1752790752
   [junit4]   2> 3326465 INFO  (SUITE-TestPullReplicaErrorHandling-seed#[5C4F9DE5439B7443]-worker) [    ] o.a.s.c.ZkController Remove node as live in ZooKeeper:/live_nodes/127.0.0.1:35665_solr
   [junit4]   2> 3326465 INFO  (SUITE-TestPullReplicaErrorHandling-seed#[5C4F9DE5439B7443]-worker) [    ] o.a.s.c.CoreContainer Publish this node as DOWN...
   [junit4]   2> 3326465 INFO  (SUITE-TestPullReplicaErrorHandling-seed#[5C4F9DE5439B7443]-worker) [    ] o.a.s.c.ZkController Publish node=127.0.0.1:35665_solr as DOWN
   [junit4]   2> 3326478 DEBUG (OverseerStateUpdate-73899435892473867-127.0.0.1:35665_solr-n_0000000001) [n:127.0.0.1:35665_solr    ] o.a.s.c.Overseer processMessage: queueSize: 1, message = {
   [junit4]   2>   "operation":"downnode",
   [junit4]   2>   "node_name":"127.0.0.1:35665_solr"} current state version: 0
   [junit4]   2> 3326478 INFO  (SUITE-TestPullReplicaErrorHandling-seed#[5C4F9DE5439B7443]-worker) [    ] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.node, tag=null
   [junit4]   2> 3326478 INFO  (SUITE-TestPullReplicaErrorHandling-seed#[5C4F9DE5439B7443]-worker) [    ] o.a.s.m.r.SolrJmxReporter Closing reporter [org.apache.solr.metrics.reporters.SolrJmxReporter@6b2d719d: rootName = solr_35665, domain = solr.node, service url = null, agent id = null] for registry solr.node / com.codahale.metrics.MetricRegistry@7ab933e3
   [junit4]   2> 3326482 INFO  (SUITE-TestPullReplicaErrorHandling-seed#[5C4F9DE5439B7443]-worker) [    ] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.jvm, tag=null
   [junit4]   2> 3326482 INFO  (SUITE-TestPullReplicaErrorHandling-seed#[5C4F9DE5439B7443]-worker) [    ] o.a.s.m.r.SolrJmxReporter Closing reporter [org.apache.solr.metrics.reporters.SolrJmxReporter@6bbcf8b8: rootName = solr_35665, domain = solr.jvm, service url = null, agent id = null] for registry solr.jvm / com.codahale.metrics.MetricRegistry@7925b85e
   [junit4]   2> 3326501 INFO  (SUITE-TestPullReplicaErrorHandling-seed#[5C4F9DE5439B7443]-worker) [    ] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.jetty, tag=null
   [junit4]   2> 3326501 INFO  (SUITE-TestPullReplicaErrorHandling-seed#[5C4F9DE5439B7443]-worker) [    ] o.a.s.m.r.SolrJmxReporter Closing reporter [org.apache.solr.metrics.reporters.SolrJmxReporter@5a327405: rootName = solr_35665, domain = solr.jetty, service url = null, agent id = null] for registry solr.jetty / com.codahale.metrics.MetricRegistry@584cda2d
   [junit4]   2> 3326501 INFO  (SUITE-TestPullReplicaErrorHandling-seed#[5C4F9DE5439B7443]-worker) [    ] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.cluster, tag=null
   [junit4]   1> Done close org.apache.solr.common.util.ExecutorUtil$MDCAwareThreadPoolExecutor@8f72d30[Terminated, pool size = 0, active threads = 0, queued tasks = 0, completed tasks = 1]
   [junit4]   2> 3326502 INFO  (closeThreadPool-9269-thread-2) [    ] o.a.s.c.Overseer Overseer (id=73899435892473867-127.0.0.1:35665_solr-n_0000000001) closing
   [junit4]   1> Done close org.apache.solr.common.util.ExecutorUtil$MDCAwareThreadPoolExecutor@198c5f31[Terminated, pool size = 0, active threads = 0, queued tasks = 0, completed tasks = 1]
   [junit4]   2> 3326502 INFO  (OverseerStateUpdate-73899435892473867-127.0.0.1:35665_solr-n_0000000001) [n:127.0.0.1:35665_solr    ] o.a.s.c.Overseer Overseer Loop exiting : 127.0.0.1:35665_solr
   [junit4]   2> 3326503 INFO  (OverseerAutoScalingTriggerThread-73899435892473867-127.0.0.1:35665_solr-n_0000000001) [    ] o.a.s.c.a.OverseerTriggerThread OverseerTriggerThread woken up but we are closed, exiting.
   [junit4]   2> 3326515 WARN  (NIOServerCxn.Factory:0.0.0.0/0.0.0.0:0) [    ] o.a.z.s.NIOServerCnxn Unable to read additional data from client sessionid 0x1068b2539790010, likely client has closed socket
   [junit4]   2> 3326516 INFO  (zkCallback-9236-thread-1) [    ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (4) -> (3)
   [junit4]   2> 3326516 INFO  (zkCallback-9202-thread-1) [    ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (4) -> (3)
   [junit4]   2> 3326516 INFO  (zkCallback-9235-thread-1) [    ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (4) -> (3)
   [junit4]   2> 3326516 INFO  (zkCallback-9192-thread-2) [    ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (4) -> (3)
   [junit4]   2> 3326516 INFO  (zkCallback-9192-thread-1) [    ] o.a.s.c.OverseerElectionContext I am going to be the leader 127.0.0.1:43408_solr
   [junit4]   2> 3326517 INFO  (zkCallback-9192-thread-1) [n:127.0.0.1:43408_solr    ] o.a.s.c.Overseer Overseer (id=73899435892473865-127.0.0.1:43408_solr-n_0000000002) starting
   [junit4]   2> 3326518 DEBUG (closeThreadPool-9269-thread-2) [    ] o.a.s.c.a.ScheduledTriggers Shutting down scheduled thread pool executor now
   [junit4]   2> 3326518 DEBUG (closeThreadPool-9269-thread-2) [    ] o.a.s.c.a.ScheduledTriggers Shutting down action executor now
   [junit4]   2> 3326518 INFO  (zkCallback-9244-thread-1) [    ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (4) -> (3)
   [junit4]   2> 3326518 DEBUG (closeThreadPool-9269-thread-2) [    ] o.a.s.c.a.ScheduledTriggers Awaiting termination for action executor
   [junit4]   2> 3326518 DEBUG (closeThreadPool-9269-thread-2) [    ] o.a.s.c.a.ScheduledTriggers Awaiting termination for scheduled thread pool executor
   [junit4]   2> 3326518 DEBUG (closeThreadPool-9269-thread-2) [    ] o.a.s.c.a.ScheduledTriggers ScheduledTriggers closed completely
   [junit4]   2> 3326518 DEBUG (closeThreadPool-9269-thread-2) [    ] o.a.s.c.a.OverseerTriggerThread OverseerTriggerThread has been closed explicitly
   [junit4]   2> 3326518 INFO  (zkCallback-9264-thread-1) [    ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (4) -> (3)
   [junit4]   2> 3326518 INFO  (SUITE-TestPullReplicaErrorHandling-seed#[5C4F9DE5439B7443]-worker) [    ] o.a.s.c.Overseer Overseer (id=73899435892473867-127.0.0.1:35665_solr-n_0000000001) closing
   [junit4]   2> 3326518 INFO  (zkCallback-9257-thread-1) [    ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (4) -> (3)
   [junit4]   2> 3326518 INFO  (closeThreadPool-9269-thread-1) [    ] o.a.s.c.Overseer Overseer (id=73899435892473867-127.0.0.1:35665_solr-n_0000000001) closing
   [junit4]   2> 3326519 INFO  (SUITE-TestPullReplicaErrorHandling-seed#[5C4F9DE5439B7443]-worker) [    ] o.e.j.s.AbstractConnector Stopped ServerConnector@396c1c67{HTTP/1.1,[http/1.1, h2c]}{127.0.0.1:0}
   [junit4]   2> 3326519 INFO  (SUITE-TestPullReplicaErrorHandling-seed#[5C4F9DE5439B7443]-worker) [    ] o.e.j.s.h.ContextHandler Stopped o.e.j.s.ServletContextHandler@626d8839{/solr,null,UNAVAILABLE}
   [junit4]   2> 3326519 INFO  (SUITE-TestPullReplicaErrorHandling-seed#[5C4F9DE5439B7443]-worker) [    ] o.e.j.s.session node0 Stopped scavenging
   [junit4]   2> 3326520 INFO  (SUITE-TestPullReplicaErrorHandling-seed#[5C4F9DE5439B7443]-worker) [    ] o.a.s.c.s.e.JettySolrRunner Start Jetty (original configured port=0)
   [junit4]   2> 3326520 WARN  (SUITE-TestPullReplicaErrorHandling-seed#[5C4F9DE5439B7443]-worker) [    ] o.e.j.s.AbstractConnector Ignoring deprecated socket close linger time
   [junit4]   2> 3326520 INFO  (SUITE-TestPullReplicaErrorHandling-seed#[5C4F9DE5439B7443]-worker) [    ] o.a.s.c.s.e.JettySolrRunner Trying to start Jetty on port 0 try number 1 ...
   [junit4]   2> 3326520 INFO  (SUITE-TestPullReplicaErrorHandling-seed#[5C4F9DE5439B7443]-worker) [    ] o.e.j.s.Server jetty-9.4.14.v20181114; built: 2018-11-14T21:20:31.478Z; git: c4550056e785fb5665914545889f21dc136ad9e6; jvm 1.8.0_191-b12
   [junit4]   2> 3326533 INFO  (OverseerStateUpdate-73899435892473865-127.0.0.1:43408_solr-n_0000000002) [n:127.0.0.1:43408_solr    ] o.a.s.c.Overseer Starting to work on the main queue : 127.0.0.1:43408_solr
   [junit4]   2> 3326534 DEBUG (OverseerAutoScalingTriggerThread-73899435892473865-127.0.0.1:43408_solr-n_0000000002) [    ] o.a.s.c.a.OverseerTriggerThread Refreshing /autoscaling.json with znode version 1
   [junit4]   2> 3326534 INFO  (SUITE-TestPullReplicaErrorHandling-seed#[5C4F9DE5439B7443]-worker) [    ] o.e.j.s.session DefaultSessionIdManager workerName=node0
   [junit4]   2> 3326534 INFO  (SUITE-TestPullReplicaErrorHandling-seed#[5C4F9DE5439B7443]-worker) [    ] o.e.j.s.session No SessionScavenger set, using defaults
   [junit4]   2> 3326534 INFO  (SUITE-TestPullReplicaErrorHandling-seed#[5C4F9DE5439B7443]-worker) [    ] o.e.j.s.session node0 Scavenging every 600000ms
   [junit4]   2> 3326534 DEBUG (OverseerAutoScalingTriggerThread-73899435892473865-127.0.0.1:43408_solr-n_0000000002) [    ] o.a.s.c.a.OverseerTriggerThread Current znodeVersion 1, lastZnodeVersion 0
   [junit4]   2> 3326534 DEBUG (OverseerAutoScalingTriggerThread-73899435892473865-127.0.0.1:43408_solr-n_0000000002) [    ] o.a.s.c.a.OverseerTriggerThread Processed trigger updates upto znodeVersion 1
   [junit4]   2> 3326534 INFO  (SUITE-TestPullReplicaErrorHandling-seed#[5C4F9DE5439B7443]-worker) [    ] o.e.j.s.h.ContextHandler Started o.e.j.s.ServletContextHandler@6775519{/solr,null,AVAILABLE}
   [junit4]   2> 3326540 INFO  (SUITE-TestPullReplicaErrorHandling-seed#[5C4F9DE5439B7443]-worker) [    ] o.e.j.s.AbstractConnector Started ServerConnector@67fa41ce{HTTP/1.1,[http/1.1, h2c]}{127.0.0.1:33034}
   [junit4]   2> 3326540 INFO  (SUITE-TestPullReplicaErrorHandling-seed#[5C4F9DE5439B7443]-worker) [    ] o.e.j.s.Server Started @3326643ms
   [junit4]   2> 3326540 INFO  (SUITE-TestPullReplicaErrorHandling-seed#[5C4F9DE5439B7443]-worker) [    ] o.a.s.c.s.e.JettySolrRunner Jetty properties: {hostContext=/solr, hostPort=33769}
   [junit4]   2> 3326540 ERROR (SUITE-TestPullReplicaErrorHandling-seed#[5C4F9DE5439B7443]-worker) [    ] o.a.s.u.StartupLoggingUtils Missing Java Option solr.log.dir. Logging may be missing or incomplete.
   [junit4]   2> 3326540 INFO  (SUITE-TestPullReplicaErrorHandling-seed#[5C4F9DE5439B7443]-worker) [    ] o.a.s.s.SolrDispatchFilter Using logger factory org.apache.logging.slf4j.Log4jLoggerFactory
   [junit4]   2> 3326540 INFO  (SUITE-TestPullReplicaErrorHandling-seed#[5C4F9DE5439B7443]-worker) [    ] o.a.s.s.SolrDispatchFilter  ___      _       Welcome to Apache Solr™ version 8.0.0
   [junit4]   2> 3326540 INFO  (SUITE-TestPullReplicaErrorHandling-seed#[5C4F9DE5439B7443]-worker) [    ] o.a.s.s.SolrDispatchFilter / __| ___| |_ _   Starting in cloud mode on port null
   [junit4]   2> 3326540 INFO  (SUITE-TestPullReplicaErrorHandling-seed#[5C4F9DE5439B7443]-worker) [    ] o.a.s.s.SolrDispatchFilter \__ \/ _ \ | '_|  Install dir: null
   [junit4]   2> 3326540 INFO  (SUITE-TestPullReplicaErrorHandling-seed#[5C4F9DE5439B7443]-worker) [    ] o.a.s.s.SolrDispatchFilter |___/\___/_|_|    Start time: 2018-12-25T19:41:17.051Z
   [junit4]   2> 3326562 DEBUG (OverseerAutoScalingTriggerThread-73899435892473865-127.0.0.1:43408_solr-n_0000000002) [    ] o.a.s.c.a.NodeLostTrigger NodeLostTrigger .auto_add_replicas - Initial livenodes: [127.0.0.1:41059_solr, 127.0.0.1:43408_solr, 127.0.0.1:37917_solr]
   [junit4]   2> 3326562 DEBUG (OverseerAutoScalingTriggerThread-73899435892473865-127.0.0.1:43408_solr-n_0000000002) [    ] o.a.s.c.a.NodeLostTrigger Adding lost node from marker path: 127.0.0.1:35665_solr
   [junit4]   2> 3326562 DEBUG (OverseerStateUpdate-73899435892473865-127.0.0.1:43408_solr-n_0000000002) [n:127.0.0.1:43408_solr    ] o.a.s.c.Overseer processMessage: queueSize: 1, message = {
   [junit4]   2>   "operation":"downnode",
   [junit4]   2>   "node_name":"127.0.0.1:35665_solr"} current state version: 0
   [junit4]   2> 3326562 INFO  (zkConnectionManagerCallback-9271-thread-1) [    ] o.a.s.c.c.ConnectionManager zkClient has connected
   [junit4]   2> 3326563 DEBUG (OverseerAutoScalingTriggerThread-73899435892473865-127.0.0.1:43408_solr-n_0000000002) [    ] o.a.s.c.a.OverseerTriggerThread -- cleaning old nodeLost / nodeAdded markers
   [junit4]   2> 3326563 INFO  (SUITE-TestPullReplicaErrorHandling-seed#[5C4F9DE5439B7443]-worker) [    ] o.a.s.s.SolrDispatchFilter solr.xml found in ZooKeeper. Loading...
   [junit4]   2> 3326568 DEBUG (OverseerAutoScalingTriggerThread-73899435892473865-127.0.0.1:43408_solr-n_0000000002) [    ] o.a.s.c.a.OverseerTriggerThread Current znodeVersion 1, lastZnodeVersion 1
   [junit4]   2> 3326585 DEBUG (ScheduledTrigger-7340-thread-2) [    ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 3 and last live nodes: 3
   [junit4]   2> 3326586 DEBUG (ScheduledTrigger-7340-thread-2) [    ] o.a.s.c.a.NodeLostTrigger Tracking lost node: 127.0.0.1:35665_solr
   [junit4]   2> 3326745 WARN  (SUITE-TestPullReplicaErrorHandling-seed#[5C4F9DE5439B7443]-worker) [    ] o.e.j.u.s.S.config No Client EndPointIdentificationAlgorithm configured for SslContextFactory@6259623f[provider=null,keyStore=null,trustStore=null]
   [junit4]   2> 3326760 WARN  (SUITE-TestPullReplicaErrorHandling-seed#[5C4F9DE5439B7443]-worker) [    ] o.e.j.u.s.S.config No Client EndPointIdentificationAlgorithm configured for SslContextFactory@125f86aa[provider=null,keyStore=null,trustStore=null]
   [junit4]   2> 3326761 INFO  (SUITE-TestPullReplicaErrorHandling-seed#[5C4F9DE5439B7443]-worker) [    ] o.a.s.c.ZkContainer Zookeeper client=127.0.0.1:37948/solr
   [junit4]   2> 3326762 INFO  (zkConnectionManagerCallback-9277-thread-1) [    ] o.a.s.c.c.ConnectionManager zkClient has connected
   [junit4]   2> 3326764 INFO  (zkConnectionManagerCallback-9279-thread-1) [    ] o.a.s.c.c.ConnectionManager zkClient has connected
   [junit4]   2> 3326776 INFO  (SUITE-TestPullReplicaErrorHandling-seed#[5C4F9DE5439B7443]-worker) [    ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (3)
   [junit4]   2> 3326779 INFO  (SUITE-TestPullReplicaErrorHandling-seed#[5C4F9DE5439B7443]-worker) [    ] o.a.s.c.ZkController Publish node=127.0.0.1:33769_solr as DOWN
   [junit4]   2> 3326780 INFO  (SUITE-TestPullReplicaErrorHandling-seed#[5C4F9DE5439B7443]-worker) [    ] o.a.s.c.TransientSolrCoreCacheDefault Allocating transient cache for 2147483647 transient cores
   [junit4]   2> 3326780 INFO  (SUITE-TestPullReplicaErrorHandling-seed#[5C4F9DE5439B7443]-worker) [    ] o.a.s.c.ZkController Register node as live in ZooKeeper:/live_nodes/127.0.0.1:33769_solr
   [junit4]   2> 3326780 DEBUG (OverseerStateUpdate-73899435892473865-127.0.0.1:43408_solr-n_0000000002) [n:127.0.0.1:43408_solr    ] o.a.s.c.Overseer processMessage: queueSize: 1, message = {
   [junit4]   2>   "operation":"downnode",
   [junit4]   2>   "node_name":"127.0.0.1:33769_solr"} current state version: 0
   [junit4]   2> 3326781 INFO  (zkCallback-9264-thread-1) [    ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (3) -> (4)
   [junit4]   2> 3326781 INFO  (zkCallback-9257-thread-1) [    ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (3) -> (4)
   [junit4]   2> 3326781 INFO  (zkCallback-9235-thread-1) [    ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (3) -> (4)
   [junit4]   2> 3326781 INFO  (zkCallback-9202-thread-1) [    ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (3) -> (4)
   [junit4]   2> 3326781 INFO  (zkCallback-9236-thread-1) [    ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (3) -> (4)
   [junit4]   2> 3326781 INFO  (zkCallback-9244-thread-1) [    ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (3) -> (4)
   [junit4]   2> 3326781 INFO  (zkCallback-9192-thread-1) [    ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (3) -> (4)
   [junit4]   2> 3326781 INFO  (zkCallback-9278-thread-1) [    ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (3) -> (4)
   [junit4]   2> 3326830 INFO  (zkConnectionManagerCallback-9286-thread-1) [    ] o.a.s.c.c.ConnectionManager zkClient has connected
   [junit4]   2> 3326831 INFO  (SUITE-TestPullReplicaErrorHandling-seed#[5C4F9DE5439B7443]-worker) [    ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (4)
   [junit4]   2> 3326832 INFO  (SUITE-TestPullReplicaErrorHandling-seed#[5C4F9DE5439B7443]-worker) [    ] o.a.s.c.s.i.ZkClientClusterStateProvider Cluster at 127.0.0.1:37948/solr ready
   [junit4]   2> 3326832 INFO  (SUITE-TestPullReplicaErrorHandling-seed#[5C4F9DE5439B7443]-worker) [    ] o.a.s.h.a.MetricsHistoryHandler No .system collection, keeping metrics history in memory.
   [junit4]   2> 3326879 INFO  (SUITE-TestPullReplicaErrorHandling-seed#[5C4F9DE5439B7443]-worker) [    ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_33769.solr.node' (registry 'solr.node') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@61c5f0a1
   [junit4]   2> 3326908 INFO  (SUITE-TestPullReplicaErrorHandling-seed#[5C4F9DE5439B7443]-worker) [    ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_33769.solr.jvm' (registry 'solr.jvm') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@61c5f0a1
   [junit4]   2> 3326908 INFO  (SUITE-TestPullReplicaErrorHandling-seed#[5C4F9DE5439B7443]-worker) [    ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_33769.solr.jetty' (registry 'solr.jetty') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@61c5f0a1
   [junit4]   2> 3326909 INFO  (SUITE-TestPullReplicaErrorHandling-seed#[5C4F9DE5439B7443]-worker) [    ] o.a.s.c.CorePropertiesLocator Found 0 core definitions underneath /home/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-master/solr/build/solr-core/test/J0/temp/solr.cloud.TestPullReplicaErrorHandling_5C4F9DE5439B7443-001/tempDir-001/node1/.
   [junit4]   2> 3326995 INFO  (SUITE-TestPullReplicaErrorHandling-seed#[5C4F9DE5439B7443]-worker) [    ] o.a.s.c.TestPullReplicaErrorHandling Adding proxy for URL: http://127.0.0.1:33034/solr. Proxy: http://127.0.0.1:33769/solr
   [junit4]   2> 3326995 INFO  (SUITE-TestPullReplicaErrorHandling-seed#[5C4F9DE5439B7443]-worker) [    ] o.a.s.c.CoreContainer Shutting down CoreContainer instance=1740469341
   [junit4]   2> 3326995 INFO  (SUITE-TestPullReplicaErrorHandling-seed#[5C4F9DE5439B7443]-worker) [    ] o.a.s.c.ZkController Remove node as live in ZooKeeper:/live_nodes/127.0.0.1:43408_solr
   [junit4]   2> 3326996 INFO  (SUITE-TestPullReplicaErrorHandling-seed#[5C4F9DE5439B7443]-worker) [    ] o.a.s.c.CoreContainer Publish this node as DOWN...
   [junit4]   2> 3326996 INFO  (SUITE-TestPullReplicaErrorHandling-seed#[5C4F9DE5439B7443]-worker) [    ] o.a.s.c.ZkController Publish node=127.0.0.1:43408_solr as DOWN
   [junit4]   2> 3326997 DEBUG (OverseerStateUpdate-73899435892473865-127.0.0.1:43408_solr-n_0000000002) [n:127.0.0.1:43408_solr    ] o.a.s.c.Overseer processMessage: queueSize: 1, message = {
   [junit4]   2>   "operation":"downnode",
   [junit4]   2>   "node_name":"127.0.0.1:43408_solr"} current state version: 0
   [junit4]   2> 3326997 INFO  (SUITE-TestPullReplicaErrorHandling-seed#[5C4F9DE5439B7443]-worker) [    ] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.node, tag=null
   [junit4]   2> 3326997 INFO  (SUITE-TestPullReplicaErrorHandling-seed#[5C4F9DE5439B7443]-worker) [    ] o.a.s.m.r.SolrJmxReporter Closing reporter [org.apache.solr.metrics.reporters.SolrJmxReporter@3810b36f: rootName = solr_43408, domain = solr.node, service url = null, agent id = null] for registry solr.node / com.codahale.metrics.MetricRegistry@374d389a
   [junit4]   2> 3327014 INFO  (SUITE-TestPullReplicaErrorHandling-seed#[5C4F9DE5439B7443]-worker) [    ] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.jvm, tag=null
   [junit4]   2> 3327014 INFO  (SUITE-TestPullReplicaErrorHandling-seed#[5C4F9DE5439B7443]-worker) [    ] o.a.s.m.r.SolrJmxReporter Closing reporter [org.apache.solr.metrics.reporters.SolrJmxReporter@1d58aca7: rootName = solr_43408, domain = solr.jvm, service url = null, agent id = null] for registry solr.jvm / com.codahale.metrics.MetricRegistry@7925b85e
   [junit4]   2> 3327024 INFO  (SUITE-TestPullReplicaErrorHandling-seed#[5C4F9DE5439B7443]-worker) [    ] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.jetty, tag=null
   [junit4]   2> 3327024 INFO  (SUITE-TestPullReplicaErrorHandling-seed#[5C4F9DE5439B7443]-worker) [    ] o.a.s.m.r.SolrJmxReporter Closing reporter [org.apache.solr.metrics.reporters.SolrJmxReporter@63178675: rootName = solr_43408, domain = solr.jetty, service url = null, agent id = null] for registry solr.jetty / com.codahale.metrics.MetricRegistry@584cda2d
   [junit4]   2> 3327025 INFO  (SUITE-TestPullReplicaErrorHandling-seed#[5C4F9DE5439B7443]-worker) [    ] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.cluster, tag=null
   [junit4]   2> 3327025 INFO  (closeThreadPool-9290-thread-2) [    ] o.a.s.c.Overseer Overseer (id=73899435892473865-127.0.0.1:43408_solr-n_0000000002) closing
   [junit4]   1> Done close org.apache.solr.common.util.ExecutorUtil$MDCAwareThreadPoolExecutor@72aecf2c[Terminated, pool size = 0, active threads = 0, queued tasks = 0, completed tasks = 1]
   [junit4]   2> 3327025 INFO  (OverseerStateUpdate-73899435892473865-127.0.0.1:43408_solr-n_0000000002) [n:127.0.0.1:43408_solr    ] o.a.s.c.Overseer Overseer Loop exiting : 127.0.0.1:43408_solr
   [junit4]   1> Done close org.apache.solr.common.util.ExecutorUtil$MDCAwareThreadPoolExecutor@1a50cc1f[Terminated, pool size = 0, active threads = 0, queued tasks = 0, completed tasks = 1]
   [junit4]   2> 3327039 INFO  (OverseerAutoScalingTriggerThread-73899435892473865-127.0.0.1:43408_solr-n_0000000002) [    ] o.a.s.c.a.OverseerTriggerThread OverseerTriggerThread woken up but we are closed, exiting.
   [junit4]   2> 3327041 DEBUG (closeThreadPool-9290-thread-2) [    ] o.a.s.c.a.ScheduledTriggers Shutting down scheduled thread pool executor now
   [junit4]   2> 3327041 DEBUG (closeThreadPool-9290-thread-2) [    ] o.a.s.c.a.ScheduledTriggers Shutting down action executor now
   [junit4]   2> 3327041 DEBUG (closeThreadPool-9290-thread-2) [    ] o.a.s.c.a.ScheduledTriggers Awaiting termination for action executor
   [junit4]   2> 3327041 DEBUG (closeThreadPool-9290-thread-2) [    ] o.a.s.c.a.ScheduledTriggers Awaiting termination for scheduled thread pool executor
   [junit4]   2> 3327041 DEBUG (closeThreadPool-9290-thread-2) [    ] o.a.s.c.a.ScheduledTriggers ScheduledTriggers closed completely
   [junit4]   2> 3327041 DEBUG (closeThreadPool-9290-thread-2) [    ] o.a.s.c.a.OverseerTriggerThread OverseerTriggerThread has been closed explicitly
   [junit4]   2> 3327042 INFO  (closeThreadPool-9290-thread-1) [    ] o.a.s.c.Overseer Overseer (id=73899435892473865-127.0.0.1:43408_solr-n_0000000002) closing
   [junit4]   2> 3327042 INFO  (SUITE-TestPullReplicaErrorHandling-seed#[5C4F9DE5439B7443]-worker) [    ] o.a.s.c.Overseer Overseer (id=73899435892473865-127.0.0.1:43408_solr-n_0000000002) closing
   [junit4]   2> 3327042 INFO  (zkCallback-9244-thread-1) [    ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (4) -> (3)
   [junit4]   2> 3327042 INFO  (zkCallback-9264-thread-1) [    ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (4) -> (3)
   [junit4]   2> 3327043 INFO  (zkCallback-9257-thread-1) [    ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (4) -> (3)
   [junit4]   2> 3327043 INFO  (zkCallback-9236-thread-1) [    ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (4) -> (3)
   [junit4]   2> 3327043 INFO  (zkCallback-9202-thread-1) [    ] o.a.s.c.OverseerElectionContext I am going to be the leader 127.0.0.1:41059_solr
   [junit4]   2> 3327051 INFO  (zkCallback-9285-thread-1) [    ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (4) -> (3)
   [junit4]   2> 3327056 INFO  (zkCallback-9202-thread-2) [    ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (4) -> (3)
   [junit4]   2> 3327067 INFO  (zkCallback-9278-thread-1) [    ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (4) -> (3)
   [junit4]   2> 3327068 INFO  (zkCallback-9202-thread-1) [n:127.0.0.1:41059_solr    ] o.a.s.c.Overseer Overseer (id=73899435892473868-127.0.0.1:41059_solr-n_0000000003) starting
   [junit4]   2> 3327068 INFO  (SUITE-TestPullReplicaErrorHandling-seed#[5C4F9DE5439B7443]-worker) [    ] o.e.j.s.AbstractConnector Stopped ServerConnector@4b96c83b{HTTP/1.1,[http/1.1, h2c]}{127.0.0.1:0}
   [junit4]   2> 3327068 INFO  (SUITE-TestPullReplicaErrorHandling-seed#[5C4F9DE5439B7443]-worker) [    ] o.e.j.s.h.ContextHandler Stopped o.e.j.s.ServletContextHandler@249be9cd{/solr,null,UNAVAILABLE}
   [junit4]   2> 3327068 INFO  (SUITE-TestPullReplicaErrorHandling-seed#[5C4F9DE5439B7443]-worker) [    ] o.e.j.s.session node0 Stopped scavenging
   [junit4]   2> 3327069 INFO  (SUITE-TestPullReplicaErrorHandling-seed#[5C4F9DE5439B7443]-worker) [    ] o.a.s.c.s.e.JettySolrRunner Start Jetty (original configured port=0)
   [junit4]   2> 3327069 WARN  (SUITE-TestPullReplicaErrorHandling-seed#[5C4F9DE5439B7443]-worker) [    ] o.e.j.s.AbstractConnector Ignoring deprecated socket close linger time
   [junit4]   2> 3327069 INFO  (SUITE-TestPullReplicaErrorHandling-seed#[5C4F9DE5439B7443]-worker) [    ] o.a.s.c.s.e.JettySolrRunner Trying to start Jetty on port 0 try number 1 ...
   [junit4]   2> 3327069 INFO  (SUITE-TestPullReplicaErrorHandling-seed#[5C4F9DE5439B7443]-worker) [    ] o.e.j.s.Server jetty-9.4.14.v20181114; built: 2018-11-14T21:20:31.478Z; git: c4550056e785fb5665914545889f21dc136ad9e6; jvm 1.8.0_191-b12
   [junit4]   2> 3327070 INFO  (SUITE-TestPullReplicaErrorHandling-seed#[5C4F9DE5439B7443]-worker) [    ] o.e.j.s.session DefaultSessionIdManager workerName=node0
   [junit4]   2> 3327070 INFO  (SUITE-TestPullReplicaErrorHandling-seed#[5C4F9DE5439B7443]-worker) [    ] o.e.j.s.session No SessionScavenger set, using defaults
   [junit4]   2> 3327070 INFO  (SUITE-TestPullReplicaErrorHandling-seed#[5C4F9DE5439B7443]-worker) [    ] o.e.j.s.session node0 Scavenging every 600000ms
   [junit4]   2> 3327070 INFO  (SUITE-TestPullReplicaErrorHandling-seed#[5C4F9DE5439B7443]-worker) [    ] o.e.j.s.h.ContextHandler Started o.e.j.s.ServletContextHandler@3baf1f07{/solr,null,AVAILABLE}
   [junit4]   2> 3327071 INFO  (SUITE-TestPullReplicaErrorHandling-seed#[5C4F9DE5439B7443]-worker) [    ] o.e.j.s.AbstractConnector Started ServerConnector@58319ca0{HTTP/1.1,[http/1.1, h2c]}{127.0.0.1:41330}
   [junit4]   2> 3327071 INFO  (SUITE-TestPullReplicaErrorHandling-seed#[5C4F9DE5439B7443]-worker) [    ] o.e.j.s.Server Started @3327175ms
   [junit4]   2> 3327071 INFO  (SUITE-TestPullReplicaErrorHandling-seed#[5C4F9DE5439B7443]-worker) [    ] o.a.s.c.s.e.JettySolrRunner Jetty properties: {hostContext=/solr, hostPort=40903}
   [junit4]   2> 3327071 ERROR (SUITE-TestPullReplicaErrorHandling-seed#[5C4F9DE5439B7443]-worker) [    ] o.a.s.u.StartupLoggingUtils Missing Java Option solr.log.dir. Logging may be missing or incomplete.
   [junit4]   2> 3327071 INFO  (SUITE-TestPullReplicaErrorHandling-seed#[5C4F9DE5439B7443]-worker) [    ] o.a.s.s.SolrDispatchFilter Using logger factory org.apache.logging.slf4j.Log4jLoggerFactory
   [junit4]   2> 3327071 INFO  (SUITE-TestPullReplicaErrorHandling-seed#[5C4F9DE5439B7443]-worker) [    ] o.a.s.s.SolrDispatchFilter  ___      _       Welcome to Apache Solr™ version 8.0.0
   [junit4]   2> 3327071 INFO  (SUITE-TestPullReplicaErrorHandling-seed#[5C4F9DE5439B7443]-worker) [    ] o.a.s.s.SolrDispatchFilter / __| ___| |_ _   Starting in cloud mode on port null
   [junit4]   2> 3327071 INFO  (SUITE-TestPullReplicaErrorHandling-seed#[5C4F9DE5439B7443]-worker) [    ] o.a.s.s.SolrDispatchFilter \__ \/ _ \ | '_|  Install dir: null
   [junit4]   2> 3327071 INFO  (SUITE-TestPullReplicaErrorHandling-seed#[5C4F9DE5439B7443]-worker) [    ] o.a.s.s.SolrDispatchFilter |___/\___/_|_|    Start time: 2018-12-25T19:41:17.582Z
   [junit4]   2> 3327080 INFO  (zkConnectionManagerCallback-9292-thread-1) [    ] o.a.s.c.c.ConnectionManager zkClient has connected
   [junit4]   2> 3327080 INFO  (SUITE-TestPullReplicaErrorHandling-seed#[5C4F9DE5439B7443]-worker) [    ] o.a.s.s.SolrDispatchFilter solr.xml found in ZooKeeper. Loading...
   [junit4]   2> 3327080 INFO  (OverseerStateUpdate-73899435892473868-127.0.0.1:41059_solr-n_0000000003) [n:127.0.0.1:41059_solr    ] o.a.s.c.Overseer Starting to work on the main queue : 127.0.0.1:41059_solr
   [junit4]   2> 3327086 DEBUG (OverseerAutoScalingTriggerThread-73899435892473868-127.0.0.1:41059_solr-n_0000000003) [    ] o.a.s.c.a.OverseerTriggerThread Refreshing /autoscaling.json with znode version 1
   [junit4]   2> 3327108 DEBUG (OverseerStateUpdate-73899435892473868-127.0.0.1:41059_solr-n_0000000003) [n:127.0.0.1:41059_solr    ] o.a.s.c.Overseer processMessage: queueSize: 1, message = {
   [junit4]   2>   "operation":"downnode",
   [junit4]   2>   "node_name":"127.0.0.1:43408_solr"} current state version: 0
   [junit4]   2> 3327109 DEBUG (OverseerAutoScalingTriggerThread-73899435892473868-127.0.0.1:41059_solr-n_0000000003) [    ] o.a.s.c.a.OverseerTriggerThread Current znodeVersion 1, lastZnodeVersion 0
   [junit4]   2> 3327109 DEBUG (OverseerAutoScalingTriggerThread-73899435892473868-127.0.0.1:41059_solr-n_0000000003) [    ] o.a.s.c.a.OverseerTriggerThread Processed trigger updates upto znodeVersion 1
   [junit4]   2> 3327112 DEBUG (OverseerAutoScalingTriggerThread-73899435892473868-127.0.0.1:41059_solr-n_0000000003) [    ] o.a.s.c.a.NodeLostTrigger NodeLostTrigger .auto_add_replicas - Initial livenodes: [127.0.0.1:41059_solr, 127.0.0.1:33769_solr, 127.0.0.1:37917_solr]
   [junit4]   2> 3327113 DEBUG (OverseerAutoScalingTriggerThread-73899435892473868-127.0.0.1:41059_solr-n_0000000003) [    ] o.a.s.c.a.NodeLostTrigger Adding lost node from marker path: 127.0.0.1:43408_solr
   [junit4]   2> 3327113 DEBUG (OverseerAutoScalingTriggerThread-73899435892473868-127.0.0.1:41059_solr-n_0000000003) [    ] o.a.s.c.a.OverseerTriggerThread -- cleaning old nodeLost / nodeAdded markers
   [junit4]   2> 3327132 DEBUG (OverseerAutoScalingTriggerThread-73899435892473868-127.0.0.1:41059_solr-n_0000000003) [    ] o.a.s.c.a.OverseerTriggerThread Current znodeVersion 1, lastZnodeVersion 1
   [junit4]   2> 3327132 DEBUG (ScheduledTrigger-7354-thread-2) [    ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 3 and last live nodes: 3
   [junit4]   2> 3327132 DEBUG (ScheduledTrigger-7354-thread-2) [    ] o.a.s.c.a.NodeLostTrigger Tracking lost node: 127.0.0.1:43408_solr
   [junit4]   2> 3328134 DEBUG (ScheduledTrigger-7354-thread-3) [    ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 3 and last live nodes: 3
   [junit4]   2> 3328269 WARN  (SUITE-TestPullReplicaErrorHandling-seed#[5C4F9DE5439B7443]-worker) [    ] o.e.j.u.s.S.config No Client EndPointIdentificationAlgorithm configured for SslContextFactory@51e1f72d[provider=null,keyStore=null,trustStore=null]
   [junit4]   2> 3328272 WARN  (SUITE-TestPullReplicaErrorHandling-seed#[5C4F9DE5439B7443]-worker) [    ] o.e.j.u.s.S.config No Client EndPointIdentificationAlgorithm configured for SslContextFactory@6581a3a0[provider=null,keyStore=null,trustStore=null]
   [junit4]   2> 3328273 INFO  (SUITE-TestPullReplicaErrorHandling-seed#[5C4F9DE5439B7443]-worker) [    ] o.a.s.c.ZkContainer Zookeeper client=127.0.0.1:37948/solr
   [junit4]   2> 3328274 INFO  (zkConnectionManagerCallback-9298-thread-1) [    ] o.a.s.c.c.ConnectionManager zkClient has connected
   [junit4]   2> 3328288 INFO  (zkConnectionManagerCallback-9300-thread-1) [    ] o.a.s.c.c.ConnectionManager zkClient has connected
   [junit4]   2> 3328300 INFO  (SUITE-TestPullReplicaErrorHandling-seed#[5C4F9DE5439B7443]-worker) [    ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (3)
   [junit4]   2> 3328303 INFO  (SUITE-TestPullReplicaErrorHandling-seed#[5C4F9DE5439B7443]-worker) [    ] o.a.s.c.ZkController Publish node=127.0.0.1:40903_solr as DOWN
   [junit4]   2> 3328304 INFO  (SUITE-TestPullReplicaErrorHandling-seed#[5C4F9DE5439B7443]-worker) [    ] o.a.s.c.TransientSolrCoreCacheDefault Allocating transient cache for 2147483647 transient cores
   [junit4]   2> 3328304 INFO  (SUITE-TestPullReplicaErrorHandling-seed#[5C4F9DE5439B7443]-worker) [    ] o.a.s.c.ZkController Register node as live in ZooKeeper:/live_nodes/127.0.0.1:40903_solr
   [junit4]   2> 3328305 DEBUG (OverseerStateUpdate-73899435892473868-127.0.0.1:41059_solr-n_0000000003) [n:127.0.0.1:41059_solr    ] o.a.s.c.Overseer processMessage: queueSize: 1, message = {
   [junit4]   2>   "operation":"downnode",
   [junit4]   2>   "node_name":"127.0.0.1:40903_solr"} current state version: 0
   [junit4]   2> 3328306 INFO  (zkCallback-9278-thread-1) [    ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (3) -> (4)
   [junit4]   2> 3328306 INFO  (zkCallback-9257-thread-1) [    ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (3) -> (4)
   [junit4]   2> 3328306 INFO  (zkCallback-9244-thread-1) [    ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (3) -> (4)
   [junit4]   2> 3328306 INFO  (zkCallback-9236-thread-1) [    ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (3) -> (4)
   [junit4]   2> 3328306 INFO  (zkCallback-9264-thread-1) [    ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (3) -> (4)
   [junit4]   2> 3328306 INFO  (zkCallback-9202-thread-1) [    ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (3) -> (4)
   [junit4]   2> 3328306 INFO  (zkCallback-9285-thread-1) [    ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (3) -> (4)
   [junit4]   2> 3328306 INFO  (zkCallback-9299-thread-1) [    ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (3) -> (4)
   [junit4]   2> 3328355 INFO  (zkConnectionManagerCallback-9307-thread-1) [    ] o.a.s.c.c.ConnectionManager zkClient has connected
   [junit4]   2> 3328356 INFO  (SUITE-TestPullReplicaErrorHandling-seed#[5C4F9DE5439B7443]-worker) [    ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (4)
   [junit4]   2> 3328357 INFO  (SUITE-TestPullReplicaErrorHandling-seed#[5C4F9DE5439B7443]-worker) [    ] o.a.s.c.s.i.ZkClientClusterStateProvider Cluster at 127.0.0.1:37948/solr ready
   [junit4]   2> 3328357 INFO  (SUITE-TestPullReplicaErrorHandling-seed#[5C4F9DE5439B7443]-worker) [    ] o.a.s.h.a.MetricsHistoryHandler No .system collection, keeping metrics history in memory.
   [junit4]   2> 3328393 INFO  (SUITE-TestPullReplicaErrorHandling-seed#[5C4F9DE5439B7443]-worker) [  

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



-ivy-fail-disallowed-ivy-version:

ivy-fail:

ivy-fail:

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

resolve:

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

-ivy-fail-disallowed-ivy-version:

ivy-fail:

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

resolve:

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

-ivy-fail-disallowed-ivy-version:

ivy-fail:

ivy-fail:

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

resolve:

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

-ivy-fail-disallowed-ivy-version:

ivy-fail:

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

resolve:

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

-ivy-fail-disallowed-ivy-version:

ivy-fail:

ivy-fail:

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

resolve:

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

-ivy-fail-disallowed-ivy-version:

ivy-fail:

ivy-fail:

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

resolve:

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

-ivy-fail-disallowed-ivy-version:

ivy-fail:

ivy-fail:

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

resolve:

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

-ivy-fail-disallowed-ivy-version:

ivy-fail:

ivy-fail:

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

resolve:

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

-ivy-fail-disallowed-ivy-version:

ivy-fail:

ivy-fail:

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

resolve:

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

-ivy-fail-disallowed-ivy-version:

ivy-fail:

ivy-fail:

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

resolve:

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

-ivy-fail-disallowed-ivy-version:

ivy-fail:

ivy-fail:

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

resolve:

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

-ivy-fail-disallowed-ivy-version:

ivy-fail:

ivy-fail:

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

resolve:

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

-ivy-fail-disallowed-ivy-version:

ivy-fail:

ivy-fail:

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

resolve:

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

-ivy-fail-disallowed-ivy-version:

ivy-fail:

ivy-fail:

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

resolve:

jar-checksums:
    [mkdir] Created dir: /home/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-master/solr/null273504878
     [copy] Copying 256 files to /home/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-master/solr/null273504878
   [delete] Deleting directory /home/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-master/solr/null273504878

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

-jenkins-base:

BUILD SUCCESSFUL
Total time: 208 minutes 28 seconds
Archiving artifacts
java.lang.InterruptedException: no matches found within 10000
	at hudson.FilePath$34.hasMatch(FilePath.java:2678)
	at hudson.FilePath$34.invoke(FilePath.java:2557)
	at hudson.FilePath$34.invoke(FilePath.java:2547)
	at hudson.FilePath$FileCallableWrapper.call(FilePath.java:2918)
Also:   hudson.remoting.Channel$CallSiteStackTrace: Remote call to lucene2
		at hudson.remoting.Channel.attachCallSiteStackTrace(Channel.java:1741)
		at hudson.remoting.UserRequest$ExceptionResponse.retrieve(UserRequest.java:357)
		at hudson.remoting.Channel.call(Channel.java:955)
		at hudson.FilePath.act(FilePath.java:1036)
		at hudson.FilePath.act(FilePath.java:1025)
		at hudson.FilePath.validateAntFileMask(FilePath.java:2547)
		at hudson.tasks.ArtifactArchiver.perform(ArtifactArchiver.java:243)
		at hudson.tasks.BuildStepCompatibilityLayer.perform(BuildStepCompatibilityLayer.java:81)
		at hudson.tasks.BuildStepMonitor$1.perform(BuildStepMonitor.java:20)
		at hudson.model.AbstractBuild$AbstractBuildExecution.perform(AbstractBuild.java:744)
		at hudson.model.AbstractBuild$AbstractBuildExecution.performAllBuildSteps(AbstractBuild.java:690)
		at hudson.model.Build$BuildExecution.post2(Build.java:186)
		at hudson.model.AbstractBuild$AbstractBuildExecution.post(AbstractBuild.java:635)
		at hudson.model.Run.execute(Run.java:1819)
		at hudson.model.FreeStyleBuild.run(FreeStyleBuild.java:43)
		at hudson.model.ResourceController.execute(ResourceController.java:97)
		at hudson.model.Executor.run(Executor.java:429)
Caused: hudson.FilePath$TunneledInterruptedException
	at hudson.FilePath$FileCallableWrapper.call(FilePath.java:2920)
	at hudson.remoting.UserRequest.perform(UserRequest.java:212)
	at hudson.remoting.UserRequest.perform(UserRequest.java:54)
	at hudson.remoting.Request$2.run(Request.java:369)
	at hudson.remoting.InterceptingExecutorService$1.call(InterceptingExecutorService.java:72)
	at java.util.concurrent.FutureTask.run(FutureTask.java:266)
	at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142)
	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
	at java.lang.Thread.run(Thread.java:748)
Caused: java.lang.InterruptedException: java.lang.InterruptedException: no matches found within 10000
	at hudson.FilePath.act(FilePath.java:1038)
	at hudson.FilePath.act(FilePath.java:1025)
	at hudson.FilePath.validateAntFileMask(FilePath.java:2547)
	at hudson.tasks.ArtifactArchiver.perform(ArtifactArchiver.java:243)
	at hudson.tasks.BuildStepCompatibilityLayer.perform(BuildStepCompatibilityLayer.java:81)
	at hudson.tasks.BuildStepMonitor$1.perform(BuildStepMonitor.java:20)
	at hudson.model.AbstractBuild$AbstractBuildExecution.perform(AbstractBuild.java:744)
	at hudson.model.AbstractBuild$AbstractBuildExecution.performAllBuildSteps(AbstractBuild.java:690)
	at hudson.model.Build$BuildExecution.post2(Build.java:186)
	at hudson.model.AbstractBuild$AbstractBuildExecution.post(AbstractBuild.java:635)
	at hudson.model.Run.execute(Run.java:1819)
	at hudson.model.FreeStyleBuild.run(FreeStyleBuild.java:43)
	at hudson.model.ResourceController.execute(ResourceController.java:97)
	at hudson.model.Executor.run(Executor.java:429)
No artifacts found that match the file pattern "**/*.events,heapdumps/**,**/hs_err_pid*". Configuration error?
Recording test results
Build step 'Publish JUnit test result report' changed build result to UNSTABLE
Email was triggered for: Unstable (Test Failures)
Sending email for trigger: Unstable (Test Failures)