lucene-dev mailing list archives

Site index · List index
Message view « Date » · « Thread »
Top « Date » · « Thread »
From Policeman Jenkins Server <jenk...@thetaphi.de>
Subject [JENKINS] Lucene-Solr-master-MacOSX (64bit/jdk-9) - Build # 4807 - Unstable!
Date Sat, 01 Sep 2018 14:51:05 GMT
Build: https://jenkins.thetaphi.de/job/Lucene-Solr-master-MacOSX/4807/
Java: 64bit/jdk-9 -XX:+UseCompressedOops -XX:+UseParallelGC

3 tests failed.
FAILED:  org.apache.solr.handler.RequestLoggingTest.testLogBeforeExecuteWithRequestLogger

Error Message:


Stack Trace:
java.lang.AssertionError
	at __randomizedtesting.SeedInfo.seed([270471930FC37441:966D519CA235CC0F]:0)
	at org.junit.Assert.fail(Assert.java:92)
	at org.junit.Assert.assertTrue(Assert.java:43)
	at org.junit.Assert.assertTrue(Assert.java:54)
	at org.apache.solr.handler.RequestLoggingTest.testLogBeforeExecute(RequestLoggingTest.java:88)
	at org.apache.solr.handler.RequestLoggingTest.testLogBeforeExecuteWithRequestLogger(RequestLoggingTest.java:71)
	at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
	at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
	at java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
	at java.base/java.lang.reflect.Method.invoke(Method.java:564)
	at com.carrotsearch.randomizedtesting.RandomizedRunner.invoke(RandomizedRunner.java:1737)
	at com.carrotsearch.randomizedtesting.RandomizedRunner$8.evaluate(RandomizedRunner.java:934)
	at com.carrotsearch.randomizedtesting.RandomizedRunner$9.evaluate(RandomizedRunner.java:970)
	at com.carrotsearch.randomizedtesting.RandomizedRunner$10.evaluate(RandomizedRunner.java:984)
	at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:57)
	at org.apache.lucene.util.TestRuleSetupTeardownChained$1.evaluate(TestRuleSetupTeardownChained.java:49)
	at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:45)
	at org.apache.lucene.util.TestRuleThreadAndTestName$1.evaluate(TestRuleThreadAndTestName.java:48)
	at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:64)
	at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:47)
	at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
	at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:368)
	at com.carrotsearch.randomizedtesting.ThreadLeakControl.forkTimeoutingTask(ThreadLeakControl.java:817)
	at com.carrotsearch.randomizedtesting.ThreadLeakControl$3.evaluate(ThreadLeakControl.java:468)
	at com.carrotsearch.randomizedtesting.RandomizedRunner.runSingleTest(RandomizedRunner.java:943)
	at com.carrotsearch.randomizedtesting.RandomizedRunner$5.evaluate(RandomizedRunner.java:829)
	at com.carrotsearch.randomizedtesting.RandomizedRunner$6.evaluate(RandomizedRunner.java:879)
	at com.carrotsearch.randomizedtesting.RandomizedRunner$7.evaluate(RandomizedRunner.java:890)
	at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
	at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:57)
	at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:45)
	at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
	at org.apache.lucene.util.TestRuleStoreClassName$1.evaluate(TestRuleStoreClassName.java:41)
	at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:40)
	at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:40)
	at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
	at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
	at org.apache.lucene.util.TestRuleAssertionsRequired$1.evaluate(TestRuleAssertionsRequired.java:53)
	at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:47)
	at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:64)
	at org.apache.lucene.util.TestRuleIgnoreTestSuites$1.evaluate(TestRuleIgnoreTestSuites.java:54)
	at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
	at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:368)
	at java.base/java.lang.Thread.run(Thread.java:844)


FAILED:  org.apache.solr.handler.RequestLoggingTest.testLogBeforeExecuteWithCoreLogger

Error Message:


Stack Trace:
java.lang.AssertionError
	at __randomizedtesting.SeedInfo.seed([270471930FC37441:EB82711DF10A1FD7]:0)
	at org.junit.Assert.fail(Assert.java:92)
	at org.junit.Assert.assertTrue(Assert.java:43)
	at org.junit.Assert.assertTrue(Assert.java:54)
	at org.apache.solr.handler.RequestLoggingTest.testLogBeforeExecute(RequestLoggingTest.java:88)
	at org.apache.solr.handler.RequestLoggingTest.testLogBeforeExecuteWithCoreLogger(RequestLoggingTest.java:65)
	at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
	at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
	at java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
	at java.base/java.lang.reflect.Method.invoke(Method.java:564)
	at com.carrotsearch.randomizedtesting.RandomizedRunner.invoke(RandomizedRunner.java:1737)
	at com.carrotsearch.randomizedtesting.RandomizedRunner$8.evaluate(RandomizedRunner.java:934)
	at com.carrotsearch.randomizedtesting.RandomizedRunner$9.evaluate(RandomizedRunner.java:970)
	at com.carrotsearch.randomizedtesting.RandomizedRunner$10.evaluate(RandomizedRunner.java:984)
	at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:57)
	at org.apache.lucene.util.TestRuleSetupTeardownChained$1.evaluate(TestRuleSetupTeardownChained.java:49)
	at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:45)
	at org.apache.lucene.util.TestRuleThreadAndTestName$1.evaluate(TestRuleThreadAndTestName.java:48)
	at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:64)
	at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:47)
	at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
	at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:368)
	at com.carrotsearch.randomizedtesting.ThreadLeakControl.forkTimeoutingTask(ThreadLeakControl.java:817)
	at com.carrotsearch.randomizedtesting.ThreadLeakControl$3.evaluate(ThreadLeakControl.java:468)
	at com.carrotsearch.randomizedtesting.RandomizedRunner.runSingleTest(RandomizedRunner.java:943)
	at com.carrotsearch.randomizedtesting.RandomizedRunner$5.evaluate(RandomizedRunner.java:829)
	at com.carrotsearch.randomizedtesting.RandomizedRunner$6.evaluate(RandomizedRunner.java:879)
	at com.carrotsearch.randomizedtesting.RandomizedRunner$7.evaluate(RandomizedRunner.java:890)
	at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
	at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:57)
	at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:45)
	at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
	at org.apache.lucene.util.TestRuleStoreClassName$1.evaluate(TestRuleStoreClassName.java:41)
	at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:40)
	at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:40)
	at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
	at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
	at org.apache.lucene.util.TestRuleAssertionsRequired$1.evaluate(TestRuleAssertionsRequired.java:53)
	at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:47)
	at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:64)
	at org.apache.lucene.util.TestRuleIgnoreTestSuites$1.evaluate(TestRuleIgnoreTestSuites.java:54)
	at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
	at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:368)
	at java.base/java.lang.Thread.run(Thread.java:844)


FAILED:  org.apache.solr.handler.RequestLoggingTest.testLogBeforeExecuteWithRequestLogger

Error Message:


Stack Trace:
java.lang.AssertionError
	at __randomizedtesting.SeedInfo.seed([270471930FC37441:966D519CA235CC0F]:0)
	at org.junit.Assert.fail(Assert.java:92)
	at org.junit.Assert.assertTrue(Assert.java:43)
	at org.junit.Assert.assertTrue(Assert.java:54)
	at org.apache.solr.handler.RequestLoggingTest.testLogBeforeExecute(RequestLoggingTest.java:88)
	at org.apache.solr.handler.RequestLoggingTest.testLogBeforeExecuteWithRequestLogger(RequestLoggingTest.java:71)
	at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
	at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
	at java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
	at java.base/java.lang.reflect.Method.invoke(Method.java:564)
	at com.carrotsearch.randomizedtesting.RandomizedRunner.invoke(RandomizedRunner.java:1737)
	at com.carrotsearch.randomizedtesting.RandomizedRunner$8.evaluate(RandomizedRunner.java:934)
	at com.carrotsearch.randomizedtesting.RandomizedRunner$9.evaluate(RandomizedRunner.java:970)
	at com.carrotsearch.randomizedtesting.RandomizedRunner$10.evaluate(RandomizedRunner.java:984)
	at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:57)
	at org.apache.lucene.util.TestRuleSetupTeardownChained$1.evaluate(TestRuleSetupTeardownChained.java:49)
	at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:45)
	at org.apache.lucene.util.TestRuleThreadAndTestName$1.evaluate(TestRuleThreadAndTestName.java:48)
	at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:64)
	at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:47)
	at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
	at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:368)
	at com.carrotsearch.randomizedtesting.ThreadLeakControl.forkTimeoutingTask(ThreadLeakControl.java:817)
	at com.carrotsearch.randomizedtesting.ThreadLeakControl$3.evaluate(ThreadLeakControl.java:468)
	at com.carrotsearch.randomizedtesting.RandomizedRunner.runSingleTest(RandomizedRunner.java:943)
	at com.carrotsearch.randomizedtesting.RandomizedRunner$5.evaluate(RandomizedRunner.java:829)
	at com.carrotsearch.randomizedtesting.RandomizedRunner$6.evaluate(RandomizedRunner.java:879)
	at com.carrotsearch.randomizedtesting.RandomizedRunner$7.evaluate(RandomizedRunner.java:890)
	at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
	at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:57)
	at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:45)
	at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
	at org.apache.lucene.util.TestRuleStoreClassName$1.evaluate(TestRuleStoreClassName.java:41)
	at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:40)
	at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:40)
	at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
	at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
	at org.apache.lucene.util.TestRuleAssertionsRequired$1.evaluate(TestRuleAssertionsRequired.java:53)
	at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:47)
	at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:64)
	at org.apache.lucene.util.TestRuleIgnoreTestSuites$1.evaluate(TestRuleIgnoreTestSuites.java:54)
	at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
	at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:368)
	at java.base/java.lang.Thread.run(Thread.java:844)




Build Log:
[...truncated 14414 lines...]
   [junit4] Suite: org.apache.solr.handler.RequestLoggingTest
   [junit4]   2> Creating dataDir: /Users/jenkins/workspace/Lucene-Solr-master-MacOSX/solr/build/solr-core/test/J0/temp/solr.handler.RequestLoggingTest_270471930FC37441-001/init-core-data-001
   [junit4]   2> 3400591 WARN  (SUITE-RequestLoggingTest-seed#[270471930FC37441]-worker) [    ] o.a.s.SolrTestCaseJ4 startTrackingSearchers: numOpens=22 numCloses=22
   [junit4]   2> 3400591 INFO  (SUITE-RequestLoggingTest-seed#[270471930FC37441]-worker) [    ] o.a.s.SolrTestCaseJ4 Using TrieFields (NUMERIC_POINTS_SYSPROP=false) w/NUMERIC_DOCVALUES_SYSPROP=false
   [junit4]   2> 3400592 INFO  (SUITE-RequestLoggingTest-seed#[270471930FC37441]-worker) [    ] o.a.s.SolrTestCaseJ4 Randomized ssl (false) and clientAuth (false) via: @org.apache.solr.util.RandomizeSSL(reason="", value=0.0/0.0, ssl=0.0/0.0, clientAuth=0.0/0.0) w/ MAC_OS_X supressed clientAuth
   [junit4]   2> 3400592 INFO  (SUITE-RequestLoggingTest-seed#[270471930FC37441]-worker) [    ] o.a.s.SolrTestCaseJ4 SecureRandom sanity checks: test.solr.allowed.securerandom=null & java.security.egd=file:/dev/./urandom
   [junit4]   2> 3400592 INFO  (SUITE-RequestLoggingTest-seed#[270471930FC37441]-worker) [    ] o.a.s.SolrTestCaseJ4 ####initCore
   [junit4]   2> 3400593 INFO  (SUITE-RequestLoggingTest-seed#[270471930FC37441]-worker) [    ] o.a.s.c.SolrResourceLoader [null] Added 2 libs to classloader, from paths: [/Users/jenkins/workspace/Lucene-Solr-master-MacOSX/solr/core/src/test-files/solr/collection1/lib, /Users/jenkins/workspace/Lucene-Solr-master-MacOSX/solr/core/src/test-files/solr/collection1/lib/classes]
   [junit4]   2> 3400616 INFO  (SUITE-RequestLoggingTest-seed#[270471930FC37441]-worker) [    ] o.a.s.c.SolrConfig Using Lucene MatchVersion: 8.0.0
   [junit4]   2> 3400631 INFO  (SUITE-RequestLoggingTest-seed#[270471930FC37441]-worker) [    ] o.a.s.s.IndexSchema [null] Schema name=test
   [junit4]   2> 3400693 INFO  (SUITE-RequestLoggingTest-seed#[270471930FC37441]-worker) [    ] o.a.s.s.IndexSchema Loaded schema test/1.0 with uniqueid field id
   [junit4]   2> 3400786 INFO  (SUITE-RequestLoggingTest-seed#[270471930FC37441]-worker) [    ] o.a.s.c.TransientSolrCoreCacheDefault Allocating transient cache for 2147483647 transient cores
   [junit4]   2> 3400786 INFO  (SUITE-RequestLoggingTest-seed#[270471930FC37441]-worker) [    ] o.a.s.h.a.MetricsHistoryHandler No .system collection, keeping metrics history in memory.
   [junit4]   2> 3400799 INFO  (SUITE-RequestLoggingTest-seed#[270471930FC37441]-worker) [    ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr.node' (registry 'solr.node') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@133abef9
   [junit4]   2> 3400807 INFO  (SUITE-RequestLoggingTest-seed#[270471930FC37441]-worker) [    ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr.jvm' (registry 'solr.jvm') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@133abef9
   [junit4]   2> 3400807 INFO  (SUITE-RequestLoggingTest-seed#[270471930FC37441]-worker) [    ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr.jetty' (registry 'solr.jetty') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@133abef9
   [junit4]   2> 3400809 INFO  (coreLoadExecutor-12579-thread-1) [    x:collection1] o.a.s.c.SolrResourceLoader [null] Added 2 libs to classloader, from paths: [/Users/jenkins/workspace/Lucene-Solr-master-MacOSX/solr/core/src/test-files/solr/collection1/lib, /Users/jenkins/workspace/Lucene-Solr-master-MacOSX/solr/core/src/test-files/solr/collection1/lib/classes]
   [junit4]   2> 3400829 INFO  (coreLoadExecutor-12579-thread-1) [    x:collection1] o.a.s.c.SolrConfig Using Lucene MatchVersion: 8.0.0
   [junit4]   2> 3400850 INFO  (coreLoadExecutor-12579-thread-1) [    x:collection1] o.a.s.s.IndexSchema [collection1] Schema name=test
   [junit4]   2> 3400903 INFO  (coreLoadExecutor-12579-thread-1) [    x:collection1] o.a.s.s.IndexSchema Loaded schema test/1.0 with uniqueid field id
   [junit4]   2> 3400910 INFO  (coreLoadExecutor-12579-thread-1) [    x:collection1] o.a.s.c.CoreContainer Creating SolrCore 'collection1' using configuration from instancedir /Users/jenkins/workspace/Lucene-Solr-master-MacOSX/solr/core/src/test-files/solr/collection1, trusted=true
   [junit4]   2> 3400910 INFO  (coreLoadExecutor-12579-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@133abef9
   [junit4]   2> 3400911 INFO  (coreLoadExecutor-12579-thread-1) [    x:collection1] o.a.s.c.SolrCore solr.RecoveryStrategy.Builder
   [junit4]   2> 3400911 INFO  (coreLoadExecutor-12579-thread-1) [    x:collection1] o.a.s.c.SolrCore [[collection1] ] Opening new SolrCore at [/Users/jenkins/workspace/Lucene-Solr-master-MacOSX/solr/core/src/test-files/solr/collection1], dataDir=[/Users/jenkins/workspace/Lucene-Solr-master-MacOSX/solr/build/solr-core/test/J0/temp/solr.handler.RequestLoggingTest_270471930FC37441-001/init-core-data-001/]
   [junit4]   2> 3400911 INFO  (coreLoadExecutor-12579-thread-1) [    x:collection1] o.a.s.u.RandomMergePolicy RandomMergePolicy wrapping class org.apache.lucene.index.AlcoholicMergePolicy: [AlcoholicMergePolicy: minMergeSize=0, mergeFactor=10, maxMergeSize=1476545815, maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=true, maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.1]
   [junit4]   2> 3400969 INFO  (coreLoadExecutor-12579-thread-1) [    x:collection1] o.a.s.u.UpdateHandler Using UpdateLog implementation: org.apache.solr.update.UpdateLog
   [junit4]   2> 3400969 INFO  (coreLoadExecutor-12579-thread-1) [    x:collection1] o.a.s.u.UpdateLog Initializing UpdateLog: dataDir= defaultSyncLevel=FLUSH numRecordsToKeep=100 maxNumLogsToKeep=10 numVersionBuckets=65536
   [junit4]   2> 3400970 INFO  (coreLoadExecutor-12579-thread-1) [    x:collection1] o.a.s.u.CommitTracker Hard AutoCommit: disabled
   [junit4]   2> 3400970 INFO  (coreLoadExecutor-12579-thread-1) [    x:collection1] o.a.s.u.CommitTracker Soft AutoCommit: disabled
   [junit4]   2> 3400971 INFO  (coreLoadExecutor-12579-thread-1) [    x:collection1] o.a.s.u.RandomMergePolicy RandomMergePolicy wrapping class org.apache.lucene.index.LogByteSizeMergePolicy: [LogByteSizeMergePolicy: minMergeSize=1677721, mergeFactor=15, maxMergeSize=2147483648, maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=true, maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.4649847431630678]
   [junit4]   2> 3400971 INFO  (coreLoadExecutor-12579-thread-1) [    x:collection1] o.a.s.s.SolrIndexSearcher Opening [Searcher@5cb698c5[collection1] main]
   [junit4]   2> 3400973 INFO  (coreLoadExecutor-12579-thread-1) [    x:collection1] o.a.s.h.c.SpellCheckComponent Initializing spell checkers
   [junit4]   2> 3400987 INFO  (coreLoadExecutor-12579-thread-1) [    x:collection1] o.a.s.s.DirectSolrSpellChecker init: {name=direct,classname=DirectSolrSpellChecker,field=lowerfilt,minQueryLength=3}
   [junit4]   2> 3401033 INFO  (coreLoadExecutor-12579-thread-1) [    x:collection1] o.a.s.h.ReplicationHandler Commits will be reserved for 10000ms.
   [junit4]   2> 3401033 INFO  (coreLoadExecutor-12579-thread-1) [    x:collection1] o.a.s.u.UpdateLog Could not find max version in index or recent updates, using new clock 1610415514888175616
   [junit4]   2> 3401034 INFO  (searcherExecutor-12580-thread-1-processing-x:collection1) [    x:collection1] o.a.s.h.c.SpellCheckComponent Loading spell index for spellchecker: default
   [junit4]   2> 3401036 INFO  (SUITE-RequestLoggingTest-seed#[270471930FC37441]-worker) [    ] o.a.s.SolrTestCaseJ4 ####initCore end
   [junit4]   2> 3401037 INFO  (searcherExecutor-12580-thread-1-processing-x:collection1) [    x:collection1] o.a.s.h.c.SpellCheckComponent Loading spell index for spellchecker: direct
   [junit4]   2> 3401037 INFO  (searcherExecutor-12580-thread-1-processing-x:collection1) [    x:collection1] o.a.s.h.c.SpellCheckComponent Loading spell index for spellchecker: wordbreak
   [junit4]   2> 3401037 INFO  (searcherExecutor-12580-thread-1-processing-x:collection1) [    x:collection1] o.a.s.h.c.SpellCheckComponent Loading spell index for spellchecker: multipleFields
   [junit4]   2> 3401038 INFO  (searcherExecutor-12580-thread-1-processing-x:collection1) [    x:collection1] o.a.s.h.c.SpellCheckComponent Loading spell index for spellchecker: jarowinkler
   [junit4]   2> 3401038 INFO  (TEST-RequestLoggingTest.testLogBeforeExecuteWithCoreLogger-seed#[270471930FC37441]) [    ] o.a.s.SolrTestCaseJ4 ###Starting testLogBeforeExecuteWithCoreLogger
   [junit4]   2> 3401039 INFO  (searcherExecutor-12580-thread-1-processing-x:collection1) [    x:collection1] o.a.s.h.c.SpellCheckComponent Loading spell index for spellchecker: external
   [junit4]   2> 3401039 INFO  (searcherExecutor-12580-thread-1-processing-x:collection1) [    x:collection1] o.a.s.h.c.SpellCheckComponent Loading spell index for spellchecker: freq
   [junit4]   2> 3401040 INFO  (searcherExecutor-12580-thread-1-processing-x:collection1) [    x:collection1] o.a.s.h.c.SpellCheckComponent Loading spell index for spellchecker: fqcn
   [junit4]   2> 3401042 INFO  (searcherExecutor-12580-thread-1-processing-x:collection1) [    x:collection1] o.a.s.h.c.SpellCheckComponent Loading spell index for spellchecker: perDict
   [junit4]   2> 3401042 INFO  (searcherExecutor-12580-thread-1-processing-x:collection1) [    x:collection1] o.a.s.c.SolrCore [collection1] Registered new searcher Searcher@5cb698c5[collection1] main{ExitableDirectoryReader(UninvertingDirectoryReader())}
   [junit4]   2> 3401049 DEBUG (TEST-RequestLoggingTest.testLogBeforeExecuteWithCoreLogger-seed#[270471930FC37441]) [    ] o.a.s.c.S.Request [collection1]  webapp=null path=null params={q=*:*&wt=xml}
   [junit4]   2> 3401049 DEBUG (TEST-RequestLoggingTest.testLogBeforeExecuteWithCoreLogger-seed#[270471930FC37441]) [    ] o.a.s.h.c.SearchHandler Adding  component:org.apache.solr.handler.component.QueryComponent@256bbccc
   [junit4]   2> 3401050 DEBUG (TEST-RequestLoggingTest.testLogBeforeExecuteWithCoreLogger-seed#[270471930FC37441]) [    ] o.a.s.h.c.SearchHandler Adding  component:org.apache.solr.handler.component.FacetComponent@19faaa69
   [junit4]   2> 3401050 DEBUG (TEST-RequestLoggingTest.testLogBeforeExecuteWithCoreLogger-seed#[270471930FC37441]) [    ] o.a.s.h.c.SearchHandler Adding  component:org.apache.solr.search.facet.FacetModule@6725759
   [junit4]   2> 3401050 DEBUG (TEST-RequestLoggingTest.testLogBeforeExecuteWithCoreLogger-seed#[270471930FC37441]) [    ] o.a.s.h.c.SearchHandler Adding  component:org.apache.solr.handler.component.MoreLikeThisComponent@3d65786c
   [junit4]   2> 3401050 DEBUG (TEST-RequestLoggingTest.testLogBeforeExecuteWithCoreLogger-seed#[270471930FC37441]) [    ] o.a.s.h.c.SearchHandler Adding  component:org.apache.solr.handler.component.HighlightComponent@45902ed0
   [junit4]   2> 3401050 DEBUG (TEST-RequestLoggingTest.testLogBeforeExecuteWithCoreLogger-seed#[270471930FC37441]) [    ] o.a.s.h.c.SearchHandler Adding  component:org.apache.solr.handler.component.StatsComponent@9f56de9
   [junit4]   2> 3401050 DEBUG (TEST-RequestLoggingTest.testLogBeforeExecuteWithCoreLogger-seed#[270471930FC37441]) [    ] o.a.s.h.c.SearchHandler Adding  component:org.apache.solr.handler.component.ExpandComponent@1d292b11
   [junit4]   2> 3401050 DEBUG (TEST-RequestLoggingTest.testLogBeforeExecuteWithCoreLogger-seed#[270471930FC37441]) [    ] o.a.s.h.c.SearchHandler Adding  component:org.apache.solr.handler.component.TermsComponent@b9986c0
   [junit4]   2> 3401050 DEBUG (TEST-RequestLoggingTest.testLogBeforeExecuteWithCoreLogger-seed#[270471930FC37441]) [    ] o.a.s.h.c.SearchHandler Adding  debug component:org.apache.solr.handler.component.DebugComponent@4fbbdfcd
   [junit4]   2> 3401050 DEBUG (TEST-RequestLoggingTest.testLogBeforeExecuteWithCoreLogger-seed#[270471930FC37441]) [    ] o.a.s.h.c.QueryComponent process: q=*:*&df=text&wt=xml&indent=off
   [junit4]   2> 3401050 DEBUG (TEST-RequestLoggingTest.testLogBeforeExecuteWithCoreLogger-seed#[270471930FC37441]) [    ] o.a.s.s.s.LocalStatsCache ## GET LocalSolrQueryRequest{q=*:*&df=text&wt=xml&indent=off}
   [junit4]   2> 3401050 INFO  (TEST-RequestLoggingTest.testLogBeforeExecuteWithCoreLogger-seed#[270471930FC37441]) [    ] o.a.s.c.S.Request [collection1]  webapp=null path=null params={q=*:*&wt=xml} hits=0 status=0 QTime=0
   [junit4]   2> 3401051 INFO  (TEST-RequestLoggingTest.testLogBeforeExecuteWithCoreLogger-seed#[270471930FC37441]) [    ] o.a.s.SolrTestCaseJ4 ###Ending testLogBeforeExecuteWithCoreLogger
   [junit4]   2> NOTE: reproduce with: ant test  -Dtestcase=RequestLoggingTest -Dtests.method=testLogBeforeExecuteWithCoreLogger -Dtests.seed=270471930FC37441 -Dtests.slow=true -Dtests.locale=ca-IT -Dtests.timezone=Europe/Zaporozhye -Dtests.asserts=true -Dtests.file.encoding=UTF-8
   [junit4] FAILURE 0.02s J0 | RequestLoggingTest.testLogBeforeExecuteWithCoreLogger <<<
   [junit4]    > Throwable #1: java.lang.AssertionError
   [junit4]    > 	at __randomizedtesting.SeedInfo.seed([270471930FC37441:EB82711DF10A1FD7]:0)
   [junit4]    > 	at org.apache.solr.handler.RequestLoggingTest.testLogBeforeExecute(RequestLoggingTest.java:88)
   [junit4]    > 	at org.apache.solr.handler.RequestLoggingTest.testLogBeforeExecuteWithCoreLogger(RequestLoggingTest.java:65)
   [junit4]    > 	at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
   [junit4]    > 	at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
   [junit4]    > 	at java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
   [junit4]    > 	at java.base/java.lang.reflect.Method.invoke(Method.java:564)
   [junit4]    > 	at java.base/java.lang.Thread.run(Thread.java:844)
   [junit4]   2> 3401056 INFO  (TEST-RequestLoggingTest.testLogBeforeExecuteWithRequestLogger-seed#[270471930FC37441]) [    ] o.a.s.SolrTestCaseJ4 ###Starting testLogBeforeExecuteWithRequestLogger
   [junit4]   2> 3401058 DEBUG (TEST-RequestLoggingTest.testLogBeforeExecuteWithRequestLogger-seed#[270471930FC37441]) [    ] o.a.s.c.S.Request [collection1]  webapp=null path=null params={q=*:*&wt=xml}
   [junit4]   2> 3401058 DEBUG (TEST-RequestLoggingTest.testLogBeforeExecuteWithRequestLogger-seed#[270471930FC37441]) [    ] o.a.s.h.c.QueryComponent process: q=*:*&df=text&wt=xml&indent=off
   [junit4]   2> 3401058 DEBUG (TEST-RequestLoggingTest.testLogBeforeExecuteWithRequestLogger-seed#[270471930FC37441]) [    ] o.a.s.s.s.LocalStatsCache ## GET LocalSolrQueryRequest{q=*:*&df=text&wt=xml&indent=off}
   [junit4]   2> 3401058 INFO  (TEST-RequestLoggingTest.testLogBeforeExecuteWithRequestLogger-seed#[270471930FC37441]) [    ] o.a.s.c.S.Request [collection1]  webapp=null path=null params={q=*:*&wt=xml} hits=0 status=0 QTime=0
   [junit4]   2> 3401059 INFO  (TEST-RequestLoggingTest.testLogBeforeExecuteWithRequestLogger-seed#[270471930FC37441]) [    ] o.a.s.SolrTestCaseJ4 ###Ending testLogBeforeExecuteWithRequestLogger
   [junit4]   2> NOTE: reproduce with: ant test  -Dtestcase=RequestLoggingTest -Dtests.method=testLogBeforeExecuteWithRequestLogger -Dtests.seed=270471930FC37441 -Dtests.slow=true -Dtests.locale=ca-IT -Dtests.timezone=Europe/Zaporozhye -Dtests.asserts=true -Dtests.file.encoding=UTF-8
   [junit4] FAILURE 0.01s J0 | RequestLoggingTest.testLogBeforeExecuteWithRequestLogger <<<
   [junit4]    > Throwable #1: java.lang.AssertionError
   [junit4]    > 	at __randomizedtesting.SeedInfo.seed([270471930FC37441:966D519CA235CC0F]:0)
   [junit4]    > 	at org.apache.solr.handler.RequestLoggingTest.testLogBeforeExecute(RequestLoggingTest.java:88)
   [junit4]    > 	at org.apache.solr.handler.RequestLoggingTest.testLogBeforeExecuteWithRequestLogger(RequestLoggingTest.java:71)
   [junit4]    > 	at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
   [junit4]    > 	at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
   [junit4]    > 	at java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
   [junit4]    > 	at java.base/java.lang.reflect.Method.invoke(Method.java:564)
   [junit4]    > 	at java.base/java.lang.Thread.run(Thread.java:844)
   [junit4]   2> 3401059 INFO  (SUITE-RequestLoggingTest-seed#[270471930FC37441]-worker) [    ] o.a.s.SolrTestCaseJ4 ###deleteCore
   [junit4]   2> 3401059 INFO  (SUITE-RequestLoggingTest-seed#[270471930FC37441]-worker) [    ] o.a.s.c.CoreContainer Shutting down CoreContainer instance=81724721
   [junit4]   2> 3401059 INFO  (SUITE-RequestLoggingTest-seed#[270471930FC37441]-worker) [    ] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.node, tag=null
   [junit4]   2> 3401059 INFO  (SUITE-RequestLoggingTest-seed#[270471930FC37441]-worker) [    ] o.a.s.m.r.SolrJmxReporter Closing reporter [org.apache.solr.metrics.reporters.SolrJmxReporter@4b577e03: rootName = null, domain = solr.node, service url = null, agent id = null] for registry solr.node / com.codahale.metrics.MetricRegistry@2359b1f3
   [junit4]   2> 3401064 INFO  (SUITE-RequestLoggingTest-seed#[270471930FC37441]-worker) [    ] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.jvm, tag=null
   [junit4]   2> 3401064 INFO  (SUITE-RequestLoggingTest-seed#[270471930FC37441]-worker) [    ] o.a.s.m.r.SolrJmxReporter Closing reporter [org.apache.solr.metrics.reporters.SolrJmxReporter@47154bc0: rootName = null, domain = solr.jvm, service url = null, agent id = null] for registry solr.jvm / com.codahale.metrics.MetricRegistry@683ada14
   [junit4]   2> 3401066 INFO  (SUITE-RequestLoggingTest-seed#[270471930FC37441]-worker) [    ] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.jetty, tag=null
   [junit4]   2> 3401066 INFO  (SUITE-RequestLoggingTest-seed#[270471930FC37441]-worker) [    ] o.a.s.m.r.SolrJmxReporter Closing reporter [org.apache.solr.metrics.reporters.SolrJmxReporter@2e8cb850: rootName = null, domain = solr.jetty, service url = null, agent id = null] for registry solr.jetty / com.codahale.metrics.MetricRegistry@2e933808
   [junit4]   2> 3401067 INFO  (coreCloseExecutor-12585-thread-1) [    x:collection1] o.a.s.c.SolrCore [collection1]  CLOSING SolrCore org.apache.solr.core.SolrCore@49796a4f
   [junit4]   2> 3401067 INFO  (coreCloseExecutor-12585-thread-1) [    x:collection1] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.core.collection1, tag=49796a4f
   [junit4]   2> 3401067 INFO  (coreCloseExecutor-12585-thread-1) [    x:collection1] o.a.s.m.r.SolrJmxReporter Closing reporter [org.apache.solr.metrics.reporters.SolrJmxReporter@11902aef: rootName = null, domain = solr.core.collection1, service url = null, agent id = null] for registry solr.core.collection1 / com.codahale.metrics.MetricRegistry@70f56f06
   [junit4]   2> NOTE: leaving temporary files on disk at: /Users/jenkins/workspace/Lucene-Solr-master-MacOSX/solr/build/solr-core/test/J0/temp/solr.handler.RequestLoggingTest_270471930FC37441-001
   [junit4]   2> NOTE: test params are: codec=Asserting(Lucene80): {}, docValues:{}, maxPointsInLeafNode=1319, maxMBSortInHeap=6.687687313786846, sim=Asserting(org.apache.lucene.search.similarities.AssertingSimilarity@4d913bec), locale=ca-IT, timezone=Europe/Zaporozhye
   [junit4]   2> NOTE: Mac OS X 10.11.6 x86_64/Oracle Corporation 9 (64-bit)/cpus=3,threads=1,free=117105256,total=528482304
   [junit4]   2> NOTE: All tests run in this JVM: [IndexSizeTriggerTest, SpatialRPTFieldTypeTest, CollectionsAPIAsyncDistributedZkTest, TestPartialUpdateDeduplication, TestConfigsApi, SparseHLLTest, LeaderVoteWaitTimeoutTest, TestHdfsUpdateLog, TestRTGBase, DisMaxRequestHandlerTest, TestNestedUpdateProcessor, HdfsBasicDistributedZk2Test, TestFileDictionaryLookup, MultiSolrCloudTestCaseTest, CdcrUpdateLogTest, AutoscalingHistoryHandlerTest, TestOmitPositions, TestTrie, SoftAutoCommitTest, NumericFieldsTest, TestFoldingMultitermQuery, DistributedTermsComponentTest, ShardRoutingCustomTest, DistributedMLTComponentTest, SystemLogListenerTest, SolrMetricsIntegrationTest, MetricsConfigTest, SolrCoreCheckLockOnStartupTest, TestSolrCoreParser, TestReqParamsAPI, BlockDirectoryTest, HdfsSyncSliceTest, OverseerStatusTest, TemplateUpdateProcessorTest, SmileWriterTest, TestCustomSort, SolrGraphiteReporterTest, QueryEqualityTest, DocValuesTest, SolrRequestParserTest, DocValuesNotIndexedTest, AliasIntegrationTest, TestSolrIndexConfig, TestJoin, ScriptEngineTest, FullSolrCloudDistribCmdsTest, AddSchemaFieldsUpdateProcessorFactoryTest, TestFilteredDocIdSet, SolrInfoBeanTest, SearchHandlerTest, TestCopyFieldCollectionResource, DOMUtilTest, TestSolrJ, NumberUtilsTest, AnalyticsMergeStrategyTest, TestMacros, TestConfigOverlay, TestSlowCompositeReaderWrapper, TestTolerantUpdateProcessorCloud, TestGeoJSONResponseWriter, V2StandaloneTest, TestMultiWordSynonyms, TestComplexPhraseQParserPlugin, TestReload, MultiTermTest, TestNonDefinedSimilarityFactory, TestPullReplica, TestMaxScoreQueryParser, TestUtilizeNode, TestGroupingSearch, TestDistributedGrouping, TestOverriddenPrefixQueryForCustomFieldType, TestLuceneIndexBackCompat, SearchRateTriggerIntegrationTest, TestCloudManagedSchema, HdfsDirectoryFactoryTest, DirectoryFactoryTest, TaggingAttributeTest, BlockJoinFacetSimpleTest, IndexSchemaTest, TestCorePropertiesReload, TestSchemaVersionResource, TestApiFramework, TolerantUpdateProcessorTest, IndexBasedSpellCheckerTest, TestBackupRepositoryFactory, DistributedUpdateProcessorTest, TestUseDocValuesAsStored2, TestManagedSchemaAPI, RuleEngineTest, TestPhraseSuggestions, LIROnShardRestartTest, TestCollectionsAPIViaSolrCloudCluster, RestoreTriggerStateTest, SegmentsInfoRequestHandlerTest, ProtectedTermFilterFactoryTest, TestLRUCache, TestUniqueKeyFieldResource, TestPivotHelperCode, HdfsTlogReplayBufferedWhileIndexingTest, MoveReplicaHDFSTest, TestSimpleQParserPlugin, TestDirectoryFactory, PluginInfoTest, TestJsonFacetsWithNestedObjects, TestStressLiveNodes, WrapperMergePolicyFactoryTest, TestRebalanceLeaders, TestAnalyzedSuggestions, TestDynamicFieldResource, TestHashQParserPlugin, NodeLostTriggerTest, TestFieldCache, DirectSolrConnectionTest, TestInfoStreamLogging, SearchHandlerTest, TestLegacyFieldCache, TestCodecSupport, RemoteQueryErrorTest, TestSortableTextField, SolrIndexSplitterTest, StatsReloadRaceTest, TestCryptoKeys, PKIAuthenticationIntegrationTest, CoreAdminRequestStatusTest, TestSolr4Spatial, ExplicitHLLTest, TestPKIAuthenticationPlugin, SpellCheckCollatorWithCollapseTest, PolyFieldTest, SimpleFacetsTest, PeerSyncWithBufferUpdatesTest, DistributedDebugComponentTest, ComputePlanActionTest, TestCSVResponseWriter, TestBinaryField, PeerSyncWithLeaderAndIndexFingerprintCachingTest, ResourceLoaderTest, BadCopyFieldTest, TestConfigSetsAPIExclusivity, TestFieldResource, TestJsonRequest, TestJmxIntegration, TestOrdValues, HdfsChaosMonkeyNothingIsSafeTest, TriggerIntegrationTest, TestChildDocTransformerHierarchy, TestScoreJoinQPNoScore, PreAnalyzedUpdateProcessorTest, TestDynamicURP, TestShortCircuitedRequests, HdfsWriteToMultipleCollectionsTest, TestHalfAndHalfDocValues, CdcrBidirectionalTest, TestSolrConfigHandlerCloud, DistribDocExpirationUpdateProcessorTest, TestStressReorder, MetricTriggerTest, CreateRoutedAliasTest, TestDownShardTolerantSearch, HdfsCollectionsAPIDistributedZkTest, ZookeeperStatusHandlerTest, TestFunctionQuery, TestManagedResource, ChaosMonkeyNothingIsSafeTest, ZkStateWriterTest, TriggerCooldownIntegrationTest, OutputWriterTest, DistributedFacetExistsSmallTest, TestLogWatcher, TestSystemCollAutoCreate, DocValuesMissingTest, TestFieldCacheSort, TestReRankQParserPlugin, CdcrRequestHandlerTest, ConnectionManagerTest, TestRangeQuery, DistributedQueryComponentOptimizationTest, RankQueryTest, RestartWhileUpdatingTest, DistributedFacetPivotLongTailTest, TestWriterPerf, WordBreakSolrSpellCheckerTest, TestSearchPerf, TestCoreContainer, TestSolrCoreSnapshots, TestSimTriggerIntegration, SignificantTermsQParserPluginTest, SolrPluginUtilsTest, AddBlockUpdateTest, EchoParamsTest, OverseerModifyCollectionTest, DirectUpdateHandlerTest, DistanceFunctionTest, SimpleCollectionCreateDeleteTest, TestLegacyField, ConvertedLegacyTest, SolrRrdBackendFactoryTest, DeleteLastCustomShardedReplicaTest, AnalysisAfterCoreReloadTest, BasicFunctionalityTest, TestCrossCoreJoin, TestCursorMarkWithoutUniqueKey, TestDistributedSearch, TestDocumentBuilder, TestRandomFaceting, TestSimpleTrackingShardHandler, TestSolrCoreProperties, TestTolerantSearch, TestLuceneMatchVersion, TestReversedWildcardFilterFactory, TestWordDelimiterFilterFactory, TokenizerChainTest, TestEmbeddedSolrServerConstructors, TestEmbeddedSolrServerSchemaAPI, TestJettySolrRunner, ConnectionReuseTest, ActionThrottleTest, AddReplicaTest, AsyncCallRequestStatusResponseTest, BasicDistributedZk2Test, BasicDistributedZkTest, BasicZkTest, ChaosMonkeySafeLeaderTest, ChaosMonkeySafeLeaderWithPullReplicasTest, CloudExitableDirectoryReaderTest, ClusterStateTest, ClusterStateUpdateTest, CollectionPropsTest, CollectionStateFormat2Test, CollectionsAPISolrJTest, ConcurrentCreateRoutedAliasTest, ConfigSetsAPITest, DeleteReplicaTest, DeleteShardTest, DeleteStatusTest, DistribCursorPagingTest, DistributedQueueTest, DistributedVersionInfoTest, HttpPartitionOnCommitTest, HttpPartitionTest, LeaderElectionContextKeyTest, LeaderFailoverAfterPartitionTest, LeaderFailureAfterFreshStartTest, MetricsHistoryIntegrationTest, MigrateRouteKeyTest, OverseerCollectionConfigSetProcessorTest, PeerSyncReplicationTest, RecoveryZkTest, ReplicationFactorTest, SSLMigrationTest, SaslZkACLProviderTest, SharedFSAutoReplicaFailoverTest, SliceStateTest, SolrCLIZkUtilsTest, SolrCloudExampleTest, TestAuthenticationFramework, TestCloudConsistency, TestCloudDeleteByQuery, TestCloudJSONFacetSKG, TestCloudPseudoReturnFields, TestCloudRecovery, TestClusterProperties, TestConfigSetsAPI, TestDistributedMap, TestHashPartitioner, TestLeaderElectionZkExpiry, TestLeaderInitiatedRecoveryThread, TestOnReconnectListenerSupport, TestPrepRecovery, TestSolrCloudWithDelegationTokens, TestSolrCloudWithKerberosAlt, TestSolrCloudWithSecureImpersonation, TestStressCloudBlindAtomicUpdates, TlogReplayBufferedWhileIndexingTest, TriLevelCompositeIdRoutingTest, VMParamsZkACLAndCredentialsProvidersTest, ZkCLITest, ZkControllerTest, ZkNodePropsTest, ZkShardTermsTest, ZkSolrClientTest, AssignTest, TestRequestStatusCollectionAPI, NodeAddedTriggerTest, ScheduledTriggerIntegrationTest, ScheduledTriggerTest, TestSimComputePlanAction, TestSimDistribStateManager, TestSimExecutePlanAction, TestSimGenericDistributedQueue, TestSimLargeCluster, TestSimNodeAddedTrigger, TestSimPolicyCloud, CdcrReplicationHandlerTest, CdcrWithNodesRestartsTest, TestSolrDeletionPolicy1, TestSolrDeletionPolicy2, TestXIncludeConfig, TestSolrCloudSnapshots, RequestLoggingTest]
   [junit4] Completed [592/832 (1!)] on J0 in 0.50s, 2 tests, 2 failures <<< FAILURES!

[...truncated 43004 lines...]
[repro] Jenkins log URL: https://jenkins.thetaphi.de/job/Lucene-Solr-master-MacOSX/4807/consoleText

[repro] Revision: d55a81df849e093d043ac21f9e98532f091694d9

[repro] Ant options: "-Dargs=-XX:+UseCompressedOops -XX:+UseParallelGC"
[repro] Repro line:  ant test  -Dtestcase=RequestLoggingTest -Dtests.method=testLogBeforeExecuteWithCoreLogger -Dtests.seed=270471930FC37441 -Dtests.slow=true -Dtests.locale=ca-IT -Dtests.timezone=Europe/Zaporozhye -Dtests.asserts=true -Dtests.file.encoding=UTF-8

[repro] Repro line:  ant test  -Dtestcase=RequestLoggingTest -Dtests.method=testLogBeforeExecuteWithRequestLogger -Dtests.seed=270471930FC37441 -Dtests.slow=true -Dtests.locale=ca-IT -Dtests.timezone=Europe/Zaporozhye -Dtests.asserts=true -Dtests.file.encoding=UTF-8

[repro] ant clean

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

[...truncated 3445 lines...]
[repro] ant test-nocompile -Dtests.dups=5 -Dtests.maxfailures=5 -Dtests.class="*.RequestLoggingTest" -Dtests.showOutput=onerror "-Dargs=-XX:+UseCompressedOops -XX:+UseParallelGC" -Dtests.seed=270471930FC37441 -Dtests.slow=true -Dtests.locale=ca-IT -Dtests.timezone=Europe/Zaporozhye -Dtests.asserts=true -Dtests.file.encoding=UTF-8

[...truncated 52 lines...]
   [junit4] Suite: org.apache.solr.handler.RequestLoggingTest
   [junit4]   2> Creating dataDir: /Users/jenkins/workspace/Lucene-Solr-master-MacOSX/solr/build/solr-core/test/J1/temp/solr.handler.RequestLoggingTest_270471930FC37441-001/init-core-data-001
   [junit4]   2> 13288 WARN  (SUITE-RequestLoggingTest-seed#[270471930FC37441]-worker) [    ] o.a.s.SolrTestCaseJ4 startTrackingSearchers: numOpens=1 numCloses=1
   [junit4]   2> 13288 INFO  (SUITE-RequestLoggingTest-seed#[270471930FC37441]-worker) [    ] o.a.s.SolrTestCaseJ4 Using TrieFields (NUMERIC_POINTS_SYSPROP=false) w/NUMERIC_DOCVALUES_SYSPROP=false
   [junit4]   2> 13290 INFO  (SUITE-RequestLoggingTest-seed#[270471930FC37441]-worker) [    ] o.a.s.SolrTestCaseJ4 Randomized ssl (false) and clientAuth (false) via: @org.apache.solr.util.RandomizeSSL(reason="", value=0.0/0.0, ssl=0.0/0.0, clientAuth=0.0/0.0) w/ MAC_OS_X supressed clientAuth
   [junit4]   2> 13290 INFO  (SUITE-RequestLoggingTest-seed#[270471930FC37441]-worker) [    ] o.a.s.SolrTestCaseJ4 SecureRandom sanity checks: test.solr.allowed.securerandom=null & java.security.egd=file:/dev/./urandom
   [junit4]   2> 13290 INFO  (SUITE-RequestLoggingTest-seed#[270471930FC37441]-worker) [    ] o.a.s.SolrTestCaseJ4 ####initCore
   [junit4]   2> 13291 INFO  (SUITE-RequestLoggingTest-seed#[270471930FC37441]-worker) [    ] o.a.s.c.SolrResourceLoader [null] Added 2 libs to classloader, from paths: [/Users/jenkins/workspace/Lucene-Solr-master-MacOSX/solr/core/src/test-files/solr/collection1/lib, /Users/jenkins/workspace/Lucene-Solr-master-MacOSX/solr/core/src/test-files/solr/collection1/lib/classes]
   [junit4]   2> 13322 INFO  (SUITE-RequestLoggingTest-seed#[270471930FC37441]-worker) [    ] o.a.s.c.SolrConfig Using Lucene MatchVersion: 8.0.0
   [junit4]   2> 13344 INFO  (SUITE-RequestLoggingTest-seed#[270471930FC37441]-worker) [    ] o.a.s.s.IndexSchema [null] Schema name=test
   [junit4]   2> 13424 INFO  (SUITE-RequestLoggingTest-seed#[270471930FC37441]-worker) [    ] o.a.s.s.IndexSchema Loaded schema test/1.0 with uniqueid field id
   [junit4]   2> 13869 INFO  (SUITE-RequestLoggingTest-seed#[270471930FC37441]-worker) [    ] o.a.s.c.TransientSolrCoreCacheDefault Allocating transient cache for 2147483647 transient cores
   [junit4]   2> 13869 INFO  (SUITE-RequestLoggingTest-seed#[270471930FC37441]-worker) [    ] o.a.s.h.a.MetricsHistoryHandler No .system collection, keeping metrics history in memory.
   [junit4]   2> 13891 INFO  (SUITE-RequestLoggingTest-seed#[270471930FC37441]-worker) [    ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr.node' (registry 'solr.node') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@4b94f9b0
   [junit4]   2> 13891 INFO  (SUITE-RequestLoggingTest-seed#[270471930FC37441]-worker) [    ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr.jvm' (registry 'solr.jvm') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@4b94f9b0
   [junit4]   2> 13892 INFO  (SUITE-RequestLoggingTest-seed#[270471930FC37441]-worker) [    ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr.jetty' (registry 'solr.jetty') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@4b94f9b0
   [junit4]   2> 13895 INFO  (coreLoadExecutor-41-thread-1) [    x:collection1] o.a.s.c.SolrResourceLoader [null] Added 2 libs to classloader, from paths: [/Users/jenkins/workspace/Lucene-Solr-master-MacOSX/solr/core/src/test-files/solr/collection1/lib, /Users/jenkins/workspace/Lucene-Solr-master-MacOSX/solr/core/src/test-files/solr/collection1/lib/classes]
   [junit4]   2> 13924 INFO  (coreLoadExecutor-41-thread-1) [    x:collection1] o.a.s.c.SolrConfig Using Lucene MatchVersion: 8.0.0
   [junit4]   2> 13949 INFO  (coreLoadExecutor-41-thread-1) [    x:collection1] o.a.s.s.IndexSchema [collection1] Schema name=test
   [junit4]   2> 14021 INFO  (coreLoadExecutor-41-thread-1) [    x:collection1] o.a.s.s.IndexSchema Loaded schema test/1.0 with uniqueid field id
   [junit4]   2> 14043 INFO  (coreLoadExecutor-41-thread-1) [    x:collection1] o.a.s.c.CoreContainer Creating SolrCore 'collection1' using configuration from instancedir /Users/jenkins/workspace/Lucene-Solr-master-MacOSX/solr/core/src/test-files/solr/collection1, trusted=true
   [junit4]   2> 14044 INFO  (coreLoadExecutor-41-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@4b94f9b0
   [junit4]   2> 14044 INFO  (coreLoadExecutor-41-thread-1) [    x:collection1] o.a.s.c.SolrCore solr.RecoveryStrategy.Builder
   [junit4]   2> 14044 INFO  (coreLoadExecutor-41-thread-1) [    x:collection1] o.a.s.c.SolrCore [[collection1] ] Opening new SolrCore at [/Users/jenkins/workspace/Lucene-Solr-master-MacOSX/solr/core/src/test-files/solr/collection1], dataDir=[/Users/jenkins/workspace/Lucene-Solr-master-MacOSX/solr/build/solr-core/test/J1/temp/solr.handler.RequestLoggingTest_270471930FC37441-001/init-core-data-001/]
   [junit4]   2> 14047 INFO  (coreLoadExecutor-41-thread-1) [    x:collection1] o.a.s.u.RandomMergePolicy RandomMergePolicy wrapping class org.apache.lucene.index.AlcoholicMergePolicy: [AlcoholicMergePolicy: minMergeSize=0, mergeFactor=10, maxMergeSize=1476545815, maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=true, maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.1]
   [junit4]   2> 14131 INFO  (coreLoadExecutor-41-thread-1) [    x:collection1] o.a.s.u.UpdateHandler Using UpdateLog implementation: org.apache.solr.update.UpdateLog
   [junit4]   2> 14131 INFO  (coreLoadExecutor-41-thread-1) [    x:collection1] o.a.s.u.UpdateLog Initializing UpdateLog: dataDir= defaultSyncLevel=FLUSH numRecordsToKeep=100 maxNumLogsToKeep=10 numVersionBuckets=65536
   [junit4]   2> 14132 INFO  (coreLoadExecutor-41-thread-1) [    x:collection1] o.a.s.u.CommitTracker Hard AutoCommit: disabled
   [junit4]   2> 14132 INFO  (coreLoadExecutor-41-thread-1) [    x:collection1] o.a.s.u.CommitTracker Soft AutoCommit: disabled
   [junit4]   2> 14133 INFO  (coreLoadExecutor-41-thread-1) [    x:collection1] o.a.s.u.RandomMergePolicy RandomMergePolicy wrapping class org.apache.lucene.index.LogByteSizeMergePolicy: [LogByteSizeMergePolicy: minMergeSize=1677721, mergeFactor=15, maxMergeSize=2147483648, maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=true, maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.4649847431630678]
   [junit4]   2> 14134 INFO  (coreLoadExecutor-41-thread-1) [    x:collection1] o.a.s.s.SolrIndexSearcher Opening [Searcher@1fb54f2b[collection1] main]
   [junit4]   2> 14135 INFO  (coreLoadExecutor-41-thread-1) [    x:collection1] o.a.s.h.c.SpellCheckComponent Initializing spell checkers
   [junit4]   2> 14192 INFO  (coreLoadExecutor-41-thread-1) [    x:collection1] o.a.s.s.DirectSolrSpellChecker init: {name=direct,classname=DirectSolrSpellChecker,field=lowerfilt,minQueryLength=3}
   [junit4]   2> 14507 INFO  (coreLoadExecutor-41-thread-1) [    x:collection1] o.a.s.h.ReplicationHandler Commits will be reserved for 10000ms.
   [junit4]   2> 14507 INFO  (coreLoadExecutor-41-thread-1) [    x:collection1] o.a.s.u.UpdateLog Could not find max version in index or recent updates, using new clock 1610416925877207040
   [junit4]   2> 14507 INFO  (searcherExecutor-42-thread-1-processing-x:collection1) [    x:collection1] o.a.s.h.c.SpellCheckComponent Loading spell index for spellchecker: default
   [junit4]   2> 14510 INFO  (SUITE-RequestLoggingTest-seed#[270471930FC37441]-worker) [    ] o.a.s.SolrTestCaseJ4 ####initCore end
   [junit4]   2> 14512 INFO  (searcherExecutor-42-thread-1-processing-x:collection1) [    x:collection1] o.a.s.h.c.SpellCheckComponent Loading spell index for spellchecker: direct
   [junit4]   2> 14512 INFO  (searcherExecutor-42-thread-1-processing-x:collection1) [    x:collection1] o.a.s.h.c.SpellCheckComponent Loading spell index for spellchecker: wordbreak
   [junit4]   2> 14512 INFO  (searcherExecutor-42-thread-1-processing-x:collection1) [    x:collection1] o.a.s.h.c.SpellCheckComponent Loading spell index for spellchecker: multipleFields
   [junit4]   2> 14513 INFO  (searcherExecutor-42-thread-1-processing-x:collection1) [    x:collection1] o.a.s.h.c.SpellCheckComponent Loading spell index for spellchecker: jarowinkler
   [junit4]   2> 14514 INFO  (searcherExecutor-42-thread-1-processing-x:collection1) [    x:collection1] o.a.s.h.c.SpellCheckComponent Loading spell index for spellchecker: external
   [junit4]   2> 14516 INFO  (searcherExecutor-42-thread-1-processing-x:collection1) [    x:collection1] o.a.s.h.c.SpellCheckComponent Loading spell index for spellchecker: freq
   [junit4]   2> 14517 INFO  (TEST-RequestLoggingTest.testLogBeforeExecuteWithCoreLogger-seed#[270471930FC37441]) [    ] o.a.s.SolrTestCaseJ4 ###Starting testLogBeforeExecuteWithCoreLogger
   [junit4]   2> 14518 DEBUG (TEST-RequestLoggingTest.testLogBeforeExecuteWithCoreLogger-seed#[270471930FC37441]) [    ] o.a.s.c.S.Request [collection1]  webapp=null path=null params={q=*:*&wt=xml}
   [junit4]   2> 14518 DEBUG (TEST-RequestLoggingTest.testLogBeforeExecuteWithCoreLogger-seed#[270471930FC37441]) [    ] o.a.s.h.c.SearchHandler Adding  component:org.apache.solr.handler.component.QueryComponent@71df1513
   [junit4]   2> 14518 DEBUG (TEST-RequestLoggingTest.testLogBeforeExecuteWithCoreLogger-seed#[270471930FC37441]) [    ] o.a.s.h.c.SearchHandler Adding  component:org.apache.solr.handler.component.FacetComponent@9addb3c
   [junit4]   2> 14518 DEBUG (TEST-RequestLoggingTest.testLogBeforeExecuteWithCoreLogger-seed#[270471930FC37441]) [    ] o.a.s.h.c.SearchHandler Adding  component:org.apache.solr.search.facet.FacetModule@3598e18d
   [junit4]   2> 14519 DEBUG (TEST-RequestLoggingTest.testLogBeforeExecuteWithCoreLogger-seed#[270471930FC37441]) [    ] o.a.s.h.c.SearchHandler Adding  component:org.apache.solr.handler.component.MoreLikeThisComponent@72471788
   [junit4]   2> 14519 DEBUG (TEST-RequestLoggingTest.testLogBeforeExecuteWithCoreLogger-seed#[270471930FC37441]) [    ] o.a.s.h.c.SearchHandler Adding  component:org.apache.solr.handler.component.HighlightComponent@7b39f35e
   [junit4]   2> 14519 DEBUG (TEST-RequestLoggingTest.testLogBeforeExecuteWithCoreLogger-seed#[270471930FC37441]) [    ] o.a.s.h.c.SearchHandler Adding  component:org.apache.solr.handler.component.StatsComponent@1c2aa33e
   [junit4]   2> 14519 DEBUG (TEST-RequestLoggingTest.testLogBeforeExecuteWithCoreLogger-seed#[270471930FC37441]) [    ] o.a.s.h.c.SearchHandler Adding  component:org.apache.solr.handler.component.ExpandComponent@6eccadbf
   [junit4]   2> 14519 DEBUG (TEST-RequestLoggingTest.testLogBeforeExecuteWithCoreLogger-seed#[270471930FC37441]) [    ] o.a.s.h.c.SearchHandler Adding  component:org.apache.solr.handler.component.TermsComponent@24fd1cb9
   [junit4]   2> 14519 DEBUG (TEST-RequestLoggingTest.testLogBeforeExecuteWithCoreLogger-seed#[270471930FC37441]) [    ] o.a.s.h.c.SearchHandler Adding  debug component:org.apache.solr.handler.component.DebugComponent@106ab87b
   [junit4]   2> 14519 DEBUG (TEST-RequestLoggingTest.testLogBeforeExecuteWithCoreLogger-seed#[270471930FC37441]) [    ] o.a.s.h.c.QueryComponent process: q=*:*&df=text&wt=xml&indent=off
   [junit4]   2> 14519 DEBUG (TEST-RequestLoggingTest.testLogBeforeExecuteWithCoreLogger-seed#[270471930FC37441]) [    ] o.a.s.s.s.LocalStatsCache ## GET LocalSolrQueryRequest{q=*:*&df=text&wt=xml&indent=off}
   [junit4]   2> 14520 INFO  (searcherExecutor-42-thread-1-processing-x:collection1) [    x:collection1] o.a.s.h.c.SpellCheckComponent Loading spell index for spellchecker: fqcn
   [junit4]   2> 14521 INFO  (searcherExecutor-42-thread-1-processing-x:collection1) [    x:collection1] o.a.s.h.c.SpellCheckComponent Loading spell index for spellchecker: perDict
   [junit4]   2> 14521 DEBUG (searcherExecutor-42-thread-1-processing-x:collection1) [    x:collection1] o.a.s.m.r.j.JmxMetricsReporter ## registered solr:category=CACHE,dom1=core,dom2=collection1,name=fieldValueCache,scope=searcher, tag=7e1aa48f
   [junit4]   2> 14521 DEBUG (searcherExecutor-42-thread-1-processing-x:collection1) [    x:collection1] o.a.s.m.r.j.JmxMetricsReporter ## registered solr:category=CACHE,dom1=core,dom2=collection1,name=filterCache,scope=searcher, tag=7e1aa48f
   [junit4]   2> 14522 DEBUG (searcherExecutor-42-thread-1-processing-x:collection1) [    x:collection1] o.a.s.m.r.j.JmxMetricsReporter ## registered solr:category=CACHE,dom1=core,dom2=collection1,name=queryResultCache,scope=searcher, tag=7e1aa48f
   [junit4]   2> 14522 DEBUG (searcherExecutor-42-thread-1-processing-x:collection1) [    x:collection1] o.a.s.m.r.j.JmxMetricsReporter ## registered solr:category=CACHE,dom1=core,dom2=collection1,name=documentCache,scope=searcher, tag=7e1aa48f
   [junit4]   2> 14522 DEBUG (searcherExecutor-42-thread-1-processing-x:collection1) [    x:collection1] o.a.s.m.r.j.JmxMetricsReporter ## registered solr:category=CACHE,dom1=core,dom2=collection1,name=perSegFilter,scope=searcher, tag=7e1aa48f
   [junit4]   2> 14522 DEBUG (searcherExecutor-42-thread-1-processing-x:collection1) [    x:collection1] o.a.s.m.r.j.JmxMetricsReporter ## registered solr:category=SEARCHER,dom1=core,dom2=collection1,name=searcherName,scope=searcher, tag=7e1aa48f
   [junit4]   2> 14522 DEBUG (searcherExecutor-42-thread-1-processing-x:collection1) [    x:collection1] o.a.s.m.r.j.JmxMetricsReporter ## registered solr:category=SEARCHER,dom1=core,dom2=collection1,name=caching,scope=searcher, tag=7e1aa48f
   [junit4]   2> 14522 DEBUG (searcherExecutor-42-thread-1-processing-x:collection1) [    x:collection1] o.a.s.m.r.j.JmxMetricsReporter ## registered solr:category=SEARCHER,dom1=core,dom2=collection1,name=openedAt,scope=searcher, tag=7e1aa48f
   [junit4]   2> 14522 DEBUG (searcherExecutor-42-thread-1-processing-x:collection1) [    x:collection1] o.a.s.m.r.j.JmxMetricsReporter ## registered solr:category=SEARCHER,dom1=core,dom2=collection1,name=warmupTime,scope=searcher, tag=7e1aa48f
   [junit4]   2> 14522 DEBUG (searcherExecutor-42-thread-1-processing-x:collection1) [    x:collection1] o.a.s.m.r.j.JmxMetricsReporter ## registered solr:category=SEARCHER,dom1=core,dom2=collection1,name=registeredAt,scope=searcher, tag=7e1aa48f
   [junit4]   2> 14522 DEBUG (searcherExecutor-42-thread-1-processing-x:collection1) [    x:collection1] o.a.s.m.r.j.JmxMetricsReporter ## registered solr:category=SEARCHER,dom1=core,dom2=collection1,name=numDocs,scope=searcher, tag=7e1aa48f
   [junit4]   2> 14522 DEBUG (searcherExecutor-42-thread-1-processing-x:collection1) [    x:collection1] o.a.s.m.r.j.JmxMetricsReporter ## registered solr:category=SEARCHER,dom1=core,dom2=collection1,name=maxDoc,scope=searcher, tag=7e1aa48f
   [junit4]   2> 14522 DEBUG (searcherExecutor-42-thread-1-processing-x:collection1) [    x:collection1] o.a.s.m.r.j.JmxMetricsReporter ## registered solr:category=SEARCHER,dom1=core,dom2=collection1,name=deletedDocs,scope=searcher, tag=7e1aa48f
   [junit4]   2> 14522 DEBUG (searcherExecutor-42-thread-1-processing-x:collection1) [    x:collection1] o.a.s.m.r.j.JmxMetricsReporter ## registered solr:category=SEARCHER,dom1=core,dom2=collection1,name=reader,scope=searcher, tag=7e1aa48f
   [junit4]   2> 14522 DEBUG (searcherExecutor-42-thread-1-processing-x:collection1) [    x:collection1] o.a.s.m.r.j.JmxMetricsReporter ## registered solr:category=SEARCHER,dom1=core,dom2=collection1,name=readerDir,scope=searcher, tag=7e1aa48f
   [junit4]   2> 14522 DEBUG (searcherExecutor-42-thread-1-processing-x:collection1) [    x:collection1] o.a.s.m.r.j.JmxMetricsReporter ## registered solr:category=SEARCHER,dom1=core,dom2=collection1,name=indexVersion,scope=searcher, tag=7e1aa48f
   [junit4]   2> 14522 INFO  (searcherExecutor-42-thread-1-processing-x:collection1) [    x:collection1] o.a.s.c.SolrCore [collection1] Registered new searcher Searcher@1fb54f2b[collection1] main{ExitableDirectoryReader(UninvertingDirectoryReader())}
   [junit4]   2> 14523 INFO  (TEST-RequestLoggingTest.testLogBeforeExecuteWithCoreLogger-seed#[270471930FC37441]) [    ] o.a.s.c.S.Request [collection1]  webapp=null path=null params={q=*:*&wt=xml} hits=0 status=0 QTime=4
   [junit4] OK      0.01s J1 | RequestLoggingTest.testLogBeforeExecuteWithCoreLogger
   [junit4]   2> 14524 INFO  (TEST-RequestLoggingTest.testLogBeforeExecuteWithCoreLogger-seed#[270471930FC37441]) [    ] o.a.s.SolrTestCaseJ4 ###Ending testLogBeforeExecuteWithCoreLogger
   [junit4]   2> 14525 INFO  (TEST-RequestLoggingTest.testLogBeforeExecuteWithRequestLogger-seed#[270471930FC37441]) [    ] o.a.s.SolrTestCaseJ4 ###Starting testLogBeforeExecuteWithRequestLogger
   [junit4]   2> 14531 DEBUG (TEST-RequestLoggingTest.testLogBeforeExecuteWithRequestLogger-seed#[270471930FC37441]) [    ] o.a.s.c.S.Request [collection1]  webapp=null path=null params={q=*:*&wt=xml}
   [junit4]   2> 14532 DEBUG (TEST-RequestLoggingTest.testLogBeforeExecuteWithRequestLogger-seed#[270471930FC37441]) [    ] o.a.s.h.c.QueryComponent process: q=*:*&df=text&wt=xml&indent=off
   [junit4]   2> 14532 DEBUG (TEST-RequestLoggingTest.testLogBeforeExecuteWithRequestLogger-seed#[270471930FC37441]) [    ] o.a.s.s.s.LocalStatsCache ## GET LocalSolrQueryRequest{q=*:*&df=text&wt=xml&indent=off}
   [junit4]   2> 14532 INFO  (TEST-RequestLoggingTest.testLogBeforeExecuteWithRequestLogger-seed#[270471930FC37441]) [    ] o.a.s.c.S.Request [collection1]  webapp=null path=null params={q=*:*&wt=xml} hits=0 status=0 QTime=0
   [junit4]   2> 14532 INFO  (TEST-RequestLoggingTest.testLogBeforeExecuteWithRequestLogger-seed#[270471930FC37441]) [    ] o.a.s.SolrTestCaseJ4 ###Ending testLogBeforeExecuteWithRequestLogger
   [junit4]   2> NOTE: reproduce with: ant test  -Dtestcase=RequestLoggingTest -Dtests.method=testLogBeforeExecuteWithRequestLogger -Dtests.seed=270471930FC37441 -Dtests.slow=true -Dtests.badapples=true -Dtests.locale=ca-IT -Dtests.timezone=Europe/Zaporozhye -Dtests.asserts=true -Dtests.file.encoding=UTF-8
   [junit4] FAILURE 0.01s J1 | RequestLoggingTest.testLogBeforeExecuteWithRequestLogger <<<
   [junit4]    > Throwable #1: java.lang.AssertionError
   [junit4]    > 	at __randomizedtesting.SeedInfo.seed([270471930FC37441:966D519CA235CC0F]:0)
   [junit4]    > 	at org.apache.solr.handler.RequestLoggingTest.testLogBeforeExecute(RequestLoggingTest.java:88)
   [junit4]    > 	at org.apache.solr.handler.RequestLoggingTest.testLogBeforeExecuteWithRequestLogger(RequestLoggingTest.java:71)
   [junit4]    > 	at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
   [junit4]    > 	at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
   [junit4]    > 	at java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
   [junit4]    > 	at java.base/java.lang.reflect.Method.invoke(Method.java:564)
   [junit4]    > 	at java.base/java.lang.Thread.run(Thread.java:844)
   [junit4]   2> 14538 INFO  (SUITE-RequestLoggingTest-seed#[270471930FC37441]-worker) [    ] o.a.s.SolrTestCaseJ4 ###deleteCore
   [junit4]   2> 14538 INFO  (SUITE-RequestLoggingTest-seed#[270471930FC37441]-worker) [    ] o.a.s.c.CoreContainer Shutting down CoreContainer instance=2012850322
   [junit4]   2> 14538 INFO  (SUITE-RequestLoggingTest-seed#[270471930FC37441]-worker) [    ] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.node, tag=null
   [junit4]   2> 14540 INFO  (SUITE-RequestLoggingTest-seed#[270471930FC37441]-worker) [    ] o.a.s.m.r.SolrJmxReporter Closing reporter [org.apache.solr.metrics.reporters.SolrJmxReporter@5533290a: rootName = null, domain = solr.node, service url = null, agent id = null] for registry solr.node / com.codahale.metrics.MetricRegistry@550272d7
   [junit4]   2> 14548 INFO  (SUITE-RequestLoggingTest-seed#[270471930FC37441]-worker) [    ] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.jvm, tag=null
   [junit4]   2> 14548 INFO  (SUITE-RequestLoggingTest-seed#[270471930FC37441]-worker) [    ] o.a.s.m.r.SolrJmxReporter Closing reporter [org.apache.solr.metrics.reporters.SolrJmxReporter@4be8b32f: rootName = null, domain = solr.jvm, service url = null, agent id = null] for registry solr.jvm / com.codahale.metrics.MetricRegistry@2c3460e
   [junit4]   2> 14548 INFO  (SUITE-RequestLoggingTest-seed#[270471930FC37441]-worker) [    ] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.jetty, tag=null
   [junit4]   2> 14548 INFO  (SUITE-RequestLoggingTest-seed#[270471930FC37441]-worker) [    ] o.a.s.m.r.SolrJmxReporter Closing reporter [org.apache.solr.metrics.reporters.SolrJmxReporter@2eae5c76: rootName = null, domain = solr.jetty, service url = null, agent id = null] for registry solr.jetty / com.codahale.metrics.MetricRegistry@2dbef274
   [junit4]   2> 14549 INFO  (coreCloseExecutor-47-thread-1) [    x:collection1] o.a.s.c.SolrCore [collection1]  CLOSING SolrCore org.apache.solr.core.SolrCore@7b344d19
   [junit4]   2> 14549 INFO  (coreCloseExecutor-47-thread-1) [    x:collection1] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.core.collection1, tag=7b344d19
   [junit4]   2> 14549 INFO  (coreCloseExecutor-47-thread-1) [    x:collection1] o.a.s.m.r.SolrJmxReporter Closing reporter [org.apache.solr.metrics.reporters.SolrJmxReporter@7e1aa48f: rootName = null, domain = solr.core.collection1, service url = null, agent id = null] for registry solr.core.collection1 / com.codahale.metrics.MetricRegistry@37a5ee67
   [junit4]   2> NOTE: leaving temporary files on disk at: /Users/jenkins/workspace/Lucene-Solr-master-MacOSX/solr/build/solr-core/test/J1/temp/solr.handler.RequestLoggingTest_270471930FC37441-001
   [junit4]   2> NOTE: test params are: codec=Asserting(Lucene80): {}, docValues:{}, maxPointsInLeafNode=1319, maxMBSortInHeap=6.687687313786846, sim=Asserting(org.apache.lucene.search.similarities.AssertingSimilarity@366adbb2), locale=ca-IT, timezone=Europe/Zaporozhye
   [junit4]   2> NOTE: Mac OS X 10.11.6 x86_64/Oracle Corporation 9 (64-bit)/cpus=3,threads=1,free=100940992,total=224919552
   [junit4]   2> NOTE: All tests run in this JVM: [RequestLoggingTest, RequestLoggingTest, RequestLoggingTest]
   [junit4] Completed [5/5 (1!)] on J1 in 1.31s, 2 tests, 1 failure <<< FAILURES!

[...truncated 10 lines...]
BUILD FAILED
/Users/jenkins/workspace/Lucene-Solr-master-MacOSX/lucene/common-build.xml:1568: The following error occurred while executing this line:
/Users/jenkins/workspace/Lucene-Solr-master-MacOSX/lucene/common-build.xml:1092: There were test failures: 5 suites, 10 tests, 1 failure [seed: 270471930FC37441]

Total time: 18 seconds

[repro] Setting last failure code to 256

[repro] Failures:
[repro]   1/5 failed: org.apache.solr.handler.RequestLoggingTest
[repro] Exiting with code 256
+ mv lucene/build lucene/build.repro
+ mv solr/build solr/build.repro
+ mv lucene/build.orig lucene/build
+ mv solr/build.orig solr/build
Archiving artifacts
Setting ANT_1_8_2_HOME=/Users/jenkins/tools/hudson.tasks.Ant_AntInstallation/ANT_1.8.2
[WARNINGS] Parsing warnings in console log with parser Java Compiler (javac)
Setting ANT_1_8_2_HOME=/Users/jenkins/tools/hudson.tasks.Ant_AntInstallation/ANT_1.8.2
Setting ANT_1_8_2_HOME=/Users/jenkins/tools/hudson.tasks.Ant_AntInstallation/ANT_1.8.2
<Git Blamer> Using GitBlamer to create author and commit information for all warnings.
<Git Blamer> GIT_COMMIT=d55a81df849e093d043ac21f9e98532f091694d9, workspace=/Users/jenkins/workspace/Lucene-Solr-master-MacOSX
[WARNINGS] Computing warning deltas based on reference build #4806
Recording test results
Setting ANT_1_8_2_HOME=/Users/jenkins/tools/hudson.tasks.Ant_AntInstallation/ANT_1.8.2
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)
Setting ANT_1_8_2_HOME=/Users/jenkins/tools/hudson.tasks.Ant_AntInstallation/ANT_1.8.2
Setting ANT_1_8_2_HOME=/Users/jenkins/tools/hudson.tasks.Ant_AntInstallation/ANT_1.8.2
Setting ANT_1_8_2_HOME=/Users/jenkins/tools/hudson.tasks.Ant_AntInstallation/ANT_1.8.2
Setting ANT_1_8_2_HOME=/Users/jenkins/tools/hudson.tasks.Ant_AntInstallation/ANT_1.8.2

Mime
View raw message