lucene-dev mailing list archives

Site index · List index
Message view « Date » · « Thread »
Top « Date » · « Thread »
From Policeman Jenkins Server <jenk...@thetaphi.de>
Subject [JENKINS] Lucene-Solr-master-Linux (64bit/jdk-9.0.4) - Build # 22794 - Unstable!
Date Mon, 03 Sep 2018 13:12:26 GMT
Build: https://jenkins.thetaphi.de/job/Lucene-Solr-master-Linux/22794/
Java: 64bit/jdk-9.0.4 -XX:+UseCompressedOops -XX:+UseParallelGC

2 tests failed.
FAILED:  org.apache.solr.handler.RequestLoggingTest.testLogBeforeExecuteWithCoreLogger

Error Message:


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


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

Error Message:


Stack Trace:
java.lang.AssertionError
	at __randomizedtesting.SeedInfo.seed([DC7D7E5F20D34432:6D145E508D25FC7C]: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 14502 lines...]
   [junit4] Suite: org.apache.solr.handler.RequestLoggingTest
   [junit4]   2> 2399499 INFO  (SUITE-RequestLoggingTest-seed#[DC7D7E5F20D34432]-worker) [    ] o.a.s.SolrTestCaseJ4 SecureRandom sanity checks: test.solr.allowed.securerandom=null & java.security.egd=file:/dev/./urandom
   [junit4]   2> Creating dataDir: /home/jenkins/workspace/Lucene-Solr-master-Linux/solr/build/solr-core/test/J0/temp/solr.handler.RequestLoggingTest_DC7D7E5F20D34432-001/init-core-data-001
   [junit4]   2> 2399499 WARN  (SUITE-RequestLoggingTest-seed#[DC7D7E5F20D34432]-worker) [    ] o.a.s.SolrTestCaseJ4 startTrackingSearchers: numOpens=5 numCloses=5
   [junit4]   2> 2399499 INFO  (SUITE-RequestLoggingTest-seed#[DC7D7E5F20D34432]-worker) [    ] o.a.s.SolrTestCaseJ4 Using PointFields (NUMERIC_POINTS_SYSPROP=true) w/NUMERIC_DOCVALUES_SYSPROP=true
   [junit4]   2> 2399499 INFO  (SUITE-RequestLoggingTest-seed#[DC7D7E5F20D34432]-worker) [    ] o.a.s.SolrTestCaseJ4 Randomized ssl (true) and clientAuth (false) via: @org.apache.solr.util.RandomizeSSL(reason="", ssl=0.0/0.0, value=0.0/0.0, clientAuth=0.0/0.0)
   [junit4]   2> 2399499 INFO  (SUITE-RequestLoggingTest-seed#[DC7D7E5F20D34432]-worker) [    ] o.a.s.SolrTestCaseJ4 ####initCore
   [junit4]   2> 2399500 INFO  (SUITE-RequestLoggingTest-seed#[DC7D7E5F20D34432]-worker) [    ] o.a.s.c.SolrResourceLoader [null] Added 2 libs to classloader, from paths: [/home/jenkins/workspace/Lucene-Solr-master-Linux/solr/core/src/test-files/solr/collection1/lib, /home/jenkins/workspace/Lucene-Solr-master-Linux/solr/core/src/test-files/solr/collection1/lib/classes]
   [junit4]   2> 2399512 INFO  (SUITE-RequestLoggingTest-seed#[DC7D7E5F20D34432]-worker) [    ] o.a.s.c.SolrConfig Using Lucene MatchVersion: 8.0.0
   [junit4]   2> 2399525 INFO  (SUITE-RequestLoggingTest-seed#[DC7D7E5F20D34432]-worker) [    ] o.a.s.s.IndexSchema [null] Schema name=test
   [junit4]   2> 2399586 INFO  (SUITE-RequestLoggingTest-seed#[DC7D7E5F20D34432]-worker) [    ] o.a.s.s.IndexSchema Loaded schema test/1.0 with uniqueid field id
   [junit4]   2> 2399691 INFO  (SUITE-RequestLoggingTest-seed#[DC7D7E5F20D34432]-worker) [    ] o.a.s.c.TransientSolrCoreCacheDefault Allocating transient cache for 2147483647 transient cores
   [junit4]   2> 2399691 INFO  (SUITE-RequestLoggingTest-seed#[DC7D7E5F20D34432]-worker) [    ] o.a.s.h.a.MetricsHistoryHandler No .system collection, keeping metrics history in memory.
   [junit4]   2> 2399698 INFO  (SUITE-RequestLoggingTest-seed#[DC7D7E5F20D34432]-worker) [    ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr.node' (registry 'solr.node') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@449407be
   [junit4]   2> 2399702 INFO  (SUITE-RequestLoggingTest-seed#[DC7D7E5F20D34432]-worker) [    ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr.jvm' (registry 'solr.jvm') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@449407be
   [junit4]   2> 2399702 INFO  (SUITE-RequestLoggingTest-seed#[DC7D7E5F20D34432]-worker) [    ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr.jetty' (registry 'solr.jetty') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@449407be
   [junit4]   2> 2399704 INFO  (coreLoadExecutor-11476-thread-1) [    x:collection1] o.a.s.c.SolrResourceLoader [null] Added 2 libs to classloader, from paths: [/home/jenkins/workspace/Lucene-Solr-master-Linux/solr/core/src/test-files/solr/collection1/lib, /home/jenkins/workspace/Lucene-Solr-master-Linux/solr/core/src/test-files/solr/collection1/lib/classes]
   [junit4]   2> 2399718 INFO  (coreLoadExecutor-11476-thread-1) [    x:collection1] o.a.s.c.SolrConfig Using Lucene MatchVersion: 8.0.0
   [junit4]   2> 2399730 INFO  (coreLoadExecutor-11476-thread-1) [    x:collection1] o.a.s.s.IndexSchema [collection1] Schema name=test
   [junit4]   2> 2399790 INFO  (coreLoadExecutor-11476-thread-1) [    x:collection1] o.a.s.s.IndexSchema Loaded schema test/1.0 with uniqueid field id
   [junit4]   2> 2399794 INFO  (coreLoadExecutor-11476-thread-1) [    x:collection1] o.a.s.c.CoreContainer Creating SolrCore 'collection1' using configuration from instancedir /home/jenkins/workspace/Lucene-Solr-master-Linux/solr/core/src/test-files/solr/collection1, trusted=true
   [junit4]   2> 2399794 INFO  (coreLoadExecutor-11476-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@449407be
   [junit4]   2> 2399794 INFO  (coreLoadExecutor-11476-thread-1) [    x:collection1] o.a.s.c.SolrCore solr.RecoveryStrategy.Builder
   [junit4]   2> 2399794 INFO  (coreLoadExecutor-11476-thread-1) [    x:collection1] o.a.s.c.SolrCore [[collection1] ] Opening new SolrCore at [/home/jenkins/workspace/Lucene-Solr-master-Linux/solr/core/src/test-files/solr/collection1], dataDir=[/home/jenkins/workspace/Lucene-Solr-master-Linux/solr/build/solr-core/test/J0/temp/solr.handler.RequestLoggingTest_DC7D7E5F20D34432-001/init-core-data-001/]
   [junit4]   2> 2399795 INFO  (coreLoadExecutor-11476-thread-1) [    x:collection1] o.a.s.u.RandomMergePolicy RandomMergePolicy wrapping class org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: maxMergeAtOnce=44, maxMergeAtOnceExplicit=40, maxMergedSegmentMB=83.9736328125, floorSegmentMB=1.9921875, forceMergeDeletesPctAllowed=4.166643404818671, segmentsPerTier=18.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.0, deletesPctAllowed=30.43498569054684
   [junit4]   2> 2399826 INFO  (coreLoadExecutor-11476-thread-1) [    x:collection1] o.a.s.u.UpdateHandler Using UpdateLog implementation: org.apache.solr.update.UpdateLog
   [junit4]   2> 2399826 INFO  (coreLoadExecutor-11476-thread-1) [    x:collection1] o.a.s.u.UpdateLog Initializing UpdateLog: dataDir= defaultSyncLevel=FLUSH numRecordsToKeep=100 maxNumLogsToKeep=10 numVersionBuckets=65536
   [junit4]   2> 2399826 INFO  (coreLoadExecutor-11476-thread-1) [    x:collection1] o.a.s.u.CommitTracker Hard AutoCommit: disabled
   [junit4]   2> 2399826 INFO  (coreLoadExecutor-11476-thread-1) [    x:collection1] o.a.s.u.CommitTracker Soft AutoCommit: disabled
   [junit4]   2> 2399827 INFO  (coreLoadExecutor-11476-thread-1) [    x:collection1] o.a.s.u.RandomMergePolicy RandomMergePolicy wrapping class org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: maxMergeAtOnce=24, maxMergeAtOnceExplicit=13, maxMergedSegmentMB=61.4560546875, floorSegmentMB=2.1103515625, forceMergeDeletesPctAllowed=18.37880392186092, segmentsPerTier=38.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.0, deletesPctAllowed=31.42395329618669
   [junit4]   2> 2399827 INFO  (coreLoadExecutor-11476-thread-1) [    x:collection1] o.a.s.s.SolrIndexSearcher Opening [Searcher@4eaa4df9[collection1] main]
   [junit4]   2> 2399827 INFO  (coreLoadExecutor-11476-thread-1) [    x:collection1] o.a.s.h.c.SpellCheckComponent Initializing spell checkers
   [junit4]   2> 2400042 INFO  (coreLoadExecutor-11476-thread-1) [    x:collection1] o.a.s.s.DirectSolrSpellChecker init: {name=direct,classname=DirectSolrSpellChecker,field=lowerfilt,minQueryLength=3}
   [junit4]   2> 2400707 INFO  (coreLoadExecutor-11476-thread-1) [    x:collection1] o.a.s.h.ReplicationHandler Commits will be reserved for 10000ms.
   [junit4]   2> 2400707 INFO  (searcherExecutor-11477-thread-1-processing-x:collection1) [    x:collection1] o.a.s.h.c.SpellCheckComponent Loading spell index for spellchecker: default
   [junit4]   2> 2400707 INFO  (coreLoadExecutor-11476-thread-1) [    x:collection1] o.a.s.u.UpdateLog Could not find max version in index or recent updates, using new clock 1610590089719578624
   [junit4]   2> 2400708 INFO  (searcherExecutor-11477-thread-1-processing-x:collection1) [    x:collection1] o.a.s.h.c.SpellCheckComponent Loading spell index for spellchecker: direct
   [junit4]   2> 2400708 INFO  (searcherExecutor-11477-thread-1-processing-x:collection1) [    x:collection1] o.a.s.h.c.SpellCheckComponent Loading spell index for spellchecker: wordbreak
   [junit4]   2> 2400708 INFO  (searcherExecutor-11477-thread-1-processing-x:collection1) [    x:collection1] o.a.s.h.c.SpellCheckComponent Loading spell index for spellchecker: multipleFields
   [junit4]   2> 2400708 INFO  (searcherExecutor-11477-thread-1-processing-x:collection1) [    x:collection1] o.a.s.h.c.SpellCheckComponent Loading spell index for spellchecker: jarowinkler
   [junit4]   2> 2400708 INFO  (searcherExecutor-11477-thread-1-processing-x:collection1) [    x:collection1] o.a.s.h.c.SpellCheckComponent Loading spell index for spellchecker: external
   [junit4]   2> 2400708 INFO  (searcherExecutor-11477-thread-1-processing-x:collection1) [    x:collection1] o.a.s.h.c.SpellCheckComponent Loading spell index for spellchecker: freq
   [junit4]   2> 2400708 INFO  (searcherExecutor-11477-thread-1-processing-x:collection1) [    x:collection1] o.a.s.h.c.SpellCheckComponent Loading spell index for spellchecker: fqcn
   [junit4]   2> 2400708 INFO  (searcherExecutor-11477-thread-1-processing-x:collection1) [    x:collection1] o.a.s.h.c.SpellCheckComponent Loading spell index for spellchecker: perDict
   [junit4]   2> 2400709 INFO  (searcherExecutor-11477-thread-1-processing-x:collection1) [    x:collection1] o.a.s.c.SolrCore [collection1] Registered new searcher Searcher@4eaa4df9[collection1] main{ExitableDirectoryReader(UninvertingDirectoryReader())}
   [junit4]   2> 2400709 INFO  (SUITE-RequestLoggingTest-seed#[DC7D7E5F20D34432]-worker) [    ] o.a.s.SolrTestCaseJ4 ####initCore end
   [junit4]   2> 2400713 INFO  (TEST-RequestLoggingTest.testLogBeforeExecuteWithRequestLogger-seed#[DC7D7E5F20D34432]) [    ] o.a.s.SolrTestCaseJ4 ###Starting testLogBeforeExecuteWithRequestLogger
   [junit4]   2> 2400718 DEBUG (TEST-RequestLoggingTest.testLogBeforeExecuteWithRequestLogger-seed#[DC7D7E5F20D34432]) [    ] o.a.s.c.S.Request [collection1]  webapp=null path=null params={q=*:*&wt=xml}
   [junit4]   2> 2400718 DEBUG (TEST-RequestLoggingTest.testLogBeforeExecuteWithRequestLogger-seed#[DC7D7E5F20D34432]) [    ] o.a.s.h.c.SearchHandler Adding  component:org.apache.solr.handler.component.QueryComponent@6f6d8916
   [junit4]   2> 2400718 DEBUG (TEST-RequestLoggingTest.testLogBeforeExecuteWithRequestLogger-seed#[DC7D7E5F20D34432]) [    ] o.a.s.h.c.SearchHandler Adding  component:org.apache.solr.handler.component.FacetComponent@6016b831
   [junit4]   2> 2400718 DEBUG (TEST-RequestLoggingTest.testLogBeforeExecuteWithRequestLogger-seed#[DC7D7E5F20D34432]) [    ] o.a.s.h.c.SearchHandler Adding  component:org.apache.solr.search.facet.FacetModule@39716577
   [junit4]   2> 2400718 DEBUG (TEST-RequestLoggingTest.testLogBeforeExecuteWithRequestLogger-seed#[DC7D7E5F20D34432]) [    ] o.a.s.h.c.SearchHandler Adding  component:org.apache.solr.handler.component.MoreLikeThisComponent@34a68687
   [junit4]   2> 2400718 DEBUG (TEST-RequestLoggingTest.testLogBeforeExecuteWithRequestLogger-seed#[DC7D7E5F20D34432]) [    ] o.a.s.h.c.SearchHandler Adding  component:org.apache.solr.handler.component.HighlightComponent@37008c3c
   [junit4]   2> 2400718 DEBUG (TEST-RequestLoggingTest.testLogBeforeExecuteWithRequestLogger-seed#[DC7D7E5F20D34432]) [    ] o.a.s.h.c.SearchHandler Adding  component:org.apache.solr.handler.component.StatsComponent@62026ddd
   [junit4]   2> 2400718 DEBUG (TEST-RequestLoggingTest.testLogBeforeExecuteWithRequestLogger-seed#[DC7D7E5F20D34432]) [    ] o.a.s.h.c.SearchHandler Adding  component:org.apache.solr.handler.component.ExpandComponent@50eaf637
   [junit4]   2> 2400718 DEBUG (TEST-RequestLoggingTest.testLogBeforeExecuteWithRequestLogger-seed#[DC7D7E5F20D34432]) [    ] o.a.s.h.c.SearchHandler Adding  component:org.apache.solr.handler.component.TermsComponent@50f8d013
   [junit4]   2> 2400718 DEBUG (TEST-RequestLoggingTest.testLogBeforeExecuteWithRequestLogger-seed#[DC7D7E5F20D34432]) [    ] o.a.s.h.c.SearchHandler Adding  debug component:org.apache.solr.handler.component.DebugComponent@63aac75c
   [junit4]   2> 2400718 DEBUG (TEST-RequestLoggingTest.testLogBeforeExecuteWithRequestLogger-seed#[DC7D7E5F20D34432]) [    ] o.a.s.h.c.QueryComponent process: q=*:*&df=text&wt=xml&indent=off
   [junit4]   2> 2400718 DEBUG (TEST-RequestLoggingTest.testLogBeforeExecuteWithRequestLogger-seed#[DC7D7E5F20D34432]) [    ] o.a.s.s.s.LocalStatsCache ## GET LocalSolrQueryRequest{q=*:*&df=text&wt=xml&indent=off}
   [junit4]   2> 2400718 INFO  (TEST-RequestLoggingTest.testLogBeforeExecuteWithRequestLogger-seed#[DC7D7E5F20D34432]) [    ] o.a.s.c.S.Request [collection1]  webapp=null path=null params={q=*:*&wt=xml} hits=0 status=0 QTime=0
   [junit4]   2> 2400719 INFO  (TEST-RequestLoggingTest.testLogBeforeExecuteWithRequestLogger-seed#[DC7D7E5F20D34432]) [    ] o.a.s.SolrTestCaseJ4 ###Ending testLogBeforeExecuteWithRequestLogger
   [junit4]   2> NOTE: reproduce with: ant test  -Dtestcase=RequestLoggingTest -Dtests.method=testLogBeforeExecuteWithRequestLogger -Dtests.seed=DC7D7E5F20D34432 -Dtests.multiplier=3 -Dtests.slow=true -Dtests.locale=uz-UZ -Dtests.timezone=America/Rosario -Dtests.asserts=true -Dtests.file.encoding=ISO-8859-1
   [junit4] FAILURE 0.01s J0 | RequestLoggingTest.testLogBeforeExecuteWithRequestLogger <<<
   [junit4]    > Throwable #1: java.lang.AssertionError
   [junit4]    > 	at __randomizedtesting.SeedInfo.seed([DC7D7E5F20D34432:6D145E508D25FC7C]: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> 2400721 INFO  (TEST-RequestLoggingTest.testLogBeforeExecuteWithCoreLogger-seed#[DC7D7E5F20D34432]) [    ] o.a.s.SolrTestCaseJ4 ###Starting testLogBeforeExecuteWithCoreLogger
   [junit4]   2> 2400723 DEBUG (TEST-RequestLoggingTest.testLogBeforeExecuteWithCoreLogger-seed#[DC7D7E5F20D34432]) [    ] o.a.s.c.S.Request [collection1]  webapp=null path=null params={q=*:*&wt=xml}
   [junit4]   2> 2400723 DEBUG (TEST-RequestLoggingTest.testLogBeforeExecuteWithCoreLogger-seed#[DC7D7E5F20D34432]) [    ] o.a.s.h.c.QueryComponent process: q=*:*&df=text&wt=xml&indent=off
   [junit4]   2> 2400723 DEBUG (TEST-RequestLoggingTest.testLogBeforeExecuteWithCoreLogger-seed#[DC7D7E5F20D34432]) [    ] o.a.s.s.s.LocalStatsCache ## GET LocalSolrQueryRequest{q=*:*&df=text&wt=xml&indent=off}
   [junit4]   2> 2400723 INFO  (TEST-RequestLoggingTest.testLogBeforeExecuteWithCoreLogger-seed#[DC7D7E5F20D34432]) [    ] o.a.s.c.S.Request [collection1]  webapp=null path=null params={q=*:*&wt=xml} hits=0 status=0 QTime=0
   [junit4]   2> 2400724 INFO  (TEST-RequestLoggingTest.testLogBeforeExecuteWithCoreLogger-seed#[DC7D7E5F20D34432]) [    ] o.a.s.SolrTestCaseJ4 ###Ending testLogBeforeExecuteWithCoreLogger
   [junit4]   2> 2400724 INFO  (SUITE-RequestLoggingTest-seed#[DC7D7E5F20D34432]-worker) [    ] o.a.s.SolrTestCaseJ4 ###deleteCore
   [junit4]   2> 2400724 INFO  (SUITE-RequestLoggingTest-seed#[DC7D7E5F20D34432]-worker) [    ] o.a.s.c.CoreContainer Shutting down CoreContainer instance=440242743
   [junit4]   2> 2400724 INFO  (SUITE-RequestLoggingTest-seed#[DC7D7E5F20D34432]-worker) [    ] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.node, tag=null
   [junit4]   2> 2400724 INFO  (SUITE-RequestLoggingTest-seed#[DC7D7E5F20D34432]-worker) [    ] o.a.s.m.r.SolrJmxReporter Closing reporter [org.apache.solr.metrics.reporters.SolrJmxReporter@25629bad: rootName = null, domain = solr.node, service url = null, agent id = null] for registry solr.node / com.codahale.metrics.MetricRegistry@6ab0f369
   [junit4]   2> 2400727 INFO  (SUITE-RequestLoggingTest-seed#[DC7D7E5F20D34432]-worker) [    ] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.jvm, tag=null
   [junit4]   2> 2400727 INFO  (SUITE-RequestLoggingTest-seed#[DC7D7E5F20D34432]-worker) [    ] o.a.s.m.r.SolrJmxReporter Closing reporter [org.apache.solr.metrics.reporters.SolrJmxReporter@43da4c0: rootName = null, domain = solr.jvm, service url = null, agent id = null] for registry solr.jvm / com.codahale.metrics.MetricRegistry@2c39b529
   [junit4]   2> 2400729 INFO  (SUITE-RequestLoggingTest-seed#[DC7D7E5F20D34432]-worker) [    ] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.jetty, tag=null
   [junit4]   2> 2400729 INFO  (SUITE-RequestLoggingTest-seed#[DC7D7E5F20D34432]-worker) [    ] o.a.s.m.r.SolrJmxReporter Closing reporter [org.apache.solr.metrics.reporters.SolrJmxReporter@14299b78: rootName = null, domain = solr.jetty, service url = null, agent id = null] for registry solr.jetty / com.codahale.metrics.MetricRegistry@4aec31ea
   [junit4]   2> 2400729 INFO  (coreCloseExecutor-11482-thread-1) [    x:collection1] o.a.s.c.SolrCore [collection1]  CLOSING SolrCore org.apache.solr.core.SolrCore@5c1b2a47
   [junit4]   2> 2400729 INFO  (coreCloseExecutor-11482-thread-1) [    x:collection1] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.core.collection1, tag=5c1b2a47
   [junit4]   2> 2400729 INFO  (coreCloseExecutor-11482-thread-1) [    x:collection1] o.a.s.m.r.SolrJmxReporter Closing reporter [org.apache.solr.metrics.reporters.SolrJmxReporter@72e62fa2: rootName = null, domain = solr.core.collection1, service url = null, agent id = null] for registry solr.core.collection1 / com.codahale.metrics.MetricRegistry@18c09e45
   [junit4]   2> NOTE: leaving temporary files on disk at: /home/jenkins/workspace/Lucene-Solr-master-Linux/solr/build/solr-core/test/J0/temp/solr.handler.RequestLoggingTest_DC7D7E5F20D34432-001
   [junit4]   2> NOTE: test params are: codec=Asserting(Lucene80): {}, docValues:{}, maxPointsInLeafNode=1552, maxMBSortInHeap=6.688305152094994, sim=Asserting(org.apache.lucene.search.similarities.AssertingSimilarity@2f35e635), locale=uz-UZ, timezone=America/Rosario
   [junit4]   2> NOTE: Linux 4.15.0-32-generic amd64/Oracle Corporation 9.0.4 (64-bit)/cpus=8,threads=1,free=189884808,total=516423680
   [junit4]   2> NOTE: All tests run in this JVM: [TestStressInPlaceUpdates, TestSortByMinMaxFunction, LeaderVoteWaitTimeoutTest, TolerantUpdateProcessorTest, MetricTriggerIntegrationTest, DocValuesMultiTest, TestCorePropertiesReload, SolrIndexMetricsTest, TestSmileRequest, CursorPagingTest, TestNonDefinedSimilarityFactory, TestBinaryField, ResponseBuilderTest, LeaderElectionContextKeyTest, SolrCoreMetricManagerTest, ClassificationUpdateProcessorFactoryTest, TestPullReplica, TriLevelCompositeIdRoutingTest, CustomHighlightComponentTest, AnalyticsMergeStrategyTest, PreAnalyzedFieldManagedSchemaCloudTest, RuleEngineTest, TestStressLucene, TestSolrCoreParser, TestClassicSimilarityFactory, TestCloudSchemaless, TestPayloadCheckQParserPlugin, DocumentAnalysisRequestHandlerTest, TestExclusionRuleCollectionAccess, ConfigureRecoveryStrategyTest, TestConfigSetsAPIZkFailure, TestRuleBasedAuthorizationPlugin, BaseCdcrDistributedZkTest, TestCoreAdminApis, CursorMarkTest, OverseerRolesTest, SimpleCollectionCreateDeleteTest, TestDistributedMissingSort, PeerSyncWithIndexFingerprintCachingTest, TestShardHandlerFactory, TestSolrCoreProperties, TestRandomDVFaceting, TestWithCollection, TestRandomRequestDistribution, HdfsAutoAddReplicasIntegrationTest, CloneFieldUpdateProcessorFactoryTest, TestCustomSort, QueryEqualityTest, ZkCLITest, TestCSVLoader, ReturnFieldsTest, ChaosMonkeyNothingIsSafeTest, TestWriterPerf, OverriddenZkACLAndCredentialsProvidersTest, CustomCollectionTest, TestScoreJoinQPNoScore, TestQueryTypes, TestSimNodeLostTrigger, DistributedFacetPivotWhiteBoxTest, IndexBasedSpellCheckerTest, DistributedExpandComponentTest, CreateCollectionCleanupTest, TestLeaderElectionZkExpiry, TestFieldCacheReopen, MultiThreadedOCPTest, MigrateRouteKeyTest, DeleteLastCustomShardedReplicaTest, DistribDocExpirationUpdateProcessorTest, TestDocBasedVersionConstraints, TestMiniSolrCloudClusterSSL, TestSolrXml, SuggestComponentTest, PluginInfoTest, CollectionsAPIAsyncDistributedZkTest, TestGraphTermsQParserPlugin, IgnoreLargeDocumentProcessorFactoryTest, PropertiesRequestHandlerTest, TestSearchPerf, TestCloudConsistency, TestHdfsCloudBackupRestore, DocExpirationUpdateProcessorFactoryTest, TestDistribIDF, TestRequestStatusCollectionAPI, TestIBSimilarityFactory, TestSolrQueryParser, TestDynamicLoading, TestSchemaNameResource, TestLogWatcher, TestRTimerTree, TestRecoveryHdfs, TestPushWriter, ChaosMonkeySafeLeaderWithPullReplicasTest, RandomizedTaggerTest, DistributedQueryComponentOptimizationTest, HdfsRecoveryZkTest, BufferStoreTest, SpellCheckComponentTest, TestGraphMLResponseWriter, TestLuceneMatchVersion, MaxSizeAutoCommitTest, GraphQueryTest, TestFreeTextSuggestions, InfixSuggestersTest, TestSolrCoreSnapshots, TriggerSetPropertiesIntegrationTest, BadCopyFieldTest, DataDrivenBlockJoinTest, ScheduledTriggerIntegrationTest, TestJsonFacetsStatsParsing, FileUtilsTest, BlobRepositoryCloudTest, NumericFieldsTest, ConjunctionSolrSpellCheckerTest, TokenizerChainTest, SolrCloudReportersTest, SliceStateTest, RequiredFieldsTest, TestManagedSchemaThreadSafety, WordBreakSolrSpellCheckerTest, CdcrVersionReplicationTest, HdfsThreadLeakTest, TestCloudPseudoReturnFields, MoreLikeThisHandlerTest, DistributedSuggestComponentTest, NodeAddedTriggerTest, ShardRoutingCustomTest, TestSimGenericDistributedQueue, ZkNodePropsTest, TestCrossCoreJoin, TestRestManager, RegexBoostProcessorTest, AddBlockUpdateTest, TestHalfAndHalfDocValues, ChangedSchemaMergeTest, AnalysisAfterCoreReloadTest, BasicFunctionalityTest, ConvertedLegacyTest, DisMaxRequestHandlerTest, DistributedIntervalFacetingTest, EchoParamsTest, SampleTest, TestDistributedSearch, TestDocumentBuilder, TestGroupingSearch, TestHighlightDedupGrouping, TestJoin, TestRandomFaceting, TestSimpleTrackingShardHandler, TestTolerantSearch, TestTrie, PathHierarchyTokenizerFactoryTest, ProtectedTermFilterFactoryTest, TestCharFilters, TestLuceneIndexBackCompat, TestEmbeddedSolrServerAdminHandler, TestEmbeddedSolrServerConstructors, ConnectionReuseTest, ActionThrottleTest, AliasIntegrationTest, CleanupOldIndexTest, ConcurrentCreateRoutedAliasTest, DeleteShardTest, DeleteStatusTest, DistributedVersionInfoTest, LeaderFailoverAfterPartitionTest, LeaderFailureAfterFreshStartTest, LegacyCloudClusterPropTest, MetricsHistoryIntegrationTest, MoveReplicaTest, MultiSolrCloudTestCaseTest, NodeMutatorTest, OutOfBoxZkACLAndCredentialsProvidersTest, OverseerTest, RollingRestartTest, SharedFSAutoReplicaFailoverTest, SolrXmlInZkTest, SyncSliceTest, TestCloudSearcherWarming, TestHashPartitioner, TestOnReconnectListenerSupport, TestSSLRandomization, TestSizeLimitedDistributedMap, TestSkipOverseerOperations, TestSolrCloudWithDelegationTokens, TestSolrCloudWithKerberosAlt, TestSolrCloudWithSecureImpersonation, TestStressCloudBlindAtomicUpdates, TestStressLiveNodes, TestTlogReplica, ZkFailoverTest, ConcurrentDeleteAndCreateCollectionTest, HdfsCollectionsAPIDistributedZkTest, ShardSplitTest, HDFSCollectionsAPITest, HdfsBasicDistributedZk2Test, HdfsBasicDistributedZkTest, HdfsChaosMonkeyNothingIsSafeTest, HdfsChaosMonkeySafeLeaderTest, HdfsNNFailoverTest, HdfsRecoverLeaseTest, HdfsWriteToMultipleCollectionsTest, ZkStateReaderTest, CachingDirectoryFactoryTest, ExitableDirectoryReaderTest, HdfsDirectoryFactoryTest, OpenCloseCoreStressTest, RequestHandlersTest, SolrCoreCheckLockOnStartupTest, SolrCoreTest, TestBackupRepositoryFactory, TestBadConfig, TestConfigOverlay, TestConfigSets, TestCustomStream, TestDirectoryFactory, TestDynamicURP, TestImplicitCoreProperties, TestInfoStreamLogging, TestLazyCores, TestMergePolicyConfig, TestNRTOpen, TestQuerySenderListener, TestQuerySenderNoQuery, TestReloadAndDeleteDocs, TestSolrDeletionPolicy1, PingRequestHandlerTest, RequestLoggingTest]
   [junit4] Completed [574/832 (1!)] on J0 in 1.25s, 2 tests, 1 failure <<< FAILURES!

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

[repro] Revision: a1ec716e107807f1dc24923cc7a91d0c5e64a7e1

[repro] Ant options: "-Dargs=-XX:+UseCompressedOops -XX:+UseParallelGC"
[repro] Repro line:  ant test  -Dtestcase=RequestLoggingTest -Dtests.method=testLogBeforeExecuteWithRequestLogger -Dtests.seed=DC7D7E5F20D34432 -Dtests.multiplier=3 -Dtests.slow=true -Dtests.locale=uz-UZ -Dtests.timezone=America/Rosario -Dtests.asserts=true -Dtests.file.encoding=ISO-8859-1

[repro] ant clean

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

[...truncated 3423 lines...]
[repro] ant test-nocompile -Dtests.dups=5 -Dtests.maxfailures=5 -Dtests.class="*.RequestLoggingTest" -Dtests.showOutput=onerror "-Dargs=-XX:+UseCompressedOops -XX:+UseParallelGC" -Dtests.seed=DC7D7E5F20D34432 -Dtests.multiplier=3 -Dtests.slow=true -Dtests.locale=uz-UZ -Dtests.timezone=America/Rosario -Dtests.asserts=true -Dtests.file.encoding=ISO-8859-1

[...truncated 53 lines...]
   [junit4] Suite: org.apache.solr.handler.RequestLoggingTest
   [junit4]   2> 6702 INFO  (SUITE-RequestLoggingTest-seed#[DC7D7E5F20D34432]-worker) [    ] o.a.s.SolrTestCaseJ4 SecureRandom sanity checks: test.solr.allowed.securerandom=null & java.security.egd=file:/dev/./urandom
   [junit4]   2> Creating dataDir: /home/jenkins/workspace/Lucene-Solr-master-Linux/solr/build/solr-core/test/J2/temp/solr.handler.RequestLoggingTest_DC7D7E5F20D34432-001/init-core-data-001
   [junit4]   2> 6712 WARN  (SUITE-RequestLoggingTest-seed#[DC7D7E5F20D34432]-worker) [    ] o.a.s.SolrTestCaseJ4 startTrackingSearchers: numOpens=1 numCloses=1
   [junit4]   2> 6712 INFO  (SUITE-RequestLoggingTest-seed#[DC7D7E5F20D34432]-worker) [    ] o.a.s.SolrTestCaseJ4 Using PointFields (NUMERIC_POINTS_SYSPROP=true) w/NUMERIC_DOCVALUES_SYSPROP=true
   [junit4]   2> 6713 INFO  (SUITE-RequestLoggingTest-seed#[DC7D7E5F20D34432]-worker) [    ] o.a.s.SolrTestCaseJ4 Randomized ssl (true) and clientAuth (false) via: @org.apache.solr.util.RandomizeSSL(reason="", ssl=0.0/0.0, value=0.0/0.0, clientAuth=0.0/0.0)
   [junit4]   2> 6714 INFO  (SUITE-RequestLoggingTest-seed#[DC7D7E5F20D34432]-worker) [    ] o.a.s.SolrTestCaseJ4 ####initCore
   [junit4]   2> 6715 INFO  (SUITE-RequestLoggingTest-seed#[DC7D7E5F20D34432]-worker) [    ] o.a.s.c.SolrResourceLoader [null] Added 2 libs to classloader, from paths: [/home/jenkins/workspace/Lucene-Solr-master-Linux/solr/core/src/test-files/solr/collection1/lib, /home/jenkins/workspace/Lucene-Solr-master-Linux/solr/core/src/test-files/solr/collection1/lib/classes]
   [junit4]   2> 6741 INFO  (SUITE-RequestLoggingTest-seed#[DC7D7E5F20D34432]-worker) [    ] o.a.s.c.SolrConfig Using Lucene MatchVersion: 8.0.0
   [junit4]   2> 6767 INFO  (SUITE-RequestLoggingTest-seed#[DC7D7E5F20D34432]-worker) [    ] o.a.s.s.IndexSchema [null] Schema name=test
   [junit4]   2> 6909 INFO  (SUITE-RequestLoggingTest-seed#[DC7D7E5F20D34432]-worker) [    ] o.a.s.s.IndexSchema Loaded schema test/1.0 with uniqueid field id
   [junit4]   2> 7074 INFO  (SUITE-RequestLoggingTest-seed#[DC7D7E5F20D34432]-worker) [    ] o.a.s.c.TransientSolrCoreCacheDefault Allocating transient cache for 2147483647 transient cores
   [junit4]   2> 7074 INFO  (SUITE-RequestLoggingTest-seed#[DC7D7E5F20D34432]-worker) [    ] o.a.s.h.a.MetricsHistoryHandler No .system collection, keeping metrics history in memory.
   [junit4]   2> 7094 INFO  (SUITE-RequestLoggingTest-seed#[DC7D7E5F20D34432]-worker) [    ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr.node' (registry 'solr.node') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@1605b6c4
   [junit4]   2> 7095 INFO  (SUITE-RequestLoggingTest-seed#[DC7D7E5F20D34432]-worker) [    ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr.jvm' (registry 'solr.jvm') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@1605b6c4
   [junit4]   2> 7095 INFO  (SUITE-RequestLoggingTest-seed#[DC7D7E5F20D34432]-worker) [    ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr.jetty' (registry 'solr.jetty') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@1605b6c4
   [junit4]   2> 7113 INFO  (coreLoadExecutor-25-thread-1) [    x:collection1] o.a.s.c.SolrResourceLoader [null] Added 2 libs to classloader, from paths: [/home/jenkins/workspace/Lucene-Solr-master-Linux/solr/core/src/test-files/solr/collection1/lib, /home/jenkins/workspace/Lucene-Solr-master-Linux/solr/core/src/test-files/solr/collection1/lib/classes]
   [junit4]   2> 7152 INFO  (coreLoadExecutor-25-thread-1) [    x:collection1] o.a.s.c.SolrConfig Using Lucene MatchVersion: 8.0.0
   [junit4]   2> 7200 INFO  (coreLoadExecutor-25-thread-1) [    x:collection1] o.a.s.s.IndexSchema [collection1] Schema name=test
   [junit4]   2> 7351 INFO  (coreLoadExecutor-25-thread-1) [    x:collection1] o.a.s.s.IndexSchema Loaded schema test/1.0 with uniqueid field id
   [junit4]   2> 7382 INFO  (coreLoadExecutor-25-thread-1) [    x:collection1] o.a.s.c.CoreContainer Creating SolrCore 'collection1' using configuration from instancedir /home/jenkins/workspace/Lucene-Solr-master-Linux/solr/core/src/test-files/solr/collection1, trusted=true
   [junit4]   2> 7390 INFO  (coreLoadExecutor-25-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@1605b6c4
   [junit4]   2> 7390 INFO  (coreLoadExecutor-25-thread-1) [    x:collection1] o.a.s.c.SolrCore solr.RecoveryStrategy.Builder
   [junit4]   2> 7390 INFO  (coreLoadExecutor-25-thread-1) [    x:collection1] o.a.s.c.SolrCore [[collection1] ] Opening new SolrCore at [/home/jenkins/workspace/Lucene-Solr-master-Linux/solr/core/src/test-files/solr/collection1], dataDir=[/home/jenkins/workspace/Lucene-Solr-master-Linux/solr/build/solr-core/test/J2/temp/solr.handler.RequestLoggingTest_DC7D7E5F20D34432-001/init-core-data-001/]
   [junit4]   2> 7393 INFO  (coreLoadExecutor-25-thread-1) [    x:collection1] o.a.s.u.RandomMergePolicy RandomMergePolicy wrapping class org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: maxMergeAtOnce=44, maxMergeAtOnceExplicit=40, maxMergedSegmentMB=83.9736328125, floorSegmentMB=1.9921875, forceMergeDeletesPctAllowed=4.166643404818671, segmentsPerTier=18.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.0, deletesPctAllowed=30.43498569054684
   [junit4]   2> 7523 INFO  (coreLoadExecutor-25-thread-1) [    x:collection1] o.a.s.u.UpdateHandler Using UpdateLog implementation: org.apache.solr.update.UpdateLog
   [junit4]   2> 7523 INFO  (coreLoadExecutor-25-thread-1) [    x:collection1] o.a.s.u.UpdateLog Initializing UpdateLog: dataDir= defaultSyncLevel=FLUSH numRecordsToKeep=100 maxNumLogsToKeep=10 numVersionBuckets=65536
   [junit4]   2> 7525 INFO  (coreLoadExecutor-25-thread-1) [    x:collection1] o.a.s.u.CommitTracker Hard AutoCommit: disabled
   [junit4]   2> 7525 INFO  (coreLoadExecutor-25-thread-1) [    x:collection1] o.a.s.u.CommitTracker Soft AutoCommit: disabled
   [junit4]   2> 7527 INFO  (coreLoadExecutor-25-thread-1) [    x:collection1] o.a.s.u.RandomMergePolicy RandomMergePolicy wrapping class org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: maxMergeAtOnce=24, maxMergeAtOnceExplicit=13, maxMergedSegmentMB=61.4560546875, floorSegmentMB=2.1103515625, forceMergeDeletesPctAllowed=18.37880392186092, segmentsPerTier=38.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.0, deletesPctAllowed=31.42395329618669
   [junit4]   2> 7528 INFO  (coreLoadExecutor-25-thread-1) [    x:collection1] o.a.s.s.SolrIndexSearcher Opening [Searcher@732719e3[collection1] main]
   [junit4]   2> 7529 INFO  (coreLoadExecutor-25-thread-1) [    x:collection1] o.a.s.h.c.SpellCheckComponent Initializing spell checkers
   [junit4]   2> 7553 INFO  (coreLoadExecutor-25-thread-1) [    x:collection1] o.a.s.s.DirectSolrSpellChecker init: {name=direct,classname=DirectSolrSpellChecker,field=lowerfilt,minQueryLength=3}
   [junit4]   2> 7700 INFO  (coreLoadExecutor-25-thread-1) [    x:collection1] o.a.s.h.ReplicationHandler Commits will be reserved for 10000ms.
   [junit4]   2> 7700 INFO  (searcherExecutor-26-thread-1-processing-x:collection1) [    x:collection1] o.a.s.h.c.SpellCheckComponent Loading spell index for spellchecker: default
   [junit4]   2> 7700 INFO  (coreLoadExecutor-25-thread-1) [    x:collection1] o.a.s.u.UpdateLog Could not find max version in index or recent updates, using new clock 1610591769033965568
   [junit4]   2> 7702 INFO  (searcherExecutor-26-thread-1-processing-x:collection1) [    x:collection1] o.a.s.h.c.SpellCheckComponent Loading spell index for spellchecker: direct
   [junit4]   2> 7702 INFO  (searcherExecutor-26-thread-1-processing-x:collection1) [    x:collection1] o.a.s.h.c.SpellCheckComponent Loading spell index for spellchecker: wordbreak
   [junit4]   2> 7702 INFO  (searcherExecutor-26-thread-1-processing-x:collection1) [    x:collection1] o.a.s.h.c.SpellCheckComponent Loading spell index for spellchecker: multipleFields
   [junit4]   2> 7703 INFO  (searcherExecutor-26-thread-1-processing-x:collection1) [    x:collection1] o.a.s.h.c.SpellCheckComponent Loading spell index for spellchecker: jarowinkler
   [junit4]   2> 7704 INFO  (searcherExecutor-26-thread-1-processing-x:collection1) [    x:collection1] o.a.s.h.c.SpellCheckComponent Loading spell index for spellchecker: external
   [junit4]   2> 7704 INFO  (SUITE-RequestLoggingTest-seed#[DC7D7E5F20D34432]-worker) [    ] o.a.s.SolrTestCaseJ4 ####initCore end
   [junit4]   2> 7705 INFO  (searcherExecutor-26-thread-1-processing-x:collection1) [    x:collection1] o.a.s.h.c.SpellCheckComponent Loading spell index for spellchecker: freq
   [junit4]   2> 7705 INFO  (searcherExecutor-26-thread-1-processing-x:collection1) [    x:collection1] o.a.s.h.c.SpellCheckComponent Loading spell index for spellchecker: fqcn
   [junit4]   2> 7708 INFO  (searcherExecutor-26-thread-1-processing-x:collection1) [    x:collection1] o.a.s.h.c.SpellCheckComponent Loading spell index for spellchecker: perDict
   [junit4]   2> 7708 INFO  (TEST-RequestLoggingTest.testLogBeforeExecuteWithRequestLogger-seed#[DC7D7E5F20D34432]) [    ] o.a.s.SolrTestCaseJ4 ###Starting testLogBeforeExecuteWithRequestLogger
   [junit4]   2> 7710 INFO  (searcherExecutor-26-thread-1-processing-x:collection1) [    x:collection1] o.a.s.c.SolrCore [collection1] Registered new searcher Searcher@732719e3[collection1] main{ExitableDirectoryReader(UninvertingDirectoryReader())}
   [junit4]   2> 7710 DEBUG (TEST-RequestLoggingTest.testLogBeforeExecuteWithRequestLogger-seed#[DC7D7E5F20D34432]) [    ] o.a.s.c.S.Request [collection1]  webapp=null path=null params={q=*:*&wt=xml}
   [junit4]   2> 7710 DEBUG (TEST-RequestLoggingTest.testLogBeforeExecuteWithRequestLogger-seed#[DC7D7E5F20D34432]) [    ] o.a.s.h.c.SearchHandler Adding  component:org.apache.solr.handler.component.QueryComponent@592298ec
   [junit4]   2> 7710 DEBUG (TEST-RequestLoggingTest.testLogBeforeExecuteWithRequestLogger-seed#[DC7D7E5F20D34432]) [    ] o.a.s.h.c.SearchHandler Adding  component:org.apache.solr.handler.component.FacetComponent@332348e
   [junit4]   2> 7710 DEBUG (TEST-RequestLoggingTest.testLogBeforeExecuteWithRequestLogger-seed#[DC7D7E5F20D34432]) [    ] o.a.s.h.c.SearchHandler Adding  component:org.apache.solr.search.facet.FacetModule@6154ed41
   [junit4]   2> 7711 DEBUG (TEST-RequestLoggingTest.testLogBeforeExecuteWithRequestLogger-seed#[DC7D7E5F20D34432]) [    ] o.a.s.h.c.SearchHandler Adding  component:org.apache.solr.handler.component.MoreLikeThisComponent@440a99c0
   [junit4]   2> 7711 DEBUG (TEST-RequestLoggingTest.testLogBeforeExecuteWithRequestLogger-seed#[DC7D7E5F20D34432]) [    ] o.a.s.h.c.SearchHandler Adding  component:org.apache.solr.handler.component.HighlightComponent@9a28c55
   [junit4]   2> 7711 DEBUG (TEST-RequestLoggingTest.testLogBeforeExecuteWithRequestLogger-seed#[DC7D7E5F20D34432]) [    ] o.a.s.h.c.SearchHandler Adding  component:org.apache.solr.handler.component.StatsComponent@1ba65fab
   [junit4]   2> 7711 DEBUG (TEST-RequestLoggingTest.testLogBeforeExecuteWithRequestLogger-seed#[DC7D7E5F20D34432]) [    ] o.a.s.h.c.SearchHandler Adding  component:org.apache.solr.handler.component.ExpandComponent@5d5e977b
   [junit4]   2> 7711 DEBUG (TEST-RequestLoggingTest.testLogBeforeExecuteWithRequestLogger-seed#[DC7D7E5F20D34432]) [    ] o.a.s.h.c.SearchHandler Adding  component:org.apache.solr.handler.component.TermsComponent@4d8ac189
   [junit4]   2> 7711 DEBUG (TEST-RequestLoggingTest.testLogBeforeExecuteWithRequestLogger-seed#[DC7D7E5F20D34432]) [    ] o.a.s.h.c.SearchHandler Adding  debug component:org.apache.solr.handler.component.DebugComponent@50572c49
   [junit4]   2> 7711 DEBUG (TEST-RequestLoggingTest.testLogBeforeExecuteWithRequestLogger-seed#[DC7D7E5F20D34432]) [    ] o.a.s.h.c.QueryComponent process: q=*:*&df=text&wt=xml&indent=off
   [junit4] OK      0.01s J2 | RequestLoggingTest.testLogBeforeExecuteWithRequestLogger
   [junit4]   2> 7711 DEBUG (TEST-RequestLoggingTest.testLogBeforeExecuteWithRequestLogger-seed#[DC7D7E5F20D34432]) [    ] o.a.s.s.s.LocalStatsCache ## GET LocalSolrQueryRequest{q=*:*&df=text&wt=xml&indent=off}
   [junit4]   2> 7711 INFO  (TEST-RequestLoggingTest.testLogBeforeExecuteWithRequestLogger-seed#[DC7D7E5F20D34432]) [    ] o.a.s.c.S.Request [collection1]  webapp=null path=null params={q=*:*&wt=xml} hits=0 status=0 QTime=0
   [junit4]   2> 7712 INFO  (TEST-RequestLoggingTest.testLogBeforeExecuteWithRequestLogger-seed#[DC7D7E5F20D34432]) [    ] o.a.s.SolrTestCaseJ4 ###Ending testLogBeforeExecuteWithRequestLogger
   [junit4]   2> 7717 INFO  (TEST-RequestLoggingTest.testLogBeforeExecuteWithCoreLogger-seed#[DC7D7E5F20D34432]) [    ] o.a.s.SolrTestCaseJ4 ###Starting testLogBeforeExecuteWithCoreLogger
   [junit4]   2> 7719 DEBUG (TEST-RequestLoggingTest.testLogBeforeExecuteWithCoreLogger-seed#[DC7D7E5F20D34432]) [    ] o.a.s.c.S.Request [collection1]  webapp=null path=null params={q=*:*&wt=xml}
   [junit4]   2> 7720 DEBUG (TEST-RequestLoggingTest.testLogBeforeExecuteWithCoreLogger-seed#[DC7D7E5F20D34432]) [    ] o.a.s.h.c.QueryComponent process: q=*:*&df=text&wt=xml&indent=off
   [junit4]   2> 7720 DEBUG (TEST-RequestLoggingTest.testLogBeforeExecuteWithCoreLogger-seed#[DC7D7E5F20D34432]) [    ] o.a.s.s.s.LocalStatsCache ## GET LocalSolrQueryRequest{q=*:*&df=text&wt=xml&indent=off}
   [junit4]   2> 7720 INFO  (TEST-RequestLoggingTest.testLogBeforeExecuteWithCoreLogger-seed#[DC7D7E5F20D34432]) [    ] o.a.s.c.S.Request [collection1]  webapp=null path=null params={q=*:*&wt=xml} hits=0 status=0 QTime=0
   [junit4]   2> 7721 INFO  (TEST-RequestLoggingTest.testLogBeforeExecuteWithCoreLogger-seed#[DC7D7E5F20D34432]) [    ] o.a.s.SolrTestCaseJ4 ###Ending testLogBeforeExecuteWithCoreLogger
   [junit4]   2> NOTE: reproduce with: ant test  -Dtestcase=RequestLoggingTest -Dtests.method=testLogBeforeExecuteWithCoreLogger -Dtests.seed=DC7D7E5F20D34432 -Dtests.multiplier=3 -Dtests.slow=true -Dtests.badapples=true -Dtests.locale=uz-UZ -Dtests.timezone=America/Rosario -Dtests.asserts=true -Dtests.file.encoding=ISO-8859-1
   [junit4] FAILURE 0.02s J2 | RequestLoggingTest.testLogBeforeExecuteWithCoreLogger <<<
   [junit4]    > Throwable #1: java.lang.AssertionError
   [junit4]    > 	at __randomizedtesting.SeedInfo.seed([DC7D7E5F20D34432:10FB7ED1DE1A2FA4]:0)
   [junit4]    > 	at org.apache.solr.handler.RequestLoggingTest.testLogBeforeExecute(RequestLoggingTest.java:88)
   [junit4]    > 	at org.apache.solr.handler.RequestLoggingTest.testLogBeforeExecuteWithCoreLogger(RequestLoggingTest.java:65)
   [junit4]    > 	at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
   [junit4]    > 	at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
   [junit4]    > 	at java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
   [junit4]    > 	at java.base/java.lang.reflect.Method.invoke(Method.java:564)
   [junit4]    > 	at java.base/java.lang.Thread.run(Thread.java:844)
   [junit4]   2> 7733 INFO  (SUITE-RequestLoggingTest-seed#[DC7D7E5F20D34432]-worker) [    ] o.a.s.SolrTestCaseJ4 ###deleteCore
   [junit4]   2> 7733 INFO  (SUITE-RequestLoggingTest-seed#[DC7D7E5F20D34432]-worker) [    ] o.a.s.c.CoreContainer Shutting down CoreContainer instance=1164503093
   [junit4]   2> 7734 INFO  (SUITE-RequestLoggingTest-seed#[DC7D7E5F20D34432]-worker) [    ] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.node, tag=null
   [junit4]   2> 7734 INFO  (SUITE-RequestLoggingTest-seed#[DC7D7E5F20D34432]-worker) [    ] o.a.s.m.r.SolrJmxReporter Closing reporter [org.apache.solr.metrics.reporters.SolrJmxReporter@520af6e7: rootName = null, domain = solr.node, service url = null, agent id = null] for registry solr.node / com.codahale.metrics.MetricRegistry@48693666
   [junit4]   2> 7740 INFO  (SUITE-RequestLoggingTest-seed#[DC7D7E5F20D34432]-worker) [    ] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.jvm, tag=null
   [junit4]   2> 7740 INFO  (SUITE-RequestLoggingTest-seed#[DC7D7E5F20D34432]-worker) [    ] o.a.s.m.r.SolrJmxReporter Closing reporter [org.apache.solr.metrics.reporters.SolrJmxReporter@638d5e2b: rootName = null, domain = solr.jvm, service url = null, agent id = null] for registry solr.jvm / com.codahale.metrics.MetricRegistry@2c178b5b
   [junit4]   2> 7740 INFO  (SUITE-RequestLoggingTest-seed#[DC7D7E5F20D34432]-worker) [    ] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.jetty, tag=null
   [junit4]   2> 7740 INFO  (SUITE-RequestLoggingTest-seed#[DC7D7E5F20D34432]-worker) [    ] o.a.s.m.r.SolrJmxReporter Closing reporter [org.apache.solr.metrics.reporters.SolrJmxReporter@5e6c76c2: rootName = null, domain = solr.jetty, service url = null, agent id = null] for registry solr.jetty / com.codahale.metrics.MetricRegistry@42f8a6a9
   [junit4]   2> 7744 INFO  (coreCloseExecutor-31-thread-1) [    x:collection1] o.a.s.c.SolrCore [collection1]  CLOSING SolrCore org.apache.solr.core.SolrCore@d7bf3b4
   [junit4]   2> 7744 INFO  (coreCloseExecutor-31-thread-1) [    x:collection1] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.core.collection1, tag=d7bf3b4
   [junit4]   2> 7745 INFO  (coreCloseExecutor-31-thread-1) [    x:collection1] o.a.s.m.r.SolrJmxReporter Closing reporter [org.apache.solr.metrics.reporters.SolrJmxReporter@bc9a52a: rootName = null, domain = solr.core.collection1, service url = null, agent id = null] for registry solr.core.collection1 / com.codahale.metrics.MetricRegistry@39937fda
   [junit4]   2> NOTE: leaving temporary files on disk at: /home/jenkins/workspace/Lucene-Solr-master-Linux/solr/build/solr-core/test/J2/temp/solr.handler.RequestLoggingTest_DC7D7E5F20D34432-001
   [junit4]   2> NOTE: test params are: codec=Asserting(Lucene80): {}, docValues:{}, maxPointsInLeafNode=1552, maxMBSortInHeap=6.688305152094994, sim=Asserting(org.apache.lucene.search.similarities.AssertingSimilarity@65718a9c), locale=uz-UZ, timezone=America/Rosario
   [junit4]   2> NOTE: Linux 4.15.0-32-generic amd64/Oracle Corporation 9.0.4 (64-bit)/cpus=8,threads=1,free=373595400,total=509083648
   [junit4]   2> NOTE: All tests run in this JVM: [RequestLoggingTest, RequestLoggingTest]
   [junit4] Completed [5/5 (1!)] on J2 in 1.13s, 2 tests, 1 failure <<< FAILURES!

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

Total time: 9 seconds

[repro] Setting last failure code to 256

[repro] Failures:
[repro]   1/5 failed: org.apache.solr.handler.RequestLoggingTest
[repro] Exiting with code 256
+ mv lucene/build lucene/build.repro
+ mv solr/build solr/build.repro
+ mv lucene/build.orig lucene/build
+ mv solr/build.orig solr/build
Archiving artifacts
Setting ANT_1_8_2_HOME=/var/lib/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=/var/lib/jenkins/tools/hudson.tasks.Ant_AntInstallation/ANT_1.8.2
Setting ANT_1_8_2_HOME=/var/lib/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=a1ec716e107807f1dc24923cc7a91d0c5e64a7e1, workspace=/var/lib/jenkins/workspace/Lucene-Solr-master-Linux
[WARNINGS] Computing warning deltas based on reference build #22793
Recording test results
Setting ANT_1_8_2_HOME=/var/lib/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=/var/lib/jenkins/tools/hudson.tasks.Ant_AntInstallation/ANT_1.8.2
Setting ANT_1_8_2_HOME=/var/lib/jenkins/tools/hudson.tasks.Ant_AntInstallation/ANT_1.8.2
Setting ANT_1_8_2_HOME=/var/lib/jenkins/tools/hudson.tasks.Ant_AntInstallation/ANT_1.8.2
Setting ANT_1_8_2_HOME=/var/lib/jenkins/tools/hudson.tasks.Ant_AntInstallation/ANT_1.8.2

Mime
View raw message