You are viewing a plain text version of this content. The canonical link for it is here.
Posted to dev@lucene.apache.org by Policeman Jenkins Server <je...@thetaphi.de> on 2018/09/03 09:12:35 UTC

[JENKINS] Lucene-Solr-master-Windows (64bit/jdk-10) - Build # 7502 - Unstable!

Build: https://jenkins.thetaphi.de/job/Lucene-Solr-master-Windows/7502/
Java: 64bit/jdk-10 -XX:+UseCompressedOops -XX:+UseSerialGC

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

Error Message:


Stack Trace:
java.lang.AssertionError
	at __randomizedtesting.SeedInfo.seed([437D83C0F26C222A:F214A3CF5F9A9A64]: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.testLogBeforeExecuteWithRequestLogger

Error Message:


Stack Trace:
java.lang.AssertionError
	at __randomizedtesting.SeedInfo.seed([437D83C0F26C222A:F214A3CF5F9A9A64]: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.testLogBeforeExecuteWithRequestLogger

Error Message:


Stack Trace:
java.lang.AssertionError
	at __randomizedtesting.SeedInfo.seed([437D83C0F26C222A:F214A3CF5F9A9A64]: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.testLogBeforeExecuteWithRequestLogger

Error Message:


Stack Trace:
java.lang.AssertionError
	at __randomizedtesting.SeedInfo.seed([437D83C0F26C222A:F214A3CF5F9A9A64]: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 14586 lines...]
   [junit4] Suite: org.apache.solr.handler.RequestLoggingTest
   [junit4]   2> Creating dataDir: C:\Users\jenkins\workspace\Lucene-Solr-master-Windows\solr\build\solr-core\test\J0\temp\solr.handler.RequestLoggingTest_437D83C0F26C222A-001\init-core-data-001
   [junit4]   2> 4406212 WARN  (SUITE-RequestLoggingTest-seed#[437D83C0F26C222A]-worker) [    ] o.a.s.SolrTestCaseJ4 startTrackingSearchers: numOpens=5 numCloses=5
   [junit4]   2> 4406212 INFO  (SUITE-RequestLoggingTest-seed#[437D83C0F26C222A]-worker) [    ] o.a.s.SolrTestCaseJ4 Using PointFields (NUMERIC_POINTS_SYSPROP=true) w/NUMERIC_DOCVALUES_SYSPROP=true
   [junit4]   2> 4406214 INFO  (SUITE-RequestLoggingTest-seed#[437D83C0F26C222A]-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)
   [junit4]   2> 4406214 INFO  (SUITE-RequestLoggingTest-seed#[437D83C0F26C222A]-worker) [    ] o.a.s.SolrTestCaseJ4 SecureRandom sanity checks: test.solr.allowed.securerandom=null & java.security.egd=file:/dev/./urandom
   [junit4]   2> 4406215 INFO  (SUITE-RequestLoggingTest-seed#[437D83C0F26C222A]-worker) [    ] o.a.s.SolrTestCaseJ4 ####initCore
   [junit4]   2> 4406215 INFO  (SUITE-RequestLoggingTest-seed#[437D83C0F26C222A]-worker) [    ] o.a.s.c.SolrResourceLoader [null] Added 2 libs to classloader, from paths: [/C:/Users/jenkins/workspace/Lucene-Solr-master-Windows/solr/core/src/test-files/solr/collection1/lib, /C:/Users/jenkins/workspace/Lucene-Solr-master-Windows/solr/core/src/test-files/solr/collection1/lib/classes]
   [junit4]   2> 4406312 INFO  (SUITE-RequestLoggingTest-seed#[437D83C0F26C222A]-worker) [    ] o.a.s.c.SolrConfig Using Lucene MatchVersion: 8.0.0
   [junit4]   2> 4406336 INFO  (SUITE-RequestLoggingTest-seed#[437D83C0F26C222A]-worker) [    ] o.a.s.s.IndexSchema [null] Schema name=test
   [junit4]   2> 4406449 INFO  (SUITE-RequestLoggingTest-seed#[437D83C0F26C222A]-worker) [    ] o.a.s.s.IndexSchema Loaded schema test/1.0 with uniqueid field id
   [junit4]   2> 4406600 INFO  (SUITE-RequestLoggingTest-seed#[437D83C0F26C222A]-worker) [    ] o.a.s.c.TransientSolrCoreCacheDefault Allocating transient cache for 2147483647 transient cores
   [junit4]   2> 4406600 INFO  (SUITE-RequestLoggingTest-seed#[437D83C0F26C222A]-worker) [    ] o.a.s.h.a.MetricsHistoryHandler No .system collection, keeping metrics history in memory.
   [junit4]   2> 4406626 INFO  (SUITE-RequestLoggingTest-seed#[437D83C0F26C222A]-worker) [    ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr.node' (registry 'solr.node') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@107cb64f
   [junit4]   2> 4406634 INFO  (SUITE-RequestLoggingTest-seed#[437D83C0F26C222A]-worker) [    ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr.jvm' (registry 'solr.jvm') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@107cb64f
   [junit4]   2> 4406635 INFO  (SUITE-RequestLoggingTest-seed#[437D83C0F26C222A]-worker) [    ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr.jetty' (registry 'solr.jetty') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@107cb64f
   [junit4]   2> 4406643 INFO  (coreLoadExecutor-15258-thread-1) [    x:collection1] o.a.s.c.SolrResourceLoader [null] Added 2 libs to classloader, from paths: [/C:/Users/jenkins/workspace/Lucene-Solr-master-Windows/solr/core/src/test-files/solr/collection1/lib, /C:/Users/jenkins/workspace/Lucene-Solr-master-Windows/solr/core/src/test-files/solr/collection1/lib/classes]
   [junit4]   2> 4406712 INFO  (coreLoadExecutor-15258-thread-1) [    x:collection1] o.a.s.c.SolrConfig Using Lucene MatchVersion: 8.0.0
   [junit4]   2> 4406764 INFO  (coreLoadExecutor-15258-thread-1) [    x:collection1] o.a.s.s.IndexSchema [collection1] Schema name=test
   [junit4]   2> 4406841 INFO  (coreLoadExecutor-15258-thread-1) [    x:collection1] o.a.s.s.IndexSchema Loaded schema test/1.0 with uniqueid field id
   [junit4]   2> 4406869 INFO  (coreLoadExecutor-15258-thread-1) [    x:collection1] o.a.s.c.CoreContainer Creating SolrCore 'collection1' using configuration from instancedir C:\Users\jenkins\workspace\Lucene-Solr-master-Windows\solr\core\src\test-files\solr\collection1, trusted=true
   [junit4]   2> 4406869 INFO  (coreLoadExecutor-15258-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@107cb64f
   [junit4]   2> 4406869 INFO  (coreLoadExecutor-15258-thread-1) [    x:collection1] o.a.s.c.SolrCore solr.RecoveryStrategy.Builder
   [junit4]   2> 4406869 INFO  (coreLoadExecutor-15258-thread-1) [    x:collection1] o.a.s.c.SolrCore [[collection1] ] Opening new SolrCore at [C:\Users\jenkins\workspace\Lucene-Solr-master-Windows\solr\core\src\test-files\solr\collection1], dataDir=[C:\Users\jenkins\workspace\Lucene-Solr-master-Windows\solr\build\solr-core\test\J0\temp\solr.handler.RequestLoggingTest_437D83C0F26C222A-001\init-core-data-001\]
   [junit4]   2> 4406869 INFO  (coreLoadExecutor-15258-thread-1) [    x:collection1] o.a.s.u.RandomMergePolicy RandomMergePolicy wrapping class org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: maxMergeAtOnce=24, maxMergeAtOnceExplicit=19, maxMergedSegmentMB=38.248046875, floorSegmentMB=1.8740234375, forceMergeDeletesPctAllowed=7.938843534166596, segmentsPerTier=33.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.26079601911510797, deletesPctAllowed=34.07969886536636
   [junit4]   2> 4407076 INFO  (coreLoadExecutor-15258-thread-1) [    x:collection1] o.a.s.u.UpdateHandler Using UpdateLog implementation: org.apache.solr.update.UpdateLog
   [junit4]   2> 4407076 INFO  (coreLoadExecutor-15258-thread-1) [    x:collection1] o.a.s.u.UpdateLog Initializing UpdateLog: dataDir= defaultSyncLevel=FLUSH numRecordsToKeep=100 maxNumLogsToKeep=10 numVersionBuckets=65536
   [junit4]   2> 4407083 INFO  (coreLoadExecutor-15258-thread-1) [    x:collection1] o.a.s.u.CommitTracker Hard AutoCommit: disabled
   [junit4]   2> 4407083 INFO  (coreLoadExecutor-15258-thread-1) [    x:collection1] o.a.s.u.CommitTracker Soft AutoCommit: disabled
   [junit4]   2> 4407085 INFO  (coreLoadExecutor-15258-thread-1) [    x:collection1] o.a.s.u.RandomMergePolicy RandomMergePolicy wrapping class org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: maxMergeAtOnce=27, maxMergeAtOnceExplicit=38, maxMergedSegmentMB=16.1982421875, floorSegmentMB=0.642578125, forceMergeDeletesPctAllowed=28.190975929931316, segmentsPerTier=45.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.0, deletesPctAllowed=26.417390670823988
   [junit4]   2> 4407085 INFO  (coreLoadExecutor-15258-thread-1) [    x:collection1] o.a.s.s.SolrIndexSearcher Opening [Searcher@3327d8ae[collection1] main]
   [junit4]   2> 4407086 INFO  (coreLoadExecutor-15258-thread-1) [    x:collection1] o.a.s.h.c.SpellCheckComponent Initializing spell checkers
   [junit4]   2> 4407203 INFO  (coreLoadExecutor-15258-thread-1) [    x:collection1] o.a.s.s.DirectSolrSpellChecker init: {name=direct,classname=DirectSolrSpellChecker,field=lowerfilt,minQueryLength=3}
   [junit4]   2> 4407717 INFO  (coreLoadExecutor-15258-thread-1) [    x:collection1] o.a.s.h.ReplicationHandler Commits will be reserved for 10000ms.
   [junit4]   2> 4407717 INFO  (coreLoadExecutor-15258-thread-1) [    x:collection1] o.a.s.u.UpdateLog Could not find max version in index or recent updates, using new clock 1610575262327504896
   [junit4]   2> 4407719 INFO  (searcherExecutor-15259-thread-1-processing-x:collection1) [    x:collection1] o.a.s.h.c.SpellCheckComponent Loading spell index for spellchecker: default
   [junit4]   2> 4407723 INFO  (searcherExecutor-15259-thread-1-processing-x:collection1) [    x:collection1] o.a.s.h.c.SpellCheckComponent Loading spell index for spellchecker: direct
   [junit4]   2> 4407723 INFO  (searcherExecutor-15259-thread-1-processing-x:collection1) [    x:collection1] o.a.s.h.c.SpellCheckComponent Loading spell index for spellchecker: wordbreak
   [junit4]   2> 4407723 INFO  (searcherExecutor-15259-thread-1-processing-x:collection1) [    x:collection1] o.a.s.h.c.SpellCheckComponent Loading spell index for spellchecker: multipleFields
   [junit4]   2> 4407724 INFO  (SUITE-RequestLoggingTest-seed#[437D83C0F26C222A]-worker) [    ] o.a.s.SolrTestCaseJ4 ####initCore end
   [junit4]   2> 4407724 INFO  (searcherExecutor-15259-thread-1-processing-x:collection1) [    x:collection1] o.a.s.h.c.SpellCheckComponent Loading spell index for spellchecker: jarowinkler
   [junit4]   2> 4407725 INFO  (searcherExecutor-15259-thread-1-processing-x:collection1) [    x:collection1] o.a.s.h.c.SpellCheckComponent Loading spell index for spellchecker: external
   [junit4]   2> 4407737 INFO  (TEST-RequestLoggingTest.testLogBeforeExecuteWithCoreLogger-seed#[437D83C0F26C222A]) [    ] o.a.s.SolrTestCaseJ4 ###Starting testLogBeforeExecuteWithCoreLogger
   [junit4]   2> 4407747 INFO  (searcherExecutor-15259-thread-1-processing-x:collection1) [    x:collection1] o.a.s.h.c.SpellCheckComponent Loading spell index for spellchecker: freq
   [junit4]   2> 4407754 INFO  (searcherExecutor-15259-thread-1-processing-x:collection1) [    x:collection1] o.a.s.h.c.SpellCheckComponent Loading spell index for spellchecker: fqcn
   [junit4]   2> 4407756 INFO  (searcherExecutor-15259-thread-1-processing-x:collection1) [    x:collection1] o.a.s.h.c.SpellCheckComponent Loading spell index for spellchecker: perDict
   [junit4]   2> 4407756 DEBUG (TEST-RequestLoggingTest.testLogBeforeExecuteWithCoreLogger-seed#[437D83C0F26C222A]) [    ] o.a.s.c.S.Request [collection1]  webapp=null path=null params={q=*:*&wt=xml}
   [junit4]   2> 4407756 DEBUG (TEST-RequestLoggingTest.testLogBeforeExecuteWithCoreLogger-seed#[437D83C0F26C222A]) [    ] o.a.s.h.c.SearchHandler Adding  component:org.apache.solr.handler.component.QueryComponent@7f7f1f9a
   [junit4]   2> 4407756 DEBUG (TEST-RequestLoggingTest.testLogBeforeExecuteWithCoreLogger-seed#[437D83C0F26C222A]) [    ] o.a.s.h.c.SearchHandler Adding  component:org.apache.solr.handler.component.FacetComponent@429dd642
   [junit4]   2> 4407756 DEBUG (TEST-RequestLoggingTest.testLogBeforeExecuteWithCoreLogger-seed#[437D83C0F26C222A]) [    ] o.a.s.h.c.SearchHandler Adding  component:org.apache.solr.search.facet.FacetModule@2b71c6b2
   [junit4]   2> 4407756 DEBUG (TEST-RequestLoggingTest.testLogBeforeExecuteWithCoreLogger-seed#[437D83C0F26C222A]) [    ] o.a.s.h.c.SearchHandler Adding  component:org.apache.solr.handler.component.MoreLikeThisComponent@1624e415
   [junit4]   2> 4407756 DEBUG (TEST-RequestLoggingTest.testLogBeforeExecuteWithCoreLogger-seed#[437D83C0F26C222A]) [    ] o.a.s.h.c.SearchHandler Adding  component:org.apache.solr.handler.component.HighlightComponent@11a0ba84
   [junit4]   2> 4407756 DEBUG (TEST-RequestLoggingTest.testLogBeforeExecuteWithCoreLogger-seed#[437D83C0F26C222A]) [    ] o.a.s.h.c.SearchHandler Adding  component:org.apache.solr.handler.component.StatsComponent@3d234134
   [junit4]   2> 4407756 DEBUG (TEST-RequestLoggingTest.testLogBeforeExecuteWithCoreLogger-seed#[437D83C0F26C222A]) [    ] o.a.s.h.c.SearchHandler Adding  component:org.apache.solr.handler.component.ExpandComponent@18425474
   [junit4]   2> 4407756 DEBUG (TEST-RequestLoggingTest.testLogBeforeExecuteWithCoreLogger-seed#[437D83C0F26C222A]) [    ] o.a.s.h.c.SearchHandler Adding  component:org.apache.solr.handler.component.TermsComponent@29f71f25
   [junit4]   2> 4407756 DEBUG (TEST-RequestLoggingTest.testLogBeforeExecuteWithCoreLogger-seed#[437D83C0F26C222A]) [    ] o.a.s.h.c.SearchHandler Adding  debug component:org.apache.solr.handler.component.DebugComponent@3d17e405
   [junit4]   2> 4407757 DEBUG (TEST-RequestLoggingTest.testLogBeforeExecuteWithCoreLogger-seed#[437D83C0F26C222A]) [    ] o.a.s.h.c.QueryComponent process: q=*:*&df=text&wt=xml&indent=off
   [junit4]   2> 4407757 DEBUG (TEST-RequestLoggingTest.testLogBeforeExecuteWithCoreLogger-seed#[437D83C0F26C222A]) [    ] o.a.s.s.s.LocalStatsCache ## GET LocalSolrQueryRequest{q=*:*&df=text&wt=xml&indent=off}
   [junit4]   2> 4407758 DEBUG (searcherExecutor-15259-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=7d1bbedb
   [junit4]   2> 4407758 DEBUG (searcherExecutor-15259-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=7d1bbedb
   [junit4]   2> 4407758 DEBUG (searcherExecutor-15259-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=7d1bbedb
   [junit4]   2> 4407758 DEBUG (searcherExecutor-15259-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=7d1bbedb
   [junit4]   2> 4407758 DEBUG (searcherExecutor-15259-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=7d1bbedb
   [junit4]   2> 4407758 DEBUG (searcherExecutor-15259-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=7d1bbedb
   [junit4]   2> 4407758 DEBUG (searcherExecutor-15259-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=7d1bbedb
   [junit4]   2> 4407758 DEBUG (searcherExecutor-15259-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=7d1bbedb
   [junit4]   2> 4407758 DEBUG (searcherExecutor-15259-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=7d1bbedb
   [junit4]   2> 4407758 DEBUG (searcherExecutor-15259-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=7d1bbedb
   [junit4]   2> 4407758 DEBUG (searcherExecutor-15259-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=7d1bbedb
   [junit4]   2> 4407758 DEBUG (searcherExecutor-15259-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=7d1bbedb
   [junit4]   2> 4407758 DEBUG (searcherExecutor-15259-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=7d1bbedb
   [junit4]   2> 4407758 DEBUG (searcherExecutor-15259-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=7d1bbedb
   [junit4]   2> 4407758 DEBUG (searcherExecutor-15259-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=7d1bbedb
   [junit4]   2> 4407758 DEBUG (searcherExecutor-15259-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=7d1bbedb
   [junit4]   2> 4407758 INFO  (searcherExecutor-15259-thread-1-processing-x:collection1) [    x:collection1] o.a.s.c.SolrCore [collection1] Registered new searcher Searcher@3327d8ae[collection1] main{ExitableDirectoryReader(UninvertingDirectoryReader())}
   [junit4]   2> 4407759 INFO  (TEST-RequestLoggingTest.testLogBeforeExecuteWithCoreLogger-seed#[437D83C0F26C222A]) [    ] o.a.s.c.S.Request [collection1]  webapp=null path=null params={q=*:*&wt=xml} hits=0 status=0 QTime=3
   [junit4]   2> 4407761 INFO  (TEST-RequestLoggingTest.testLogBeforeExecuteWithCoreLogger-seed#[437D83C0F26C222A]) [    ] o.a.s.SolrTestCaseJ4 ###Ending testLogBeforeExecuteWithCoreLogger
   [junit4]   2> 4407763 INFO  (TEST-RequestLoggingTest.testLogBeforeExecuteWithRequestLogger-seed#[437D83C0F26C222A]) [    ] o.a.s.SolrTestCaseJ4 ###Starting testLogBeforeExecuteWithRequestLogger
   [junit4]   2> 4407767 DEBUG (TEST-RequestLoggingTest.testLogBeforeExecuteWithRequestLogger-seed#[437D83C0F26C222A]) [    ] o.a.s.c.S.Request [collection1]  webapp=null path=null params={q=*:*&wt=xml}
   [junit4]   2> 4407767 DEBUG (TEST-RequestLoggingTest.testLogBeforeExecuteWithRequestLogger-seed#[437D83C0F26C222A]) [    ] o.a.s.h.c.QueryComponent process: q=*:*&df=text&wt=xml&indent=off
   [junit4]   2> 4407767 DEBUG (TEST-RequestLoggingTest.testLogBeforeExecuteWithRequestLogger-seed#[437D83C0F26C222A]) [    ] o.a.s.s.s.LocalStatsCache ## GET LocalSolrQueryRequest{q=*:*&df=text&wt=xml&indent=off}
   [junit4]   2> 4407767 INFO  (TEST-RequestLoggingTest.testLogBeforeExecuteWithRequestLogger-seed#[437D83C0F26C222A]) [    ] o.a.s.c.S.Request [collection1]  webapp=null path=null params={q=*:*&wt=xml} hits=0 status=0 QTime=0
   [junit4]   2> 4407793 INFO  (TEST-RequestLoggingTest.testLogBeforeExecuteWithRequestLogger-seed#[437D83C0F26C222A]) [    ] o.a.s.SolrTestCaseJ4 ###Ending testLogBeforeExecuteWithRequestLogger
   [junit4]   2> NOTE: reproduce with: ant test  -Dtestcase=RequestLoggingTest -Dtests.method=testLogBeforeExecuteWithRequestLogger -Dtests.seed=437D83C0F26C222A -Dtests.slow=true -Dtests.locale=lt-LT -Dtests.timezone=NST -Dtests.asserts=true -Dtests.file.encoding=ISO-8859-1
   [junit4] FAILURE 0.03s J0 | RequestLoggingTest.testLogBeforeExecuteWithRequestLogger <<<
   [junit4]    > Throwable #1: java.lang.AssertionError
   [junit4]    > 	at __randomizedtesting.SeedInfo.seed([437D83C0F26C222A:F214A3CF5F9A9A64]: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> 4407795 INFO  (SUITE-RequestLoggingTest-seed#[437D83C0F26C222A]-worker) [    ] o.a.s.SolrTestCaseJ4 ###deleteCore
   [junit4]   2> 4407795 INFO  (SUITE-RequestLoggingTest-seed#[437D83C0F26C222A]-worker) [    ] o.a.s.c.CoreContainer Shutting down CoreContainer instance=401254288
   [junit4]   2> 4407796 INFO  (SUITE-RequestLoggingTest-seed#[437D83C0F26C222A]-worker) [    ] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.node, tag=null
   [junit4]   2> 4407796 INFO  (SUITE-RequestLoggingTest-seed#[437D83C0F26C222A]-worker) [    ] o.a.s.m.r.SolrJmxReporter Closing reporter [org.apache.solr.metrics.reporters.SolrJmxReporter@4512c3df: rootName = null, domain = solr.node, service url = null, agent id = null] for registry solr.node / com.codahale.metrics.MetricRegistry@7c7c2e52
   [junit4]   2> 4407800 INFO  (SUITE-RequestLoggingTest-seed#[437D83C0F26C222A]-worker) [    ] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.jvm, tag=null
   [junit4]   2> 4407800 INFO  (SUITE-RequestLoggingTest-seed#[437D83C0F26C222A]-worker) [    ] o.a.s.m.r.SolrJmxReporter Closing reporter [org.apache.solr.metrics.reporters.SolrJmxReporter@3e0c7eb8: rootName = null, domain = solr.jvm, service url = null, agent id = null] for registry solr.jvm / com.codahale.metrics.MetricRegistry@41abec04
   [junit4]   2> 4407803 INFO  (SUITE-RequestLoggingTest-seed#[437D83C0F26C222A]-worker) [    ] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.jetty, tag=null
   [junit4]   2> 4407803 INFO  (SUITE-RequestLoggingTest-seed#[437D83C0F26C222A]-worker) [    ] o.a.s.m.r.SolrJmxReporter Closing reporter [org.apache.solr.metrics.reporters.SolrJmxReporter@6df1ca0f: rootName = null, domain = solr.jetty, service url = null, agent id = null] for registry solr.jetty / com.codahale.metrics.MetricRegistry@1f5dcadc
   [junit4]   2> 4407804 INFO  (coreCloseExecutor-15264-thread-1) [    x:collection1] o.a.s.c.SolrCore [collection1]  CLOSING SolrCore org.apache.solr.core.SolrCore@1d6584f5
   [junit4]   2> 4407804 INFO  (coreCloseExecutor-15264-thread-1) [    x:collection1] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.core.collection1, tag=1d6584f5
   [junit4]   2> 4407804 INFO  (coreCloseExecutor-15264-thread-1) [    x:collection1] o.a.s.m.r.SolrJmxReporter Closing reporter [org.apache.solr.metrics.reporters.SolrJmxReporter@7d1bbedb: rootName = null, domain = solr.core.collection1, service url = null, agent id = null] for registry solr.core.collection1 / com.codahale.metrics.MetricRegistry@588cc6ab
   [junit4]   2> NOTE: leaving temporary files on disk at: C:\Users\jenkins\workspace\Lucene-Solr-master-Windows\solr\build\solr-core\test\J0\temp\solr.handler.RequestLoggingTest_437D83C0F26C222A-001
   [junit4]   2> Sep 03, 2018 8:44:22 AM com.carrotsearch.randomizedtesting.ThreadLeakControl checkThreadLeaks
   [junit4]   2> WARNING: Will linger awaiting termination of 2 leaked thread(s).
   [junit4]   2> NOTE: test params are: codec=CheapBastard, sim=Asserting(org.apache.lucene.search.similarities.AssertingSimilarity@5909153f), locale=lt-LT, timezone=NST
   [junit4]   2> NOTE: Windows 10 10.0 amd64/Oracle Corporation 10 (64-bit)/cpus=3,threads=1,free=140965944,total=518979584
   [junit4]   2> NOTE: All tests run in this JVM: [ConfigureRecoveryStrategyTest, TestZkAclsWithHadoopAuth, CoreAdminHandlerTest, AnalyticsMergeStrategyTest, ProtectedTermFilterFactoryTest, TestHashQParserPlugin, TestApiFramework, RecoveryAfterSoftCommitTest, TestGeoJSONResponseWriter, HighlighterMaxOffsetTest, TestRecovery, DistributedTermsComponentTest, HdfsChaosMonkeyNothingIsSafeTest, NodeAddedTriggerTest, SolrCLIZkUtilsTest, TestScoreJoinQPNoScore, ChaosMonkeySafeLeaderTest, TestJmxIntegration, NoCacheHeaderTest, TriggerCooldownIntegrationTest, CreateRoutedAliasTest, SmileWriterTest, TestSchemaVersionResource, TestExpandComponent, TestSearchPerf, MultiTermTest, TestReload, WrapperMergePolicyFactoryTest, TestSQLHandler, PeerSyncWithLeaderAndIndexFingerprintCachingTest, TestReplicationHandler, HdfsDirectoryTest, LIROnShardRestartTest, TestSolrConfigHandlerCloud, SolrRequestParserTest, SpatialHeatmapFacetsTest, PolyFieldTest, TestShortCircuitedRequests, WordBreakSolrSpellCheckerTest, TestClusterProperties, MissingSegmentRecoveryTest, TestLegacyField, TestJoin, NodeMutatorTest, ActionThrottleTest, SpellCheckCollatorWithCollapseTest, SolrMetricManagerTest, CdcrUpdateLogTest, TestSimpleTextCodec, TestRestManager, CdcrBidirectionalTest, CollectionStateFormat2Test, SimpleFacetsTest, NumericFieldsTest, TestMaxScoreQueryParser, MaxSizeAutoCommitTest, ClassificationUpdateProcessorIntegrationTest, TestLuceneIndexBackCompat, TestCloudDeleteByQuery, HttpPartitionOnCommitTest, TestXmlQParser, TestCollapseQParserPlugin, DOMUtilTest, TransactionLogTest, TestWriterPerf, TestPullReplica, LukeRequestHandlerTest, TestCopyFieldCollectionResource, TestHdfsUpdateLog, ConvertedLegacyTest, TestInfoStreamLogging, BigEndianAscendingWordSerializerTest, TestGroupingSearch, SpatialFilterTest, SuggesterTSTTest, TestManagedResource, TestCoreBackup, TestCorePropertiesReload, LeaderFailureAfterFreshStartTest, AtomicUpdatesTest, DistributedQueueTest, TestQuerySenderListener, SolrCloudReportersTest, TestDynamicFieldResource, SoftAutoCommitTest, TestFilteredDocIdSet, DistributedSpellCheckComponentTest, AutoAddReplicasPlanActionTest, ScheduledTriggerIntegrationTest, TolerantUpdateProcessorTest, DirectoryFactoryTest, TestPKIAuthenticationPlugin, PropertiesRequestHandlerTest, TestManagedSynonymFilterFactory, TestRawTransformer, OverseerTest, TestSimExecutePlanAction, DistributedMLTComponentTest, TestLRUCache, ZkStateWriterTest, TestExactStatsCache, TestRangeQuery, AnalysisAfterCoreReloadTest, TestCrossCoreJoin, AutoscalingHistoryHandlerTest, TestJsonRequest, PluginInfoTest, RemoteQueryErrorTest, TermsComponentTest, TestPostingsSolrHighlighter, ZkNodePropsTest, V2StandaloneTest, TestSolrIndexConfig, RuleEngineTest, PreAnalyzedUpdateProcessorTest, TestAuthenticationFramework, TermVectorComponentDistributedTest, MultiSolrCloudTestCaseTest, SpellCheckComponentTest, IndexSchemaTest, TestStressVersions, TestDocBasedVersionConstraints, TestDistribIDF, ReplaceNodeTest, TemplateUpdateProcessorTest, TriggerIntegrationTest, TestHalfAndHalfDocValues, RestoreTriggerStateTest, TestJettySolrRunner, TestClusterStateMutator, TestRandomFaceting, TestCustomSort, UpdateRequestProcessorFactoryTest, CdcrRequestHandlerTest, TestRTimerTree, DistanceFunctionTest, TestSimLargeCluster, TestDFRSimilarityFactory, ShardRoutingCustomTest, SolrXmlInZkTest, CoreAdminRequestStatusTest, DistributedDebugComponentTest, CurrencyRangeFacetCloudTest, TestSha256AuthenticationProvider, TestSystemCollAutoCreate, TestStressCloudBlindAtomicUpdates, TestSolrCLIRunExample, TestChildDocTransformerHierarchy, ZookeeperStatusHandlerTest, TestJsonFacets, SolrIndexSplitterTest, TestSolrCoreSnapshots, TestLegacyNumericUtils, TaggingAttributeTest, TestFieldTypeResource, SchemaVersionSpecificBehaviorTest, DeleteLastCustomShardedReplicaTest, TestRandomFlRTGCloud, FieldAnalysisRequestHandlerTest, TestSort, DocValuesTest, LeaderVoteWaitTimeoutTest, ConcurrentDeleteAndCreateCollectionTest, TestAnalyzedSuggestions, OverriddenZkACLAndCredentialsProvidersTest, OutputWriterTest, SolrJmxReporterTest, XsltUpdateRequestHandlerTest, TestCodecSupport, TestPartialUpdateDeduplication, TestLMDirichletSimilarityFactory, SearchHandlerTest, TestRebalanceLeaders, HdfsTlogReplayBufferedWhileIndexingTest, CollectionReloadTest, SimpleCollectionCreateDeleteTest, TestSortableTextField, FullSolrCloudDistribCmdsTest, DirectUpdateHandlerTest, NodeLostTriggerTest, TestMergePolicyConfig, LeaderElectionContextKeyTest, SearchRateTriggerIntegrationTest, UUIDUpdateProcessorFallbackTest, IgnoreLargeDocumentProcessorFactoryTest, TestSchemaResource, TestDownShardTolerantSearch, TestConfigSetProperties, TestInPlaceUpdatesStandalone, TestLockTree, TestSchemaManager, TestSolrDeletionPolicy1, PreAnalyzedFieldTest, TestFastLRUCache, TestRequestStatusCollectionAPI, ScriptEngineTest, DeleteStatusTest, TestStressLucene, TestOnReconnectListenerSupport, TestComplexPhraseQParserPlugin, TestDistributedSearch, TestUseDocValuesAsStored2, DisMaxRequestHandlerTest, DistributedIntervalFacetingTest, EchoParamsTest, MinimalSchemaTest, SolrInfoBeanTest, SolrTestCaseJ4Test, TestDistributedGrouping, TestDistributedMissingSort, TestSolrCoreProperties, TestTolerantSearch, TestTrie, PathHierarchyTokenizerFactoryTest, TestLuceneMatchVersion, TestReversedWildcardFilterFactory, TestWordDelimiterFilterFactory, TokenizerChainTest, TestEmbeddedSolrServerConstructors, TestEmbeddedSolrServerSchemaAPI, AliasIntegrationTest, AsyncCallRequestStatusResponseTest, BasicDistributedZk2Test, BasicZkTest, ChaosMonkeyNothingIsSafeTest, ChaosMonkeyNothingIsSafeWithPullReplicasTest, CloudExitableDirectoryReaderTest, ClusterStateTest, ClusterStateUpdateTest, CollectionPropsTest, ConcurrentCreateRoutedAliasTest, ConfigSetsAPITest, ConnectionManagerTest, CreateCollectionCleanupTest, DeleteReplicaTest, DeleteShardTest, DistribDocExpirationUpdateProcessorTest, DistribJoinFromCollectionTest, DocValuesNotIndexedTest, ForceLeaderTest, LeaderElectionTest, LeaderFailoverAfterPartitionTest, MetricsHistoryIntegrationTest, MigrateRouteKeyTest, MoveReplicaHDFSTest, MoveReplicaTest, OverseerModifyCollectionTest, OverseerRolesTest, OverseerStatusTest, OverseerTaskQueueTest, RestartWhileUpdatingTest, RollingRestartTest, SSLMigrationTest, SaslZkACLProviderTest, SharedFSAutoReplicaFailoverTest, SliceStateTest, TestCloudJSONFacetJoinDomain, TestCloudJSONFacetSKG, TestCloudPivotFacet, TestCloudPseudoReturnFields, TestCloudRecovery, TestCloudSearcherWarming, TestConfigSetsAPIExclusivity, TestConfigSetsAPIZkFailure, TestCryptoKeys, TestDistribDocBasedVersion, TestLeaderElectionZkExpiry, TestLeaderInitiatedRecoveryThread, TestSkipOverseerOperations, TestTlogReplica, TestZkChroot, TlogReplayBufferedWhileIndexingTest, TriLevelCompositeIdRoutingTest, VMParamsZkACLAndCredentialsProvidersTest, ZkCLITest, ZkControllerTest, ZkFailoverTest, CollectionsAPIDistributedZkTest, TestCollectionsAPIViaSolrCloudCluster, TestHdfsCloudBackupRestore, TestLocalFSCloudBackupRestore, TestReplicaProperties, ComputePlanActionTest, ExecutePlanActionTest, HdfsAutoAddReplicasIntegrationTest, HttpTriggerListenerTest, IndexSizeTriggerTest, MetricTriggerIntegrationTest, MetricTriggerTest, NodeAddedTriggerIntegrationTest, TestPolicyCloud, CdcrReplicationHandlerTest, CdcrWithNodesRestartsTest, HDFSCollectionsAPITest, HdfsBasicDistributedZk2Test, HdfsBasicDistributedZkTest, HdfsNNFailoverTest, HdfsRecoverLeaseTest, HdfsRecoveryZkTest, HdfsRestartWhileUpdatingTest, HdfsSyncSliceTest, HdfsThreadLeakTest, HdfsWriteToMultipleCollectionsTest, StressHdfsTest, AlternateDirectoryTest, BlobRepositoryCloudTest, CachingDirectoryFactoryTest, HdfsDirectoryFactoryTest, OpenCloseCoreStressTest, RAMDirectoryFactoryTest, RequestHandlersTest, ResourceLoaderTest, SOLR749Test, SolrCoreCheckLockOnStartupTest, SolrCoreTest, TestBackupRepositoryFactory, TestBadConfig, TestConfigOverlay, TestConfigSetImmutable, TestCoreContainer, TestCoreDiscovery, TestDirectoryFactory, TestDynamicLoading, TestDynamicURP, TestImplicitCoreProperties, TestReloadAndDeleteDocs, TestShardHandlerFactory, TestXIncludeConfig, TestSolrCloudSnapshots, CSVRequestHandlerTest, DocumentAnalysisRequestHandlerTest, MoreLikeThisHandlerTest, PingRequestHandlerTest, RequestLoggingTest]
   [junit4] Completed [580/832 (1!)] on J0 in 1.91s, 2 tests, 1 failure <<< FAILURES!

[...truncated 43032 lines...]
[repro] Jenkins log URL: https://jenkins.thetaphi.de/job/Lucene-Solr-master-Windows/7502/consoleText

[repro] Revision: d93c46ea94dec612aa53e37d119fe34b5e8a828e

[repro] Ant options: "-Dargs=-XX:+UseCompressedOops -XX:+UseSerialGC"

[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:+UseSerialGC" -Dtests.seed=437D83C0F26C222A -Dtests.slow=true -Dtests.locale=lt-LT -Dtests.timezone=NST -Dtests.asserts=true -Dtests.file.encoding=ISO-8859-1

[...truncated 32 lines...]
   [junit4] Suite: org.apache.solr.handler.RequestLoggingTest
   [junit4]   2> Creating dataDir: C:\Users\jenkins\workspace\Lucene-Solr-master-Windows\solr\build\solr-core\test\J0\temp\solr.handler.RequestLoggingTest_437D83C0F26C222A-001\init-core-data-001
   [junit4]   2> 10982 INFO  (SUITE-RequestLoggingTest-seed#[437D83C0F26C222A]-worker) [    ] o.a.s.SolrTestCaseJ4 Using PointFields (NUMERIC_POINTS_SYSPROP=true) w/NUMERIC_DOCVALUES_SYSPROP=true
   [junit4]   2> 11064 INFO  (SUITE-RequestLoggingTest-seed#[437D83C0F26C222A]-worker) [    ] o.e.j.u.log Logging initialized @11090ms to org.eclipse.jetty.util.log.Slf4jLog
   [junit4]   2> 11075 INFO  (SUITE-RequestLoggingTest-seed#[437D83C0F26C222A]-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)
   [junit4]   2> 11086 INFO  (SUITE-RequestLoggingTest-seed#[437D83C0F26C222A]-worker) [    ] o.a.s.SolrTestCaseJ4 SecureRandom sanity checks: test.solr.allowed.securerandom=null & java.security.egd=file:/dev/./urandom
   [junit4]   2> 11088 INFO  (SUITE-RequestLoggingTest-seed#[437D83C0F26C222A]-worker) [    ] o.a.s.SolrTestCaseJ4 ####initCore
   [junit4]   2> 11201 INFO  (SUITE-RequestLoggingTest-seed#[437D83C0F26C222A]-worker) [    ] o.a.s.c.SolrResourceLoader Using system property solr.solr.home: C:\Users\jenkins\workspace\Lucene-Solr-master-Windows\solr\core\src\test-files\solr
   [junit4]   2> 11217 INFO  (SUITE-RequestLoggingTest-seed#[437D83C0F26C222A]-worker) [    ] o.a.s.c.SolrResourceLoader [null] Added 2 libs to classloader, from paths: [/C:/Users/jenkins/workspace/Lucene-Solr-master-Windows/solr/core/src/test-files/solr/collection1/lib, /C:/Users/jenkins/workspace/Lucene-Solr-master-Windows/solr/core/src/test-files/solr/collection1/lib/classes]
   [junit4]   2> 11509 INFO  (SUITE-RequestLoggingTest-seed#[437D83C0F26C222A]-worker) [    ] o.a.s.c.SolrConfig Using Lucene MatchVersion: 8.0.0
   [junit4]   2> 11757 INFO  (SUITE-RequestLoggingTest-seed#[437D83C0F26C222A]-worker) [    ] o.a.s.s.IndexSchema [null] Schema name=test
   [junit4]   2> 12187 WARN  (SUITE-RequestLoggingTest-seed#[437D83C0F26C222A]-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> 12287 WARN  (SUITE-RequestLoggingTest-seed#[437D83C0F26C222A]-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> 12320 WARN  (SUITE-RequestLoggingTest-seed#[437D83C0F26C222A]-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> 12326 WARN  (SUITE-RequestLoggingTest-seed#[437D83C0F26C222A]-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> 12461 INFO  (SUITE-RequestLoggingTest-seed#[437D83C0F26C222A]-worker) [    ] o.a.s.s.IndexSchema Loaded schema test/1.0 with uniqueid field id
   [junit4]   2> 13830 INFO  (SUITE-RequestLoggingTest-seed#[437D83C0F26C222A]-worker) [    ] o.a.s.c.TransientSolrCoreCacheDefault Allocating transient cache for 2147483647 transient cores
   [junit4]   2> 13833 INFO  (SUITE-RequestLoggingTest-seed#[437D83C0F26C222A]-worker) [    ] o.a.s.h.a.MetricsHistoryHandler No .system collection, keeping metrics history in memory.
   [junit4]   2> 13924 INFO  (SUITE-RequestLoggingTest-seed#[437D83C0F26C222A]-worker) [    ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr.node' (registry 'solr.node') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@77ebbbbc
   [junit4]   2> 13925 INFO  (SUITE-RequestLoggingTest-seed#[437D83C0F26C222A]-worker) [    ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr.jvm' (registry 'solr.jvm') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@77ebbbbc
   [junit4]   2> 13925 INFO  (SUITE-RequestLoggingTest-seed#[437D83C0F26C222A]-worker) [    ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr.jetty' (registry 'solr.jetty') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@77ebbbbc
   [junit4]   2> 14005 INFO  (coreLoadExecutor-9-thread-1) [    x:collection1] o.a.s.c.SolrResourceLoader [null] Added 2 libs to classloader, from paths: [/C:/Users/jenkins/workspace/Lucene-Solr-master-Windows/solr/core/src/test-files/solr/collection1/lib, /C:/Users/jenkins/workspace/Lucene-Solr-master-Windows/solr/core/src/test-files/solr/collection1/lib/classes]
   [junit4]   2> 14255 INFO  (coreLoadExecutor-9-thread-1) [    x:collection1] o.a.s.c.SolrConfig Using Lucene MatchVersion: 8.0.0
   [junit4]   2> 14314 INFO  (coreLoadExecutor-9-thread-1) [    x:collection1] o.a.s.s.IndexSchema [collection1] Schema name=test
   [junit4]   2> 14524 INFO  (coreLoadExecutor-9-thread-1) [    x:collection1] o.a.s.s.IndexSchema Loaded schema test/1.0 with uniqueid field id
   [junit4]   2> 14587 INFO  (coreLoadExecutor-9-thread-1) [    x:collection1] o.a.s.c.CoreContainer Creating SolrCore 'collection1' using configuration from instancedir C:\Users\jenkins\workspace\Lucene-Solr-master-Windows\solr\core\src\test-files\solr\collection1, trusted=true
   [junit4]   2> 14688 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@77ebbbbc
   [junit4]   2> 14694 INFO  (coreLoadExecutor-9-thread-1) [    x:collection1] o.a.s.c.SolrCore solr.RecoveryStrategy.Builder
   [junit4]   2> 14702 INFO  (coreLoadExecutor-9-thread-1) [    x:collection1] o.a.s.c.SolrCore [[collection1] ] Opening new SolrCore at [C:\Users\jenkins\workspace\Lucene-Solr-master-Windows\solr\core\src\test-files\solr\collection1], dataDir=[C:\Users\jenkins\workspace\Lucene-Solr-master-Windows\solr\build\solr-core\test\J0\temp\solr.handler.RequestLoggingTest_437D83C0F26C222A-001\init-core-data-001\]
   [junit4]   2> 14747 INFO  (coreLoadExecutor-9-thread-1) [    x:collection1] o.a.s.u.RandomMergePolicy RandomMergePolicy wrapping class org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: maxMergeAtOnce=24, maxMergeAtOnceExplicit=19, maxMergedSegmentMB=38.248046875, floorSegmentMB=1.8740234375, forceMergeDeletesPctAllowed=7.938843534166596, segmentsPerTier=33.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.26079601911510797, deletesPctAllowed=34.07969886536636
   [junit4]   2> 15575 INFO  (coreLoadExecutor-9-thread-1) [    x:collection1] o.a.s.u.UpdateHandler Using UpdateLog implementation: org.apache.solr.update.UpdateLog
   [junit4]   2> 15575 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> 15679 INFO  (coreLoadExecutor-9-thread-1) [    x:collection1] o.a.s.u.CommitTracker Hard AutoCommit: disabled
   [junit4]   2> 15679 INFO  (coreLoadExecutor-9-thread-1) [    x:collection1] o.a.s.u.CommitTracker Soft AutoCommit: disabled
   [junit4]   2> 15684 INFO  (coreLoadExecutor-9-thread-1) [    x:collection1] o.a.s.u.RandomMergePolicy RandomMergePolicy wrapping class org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: maxMergeAtOnce=27, maxMergeAtOnceExplicit=38, maxMergedSegmentMB=16.1982421875, floorSegmentMB=0.642578125, forceMergeDeletesPctAllowed=28.190975929931316, segmentsPerTier=45.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.0, deletesPctAllowed=26.417390670823988
   [junit4]   2> 15699 INFO  (coreLoadExecutor-9-thread-1) [    x:collection1] o.a.s.s.SolrIndexSearcher Opening [Searcher@3b48447f[collection1] main]
   [junit4]   2> 15744 INFO  (coreLoadExecutor-9-thread-1) [    x:collection1] o.a.s.h.c.SpellCheckComponent Initializing spell checkers
   [junit4]   2> 16075 INFO  (coreLoadExecutor-9-thread-1) [    x:collection1] o.a.s.s.DirectSolrSpellChecker init: {name=direct,classname=DirectSolrSpellChecker,field=lowerfilt,minQueryLength=3}
   [junit4]   2> 16199 INFO  (coreLoadExecutor-9-thread-1) [    x:collection1] o.a.s.h.ReplicationHandler Commits will be reserved for 10000ms.
   [junit4]   2> 16201 INFO  (searcherExecutor-10-thread-1-processing-x:collection1) [    x:collection1] o.a.s.h.c.SpellCheckComponent Loading spell index for spellchecker: default
   [junit4]   2> 16207 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 1610576872049999872
   [junit4]   2> 16208 INFO  (searcherExecutor-10-thread-1-processing-x:collection1) [    x:collection1] o.a.s.h.c.SpellCheckComponent Loading spell index for spellchecker: direct
   [junit4]   2> 16208 INFO  (searcherExecutor-10-thread-1-processing-x:collection1) [    x:collection1] o.a.s.h.c.SpellCheckComponent Loading spell index for spellchecker: wordbreak
   [junit4]   2> 16208 INFO  (searcherExecutor-10-thread-1-processing-x:collection1) [    x:collection1] o.a.s.h.c.SpellCheckComponent Loading spell index for spellchecker: multipleFields
   [junit4]   2> 16209 INFO  (searcherExecutor-10-thread-1-processing-x:collection1) [    x:collection1] o.a.s.h.c.SpellCheckComponent Loading spell index for spellchecker: jarowinkler
   [junit4]   2> 16211 INFO  (searcherExecutor-10-thread-1-processing-x:collection1) [    x:collection1] o.a.s.h.c.SpellCheckComponent Loading spell index for spellchecker: external
   [junit4]   2> 16212 INFO  (searcherExecutor-10-thread-1-processing-x:collection1) [    x:collection1] o.a.s.h.c.SpellCheckComponent Loading spell index for spellchecker: freq
   [junit4]   2> 16213 INFO  (searcherExecutor-10-thread-1-processing-x:collection1) [    x:collection1] o.a.s.h.c.SpellCheckComponent Loading spell index for spellchecker: fqcn
   [junit4]   2> 16213 INFO  (SUITE-RequestLoggingTest-seed#[437D83C0F26C222A]-worker) [    ] o.a.s.SolrTestCaseJ4 ####initCore end
   [junit4]   2> 16214 INFO  (searcherExecutor-10-thread-1-processing-x:collection1) [    x:collection1] o.a.s.h.c.SpellCheckComponent Loading spell index for spellchecker: perDict
   [junit4]   2> 16237 INFO  (searcherExecutor-10-thread-1-processing-x:collection1) [    x:collection1] o.a.s.c.SolrCore [collection1] Registered new searcher Searcher@3b48447f[collection1] main{ExitableDirectoryReader(UninvertingDirectoryReader())}
   [junit4]   2> 16254 INFO  (TEST-RequestLoggingTest.testLogBeforeExecuteWithCoreLogger-seed#[437D83C0F26C222A]) [    ] o.a.s.SolrTestCaseJ4 ###Starting testLogBeforeExecuteWithCoreLogger
   [junit4]   2> 16260 DEBUG (TEST-RequestLoggingTest.testLogBeforeExecuteWithCoreLogger-seed#[437D83C0F26C222A]) [    ] o.a.s.c.S.Request [collection1]  webapp=null path=null params={q=*:*&wt=xml}
   [junit4]   2> 16262 DEBUG (TEST-RequestLoggingTest.testLogBeforeExecuteWithCoreLogger-seed#[437D83C0F26C222A]) [    ] o.a.s.h.c.SearchHandler Adding  component:org.apache.solr.handler.component.QueryComponent@4fac2657
   [junit4]   2> 16262 DEBUG (TEST-RequestLoggingTest.testLogBeforeExecuteWithCoreLogger-seed#[437D83C0F26C222A]) [    ] o.a.s.h.c.SearchHandler Adding  component:org.apache.solr.handler.component.FacetComponent@4e3709dc
   [junit4]   2> 16262 DEBUG (TEST-RequestLoggingTest.testLogBeforeExecuteWithCoreLogger-seed#[437D83C0F26C222A]) [    ] o.a.s.h.c.SearchHandler Adding  component:org.apache.solr.search.facet.FacetModule@64dbfc49
   [junit4]   2> 16262 DEBUG (TEST-RequestLoggingTest.testLogBeforeExecuteWithCoreLogger-seed#[437D83C0F26C222A]) [    ] o.a.s.h.c.SearchHandler Adding  component:org.apache.solr.handler.component.MoreLikeThisComponent@25c06cbe
   [junit4]   2> 16262 DEBUG (TEST-RequestLoggingTest.testLogBeforeExecuteWithCoreLogger-seed#[437D83C0F26C222A]) [    ] o.a.s.h.c.SearchHandler Adding  component:org.apache.solr.handler.component.HighlightComponent@b7078cf
   [junit4]   2> 16262 DEBUG (TEST-RequestLoggingTest.testLogBeforeExecuteWithCoreLogger-seed#[437D83C0F26C222A]) [    ] o.a.s.h.c.SearchHandler Adding  component:org.apache.solr.handler.component.StatsComponent@7dfff994
   [junit4]   2> 16262 DEBUG (TEST-RequestLoggingTest.testLogBeforeExecuteWithCoreLogger-seed#[437D83C0F26C222A]) [    ] o.a.s.h.c.SearchHandler Adding  component:org.apache.solr.handler.component.ExpandComponent@467d7bd6
   [junit4]   2> 16262 DEBUG (TEST-RequestLoggingTest.testLogBeforeExecuteWithCoreLogger-seed#[437D83C0F26C222A]) [    ] o.a.s.h.c.SearchHandler Adding  component:org.apache.solr.handler.component.TermsComponent@607e5a3b
   [junit4]   2> 16262 DEBUG (TEST-RequestLoggingTest.testLogBeforeExecuteWithCoreLogger-seed#[437D83C0F26C222A]) [    ] o.a.s.h.c.SearchHandler Adding  debug component:org.apache.solr.handler.component.DebugComponent@68c0e0fb
   [junit4]   2> 16315 DEBUG (TEST-RequestLoggingTest.testLogBeforeExecuteWithCoreLogger-seed#[437D83C0F26C222A]) [    ] o.a.s.h.c.QueryComponent process: q=*:*&df=text&wt=xml&indent=off
   [junit4]   2> 16316 DEBUG (TEST-RequestLoggingTest.testLogBeforeExecuteWithCoreLogger-seed#[437D83C0F26C222A]) [    ] o.a.s.s.s.LocalStatsCache ## GET LocalSolrQueryRequest{q=*:*&df=text&wt=xml&indent=off}
   [junit4]   2> 16326 INFO  (TEST-RequestLoggingTest.testLogBeforeExecuteWithCoreLogger-seed#[437D83C0F26C222A]) [    ] o.a.s.c.S.Request [collection1]  webapp=null path=null params={q=*:*&wt=xml} hits=0 status=0 QTime=65
   [junit4] OK      0.15s J0 | RequestLoggingTest.testLogBeforeExecuteWithCoreLogger
   [junit4]   2> 16364 INFO  (TEST-RequestLoggingTest.testLogBeforeExecuteWithCoreLogger-seed#[437D83C0F26C222A]) [    ] o.a.s.SolrTestCaseJ4 ###Ending testLogBeforeExecuteWithCoreLogger
   [junit4]   2> 16377 INFO  (TEST-RequestLoggingTest.testLogBeforeExecuteWithRequestLogger-seed#[437D83C0F26C222A]) [    ] o.a.s.SolrTestCaseJ4 ###Starting testLogBeforeExecuteWithRequestLogger
   [junit4]   2> NOTE: reproduce with: ant test  -Dtestcase=RequestLoggingTest -Dtests.method=testLogBeforeExecuteWithRequestLogger -Dtests.seed=437D83C0F26C222A -Dtests.slow=true -Dtests.badapples=true -Dtests.locale=lt-LT -Dtests.timezone=NST -Dtests.asserts=true -Dtests.file.encoding=ISO-8859-1
   [junit4] FAILURE 0.02s J0 | RequestLoggingTest.testLogBeforeExecuteWithRequestLogger <<<
   [junit4]    > Throwable #1: java.lang.AssertionError
   [junit4]    > 	at __randomizedtesting.SeedInfo.seed([437D83C0F26C222A:F214A3CF5F9A9A64]: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> 16382 DEBUG (TEST-RequestLoggingTest.testLogBeforeExecuteWithRequestLogger-seed#[437D83C0F26C222A]) [    ] o.a.s.c.S.Request [collection1]  webapp=null path=null params={q=*:*&wt=xml}
   [junit4]   2> 16382 DEBUG (TEST-RequestLoggingTest.testLogBeforeExecuteWithRequestLogger-seed#[437D83C0F26C222A]) [    ] o.a.s.h.c.QueryComponent process: q=*:*&df=text&wt=xml&indent=off
   [junit4]   2> 16382 DEBUG (TEST-RequestLoggingTest.testLogBeforeExecuteWithRequestLogger-seed#[437D83C0F26C222A]) [    ] o.a.s.s.s.LocalStatsCache ## GET LocalSolrQueryRequest{q=*:*&df=text&wt=xml&indent=off}
   [junit4]   2> 16382 INFO  (TEST-RequestLoggingTest.testLogBeforeExecuteWithRequestLogger-seed#[437D83C0F26C222A]) [    ] o.a.s.c.S.Request [collection1]  webapp=null path=null params={q=*:*&wt=xml} hits=0 status=0 QTime=0
   [junit4]   2> 16383 INFO  (TEST-RequestLoggingTest.testLogBeforeExecuteWithRequestLogger-seed#[437D83C0F26C222A]) [    ] o.a.s.SolrTestCaseJ4 ###Ending testLogBeforeExecuteWithRequestLogger
   [junit4]   2> 16391 INFO  (SUITE-RequestLoggingTest-seed#[437D83C0F26C222A]-worker) [    ] o.a.s.SolrTestCaseJ4 ###deleteCore
   [junit4]   2> 16391 INFO  (SUITE-RequestLoggingTest-seed#[437D83C0F26C222A]-worker) [    ] o.a.s.c.CoreContainer Shutting down CoreContainer instance=381547996
   [junit4]   2> 16395 INFO  (SUITE-RequestLoggingTest-seed#[437D83C0F26C222A]-worker) [    ] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.node, tag=null
   [junit4]   2> 16395 INFO  (SUITE-RequestLoggingTest-seed#[437D83C0F26C222A]-worker) [    ] o.a.s.m.r.SolrJmxReporter Closing reporter [org.apache.solr.metrics.reporters.SolrJmxReporter@15f088e3: rootName = null, domain = solr.node, service url = null, agent id = null] for registry solr.node / com.codahale.metrics.MetricRegistry@34264ff0
   [junit4]   2> 16409 INFO  (SUITE-RequestLoggingTest-seed#[437D83C0F26C222A]-worker) [    ] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.jvm, tag=null
   [junit4]   2> 16409 INFO  (SUITE-RequestLoggingTest-seed#[437D83C0F26C222A]-worker) [    ] o.a.s.m.r.SolrJmxReporter Closing reporter [org.apache.solr.metrics.reporters.SolrJmxReporter@1dafdef7: rootName = null, domain = solr.jvm, service url = null, agent id = null] for registry solr.jvm / com.codahale.metrics.MetricRegistry@5be1599a
   [junit4]   2> 16409 INFO  (SUITE-RequestLoggingTest-seed#[437D83C0F26C222A]-worker) [    ] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.jetty, tag=null
   [junit4]   2> 16409 INFO  (SUITE-RequestLoggingTest-seed#[437D83C0F26C222A]-worker) [    ] o.a.s.m.r.SolrJmxReporter Closing reporter [org.apache.solr.metrics.reporters.SolrJmxReporter@3c8e01f6: rootName = null, domain = solr.jetty, service url = null, agent id = null] for registry solr.jetty / com.codahale.metrics.MetricRegistry@35e8079
   [junit4]   2> 16411 INFO  (coreCloseExecutor-15-thread-1) [    x:collection1] o.a.s.c.SolrCore [collection1]  CLOSING SolrCore org.apache.solr.core.SolrCore@5d2e8101
   [junit4]   2> 16412 INFO  (coreCloseExecutor-15-thread-1) [    x:collection1] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.core.collection1, tag=5d2e8101
   [junit4]   2> 16412 INFO  (coreCloseExecutor-15-thread-1) [    x:collection1] o.a.s.m.r.SolrJmxReporter Closing reporter [org.apache.solr.metrics.reporters.SolrJmxReporter@64a48b54: rootName = null, domain = solr.core.collection1, service url = null, agent id = null] for registry solr.core.collection1 / com.codahale.metrics.MetricRegistry@38ea5205
   [junit4]   2> NOTE: leaving temporary files on disk at: C:\Users\jenkins\workspace\Lucene-Solr-master-Windows\solr\build\solr-core\test\J0\temp\solr.handler.RequestLoggingTest_437D83C0F26C222A-001
   [junit4]   2> NOTE: test params are: codec=CheapBastard, sim=Asserting(org.apache.lucene.search.similarities.AssertingSimilarity@465da970), locale=lt-LT, timezone=NST
   [junit4]   2> NOTE: Windows 10 10.0 amd64/Oracle Corporation 10 (64-bit)/cpus=3,threads=2,free=47634576,total=97386496
   [junit4]   2> NOTE: All tests run in this JVM: [RequestLoggingTest]
   [junit4] Completed [1/5 (1!)] on J0 in 15.55s, 2 tests, 1 failure <<< FAILURES!

[...truncated 1 lines...]
   [junit4] Suite: org.apache.solr.handler.RequestLoggingTest
   [junit4]   2> Creating dataDir: C:\Users\jenkins\workspace\Lucene-Solr-master-Windows\solr\build\solr-core\test\J1\temp\solr.handler.RequestLoggingTest_437D83C0F26C222A-001\init-core-data-001
   [junit4]   2> 10996 INFO  (SUITE-RequestLoggingTest-seed#[437D83C0F26C222A]-worker) [    ] o.a.s.SolrTestCaseJ4 Using PointFields (NUMERIC_POINTS_SYSPROP=true) w/NUMERIC_DOCVALUES_SYSPROP=true
   [junit4]   2> 11073 INFO  (SUITE-RequestLoggingTest-seed#[437D83C0F26C222A]-worker) [    ] o.e.j.u.log Logging initialized @11103ms to org.eclipse.jetty.util.log.Slf4jLog
   [junit4]   2> 11091 INFO  (SUITE-RequestLoggingTest-seed#[437D83C0F26C222A]-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)
   [junit4]   2> 11100 INFO  (SUITE-RequestLoggingTest-seed#[437D83C0F26C222A]-worker) [    ] o.a.s.SolrTestCaseJ4 SecureRandom sanity checks: test.solr.allowed.securerandom=null & java.security.egd=file:/dev/./urandom
   [junit4]   2> 11100 INFO  (SUITE-RequestLoggingTest-seed#[437D83C0F26C222A]-worker) [    ] o.a.s.SolrTestCaseJ4 ####initCore
   [junit4]   2> 11178 INFO  (SUITE-RequestLoggingTest-seed#[437D83C0F26C222A]-worker) [    ] o.a.s.c.SolrResourceLoader Using system property solr.solr.home: C:\Users\jenkins\workspace\Lucene-Solr-master-Windows\solr\core\src\test-files\solr
   [junit4]   2> 11181 INFO  (SUITE-RequestLoggingTest-seed#[437D83C0F26C222A]-worker) [    ] o.a.s.c.SolrResourceLoader [null] Added 2 libs to classloader, from paths: [/C:/Users/jenkins/workspace/Lucene-Solr-master-Windows/solr/core/src/test-files/solr/collection1/lib, /C:/Users/jenkins/workspace/Lucene-Solr-master-Windows/solr/core/src/test-files/solr/collection1/lib/classes]
   [junit4]   2> 11523 INFO  (SUITE-RequestLoggingTest-seed#[437D83C0F26C222A]-worker) [    ] o.a.s.c.SolrConfig Using Lucene MatchVersion: 8.0.0
   [junit4]   2> 11689 INFO  (SUITE-RequestLoggingTest-seed#[437D83C0F26C222A]-worker) [    ] o.a.s.s.IndexSchema [null] Schema name=test
   [junit4]   2> 12245 WARN  (SUITE-RequestLoggingTest-seed#[437D83C0F26C222A]-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> 12341 WARN  (SUITE-RequestLoggingTest-seed#[437D83C0F26C222A]-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> 12346 WARN  (SUITE-RequestLoggingTest-seed#[437D83C0F26C222A]-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> 12352 WARN  (SUITE-RequestLoggingTest-seed#[437D83C0F26C222A]-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> 12506 INFO  (SUITE-RequestLoggingTest-seed#[437D83C0F26C222A]-worker) [    ] o.a.s.s.IndexSchema Loaded schema test/1.0 with uniqueid field id
   [junit4]   2> 14111 INFO  (SUITE-RequestLoggingTest-seed#[437D83C0F26C222A]-worker) [    ] o.a.s.c.TransientSolrCoreCacheDefault Allocating transient cache for 2147483647 transient cores
   [junit4]   2> 14115 INFO  (SUITE-RequestLoggingTest-seed#[437D83C0F26C222A]-worker) [    ] o.a.s.h.a.MetricsHistoryHandler No .system collection, keeping metrics history in memory.
   [junit4]   2> 14210 INFO  (SUITE-RequestLoggingTest-seed#[437D83C0F26C222A]-worker) [    ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr.node' (registry 'solr.node') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@4967b30d
   [junit4]   2> 14211 INFO  (SUITE-RequestLoggingTest-seed#[437D83C0F26C222A]-worker) [    ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr.jvm' (registry 'solr.jvm') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@4967b30d
   [junit4]   2> 14212 INFO  (SUITE-RequestLoggingTest-seed#[437D83C0F26C222A]-worker) [    ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr.jetty' (registry 'solr.jetty') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@4967b30d
   [junit4]   2> 14230 INFO  (coreLoadExecutor-9-thread-1) [    x:collection1] o.a.s.c.SolrResourceLoader [null] Added 2 libs to classloader, from paths: [/C:/Users/jenkins/workspace/Lucene-Solr-master-Windows/solr/core/src/test-files/solr/collection1/lib, /C:/Users/jenkins/workspace/Lucene-Solr-master-Windows/solr/core/src/test-files/solr/collection1/lib/classes]
   [junit4]   2> 14335 INFO  (coreLoadExecutor-9-thread-1) [    x:collection1] o.a.s.c.SolrConfig Using Lucene MatchVersion: 8.0.0
   [junit4]   2> 14378 INFO  (coreLoadExecutor-9-thread-1) [    x:collection1] o.a.s.s.IndexSchema [collection1] Schema name=test
   [junit4]   2> 14593 INFO  (coreLoadExecutor-9-thread-1) [    x:collection1] o.a.s.s.IndexSchema Loaded schema test/1.0 with uniqueid field id
   [junit4]   2> 14630 INFO  (coreLoadExecutor-9-thread-1) [    x:collection1] o.a.s.c.CoreContainer Creating SolrCore 'collection1' using configuration from instancedir C:\Users\jenkins\workspace\Lucene-Solr-master-Windows\solr\core\src\test-files\solr\collection1, trusted=true
   [junit4]   2> 14666 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@4967b30d
   [junit4]   2> 14673 INFO  (coreLoadExecutor-9-thread-1) [    x:collection1] o.a.s.c.SolrCore solr.RecoveryStrategy.Builder
   [junit4]   2> 14683 INFO  (coreLoadExecutor-9-thread-1) [    x:collection1] o.a.s.c.SolrCore [[collection1] ] Opening new SolrCore at [C:\Users\jenkins\workspace\Lucene-Solr-master-Windows\solr\core\src\test-files\solr\collection1], dataDir=[C:\Users\jenkins\workspace\Lucene-Solr-master-Windows\solr\build\solr-core\test\J1\temp\solr.handler.RequestLoggingTest_437D83C0F26C222A-001\init-core-data-001\]
   [junit4]   2> 14771 INFO  (coreLoadExecutor-9-thread-1) [    x:collection1] o.a.s.u.RandomMergePolicy RandomMergePolicy wrapping class org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: maxMergeAtOnce=24, maxMergeAtOnceExplicit=19, maxMergedSegmentMB=38.248046875, floorSegmentMB=1.8740234375, forceMergeDeletesPctAllowed=7.938843534166596, segmentsPerTier=33.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.26079601911510797, deletesPctAllowed=34.07969886536636
   [junit4]   2> 15444 INFO  (coreLoadExecutor-9-thread-1) [    x:collection1] o.a.s.u.UpdateHandler Using UpdateLog implementation: org.apache.solr.update.UpdateLog
   [junit4]   2> 15444 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> 15454 INFO  (coreLoadExecutor-9-thread-1) [    x:collection1] o.a.s.u.CommitTracker Hard AutoCommit: disabled
   [junit4]   2> 15454 INFO  (coreLoadExecutor-9-thread-1) [    x:collection1] o.a.s.u.CommitTracker Soft AutoCommit: disabled
   [junit4]   2> 15455 INFO  (coreLoadExecutor-9-thread-1) [    x:collection1] o.a.s.u.RandomMergePolicy RandomMergePolicy wrapping class org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: maxMergeAtOnce=27, maxMergeAtOnceExplicit=38, maxMergedSegmentMB=16.1982421875, floorSegmentMB=0.642578125, forceMergeDeletesPctAllowed=28.190975929931316, segmentsPerTier=45.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.0, deletesPctAllowed=26.417390670823988
   [junit4]   2> 15481 INFO  (coreLoadExecutor-9-thread-1) [    x:collection1] o.a.s.s.SolrIndexSearcher Opening [Searcher@6aba002a[collection1] main]
   [junit4]   2> 15579 INFO  (coreLoadExecutor-9-thread-1) [    x:collection1] o.a.s.h.c.SpellCheckComponent Initializing spell checkers
   [junit4]   2> 16030 INFO  (coreLoadExecutor-9-thread-1) [    x:collection1] o.a.s.s.DirectSolrSpellChecker init: {name=direct,classname=DirectSolrSpellChecker,field=lowerfilt,minQueryLength=3}
   [junit4]   2> 16204 INFO  (coreLoadExecutor-9-thread-1) [    x:collection1] o.a.s.h.ReplicationHandler Commits will be reserved for 10000ms.
   [junit4]   2> 16204 INFO  (searcherExecutor-10-thread-1-processing-x:collection1) [    x:collection1] o.a.s.h.c.SpellCheckComponent Loading spell index for spellchecker: default
   [junit4]   2> 16209 INFO  (searcherExecutor-10-thread-1-processing-x:collection1) [    x:collection1] o.a.s.h.c.SpellCheckComponent Loading spell index for spellchecker: direct
   [junit4]   2> 16210 INFO  (searcherExecutor-10-thread-1-processing-x:collection1) [    x:collection1] o.a.s.h.c.SpellCheckComponent Loading spell index for spellchecker: wordbreak
   [junit4]   2> 16210 INFO  (searcherExecutor-10-thread-1-processing-x:collection1) [    x:collection1] o.a.s.h.c.SpellCheckComponent Loading spell index for spellchecker: multipleFields
   [junit4]   2> 16210 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 1610576872063631360
   [junit4]   2> 16211 INFO  (searcherExecutor-10-thread-1-processing-x:collection1) [    x:collection1] o.a.s.h.c.SpellCheckComponent Loading spell index for spellchecker: jarowinkler
   [junit4]   2> 16213 INFO  (searcherExecutor-10-thread-1-processing-x:collection1) [    x:collection1] o.a.s.h.c.SpellCheckComponent Loading spell index for spellchecker: external
   [junit4]   2> 16214 INFO  (searcherExecutor-10-thread-1-processing-x:collection1) [    x:collection1] o.a.s.h.c.SpellCheckComponent Loading spell index for spellchecker: freq
   [junit4]   2> 16217 INFO  (SUITE-RequestLoggingTest-seed#[437D83C0F26C222A]-worker) [    ] o.a.s.SolrTestCaseJ4 ####initCore end
   [junit4]   2> 16221 INFO  (searcherExecutor-10-thread-1-processing-x:collection1) [    x:collection1] o.a.s.h.c.SpellCheckComponent Loading spell index for spellchecker: fqcn
   [junit4]   2> 16222 INFO  (searcherExecutor-10-thread-1-processing-x:collection1) [    x:collection1] o.a.s.h.c.SpellCheckComponent Loading spell index for spellchecker: perDict
   [junit4]   2> 16239 INFO  (searcherExecutor-10-thread-1-processing-x:collection1) [    x:collection1] o.a.s.c.SolrCore [collection1] Registered new searcher Searcher@6aba002a[collection1] main{ExitableDirectoryReader(UninvertingDirectoryReader())}
   [junit4]   2> 16323 INFO  (TEST-RequestLoggingTest.testLogBeforeExecuteWithCoreLogger-seed#[437D83C0F26C222A]) [    ] o.a.s.SolrTestCaseJ4 ###Starting testLogBeforeExecuteWithCoreLogger
   [junit4]   2> 16331 DEBUG (TEST-RequestLoggingTest.testLogBeforeExecuteWithCoreLogger-seed#[437D83C0F26C222A]) [    ] o.a.s.c.S.Request [collection1]  webapp=null path=null params={q=*:*&wt=xml}
   [junit4]   2> 16331 DEBUG (TEST-RequestLoggingTest.testLogBeforeExecuteWithCoreLogger-seed#[437D83C0F26C222A]) [    ] o.a.s.h.c.SearchHandler Adding  component:org.apache.solr.handler.component.QueryComponent@4fac2657
   [junit4]   2> 16331 DEBUG (TEST-RequestLoggingTest.testLogBeforeExecuteWithCoreLogger-seed#[437D83C0F26C222A]) [    ] o.a.s.h.c.SearchHandler Adding  component:org.apache.solr.handler.component.FacetComponent@4e3709dc
   [junit4]   2> 16331 DEBUG (TEST-RequestLoggingTest.testLogBeforeExecuteWithCoreLogger-seed#[437D83C0F26C222A]) [    ] o.a.s.h.c.SearchHandler Adding  component:org.apache.solr.search.facet.FacetModule@64dbfc49
   [junit4]   2> 16331 DEBUG (TEST-RequestLoggingTest.testLogBeforeExecuteWithCoreLogger-seed#[437D83C0F26C222A]) [    ] o.a.s.h.c.SearchHandler Adding  component:org.apache.solr.handler.component.MoreLikeThisComponent@25c06cbe
   [junit4]   2> 16331 DEBUG (TEST-RequestLoggingTest.testLogBeforeExecuteWithCoreLogger-seed#[437D83C0F26C222A]) [    ] o.a.s.h.c.SearchHandler Adding  component:org.apache.solr.handler.component.HighlightComponent@b7078cf
   [junit4]   2> 16331 DEBUG (TEST-RequestLoggingTest.testLogBeforeExecuteWithCoreLogger-seed#[437D83C0F26C222A]) [    ] o.a.s.h.c.SearchHandler Adding  component:org.apache.solr.handler.component.StatsComponent@7dfff994
   [junit4]   2> 16331 DEBUG (TEST-RequestLoggingTest.testLogBeforeExecuteWithCoreLogger-seed#[437D83C0F26C222A]) [    ] o.a.s.h.c.SearchHandler Adding  component:org.apache.solr.handler.component.ExpandComponent@467d7bd6
   [junit4]   2> 16331 DEBUG (TEST-RequestLoggingTest.testLogBeforeExecuteWithCoreLogger-seed#[437D83C0F26C222A]) [    ] o.a.s.h.c.SearchHandler Adding  component:org.apache.solr.handler.component.TermsComponent@607e5a3b
   [junit4]   2> 16331 DEBUG (TEST-RequestLoggingTest.testLogBeforeExecuteWithCoreLogger-seed#[437D83C0F26C222A]) [    ] o.a.s.h.c.SearchHandler Adding  debug component:org.apache.solr.handler.component.DebugComponent@68c0e0fb
   [junit4]   2> 16354 DEBUG (TEST-RequestLoggingTest.testLogBeforeExecuteWithCoreLogger-seed#[437D83C0F26C222A]) [    ] o.a.s.h.c.QueryComponent process: q=*:*&df=text&wt=xml&indent=off
   [junit4]   2> 16362 DEBUG (TEST-RequestLoggingTest.testLogBeforeExecuteWithCoreLogger-seed#[437D83C0F26C222A]) [    ] o.a.s.s.s.LocalStatsCache ## GET LocalSolrQueryRequest{q=*:*&df=text&wt=xml&indent=off}
   [junit4]   2> 16378 INFO  (TEST-RequestLoggingTest.testLogBeforeExecuteWithCoreLogger-seed#[437D83C0F26C222A]) [    ] o.a.s.c.S.Request [collection1]  webapp=null path=null params={q=*:*&wt=xml} hits=0 status=0 QTime=47
   [junit4] OK      0.19s J1 | RequestLoggingTest.testLogBeforeExecuteWithCoreLogger
   [junit4]   2> NOTE: reproduce with: ant test  -Dtestcase=RequestLoggingTest -Dtests.method=testLogBeforeExecuteWithRequestLogger -Dtests.seed=437D83C0F26C222A -Dtests.slow=true -Dtests.badapples=true -Dtests.locale=lt-LT -Dtests.timezone=NST -Dtests.asserts=true -Dtests.file.encoding=ISO-8859-1
   [junit4] FAILURE 0.04s J1 | RequestLoggingTest.testLogBeforeExecuteWithRequestLogger <<<
   [junit4]    > Throwable #1: java.lang.AssertionError
   [junit4]    > 	at __randomizedtesting.SeedInfo.seed([437D83C0F26C222A:F214A3CF5F9A9A64]: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> 16407 INFO  (TEST-RequestLoggingTest.testLogBeforeExecuteWithCoreLogger-seed#[437D83C0F26C222A]) [    ] o.a.s.SolrTestCaseJ4 ###Ending testLogBeforeExecuteWithCoreLogger
   [junit4]   2> 16417 INFO  (TEST-RequestLoggingTest.testLogBeforeExecuteWithRequestLogger-seed#[437D83C0F26C222A]) [    ] o.a.s.SolrTestCaseJ4 ###Starting testLogBeforeExecuteWithRequestLogger
   [junit4]   2> 16422 DEBUG (TEST-RequestLoggingTest.testLogBeforeExecuteWithRequestLogger-seed#[437D83C0F26C222A]) [    ] o.a.s.c.S.Request [collection1]  webapp=null path=null params={q=*:*&wt=xml}
   [junit4]   2> 16423 DEBUG (TEST-RequestLoggingTest.testLogBeforeExecuteWithRequestLogger-seed#[437D83C0F26C222A]) [    ] o.a.s.h.c.QueryComponent process: q=*:*&df=text&wt=xml&indent=off
   [junit4]   2> 16423 DEBUG (TEST-RequestLoggingTest.testLogBeforeExecuteWithRequestLogger-seed#[437D83C0F26C222A]) [    ] o.a.s.s.s.LocalStatsCache ## GET LocalSolrQueryRequest{q=*:*&df=text&wt=xml&indent=off}
   [junit4]   2> 16423 INFO  (TEST-RequestLoggingTest.testLogBeforeExecuteWithRequestLogger-seed#[437D83C0F26C222A]) [    ] o.a.s.c.S.Request [collection1]  webapp=null path=null params={q=*:*&wt=xml} hits=0 status=0 QTime=1
   [junit4]   2> 16424 INFO  (TEST-RequestLoggingTest.testLogBeforeExecuteWithRequestLogger-seed#[437D83C0F26C222A]) [    ] o.a.s.SolrTestCaseJ4 ###Ending testLogBeforeExecuteWithRequestLogger
   [junit4]   2> 16458 INFO  (SUITE-RequestLoggingTest-seed#[437D83C0F26C222A]-worker) [    ] o.a.s.SolrTestCaseJ4 ###deleteCore
   [junit4]   2> 16458 INFO  (SUITE-RequestLoggingTest-seed#[437D83C0F26C222A]-worker) [    ] o.a.s.c.CoreContainer Shutting down CoreContainer instance=381547996
   [junit4]   2> 16459 INFO  (SUITE-RequestLoggingTest-seed#[437D83C0F26C222A]-worker) [    ] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.node, tag=null
   [junit4]   2> 16461 INFO  (SUITE-RequestLoggingTest-seed#[437D83C0F26C222A]-worker) [    ] o.a.s.m.r.SolrJmxReporter Closing reporter [org.apache.solr.metrics.reporters.SolrJmxReporter@15f088e3: rootName = null, domain = solr.node, service url = null, agent id = null] for registry solr.node / com.codahale.metrics.MetricRegistry@34264ff0
   [junit4]   2> 16472 INFO  (SUITE-RequestLoggingTest-seed#[437D83C0F26C222A]-worker) [    ] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.jvm, tag=null
   [junit4]   2> 16472 INFO  (SUITE-RequestLoggingTest-seed#[437D83C0F26C222A]-worker) [    ] o.a.s.m.r.SolrJmxReporter Closing reporter [org.apache.solr.metrics.reporters.SolrJmxReporter@1dafdef7: rootName = null, domain = solr.jvm, service url = null, agent id = null] for registry solr.jvm / com.codahale.metrics.MetricRegistry@5be1599a
   [junit4]   2> 16472 INFO  (SUITE-RequestLoggingTest-seed#[437D83C0F26C222A]-worker) [    ] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.jetty, tag=null
   [junit4]   2> 16472 INFO  (SUITE-RequestLoggingTest-seed#[437D83C0F26C222A]-worker) [    ] o.a.s.m.r.SolrJmxReporter Closing reporter [org.apache.solr.metrics.reporters.SolrJmxReporter@3c8e01f6: rootName = null, domain = solr.jetty, service url = null, agent id = null] for registry solr.jetty / com.codahale.metrics.MetricRegistry@35e8079
   [junit4]   2> 16475 INFO  (coreCloseExecutor-15-thread-1) [    x:collection1] o.a.s.c.SolrCore [collection1]  CLOSING SolrCore org.apache.solr.core.SolrCore@59557d3e
   [junit4]   2> 16475 INFO  (coreCloseExecutor-15-thread-1) [    x:collection1] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.core.collection1, tag=59557d3e
   [junit4]   2> 16475 INFO  (coreCloseExecutor-15-thread-1) [    x:collection1] o.a.s.m.r.SolrJmxReporter Closing reporter [org.apache.solr.metrics.reporters.SolrJmxReporter@1d65947f: rootName = null, domain = solr.core.collection1, service url = null, agent id = null] for registry solr.core.collection1 / com.codahale.metrics.MetricRegistry@b0c1aed
   [junit4]   2> NOTE: leaving temporary files on disk at: C:\Users\jenkins\workspace\Lucene-Solr-master-Windows\solr\build\solr-core\test\J1\temp\solr.handler.RequestLoggingTest_437D83C0F26C222A-001
   [junit4]   2> Sep 03, 2018 9:09:57 AM com.carrotsearch.randomizedtesting.ThreadLeakControl checkThreadLeaks
   [junit4]   2> WARNING: Will linger awaiting termination of 1 leaked thread(s).
   [junit4]   2> NOTE: test params are: codec=CheapBastard, sim=Asserting(org.apache.lucene.search.similarities.AssertingSimilarity@23ec1fe7), locale=lt-LT, timezone=NST
   [junit4]   2> NOTE: Windows 10 10.0 amd64/Oracle Corporation 10 (64-bit)/cpus=3,threads=2,free=57852808,total=97386496
   [junit4]   2> NOTE: All tests run in this JVM: [RequestLoggingTest]
   [junit4] Completed [2/5 (2!)] on J1 in 15.79s, 2 tests, 1 failure <<< FAILURES!

[...truncated 7 lines...]
   [junit4] Suite: org.apache.solr.handler.RequestLoggingTest
   [junit4]   2> Creating dataDir: C:\Users\jenkins\workspace\Lucene-Solr-master-Windows\solr\build\solr-core\test\J0\temp\solr.handler.RequestLoggingTest_437D83C0F26C222A-002\init-core-data-001
   [junit4]   2> 16671 WARN  (SUITE-RequestLoggingTest-seed#[437D83C0F26C222A]-worker) [    ] o.a.s.SolrTestCaseJ4 startTrackingSearchers: numOpens=1 numCloses=1
   [junit4]   2> 16671 INFO  (SUITE-RequestLoggingTest-seed#[437D83C0F26C222A]-worker) [    ] o.a.s.SolrTestCaseJ4 Using PointFields (NUMERIC_POINTS_SYSPROP=true) w/NUMERIC_DOCVALUES_SYSPROP=true
   [junit4]   2> 16673 INFO  (SUITE-RequestLoggingTest-seed#[437D83C0F26C222A]-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)
   [junit4]   2> 16673 INFO  (SUITE-RequestLoggingTest-seed#[437D8

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

oc,scope=searcher, tag=7f84eb8e
   [junit4]   2> 19338 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=7f84eb8e
   [junit4]   2> 19338 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=7f84eb8e
   [junit4]   2> 19339 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=7f84eb8e
   [junit4]   2> 19339 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=7f84eb8e
   [junit4]   2> 19339 INFO  (searcherExecutor-42-thread-1-processing-x:collection1) [    x:collection1] o.a.s.c.SolrCore [collection1] Registered new searcher Searcher@762622e7[collection1] main{ExitableDirectoryReader(UninvertingDirectoryReader())}
   [junit4]   2> 19339 INFO  (TEST-RequestLoggingTest.testLogBeforeExecuteWithCoreLogger-seed#[437D83C0F26C222A]) [    ] o.a.s.c.S.Request [collection1]  webapp=null path=null params={q=*:*&wt=xml} hits=0 status=0 QTime=4
   [junit4]   2> 19340 INFO  (TEST-RequestLoggingTest.testLogBeforeExecuteWithCoreLogger-seed#[437D83C0F26C222A]) [    ] o.a.s.SolrTestCaseJ4 ###Ending testLogBeforeExecuteWithCoreLogger
   [junit4] OK      0.01s J1 | RequestLoggingTest.testLogBeforeExecuteWithCoreLogger
   [junit4]   2> 19342 INFO  (TEST-RequestLoggingTest.testLogBeforeExecuteWithRequestLogger-seed#[437D83C0F26C222A]) [    ] o.a.s.SolrTestCaseJ4 ###Starting testLogBeforeExecuteWithRequestLogger
   [junit4]   2> NOTE: reproduce with: ant test  -Dtestcase=RequestLoggingTest -Dtests.method=testLogBeforeExecuteWithRequestLogger -Dtests.seed=437D83C0F26C222A -Dtests.slow=true -Dtests.badapples=true -Dtests.locale=lt-LT -Dtests.timezone=NST -Dtests.asserts=true -Dtests.file.encoding=ISO-8859-1
   [junit4] FAILURE 0.01s J1 | RequestLoggingTest.testLogBeforeExecuteWithRequestLogger <<<
   [junit4]    > Throwable #1: java.lang.AssertionError
   [junit4]    > 	at __randomizedtesting.SeedInfo.seed([437D83C0F26C222A:F214A3CF5F9A9A64]: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> 19345 DEBUG (TEST-RequestLoggingTest.testLogBeforeExecuteWithRequestLogger-seed#[437D83C0F26C222A]) [    ] o.a.s.c.S.Request [collection1]  webapp=null path=null params={q=*:*&wt=xml}
   [junit4]   2> 19345 DEBUG (TEST-RequestLoggingTest.testLogBeforeExecuteWithRequestLogger-seed#[437D83C0F26C222A]) [    ] o.a.s.h.c.QueryComponent process: q=*:*&df=text&wt=xml&indent=off
   [junit4]   2> 19345 DEBUG (TEST-RequestLoggingTest.testLogBeforeExecuteWithRequestLogger-seed#[437D83C0F26C222A]) [    ] o.a.s.s.s.LocalStatsCache ## GET LocalSolrQueryRequest{q=*:*&df=text&wt=xml&indent=off}
   [junit4]   2> 19345 INFO  (TEST-RequestLoggingTest.testLogBeforeExecuteWithRequestLogger-seed#[437D83C0F26C222A]) [    ] o.a.s.c.S.Request [collection1]  webapp=null path=null params={q=*:*&wt=xml} hits=0 status=0 QTime=0
   [junit4]   2> 19346 INFO  (TEST-RequestLoggingTest.testLogBeforeExecuteWithRequestLogger-seed#[437D83C0F26C222A]) [    ] o.a.s.SolrTestCaseJ4 ###Ending testLogBeforeExecuteWithRequestLogger
   [junit4]   2> 19347 INFO  (SUITE-RequestLoggingTest-seed#[437D83C0F26C222A]-worker) [    ] o.a.s.SolrTestCaseJ4 ###deleteCore
   [junit4]   2> 19347 INFO  (SUITE-RequestLoggingTest-seed#[437D83C0F26C222A]-worker) [    ] o.a.s.c.CoreContainer Shutting down CoreContainer instance=150835857
   [junit4]   2> 19347 INFO  (SUITE-RequestLoggingTest-seed#[437D83C0F26C222A]-worker) [    ] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.node, tag=null
   [junit4]   2> 19347 INFO  (SUITE-RequestLoggingTest-seed#[437D83C0F26C222A]-worker) [    ] o.a.s.m.r.SolrJmxReporter Closing reporter [org.apache.solr.metrics.reporters.SolrJmxReporter@38212f2e: rootName = null, domain = solr.node, service url = null, agent id = null] for registry solr.node / com.codahale.metrics.MetricRegistry@75814ab4
   [junit4]   2> 19352 INFO  (SUITE-RequestLoggingTest-seed#[437D83C0F26C222A]-worker) [    ] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.jvm, tag=null
   [junit4]   2> 19352 INFO  (SUITE-RequestLoggingTest-seed#[437D83C0F26C222A]-worker) [    ] o.a.s.m.r.SolrJmxReporter Closing reporter [org.apache.solr.metrics.reporters.SolrJmxReporter@56e1771d: rootName = null, domain = solr.jvm, service url = null, agent id = null] for registry solr.jvm / com.codahale.metrics.MetricRegistry@5be1599a
   [junit4]   2> 19352 INFO  (SUITE-RequestLoggingTest-seed#[437D83C0F26C222A]-worker) [    ] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.jetty, tag=null
   [junit4]   2> 19352 INFO  (SUITE-RequestLoggingTest-seed#[437D83C0F26C222A]-worker) [    ] o.a.s.m.r.SolrJmxReporter Closing reporter [org.apache.solr.metrics.reporters.SolrJmxReporter@1cc04e36: rootName = null, domain = solr.jetty, service url = null, agent id = null] for registry solr.jetty / com.codahale.metrics.MetricRegistry@35e8079
   [junit4]   2> 19353 INFO  (coreCloseExecutor-47-thread-1) [    x:collection1] o.a.s.c.SolrCore [collection1]  CLOSING SolrCore org.apache.solr.core.SolrCore@5d5c3a1a
   [junit4]   2> 19353 INFO  (coreCloseExecutor-47-thread-1) [    x:collection1] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.core.collection1, tag=5d5c3a1a
   [junit4]   2> 19354 INFO  (coreCloseExecutor-47-thread-1) [    x:collection1] o.a.s.m.r.SolrJmxReporter Closing reporter [org.apache.solr.metrics.reporters.SolrJmxReporter@7f84eb8e: rootName = null, domain = solr.core.collection1, service url = null, agent id = null] for registry solr.core.collection1 / com.codahale.metrics.MetricRegistry@6e05e5fe
   [junit4]   2> NOTE: leaving temporary files on disk at: C:\Users\jenkins\workspace\Lucene-Solr-master-Windows\solr\build\solr-core\test\J1\temp\solr.handler.RequestLoggingTest_437D83C0F26C222A-002
   [junit4]   2> NOTE: test params are: codec=CheapBastard, sim=Asserting(org.apache.lucene.search.similarities.AssertingSimilarity@44344c26), locale=lt-LT, timezone=NST
   [junit4]   2> NOTE: Windows 10 10.0 amd64/Oracle Corporation 10 (64-bit)/cpus=3,threads=1,free=31553896,total=97386496
   [junit4]   2> NOTE: All tests run in this JVM: [RequestLoggingTest, RequestLoggingTest, RequestLoggingTest]
   [junit4] Completed [5/5 (4!)] on J1 in 0.73s, 2 tests, 1 failure <<< FAILURES!

[...truncated 13 lines...]
BUILD FAILED
C:\Users\jenkins\workspace\Lucene-Solr-master-Windows\lucene\common-build.xml:1568: The following error occurred while executing this line:
C:\Users\jenkins\workspace\Lucene-Solr-master-Windows\lucene\common-build.xml:1092: There were test failures: 5 suites, 10 tests, 4 failures [seed: 437D83C0F26C222A]

Total time: 21 seconds

[repro] Setting last failure code to 1

[repro] Failures:
[repro]   4/5 failed: org.apache.solr.handler.RequestLoggingTest
[repro] Exiting with code 1

C:\Users\jenkins\workspace\Lucene-Solr-master-Windows>IF EXIST lucene\build move /y lucene\build lucene\build.repro 
        1 dir(s) moved.

C:\Users\jenkins\workspace\Lucene-Solr-master-Windows>IF EXIST solr\build move /y solr\build solr\build.repro 
        1 dir(s) moved.

C:\Users\jenkins\workspace\Lucene-Solr-master-Windows>IF EXIST lucene\build.orig move /y lucene\build.orig lucene\build 
        1 dir(s) moved.

C:\Users\jenkins\workspace\Lucene-Solr-master-Windows>IF EXIST solr\build.orig move /y solr\build.orig solr\build 
        1 dir(s) moved.

C:\Users\jenkins\workspace\Lucene-Solr-master-Windows>exit 0 
Archiving artifacts
Setting ANT_1_8_2_HOME=C:\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=C:\Users\jenkins\tools\hudson.tasks.Ant_AntInstallation\ANT_1.8.2
Setting ANT_1_8_2_HOME=C:\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=d93c46ea94dec612aa53e37d119fe34b5e8a828e, workspace=C:\Users\jenkins\workspace\Lucene-Solr-master-Windows
[WARNINGS] Computing warning deltas based on reference build #7501
Recording test results
Setting ANT_1_8_2_HOME=C:\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=C:\Users\jenkins\tools\hudson.tasks.Ant_AntInstallation\ANT_1.8.2
Setting ANT_1_8_2_HOME=C:\Users\jenkins\tools\hudson.tasks.Ant_AntInstallation\ANT_1.8.2
Setting ANT_1_8_2_HOME=C:\Users\jenkins\tools\hudson.tasks.Ant_AntInstallation\ANT_1.8.2
Setting ANT_1_8_2_HOME=C:\Users\jenkins\tools\hudson.tasks.Ant_AntInstallation\ANT_1.8.2