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/06/18 09:36:32 UTC
[JENKINS] Lucene-Solr-7.4-Windows (64bit/jdk-10.0.1) - Build # 3 -
Unstable!
Build: https://jenkins.thetaphi.de/job/Lucene-Solr-7.4-Windows/3/
Java: 64bit/jdk-10.0.1 -XX:+UseCompressedOops -XX:+UseSerialGC
3 tests failed.
FAILED: org.apache.solr.common.util.TestTimeSource.testEpochTime
Error Message:
SimTimeSource:50.0 time diff=15645000
Stack Trace:
java.lang.AssertionError: SimTimeSource:50.0 time diff=15645000
at __randomizedtesting.SeedInfo.seed([10DDCFEC31B71734:28B1BCC9A567B572]:0)
at org.junit.Assert.fail(Assert.java:93)
at org.junit.Assert.assertTrue(Assert.java:43)
at org.apache.solr.common.util.TestTimeSource.doTestEpochTime(TestTimeSource.java:52)
at org.apache.solr.common.util.TestTimeSource.testEpochTime(TestTimeSource.java:32)
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.common.util.TestTimeSource.testEpochTime
Error Message:
SimTimeSource:50.0 time diff=28385000
Stack Trace:
java.lang.AssertionError: SimTimeSource:50.0 time diff=28385000
at __randomizedtesting.SeedInfo.seed([10DDCFEC31B71734:28B1BCC9A567B572]:0)
at org.junit.Assert.fail(Assert.java:93)
at org.junit.Assert.assertTrue(Assert.java:43)
at org.apache.solr.common.util.TestTimeSource.doTestEpochTime(TestTimeSource.java:52)
at org.apache.solr.common.util.TestTimeSource.testEpochTime(TestTimeSource.java:32)
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.common.util.TestTimeSource.testEpochTime
Error Message:
SimTimeSource:50.0 time diff=77420000
Stack Trace:
java.lang.AssertionError: SimTimeSource:50.0 time diff=77420000
at __randomizedtesting.SeedInfo.seed([10DDCFEC31B71734:28B1BCC9A567B572]:0)
at org.junit.Assert.fail(Assert.java:93)
at org.junit.Assert.assertTrue(Assert.java:43)
at org.apache.solr.common.util.TestTimeSource.doTestEpochTime(TestTimeSource.java:52)
at org.apache.solr.common.util.TestTimeSource.testEpochTime(TestTimeSource.java:32)
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 16326 lines...]
[junit4] Suite: org.apache.solr.common.util.TestTimeSource
[junit4] 2> Creating dataDir: C:\Users\jenkins\workspace\Lucene-Solr-7.4-Windows\solr\build\solr-solrj\test\J0\temp\solr.common.util.TestTimeSource_10DDCFEC31B71734-001\init-core-data-001
[junit4] 2> 240634 INFO (SUITE-TestTimeSource-seed#[10DDCFEC31B71734]-worker) [ ] o.a.s.SolrTestCaseJ4 Using PointFields (NUMERIC_POINTS_SYSPROP=true) w/NUMERIC_DOCVALUES_SYSPROP=true
[junit4] 2> 240637 INFO (SUITE-TestTimeSource-seed#[10DDCFEC31B71734]-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> 240637 INFO (SUITE-TestTimeSource-seed#[10DDCFEC31B71734]-worker) [ ] o.a.s.SolrTestCaseJ4 SecureRandom sanity checks: test.solr.allowed.securerandom=null & java.security.egd=file:/dev/./urandom
[junit4] 2> 240638 INFO (TEST-TestTimeSource.testEpochTime-seed#[10DDCFEC31B71734]) [ ] o.a.s.SolrTestCaseJ4 ###Starting testEpochTime
[junit4] 2> 250767 INFO (TEST-TestTimeSource.testEpochTime-seed#[10DDCFEC31B71734]) [ ] o.a.s.SolrTestCaseJ4 ###Ending testEpochTime
[junit4] 2> NOTE: reproduce with: ant test -Dtestcase=TestTimeSource -Dtests.method=testEpochTime -Dtests.seed=10DDCFEC31B71734 -Dtests.slow=true -Dtests.locale=eo -Dtests.timezone=Australia/Canberra -Dtests.asserts=true -Dtests.file.encoding=UTF-8
[junit4] FAILURE 10.1s J0 | TestTimeSource.testEpochTime <<<
[junit4] > Throwable #1: java.lang.AssertionError: SimTimeSource:50.0 time diff=77420000
[junit4] > at __randomizedtesting.SeedInfo.seed([10DDCFEC31B71734:28B1BCC9A567B572]:0)
[junit4] > at org.apache.solr.common.util.TestTimeSource.doTestEpochTime(TestTimeSource.java:52)
[junit4] > at org.apache.solr.common.util.TestTimeSource.testEpochTime(TestTimeSource.java:32)
[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> NOTE: leaving temporary files on disk at: C:\Users\jenkins\workspace\Lucene-Solr-7.4-Windows\solr\build\solr-solrj\test\J0\temp\solr.common.util.TestTimeSource_10DDCFEC31B71734-001
[junit4] 2> NOTE: test params are: codec=Asserting(Lucene70): {}, docValues:{}, maxPointsInLeafNode=1329, maxMBSortInHeap=7.979278249268071, sim=RandomSimilarity(queryNorm=false): {}, locale=eo, timezone=Australia/Canberra
[junit4] 2> NOTE: Windows 10 10.0 amd64/Oracle Corporation 10.0.1 (64-bit)/cpus=3,threads=1,free=145832968,total=309825536
[junit4] 2> NOTE: All tests run in this JVM: [HttpSolrClientSSLAuthConPoolTest, AnlysisResponseBaseTest, UsingSolrJRefGuideExamplesTest, TestConfigSetAdminRequest, CubedRootEvaluatorTest, GreaterThanEqualToEvaluatorTest, TestJavaBinCodec, HyperbolicCosineEvaluatorTest, RoundEvaluatorTest, NamedListTest, TestHash, JettyWebappTest, FieldAnalysisResponseTest, DocumentAnalysisResponseTest, TestCoreAdmin, TestClusteringResponse, TestValidatingJsonMap, TestXMLEscaping, ArcCosineEvaluatorTest, TestJsonRecordReader, HyperbolicTangentEvaluatorTest, RegressionEvaluatorTest, SolrZkClientTest, CoalesceEvaluatorTest, TestPolicy, StreamExpressionParserTest, AndEvaluatorTest, NaturalLogEvaluatorTest, UniformDistributionEvaluatorTest, GraphExpressionTest, FieldValueEvaluatorTest, NormalizeEvaluatorTest, SquareRootEvaluatorTest, TestLBHttpSolrClient, TestSolrProperties, OperationsTest, TestCollectionStateWatchers, AscEvaluatorTest, SolrExampleStreamingTest, SolrExampleXMLTest, SolrExampleJettyTest, SolrExampleEmbeddedTest, LargeVolumeBinaryJettyTest, TestBatchUpdate, TestSpellCheckResponse, SolrParamTest, TermsResponseTest, MergeIndexesEmbeddedTest, TestEmbeddedSolrServer, TestDocumentObjectBinder, ModifiableSolrParamsTest, TestFastInputStream, SolrDocumentTest, TestUpdateRequestCodec, ClientUtilsTest, CollectionAdminRequestRequiredParamsTest, GetByIdTest, SolrSchemalessExampleTest, CloudSolrClientBuilderTest, CloudSolrClientMultiConstructorTest, CloudSolrClientTest, ConcurrentUpdateSolrClientBuilderTest, HttpSolrClientBuilderTest, HttpSolrClientConPoolTest, TestCloudSolrClientConnections, JDBCStreamTest, MathExpressionTest, StreamExpressionToExplanationTest, AbsoluteValueEvaluatorTest, AddEvaluatorTest, AppendEvaluatorTest, ArcTangentEvaluatorTest, ArrayEvaluatorTest, CorrelationEvaluatorTest, CumulativeProbabilityEvaluatorTest, DivideEvaluatorTest, EqualToEvaluatorTest, ExclusiveOrEvaluatorTest, HyperbolicSineEvaluatorTest, LessThanEqualToEvaluatorTest, LessThanEvaluatorTest, ModuloEvaluatorTest, MultiplyEvaluatorTest, NotEvaluatorTest, OrEvaluatorTest, PowerEvaluatorTest, RawValueEvaluatorTest, RecursiveEvaluatorTest, ReverseEvaluatorTest, SubtractEvaluatorTest, SchemaTest, CommonAdminParamsTest, CommonParamsTest, ShardParamsTest, TestRetryUtil, TestTimeSource]
[junit4] Completed [151/152 (1!)] on J0 in 10.16s, 1 test, 1 failure <<< FAILURES!
[...truncated 42868 lines...]
[repro] Jenkins log URL: https://jenkins.thetaphi.de/job/Lucene-Solr-7.4-Windows/3/consoleText
[repro] Revision: 3aa6086ed99fa7158d423dc7c33dae6da466b093
[repro] Ant options: "-Dargs=-XX:+UseCompressedOops -XX:+UseSerialGC"
[repro] ant clean
[...truncated 6 lines...]
[repro] Test suites by module:
[repro] solr\solrj
[repro] TestTimeSource
[repro] ant compile-test
[...truncated 2492 lines...]
[repro] ant test-nocompile -Dtests.dups=5 -Dtests.maxfailures=5 -Dtests.class="*.TestTimeSource" -Dtests.showOutput=onerror "-Dargs=-XX:+UseCompressedOops -XX:+UseSerialGC" -Dtests.seed=10DDCFEC31B71734 -Dtests.slow=true -Dtests.locale=eo -Dtests.timezone=Australia/Canberra -Dtests.asserts=true -Dtests.file.encoding=UTF-8
[...truncated 32 lines...]
[junit4] Suite: org.apache.solr.common.util.TestTimeSource
[junit4] 2> SLF4J: Class path contains multiple SLF4J bindings.
[junit4] 2> SLF4J: Found binding in [jar:file:/C:/Users/jenkins/workspace/Lucene-Solr-7.4-Windows/solr/solrj/test-lib/log4j-slf4j-impl-2.11.0.jar!/org/slf4j/impl/StaticLoggerBinder.class]
[junit4] 2> SLF4J: Found binding in [jar:file:/C:/Users/jenkins/workspace/Lucene-Solr-7.4-Windows/solr/core/lib/log4j-slf4j-impl-2.11.0.jar!/org/slf4j/impl/StaticLoggerBinder.class]
[junit4] 2> SLF4J: See http://www.slf4j.org/codes.html#multiple_bindings for an explanation.
[junit4] 2> SLF4J: Actual binding is of type [org.apache.logging.slf4j.Log4jLoggerFactory]
[junit4] 2> Creating dataDir: C:\Users\jenkins\workspace\Lucene-Solr-7.4-Windows\solr\build\solr-solrj\test\J1\temp\solr.common.util.TestTimeSource_10DDCFEC31B71734-001\init-core-data-001
[junit4] 2> 10561 INFO (SUITE-TestTimeSource-seed#[10DDCFEC31B71734]-worker) [ ] o.a.s.SolrTestCaseJ4 Using PointFields (NUMERIC_POINTS_SYSPROP=true) w/NUMERIC_DOCVALUES_SYSPROP=true
[junit4] 2> 10601 INFO (SUITE-TestTimeSource-seed#[10DDCFEC31B71734]-worker) [ ] o.e.j.u.log Logging initialized @10630ms to org.eclipse.jetty.util.log.Slf4jLog
[junit4] 2> 10609 INFO (SUITE-TestTimeSource-seed#[10DDCFEC31B71734]-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> 10615 INFO (SUITE-TestTimeSource-seed#[10DDCFEC31B71734]-worker) [ ] o.a.s.SolrTestCaseJ4 SecureRandom sanity checks: test.solr.allowed.securerandom=null & java.security.egd=file:/dev/./urandom
[junit4] 2> 10622 INFO (TEST-TestTimeSource.testEpochTime-seed#[10DDCFEC31B71734]) [ ] o.a.s.SolrTestCaseJ4 ###Starting testEpochTime
[junit4] 2> 20646 INFO (TEST-TestTimeSource.testEpochTime-seed#[10DDCFEC31B71734]) [ ] o.a.s.SolrTestCaseJ4 ###Ending testEpochTime
[junit4] 2> NOTE: reproduce with: ant test -Dtestcase=TestTimeSource -Dtests.method=testEpochTime -Dtests.seed=10DDCFEC31B71734 -Dtests.slow=true -Dtests.badapples=true -Dtests.locale=eo -Dtests.timezone=Australia/Canberra -Dtests.asserts=true -Dtests.file.encoding=UTF-8
[junit4] FAILURE 10.0s J1 | TestTimeSource.testEpochTime <<<
[junit4] > Throwable #1: java.lang.AssertionError: SimTimeSource:50.0 time diff=28385000
[junit4] > at __randomizedtesting.SeedInfo.seed([10DDCFEC31B71734:28B1BCC9A567B572]:0)
[junit4] > at org.apache.solr.common.util.TestTimeSource.doTestEpochTime(TestTimeSource.java:52)
[junit4] > at org.apache.solr.common.util.TestTimeSource.testEpochTime(TestTimeSource.java:32)
[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> NOTE: leaving temporary files on disk at: C:\Users\jenkins\workspace\Lucene-Solr-7.4-Windows\solr\build\solr-solrj\test\J1\temp\solr.common.util.TestTimeSource_10DDCFEC31B71734-001
[junit4] 2> NOTE: test params are: codec=Asserting(Lucene70): {}, docValues:{}, maxPointsInLeafNode=1329, maxMBSortInHeap=7.979278249268071, sim=RandomSimilarity(queryNorm=false): {}, locale=eo, timezone=Australia/Canberra
[junit4] 2> NOTE: Windows 10 10.0 amd64/Oracle Corporation 10.0.1 (64-bit)/cpus=3,threads=1,free=76199424,total=97386496
[junit4] 2> NOTE: All tests run in this JVM: [TestTimeSource]
[junit4] Completed [1/5 (1!)] on J1 in 19.66s, 1 test, 1 failure <<< FAILURES!
[...truncated 1 lines...]
[junit4] Suite: org.apache.solr.common.util.TestTimeSource
[junit4] 2> SLF4J: Class path contains multiple SLF4J bindings.
[junit4] 2> SLF4J: Found binding in [jar:file:/C:/Users/jenkins/workspace/Lucene-Solr-7.4-Windows/solr/solrj/test-lib/log4j-slf4j-impl-2.11.0.jar!/org/slf4j/impl/StaticLoggerBinder.class]
[junit4] 2> SLF4J: Found binding in [jar:file:/C:/Users/jenkins/workspace/Lucene-Solr-7.4-Windows/solr/core/lib/log4j-slf4j-impl-2.11.0.jar!/org/slf4j/impl/StaticLoggerBinder.class]
[junit4] 2> SLF4J: See http://www.slf4j.org/codes.html#multiple_bindings for an explanation.
[junit4] 2> SLF4J: Actual binding is of type [org.apache.logging.slf4j.Log4jLoggerFactory]
[junit4] 2> Creating dataDir: C:\Users\jenkins\workspace\Lucene-Solr-7.4-Windows\solr\build\solr-solrj\test\J0\temp\solr.common.util.TestTimeSource_10DDCFEC31B71734-001\init-core-data-001
[junit4] 2> 10884 INFO (SUITE-TestTimeSource-seed#[10DDCFEC31B71734]-worker) [ ] o.a.s.SolrTestCaseJ4 Using PointFields (NUMERIC_POINTS_SYSPROP=true) w/NUMERIC_DOCVALUES_SYSPROP=true
[junit4] 2> 10923 INFO (SUITE-TestTimeSource-seed#[10DDCFEC31B71734]-worker) [ ] o.e.j.u.log Logging initialized @10955ms to org.eclipse.jetty.util.log.Slf4jLog
[junit4] 2> 10931 INFO (SUITE-TestTimeSource-seed#[10DDCFEC31B71734]-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> 10937 INFO (SUITE-TestTimeSource-seed#[10DDCFEC31B71734]-worker) [ ] o.a.s.SolrTestCaseJ4 SecureRandom sanity checks: test.solr.allowed.securerandom=null & java.security.egd=file:/dev/./urandom
[junit4] 2> 10944 INFO (TEST-TestTimeSource.testEpochTime-seed#[10DDCFEC31B71734]) [ ] o.a.s.SolrTestCaseJ4 ###Starting testEpochTime
[junit4] 2> 20968 INFO (TEST-TestTimeSource.testEpochTime-seed#[10DDCFEC31B71734]) [ ] o.a.s.SolrTestCaseJ4 ###Ending testEpochTime
[junit4] 2> NOTE: reproduce with: ant test -Dtestcase=TestTimeSource -Dtests.method=testEpochTime -Dtests.seed=10DDCFEC31B71734 -Dtests.slow=true -Dtests.badapples=true -Dtests.locale=eo -Dtests.timezone=Australia/Canberra -Dtests.asserts=true -Dtests.file.encoding=UTF-8
[junit4] FAILURE 10.0s J0 | TestTimeSource.testEpochTime <<<
[junit4] > Throwable #1: java.lang.AssertionError: SimTimeSource:50.0 time diff=15645000
[junit4] > at __randomizedtesting.SeedInfo.seed([10DDCFEC31B71734:28B1BCC9A567B572]:0)
[junit4] > at org.apache.solr.common.util.TestTimeSource.doTestEpochTime(TestTimeSource.java:52)
[junit4] > at org.apache.solr.common.util.TestTimeSource.testEpochTime(TestTimeSource.java:32)
[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> NOTE: leaving temporary files on disk at: C:\Users\jenkins\workspace\Lucene-Solr-7.4-Windows\solr\build\solr-solrj\test\J0\temp\solr.common.util.TestTimeSource_10DDCFEC31B71734-001
[junit4] 2> NOTE: test params are: codec=Asserting(Lucene70): {}, docValues:{}, maxPointsInLeafNode=1329, maxMBSortInHeap=7.979278249268071, sim=RandomSimilarity(queryNorm=false): {}, locale=eo, timezone=Australia/Canberra
[junit4] 2> NOTE: Windows 10 10.0 amd64/Oracle Corporation 10.0.1 (64-bit)/cpus=3,threads=1,free=75139904,total=97386496
[junit4] 2> NOTE: All tests run in this JVM: [TestTimeSource]
[junit4] Completed [2/5 (2!)] on J0 in 19.71s, 1 test, 1 failure <<< FAILURES!
[...truncated 24 lines...]
BUILD FAILED
C:\Users\jenkins\workspace\Lucene-Solr-7.4-Windows\lucene\common-build.xml:1568: The following error occurred while executing this line:
C:\Users\jenkins\workspace\Lucene-Solr-7.4-Windows\lucene\common-build.xml:1092: There were test failures: 5 suites, 5 tests, 2 failures [seed: 10DDCFEC31B71734]
Total time: 44 seconds
[repro] Setting last failure code to 1
[repro] Failures:
[repro] 2/5 failed: org.apache.solr.common.util.TestTimeSource
[repro] Exiting with code 1
C:\Users\jenkins\workspace\Lucene-Solr-7.4-Windows>IF EXIST lucene\build move /y lucene\build lucene\build.repro
1 dir(s) moved.
C:\Users\jenkins\workspace\Lucene-Solr-7.4-Windows>IF EXIST solr\build move /y solr\build solr\build.repro
1 dir(s) moved.
C:\Users\jenkins\workspace\Lucene-Solr-7.4-Windows>IF EXIST lucene\build.orig move /y lucene\build.orig lucene\build
1 dir(s) moved.
C:\Users\jenkins\workspace\Lucene-Solr-7.4-Windows>IF EXIST solr\build.orig move /y solr\build.orig solr\build
1 dir(s) moved.
C:\Users\jenkins\workspace\Lucene-Solr-7.4-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=3aa6086ed99fa7158d423dc7c33dae6da466b093, workspace=C:\Users\jenkins\workspace\Lucene-Solr-7.4-Windows
[WARNINGS] Computing warning deltas based on reference build #2
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
[JENKINS] Lucene-Solr-7.4-Windows (32bit/jdk1.8.0_172) - Build # 4
- Still Unstable!
Posted by Policeman Jenkins Server <je...@thetaphi.de>.
Build: https://jenkins.thetaphi.de/job/Lucene-Solr-7.4-Windows/4/
Java: 32bit/jdk1.8.0_172 -server -XX:+UseSerialGC
4 tests failed.
FAILED: org.apache.solr.cloud.TestCloudRecovery.leaderRecoverFromLogOnStartupTest
Error Message:
expected:<4> but was:<2>
Stack Trace:
java.lang.AssertionError: expected:<4> but was:<2>
at __randomizedtesting.SeedInfo.seed([266A6FC4A1996F06:529A8E81E5BD2889]:0)
at org.junit.Assert.fail(Assert.java:93)
at org.junit.Assert.failNotEquals(Assert.java:647)
at org.junit.Assert.assertEquals(Assert.java:128)
at org.junit.Assert.assertEquals(Assert.java:472)
at org.junit.Assert.assertEquals(Assert.java:456)
at org.apache.solr.cloud.TestCloudRecovery.leaderRecoverFromLogOnStartupTest(TestCloudRecovery.java:113)
at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
at java.lang.reflect.Method.invoke(Method.java:498)
at com.carrotsearch.randomizedtesting.RandomizedRunner.invoke(RandomizedRunner.java: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 com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at org.apache.lucene.util.TestRuleAssertionsRequired$1.evaluate(TestRuleAssertionsRequired.java:53)
at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:47)
at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:64)
at org.apache.lucene.util.TestRuleIgnoreTestSuites$1.evaluate(TestRuleIgnoreTestSuites.java:54)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:368)
at java.lang.Thread.run(Thread.java:748)
FAILED: org.apache.solr.search.TestRecovery.testExistOldBufferLog
Error Message:
Stack Trace:
java.lang.AssertionError
at __randomizedtesting.SeedInfo.seed([266A6FC4A1996F06:783A72912F56FF8F]:0)
at org.junit.Assert.fail(Assert.java:92)
at org.junit.Assert.assertTrue(Assert.java:43)
at org.junit.Assert.assertFalse(Assert.java:68)
at org.junit.Assert.assertFalse(Assert.java:79)
at org.apache.solr.search.TestRecovery.testExistOldBufferLog(TestRecovery.java:1071)
at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
at java.lang.reflect.Method.invoke(Method.java:498)
at com.carrotsearch.randomizedtesting.RandomizedRunner.invoke(RandomizedRunner.java: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 com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at org.apache.lucene.util.TestRuleAssertionsRequired$1.evaluate(TestRuleAssertionsRequired.java:53)
at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:47)
at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:64)
at org.apache.lucene.util.TestRuleIgnoreTestSuites$1.evaluate(TestRuleIgnoreTestSuites.java:54)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:368)
at java.lang.Thread.run(Thread.java:748)
FAILED: junit.framework.TestSuite.org.apache.solr.search.TestRecovery
Error Message:
Suite timeout exceeded (>= 7200000 msec).
Stack Trace:
java.lang.Exception: Suite timeout exceeded (>= 7200000 msec).
at __randomizedtesting.SeedInfo.seed([266A6FC4A1996F06]:0)
FAILED: org.apache.solr.search.TestRecovery.testExistOldBufferLog
Error Message:
Stack Trace:
java.lang.AssertionError
at __randomizedtesting.SeedInfo.seed([266A6FC4A1996F06:783A72912F56FF8F]:0)
at org.junit.Assert.fail(Assert.java:92)
at org.junit.Assert.assertTrue(Assert.java:43)
at org.junit.Assert.assertFalse(Assert.java:68)
at org.junit.Assert.assertFalse(Assert.java:79)
at org.apache.solr.search.TestRecovery.testExistOldBufferLog(TestRecovery.java:1071)
at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
at java.lang.reflect.Method.invoke(Method.java:498)
at com.carrotsearch.randomizedtesting.RandomizedRunner.invoke(RandomizedRunner.java: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 com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at org.apache.lucene.util.TestRuleAssertionsRequired$1.evaluate(TestRuleAssertionsRequired.java:53)
at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:47)
at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:64)
at org.apache.lucene.util.TestRuleIgnoreTestSuites$1.evaluate(TestRuleIgnoreTestSuites.java:54)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:368)
at java.lang.Thread.run(Thread.java:748)
Build Log:
[...truncated 14012 lines...]
[junit4] Suite: org.apache.solr.search.TestRecovery
[junit4] 2> Creating dataDir: C:\Users\jenkins\workspace\Lucene-Solr-7.4-Windows\solr\build\solr-core\test\J1\temp\solr.search.TestRecovery_266A6FC4A1996F06-001\init-core-data-001
[junit4] 2> 1851345 INFO (SUITE-TestRecovery-seed#[266A6FC4A1996F06]-worker) [ ] o.a.s.c.SolrResourceLoader [null] Added 2 libs to classloader, from paths: [/C:/Users/jenkins/workspace/Lucene-Solr-7.4-Windows/solr/core/src/test-files/solr/collection1/lib, /C:/Users/jenkins/workspace/Lucene-Solr-7.4-Windows/solr/core/src/test-files/solr/collection1/lib/classes]
[junit4] 2> 1851387 INFO (SUITE-TestRecovery-seed#[266A6FC4A1996F06]-worker) [ ] o.a.s.c.SolrConfig Using Lucene MatchVersion: 7.4.0
[junit4] 2> 1851394 INFO (SUITE-TestRecovery-seed#[266A6FC4A1996F06]-worker) [ ] o.a.s.s.IndexSchema [null] Schema name=test
[junit4] 2> 1851442 INFO (SUITE-TestRecovery-seed#[266A6FC4A1996F06]-worker) [ ] o.a.s.s.IndexSchema Loaded schema test/1.6 with uniqueid field id
[junit4] 2> 1851925 INFO (SUITE-TestRecovery-seed#[266A6FC4A1996F06]-worker) [ ] o.a.s.c.TransientSolrCoreCacheDefault Allocating transient cache for 2147483647 transient cores
[junit4] 2> 1851925 INFO (SUITE-TestRecovery-seed#[266A6FC4A1996F06]-worker) [ ] o.a.s.h.a.MetricsHistoryHandler No .system collection, keeping metrics history in memory.
[junit4] 2> 1851946 INFO (SUITE-TestRecovery-seed#[266A6FC4A1996F06]-worker) [ ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr.node' (registry 'solr.node') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@999068
[junit4] 2> 1851951 INFO (SUITE-TestRecovery-seed#[266A6FC4A1996F06]-worker) [ ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr.jvm' (registry 'solr.jvm') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@999068
[junit4] 2> 1851951 INFO (SUITE-TestRecovery-seed#[266A6FC4A1996F06]-worker) [ ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr.jetty' (registry 'solr.jetty') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@999068
[junit4] 2> 1851953 INFO (coreLoadExecutor-7394-thread-1) [ x:collection1] o.a.s.c.SolrResourceLoader [null] Added 2 libs to classloader, from paths: [/C:/Users/jenkins/workspace/Lucene-Solr-7.4-Windows/solr/core/src/test-files/solr/collection1/lib, /C:/Users/jenkins/workspace/Lucene-Solr-7.4-Windows/solr/core/src/test-files/solr/collection1/lib/classes]
[junit4] 2> 1852016 INFO (coreLoadExecutor-7394-thread-1) [ x:collection1] o.a.s.c.SolrConfig Using Lucene MatchVersion: 7.4.0
[junit4] 2> 1852024 INFO (coreLoadExecutor-7394-thread-1) [ x:collection1] o.a.s.s.IndexSchema [collection1] Schema name=test
[junit4] 2> 1852079 INFO (coreLoadExecutor-7394-thread-1) [ x:collection1] o.a.s.s.IndexSchema Loaded schema test/1.6 with uniqueid field id
[junit4] 2> 1852086 INFO (coreLoadExecutor-7394-thread-1) [ x:collection1] o.a.s.c.CoreContainer Creating SolrCore 'collection1' using configuration from instancedir C:\Users\jenkins\workspace\Lucene-Solr-7.4-Windows\solr\core\src\test-files\solr\collection1, trusted=true
[junit4] 2> 1852086 INFO (coreLoadExecutor-7394-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@999068
[junit4] 2> 1852087 INFO (coreLoadExecutor-7394-thread-1) [ x:collection1] o.a.s.c.SolrCore solr.RecoveryStrategy.Builder
[junit4] 2> 1852087 INFO (coreLoadExecutor-7394-thread-1) [ x:collection1] o.a.s.c.SolrCore [[collection1] ] Opening new SolrCore at [C:\Users\jenkins\workspace\Lucene-Solr-7.4-Windows\solr\core\src\test-files\solr\collection1], dataDir=[C:\Users\jenkins\workspace\Lucene-Solr-7.4-Windows\solr\build\solr-core\test\J1\temp\solr.search.TestRecovery_266A6FC4A1996F06-001\init-core-data-001\]
[junit4] 2> 1852092 INFO (coreLoadExecutor-7394-thread-1) [ x:collection1] o.a.s.u.RandomMergePolicy RandomMergePolicy wrapping class org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: maxMergeAtOnce=44, maxMergeAtOnceExplicit=29, maxMergedSegmentMB=62.1201171875, floorSegmentMB=1.0625, forceMergeDeletesPctAllowed=18.25526037168861, segmentsPerTier=34.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.22628571333180184
[junit4] 2> 1852108 WARN (coreLoadExecutor-7394-thread-1) [ x:collection1] o.a.s.c.RequestHandlers INVALID paramSet a in requestHandler {type = requestHandler,name = /dump,class = DumpRequestHandler,attributes = {initParams=a, name=/dump, class=DumpRequestHandler},args = {defaults={a=A,b=B}}}
[junit4] 2> 1852236 INFO (coreLoadExecutor-7394-thread-1) [ x:collection1] o.a.s.u.UpdateHandler Using UpdateLog implementation: org.apache.solr.update.CdcrUpdateLog
[junit4] 2> 1852236 INFO (coreLoadExecutor-7394-thread-1) [ x:collection1] o.a.s.u.UpdateLog Initializing UpdateLog: dataDir= defaultSyncLevel=FLUSH numRecordsToKeep=100 maxNumLogsToKeep=10 numVersionBuckets=65536
[junit4] 2> 1852237 INFO (coreLoadExecutor-7394-thread-1) [ x:collection1] o.a.s.u.CommitTracker Hard AutoCommit: disabled
[junit4] 2> 1852237 INFO (coreLoadExecutor-7394-thread-1) [ x:collection1] o.a.s.u.CommitTracker Soft AutoCommit: disabled
[junit4] 2> 1852238 INFO (coreLoadExecutor-7394-thread-1) [ x:collection1] o.a.s.u.RandomMergePolicy RandomMergePolicy wrapping class org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: maxMergeAtOnce=11, maxMergeAtOnceExplicit=27, maxMergedSegmentMB=98.8212890625, floorSegmentMB=0.3203125, forceMergeDeletesPctAllowed=13.303440793526347, segmentsPerTier=25.0, maxCFSSegmentSizeMB=1.2333984375, noCFSRatio=1.0
[junit4] 2> 1852238 INFO (coreLoadExecutor-7394-thread-1) [ x:collection1] o.a.s.s.SolrIndexSearcher Opening [Searcher@153d1b4[collection1] main]
[junit4] 2> 1852240 WARN (coreLoadExecutor-7394-thread-1) [ x:collection1] o.a.s.r.ManagedResourceStorage Cannot write to config directory C:\Users\jenkins\workspace\Lucene-Solr-7.4-Windows\solr\core\src\test-files\solr\collection1\conf; switching to use InMemory storage instead.
[junit4] 2> 1852240 INFO (coreLoadExecutor-7394-thread-1) [ x:collection1] o.a.s.h.ReplicationHandler Commits will be reserved for 10000ms.
[junit4] 2> 1852241 INFO (searcherExecutor-7395-thread-1-processing-x:collection1) [ x:collection1] o.a.s.c.SolrCore [collection1] Registered new searcher Searcher@153d1b4[collection1] main{ExitableDirectoryReader(UninvertingDirectoryReader())}
[junit4] 2> 1852241 INFO (coreLoadExecutor-7394-thread-1) [ x:collection1] o.a.s.u.UpdateLog Could not find max version in index or recent updates, using new clock 1603648410031751168
[junit4] 2> 1852246 INFO (TEST-TestRecovery.testLogReplayWithReorderedDBQByIdAndChildDocs-seed#[266A6FC4A1996F06]) [ ] o.a.s.u.DirectUpdateHandler2 [collection1] REMOVING ALL DOCUMENTS FROM INDEX
[junit4] 2> 1852247 INFO (TEST-TestRecovery.testLogReplayWithReorderedDBQByIdAndChildDocs-seed#[266A6FC4A1996F06]) [ ] o.a.s.s.SolrIndexSearcher Opening [Searcher@482af9[collection1] realtime]
[junit4] 2> 1852248 INFO (TEST-TestRecovery.testLogReplayWithReorderedDBQByIdAndChildDocs-seed#[266A6FC4A1996F06]) [ ] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=null path=null params={_version_=-9223372036854775807&update.distrib=FROMLEADER&versions=true&wt=json&indent=true}{deleteByQuery=*:* (-9223372036854775807)} 0 1
[junit4] 2> 1852248 INFO (TEST-TestRecovery.testLogReplayWithReorderedDBQByIdAndChildDocs-seed#[266A6FC4A1996F06]) [ ] o.a.s.u.DirectUpdateHandler2 start commit{_version_=1603648410039091200,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4] 2> 1852248 INFO (TEST-TestRecovery.testLogReplayWithReorderedDBQByIdAndChildDocs-seed#[266A6FC4A1996F06]) [ ] o.a.s.u.SolrIndexWriter Calling setCommitData with IW:org.apache.solr.update.SolrIndexWriter@b6ad1d commitCommandVersion:1603648410039091200
[junit4] 2> 1852256 INFO (TEST-TestRecovery.testLogReplayWithReorderedDBQByIdAndChildDocs-seed#[266A6FC4A1996F06]) [ ] o.a.s.s.SolrIndexSearcher Opening [Searcher@1af0875[collection1] main]
[junit4] 2> 1852257 INFO (TEST-TestRecovery.testLogReplayWithReorderedDBQByIdAndChildDocs-seed#[266A6FC4A1996F06]) [ ] o.a.s.u.DirectUpdateHandler2 end_commit_flush
[junit4] 2> 1852258 INFO (searcherExecutor-7395-thread-1) [ ] o.a.s.c.SolrCore [collection1] Registered new searcher Searcher@1af0875[collection1] main{ExitableDirectoryReader(UninvertingDirectoryReader())}
[junit4] 2> 1852258 INFO (TEST-TestRecovery.testLogReplayWithReorderedDBQByIdAndChildDocs-seed#[266A6FC4A1996F06]) [ ] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=null path=null params={}{commit=} 0 10
[junit4] 2> 1852267 INFO (TEST-TestRecovery.testLogReplayWithReorderedDBQByIdAndChildDocs-seed#[266A6FC4A1996F06]) [ ] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=null path=null params={update.distrib=FROMLEADER&wt=json&indent=true}{add=[RDBQ3_1]} 0 4
[junit4] 2> 1852268 INFO (TEST-TestRecovery.testLogReplayWithReorderedDBQByIdAndChildDocs-seed#[266A6FC4A1996F06]) [ ] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=null path=null params={update.distrib=FROMLEADER&wt=json&indent=true}{add=[RDBQ3_2 (3)]} 0 0
[junit4] 2> 1852292 INFO (TEST-TestRecovery.testLogReplayWithReorderedDBQByIdAndChildDocs-seed#[266A6FC4A1996F06]) [ ] o.a.s.s.SolrIndexSearcher Opening [Searcher@d0c582[collection1] realtime]
[junit4] 2> 1852293 INFO (TEST-TestRecovery.testLogReplayWithReorderedDBQByIdAndChildDocs-seed#[266A6FC4A1996F06]) [ ] o.a.s.s.SolrIndexSearcher Opening [Searcher@bb1a17[collection1] realtime]
[junit4] 2> 1852293 INFO (TEST-TestRecovery.testLogReplayWithReorderedDBQByIdAndChildDocs-seed#[266A6FC4A1996F06]) [ ] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=null path=null params={update.distrib=FROMLEADER&_version_=-2&wt=json&indent=true}{deleteByQuery=id:RDBQ3_1 id:RDBQ3_2 id:RDBQ3_3 id:RDBQ3_4 (-2)} 0 25
[junit4] 2> 1852294 INFO (TEST-TestRecovery.testLogReplayWithReorderedDBQByIdAndChildDocs-seed#[266A6FC4A1996F06]) [ ] o.a.s.u.DirectUpdateHandler2 Reordered DBQs detected. Update=add{_version_=1,id=RDBQ3_3} DBQs=[DBQ{version=2,q=id:RDBQ3_1 id:RDBQ3_2 id:RDBQ3_3 id:RDBQ3_4}]
[junit4] 2> 1852308 INFO (TEST-TestRecovery.testLogReplayWithReorderedDBQByIdAndChildDocs-seed#[266A6FC4A1996F06]) [ ] o.a.s.s.SolrIndexSearcher Opening [Searcher@cf4ee8[collection1] realtime]
[junit4] 2> 1852309 INFO (TEST-TestRecovery.testLogReplayWithReorderedDBQByIdAndChildDocs-seed#[266A6FC4A1996F06]) [ ] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=null path=null params={update.distrib=FROMLEADER&wt=json&indent=true}{add=[RDBQ3_3 (1)]} 0 15
[junit4] 2> 1852311 INFO (TEST-TestRecovery.testLogReplayWithReorderedDBQByIdAndChildDocs-seed#[266A6FC4A1996F06]) [ ] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=null path=null params={update.distrib=FROMLEADER&wt=json&indent=true}{add=[RDBQ3_4 (4)]} 0 1
[junit4] 2> 1852311 INFO (TEST-TestRecovery.testLogReplayWithReorderedDBQByIdAndChildDocs-seed#[266A6FC4A1996F06]) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={q=*:*&wt=xml} hits=0 status=0 QTime=0
[junit4] 2> 1852311 INFO (TEST-TestRecovery.testLogReplayWithReorderedDBQByIdAndChildDocs-seed#[266A6FC4A1996F06]) [ ] o.a.s.c.CoreContainer Shutting down CoreContainer instance=18535823
[junit4] 2> 1852312 INFO (TEST-TestRecovery.testLogReplayWithReorderedDBQByIdAndChildDocs-seed#[266A6FC4A1996F06]) [ ] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.node, tag=null
[junit4] 2> 1852312 INFO (TEST-TestRecovery.testLogReplayWithReorderedDBQByIdAndChildDocs-seed#[266A6FC4A1996F06]) [ ] o.a.s.m.r.SolrJmxReporter Closing reporter [org.apache.solr.metrics.reporters.SolrJmxReporter@10873db: rootName = null, domain = solr.node, service url = null, agent id = null] for registry solr.node / com.codahale.metrics.MetricRegistry@1dc70a
[junit4] 2> 1852317 INFO (TEST-TestRecovery.testLogReplayWithReorderedDBQByIdAndChildDocs-seed#[266A6FC4A1996F06]) [ ] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.jvm, tag=null
[junit4] 2> 1852317 INFO (TEST-TestRecovery.testLogReplayWithReorderedDBQByIdAndChildDocs-seed#[266A6FC4A1996F06]) [ ] o.a.s.m.r.SolrJmxReporter Closing reporter [org.apache.solr.metrics.reporters.SolrJmxReporter@1105687: rootName = null, domain = solr.jvm, service url = null, agent id = null] for registry solr.jvm / com.codahale.metrics.MetricRegistry@134ee37
[junit4] 2> 1852319 INFO (TEST-TestRecovery.testLogReplayWithReorderedDBQByIdAndChildDocs-seed#[266A6FC4A1996F06]) [ ] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.jetty, tag=null
[junit4] 2> 1852319 INFO (TEST-TestRecovery.testLogReplayWithReorderedDBQByIdAndChildDocs-seed#[266A6FC4A1996F06]) [ ] o.a.s.m.r.SolrJmxReporter Closing reporter [org.apache.solr.metrics.reporters.SolrJmxReporter@653a90: rootName = null, domain = solr.jetty, service url = null, agent id = null] for registry solr.jetty / com.codahale.metrics.MetricRegistry@27da6
[junit4] 2> 1852320 INFO (coreCloseExecutor-7400-thread-1) [ x:collection1] o.a.s.c.SolrCore [collection1] CLOSING SolrCore org.apache.solr.core.SolrCore@1bfd831
[junit4] 2> 1852320 INFO (coreCloseExecutor-7400-thread-1) [ x:collection1] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.core.collection1, tag=1bfd831
[junit4] 2> 1852320 INFO (coreCloseExecutor-7400-thread-1) [ x:collection1] o.a.s.m.r.SolrJmxReporter Closing reporter [org.apache.solr.metrics.reporters.SolrJmxReporter@1d38aa4: rootName = null, domain = solr.core.collection1, service url = null, agent id = null] for registry solr.core.collection1 / com.codahale.metrics.MetricRegistry@b16955
[junit4] 2> 1852333 INFO (TEST-TestRecovery.testLogReplayWithReorderedDBQByIdAndChildDocs-seed#[266A6FC4A1996F06]) [ ] o.a.s.c.SolrResourceLoader [null] Added 2 libs to classloader, from paths: [/C:/Users/jenkins/workspace/Lucene-Solr-7.4-Windows/solr/core/src/test-files/solr/collection1/lib, /C:/Users/jenkins/workspace/Lucene-Solr-7.4-Windows/solr/core/src/test-files/solr/collection1/lib/classes]
[junit4] 2> 1852386 INFO (TEST-TestRecovery.testLogReplayWithReorderedDBQByIdAndChildDocs-seed#[266A6FC4A1996F06]) [ ] o.a.s.c.SolrConfig Using Lucene MatchVersion: 7.4.0
[junit4] 2> 1852396 INFO (TEST-TestRecovery.testLogReplayWithReorderedDBQByIdAndChildDocs-seed#[266A6FC4A1996F06]) [ ] o.a.s.s.IndexSchema [null] Schema name=test
[junit4] 2> 1852454 INFO (TEST-TestRecovery.testLogReplayWithReorderedDBQByIdAndChildDocs-seed#[266A6FC4A1996F06]) [ ] o.a.s.s.IndexSchema Loaded schema test/1.6 with uniqueid field id
[junit4] 2> 1853792 INFO (TEST-TestRecovery.testLogReplayWithReorderedDBQByIdAndChildDocs-seed#[266A6FC4A1996F06]) [ ] o.a.s.c.TransientSolrCoreCacheDefault Allocating transient cache for 2147483647 transient cores
[junit4] 2> 1853792 INFO (TEST-TestRecovery.testLogReplayWithReorderedDBQByIdAndChildDocs-seed#[266A6FC4A1996F06]) [ ] o.a.s.h.a.MetricsHistoryHandler No .system collection, keeping metrics history in memory.
[junit4] 2> 1853816 INFO (TEST-TestRecovery.testLogReplayWithReorderedDBQByIdAndChildDocs-seed#[266A6FC4A1996F06]) [ ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr.node' (registry 'solr.node') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@999068
[junit4] 2> 1853821 INFO (TEST-TestRecovery.testLogReplayWithReorderedDBQByIdAndChildDocs-seed#[266A6FC4A1996F06]) [ ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr.jvm' (registry 'solr.jvm') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@999068
[junit4] 2> 1853821 INFO (TEST-TestRecovery.testLogReplayWithReorderedDBQByIdAndChildDocs-seed#[266A6FC4A1996F06]) [ ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr.jetty' (registry 'solr.jetty') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@999068
[junit4] 2> 1853824 INFO (coreLoadExecutor-7410-thread-1) [ x:collection1] o.a.s.c.SolrResourceLoader [null] Added 2 libs to classloader, from paths: [/C:/Users/jenkins/workspace/Lucene-Solr-7.4-Windows/solr/core/src/test-files/solr/collection1/lib, /C:/Users/jenkins/workspace/Lucene-Solr-7.4-Windows/solr/core/src/test-files/solr/collection1/lib/classes]
[junit4] 2> 1853876 INFO (coreLoadExecutor-7410-thread-1) [ x:collection1] o.a.s.c.SolrConfig Using Lucene MatchVersion: 7.4.0
[junit4] 2> 1853880 INFO (coreLoadExecutor-7410-thread-1) [ x:collection1] o.a.s.s.IndexSchema [collection1] Schema name=test
[junit4] 2> 1853936 INFO (coreLoadExecutor-7410-thread-1) [ x:collection1] o.a.s.s.IndexSchema Loaded schema test/1.6 with uniqueid field id
[junit4] 2> 1853943 INFO (coreLoadExecutor-7410-thread-1) [ x:collection1] o.a.s.c.CoreContainer Creating SolrCore 'collection1' using configuration from instancedir C:\Users\jenkins\workspace\Lucene-Solr-7.4-Windows\solr\core\src\test-files\solr\collection1, trusted=true
[junit4] 2> 1853943 INFO (coreLoadExecutor-7410-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@999068
[junit4] 2> 1853943 INFO (coreLoadExecutor-7410-thread-1) [ x:collection1] o.a.s.c.SolrCore solr.RecoveryStrategy.Builder
[junit4] 2> 1853943 INFO (coreLoadExecutor-7410-thread-1) [ x:collection1] o.a.s.c.SolrCore [[collection1] ] Opening new SolrCore at [C:\Users\jenkins\workspace\Lucene-Solr-7.4-Windows\solr\core\src\test-files\solr\collection1], dataDir=[C:\Users\jenkins\workspace\Lucene-Solr-7.4-Windows\solr\build\solr-core\test\J1\temp\solr.search.TestRecovery_266A6FC4A1996F06-001\init-core-data-001\]
[junit4] 2> 1853949 WARN (coreLoadExecutor-7410-thread-1) [ x:collection1] o.a.s.c.RequestHandlers INVALID paramSet a in requestHandler {type = requestHandler,name = /dump,class = DumpRequestHandler,attributes = {initParams=a, name=/dump, class=DumpRequestHandler},args = {defaults={a=A,b=B}}}
[junit4] 2> 1854022 INFO (coreLoadExecutor-7410-thread-1) [ x:collection1] o.a.s.u.UpdateHandler Using UpdateLog implementation: org.apache.solr.update.CdcrUpdateLog
[junit4] 2> 1854022 INFO (coreLoadExecutor-7410-thread-1) [ x:collection1] o.a.s.u.UpdateLog Initializing UpdateLog: dataDir= defaultSyncLevel=FLUSH numRecordsToKeep=100 maxNumLogsToKeep=10 numVersionBuckets=65536
[junit4] 2> 1854024 INFO (coreLoadExecutor-7410-thread-1) [ x:collection1] o.a.s.u.CommitTracker Hard AutoCommit: disabled
[junit4] 2> 1854024 INFO (coreLoadExecutor-7410-thread-1) [ x:collection1] o.a.s.u.CommitTracker Soft AutoCommit: disabled
[junit4] 2> 1854026 INFO (coreLoadExecutor-7410-thread-1) [ x:collection1] o.a.s.u.RandomMergePolicy RandomMergePolicy wrapping class org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: maxMergeAtOnce=44, maxMergeAtOnceExplicit=29, maxMergedSegmentMB=62.1201171875, floorSegmentMB=1.0625, forceMergeDeletesPctAllowed=18.25526037168861, segmentsPerTier=34.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.22628571333180184
[junit4] 2> 1854027 INFO (coreLoadExecutor-7410-thread-1) [ x:collection1] o.a.s.s.SolrIndexSearcher Opening [Searcher@11034f5[collection1] main]
[junit4] 2> 1854028 WARN (coreLoadExecutor-7410-thread-1) [ x:collection1] o.a.s.r.ManagedResourceStorage Cannot write to config directory C:\Users\jenkins\workspace\Lucene-Solr-7.4-Windows\solr\core\src\test-files\solr\collection1\conf; switching to use InMemory storage instead.
[junit4] 2> 1854028 INFO (coreLoadExecutor-7410-thread-1) [ x:collection1] o.a.s.h.ReplicationHandler Commits will be reserved for 10000ms.
[junit4] 2> 1854029 INFO (searcherExecutor-7411-thread-1-processing-x:collection1) [ x:collection1] o.a.s.c.SolrCore [collection1] Registered new searcher Searcher@11034f5[collection1] main{ExitableDirectoryReader(UninvertingDirectoryReader())}
[junit4] 2> 1854030 WARN (recoveryExecutor-7413-thread-1-processing-x:collection1) [ x:collection1] o.a.s.u.UpdateLog Starting log replay tlog{file=C:\Users\jenkins\workspace\Lucene-Solr-7.4-Windows\solr\build\solr-core\test\J1\temp\solr.search.TestRecovery_266A6FC4A1996F06-001\init-core-data-001\tlog\tlog.0000000000000000001.0 refcount=1} active=false starting pos=0 inSortedOrder=false
[junit4] 2> 1854032 INFO (TEST-TestRecovery.testLogReplayWithReorderedDBQByIdAndChildDocs-seed#[266A6FC4A1996F06]) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={q=*:*&wt=xml} hits=0 status=0 QTime=0
[junit4] 2> 1854553 INFO (recoveryExecutor-7413-thread-1-processing-x:collection1) [ x:collection1] o.a.s.s.SolrIndexSearcher Opening [Searcher@13bebef[collection1] realtime]
[junit4] 2> 1854562 INFO (recoveryExecutor-7413-thread-1-processing-x:collection1) [ x:collection1] o.a.s.s.SolrIndexSearcher Opening [Searcher@1c3c427[collection1] realtime]
[junit4] 2> 1854562 INFO (replayUpdatesExecutor-7404-thread-1-processing-x:collection1) [ x:collection1] o.a.s.u.DirectUpdateHandler2 Reordered DBQs detected. Update=add{flags=a,_version_=1,id=RDBQ3_3} DBQs=[DBQ{version=2,q=id:RDBQ3_1 id:RDBQ3_2 id:RDBQ3_3 id:RDBQ3_4}]
[junit4] 2> 1854568 INFO (replayUpdatesExecutor-7404-thread-1-processing-x:collection1) [ x:collection1] o.a.s.s.SolrIndexSearcher Opening [Searcher@e81c12[collection1] realtime]
[junit4] 2> 1855063 INFO (recoveryExecutor-7413-thread-1-processing-x:collection1) [ x:collection1] o.a.s.u.DirectUpdateHandler2 start commit{flags=2,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4] 2> 1855063 INFO (recoveryExecutor-7413-thread-1-processing-x:collection1) [ x:collection1] o.a.s.u.SolrIndexWriter Calling setCommitData with IW:org.apache.solr.update.SolrIndexWriter@da7971 commitCommandVersion:0
[junit4] 2> 1855340 INFO (recoveryExecutor-7413-thread-1-processing-x:collection1) [ x:collection1] o.a.s.s.SolrIndexSearcher Opening [Searcher@166d4b8[collection1] main]
[junit4] 2> 1855341 INFO (recoveryExecutor-7413-thread-1-processing-x:collection1) [ x:collection1] o.a.s.u.DirectUpdateHandler2 end_commit_flush
[junit4] 2> 1855342 INFO (searcherExecutor-7411-thread-1-processing-x:collection1) [ x:collection1] o.a.s.c.SolrCore [collection1] Registered new searcher Searcher@166d4b8[collection1] main{ExitableDirectoryReader(UninvertingDirectoryReader(Uninverting(_1(7.4.0):c6/1:delGen=1) Uninverting(_3(7.4.0):c3)))}
[junit4] 2> 1855342 INFO (recoveryExecutor-7413-thread-1-processing-x:collection1) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] {add=[RDBQ3_1, RDBQ3_2 (3), RDBQ3_3 (1), RDBQ3_4 (4)],deleteByQuery=id:RDBQ3_1 id:RDBQ3_2 id:RDBQ3_3 id:RDBQ3_4 (-2)} 0 1311
[junit4] 2> 1855342 WARN (recoveryExecutor-7413-thread-1-processing-x:collection1) [ x:collection1] o.a.s.u.UpdateLog Log replay finished. recoveryInfo=RecoveryInfo{adds=4 deletes=0 deleteByQuery=1 errors=0 positionOfStart=0}
[junit4] 2> 1855342 INFO (TEST-TestRecovery.testLogReplayWithReorderedDBQByIdAndChildDocs-seed#[266A6FC4A1996F06]) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={q=*:*&wt=xml} hits=8 status=0 QTime=0
[junit4] 2> 1855345 INFO (TEST-TestRecovery.testLogReplayWithReorderedDBQUpdateWithDifferentChildCount-seed#[266A6FC4A1996F06]) [ ] o.a.s.u.DirectUpdateHandler2 [collection1] REMOVING ALL DOCUMENTS FROM INDEX
[junit4] 2> 1855346 INFO (TEST-TestRecovery.testLogReplayWithReorderedDBQUpdateWithDifferentChildCount-seed#[266A6FC4A1996F06]) [ ] o.a.s.s.SolrIndexSearcher Opening [Searcher@1b6b860[collection1] realtime]
[junit4] 2> 1855346 INFO (TEST-TestRecovery.testLogReplayWithReorderedDBQUpdateWithDifferentChildCount-seed#[266A6FC4A1996F06]) [ ] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=null path=null params={_version_=-9223372036854775807&update.distrib=FROMLEADER&versions=true&wt=json&indent=true}{deleteByQuery=*:* (-9223372036854775807)} 0 0
[junit4] 2> 1855346 INFO (TEST-TestRecovery.testLogReplayWithReorderedDBQUpdateWithDifferentChildCount-seed#[266A6FC4A1996F06]) [ ] o.a.s.u.DirectUpdateHandler2 start commit{_version_=1603648413287579648,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4] 2> 1855346 INFO (TEST-TestRecovery.testLogReplayWithReorderedDBQUpdateWithDifferentChildCount-seed#[266A6FC4A1996F06]) [ ] o.a.s.u.SolrIndexWriter Calling setCommitData with IW:org.apache.solr.update.SolrIndexWriter@da7971 commitCommandVersion:1603648413287579648
[junit4] 2> 1855354 INFO (TEST-TestRecovery.testLogReplayWithReorderedDBQUpdateWithDifferentChildCount-seed#[266A6FC4A1996F06]) [ ] o.a.s.s.SolrIndexSearcher Opening [Searcher@11635f2[collection1] main]
[junit4] 2> 1855354 INFO (TEST-TestRecovery.testLogReplayWithReorderedDBQUpdateWithDifferentChildCount-seed#[266A6FC4A1996F06]) [ ] o.a.s.u.DirectUpdateHandler2 end_commit_flush
[junit4] 2> 1855355 INFO (searcherExecutor-7411-thread-1) [ ] o.a.s.c.SolrCore [collection1] Registered new searcher Searcher@11635f2[collection1] main{ExitableDirectoryReader(UninvertingDirectoryReader())}
[junit4] 2> 1855356 INFO (TEST-TestRecovery.testLogReplayWithReorderedDBQUpdateWithDifferentChildCount-seed#[266A6FC4A1996F06]) [ ] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=null path=null params={}{commit=} 0 9
[junit4] 2> 1855358 INFO (TEST-TestRecovery.testLogReplayWithReorderedDBQUpdateWithDifferentChildCount-seed#[266A6FC4A1996F06]) [ ] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=null path=null params={update.distrib=FROMLEADER&wt=json&indent=true}{add=[RDBQ5_1 (5)]} 0 1
[junit4] 2> 1855358 INFO (TEST-TestRecovery.testLogReplayWithReorderedDBQUpdateWithDifferentChildCount-seed#[266A6FC4A1996F06]) [ ] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=null path=null params={update.distrib=FROMLEADER&wt=json&indent=true}{add=[RDBQ5_1 (6)]} 0 0
[junit4] 2> 1855358 INFO (TEST-TestRecovery.testLogReplayWithReorderedDBQUpdateWithDifferentChildCount-seed#[266A6FC4A1996F06]) [ ] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=null path=null params={update.distrib=FROMLEADER&wt=json&indent=true}{add=[RDBQ5_2 (7)]} 0 0
[junit4] 2> 1855366 INFO (TEST-TestRecovery.testLogReplayWithReorderedDBQUpdateWithDifferentChildCount-seed#[266A6FC4A1996F06]) [ ] o.a.s.s.SolrIndexSearcher Opening [Searcher@520929[collection1] realtime]
[junit4] 2> 1855367 INFO (TEST-TestRecovery.testLogReplayWithReorderedDBQUpdateWithDifferentChildCount-seed#[266A6FC4A1996F06]) [ ] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=null path=null params={update.distrib=FROMLEADER&_version_=-9&wt=json&indent=true}{deleteByQuery=id:RDBQ5_3 (-9)} 0 8
[junit4] 2> 1855367 INFO (TEST-TestRecovery.testLogReplayWithReorderedDBQUpdateWithDifferentChildCount-seed#[266A6FC4A1996F06]) [ ] o.a.s.u.DirectUpdateHandler2 Reordered DBQs detected. Update=add{_version_=8,id=RDBQ5_2} DBQs=[DBQ{version=9,q=id:RDBQ5_3}]
[junit4] 2> 1855378 INFO (TEST-TestRecovery.testLogReplayWithReorderedDBQUpdateWithDifferentChildCount-seed#[266A6FC4A1996F06]) [ ] o.a.s.s.SolrIndexSearcher Opening [Searcher@18a513e[collection1] realtime]
[junit4] 2> 1855379 INFO (TEST-TestRecovery.testLogReplayWithReorderedDBQUpdateWithDifferentChildCount-seed#[266A6FC4A1996F06]) [ ] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=null path=null params={update.distrib=FROMLEADER&wt=json&indent=true}{add=[RDBQ5_2 (8)]} 0 11
[junit4] 2> 1855379 INFO (TEST-TestRecovery.testLogReplayWithReorderedDBQUpdateWithDifferentChildCount-seed#[266A6FC4A1996F06]) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={q=*:*&wt=xml} hits=0 status=0 QTime=0
[junit4] 2> 1855379 INFO (TEST-TestRecovery.testLogReplayWithReorderedDBQUpdateWithDifferentChildCount-seed#[266A6FC4A1996F06]) [ ] o.a.s.c.CoreContainer Shutting down CoreContainer instance=14488862
[junit4] 2> 1855379 INFO (TEST-TestRecovery.testLogReplayWithReorderedDBQUpdateWithDifferentChildCount-seed#[266A6FC4A1996F06]) [ ] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.node, tag=null
[junit4] 2> 1855379 INFO (TEST-TestRecovery.testLogReplayWithReorderedDBQUpdateWithDifferentChildCount-seed#[266A6FC4A1996F06]) [ ] o.a.s.m.r.SolrJmxReporter Closing reporter [org.apache.solr.metrics.reporters.SolrJmxReporter@4dc8a1: rootName = null, domain = solr.node, service url = null, agent id = null] for registry solr.node / com.codahale.metrics.MetricRegistry@1d0e86f
[junit4] 2> 1855383 INFO (TEST-TestRecovery.testLogReplayWithReorderedDBQUpdateWithDifferentChildCount-seed#[266A6FC4A1996F06]) [ ] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.jvm, tag=null
[junit4] 2> 1855383 INFO (TEST-TestRecovery.testLogReplayWithReorderedDBQUpdateWithDifferentChildCount-seed#[266A6FC4A1996F06]) [ ] o.a.s.m.r.SolrJmxReporter Closing reporter [org.apache.solr.metrics.reporters.SolrJmxReporter@1f44d48: rootName = null, domain = solr.jvm, service url = null, agent id = null] for registry solr.jvm / com.codahale.metrics.MetricRegistry@134ee37
[junit4] 2> 1855384 INFO (TEST-TestRecovery.testLogReplayWithReorderedDBQUpdateWithDifferentChildCount-seed#[266A6FC4A1996F06]) [ ] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.jetty, tag=null
[junit4] 2> 1855384 INFO (TEST-TestRecovery.testLogReplayWithReorderedDBQUpdateWithDifferentChildCount-seed#[266A6FC4A1996F06]) [ ] o.a.s.m.r.SolrJmxReporter Closing reporter [org.apache.solr.metrics.reporters.SolrJmxReporter@1abbc95: rootName = null, domain = solr.jetty, service url = null, agent id = null] for registry solr.jetty / com.codahale.metrics.MetricRegistry@27da6
[junit4] 2> 1855384 INFO (coreCloseExecutor-7416-thread-1) [ x:collection1] o.a.s.c.SolrCore [collection1] CLOSING SolrCore org.apache.solr.core.SolrCore@25c165
[junit4] 2> 1855384 INFO (coreCloseExecutor-7416-thread-1) [ x:collection1] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.core.collection1, tag=25c165
[junit4] 2> 1855384 INFO (coreCloseExecutor-7416-thread-1) [ x:collection1] o.a.s.m.r.SolrJmxReporter Closing reporter [org.apache.solr.metrics.reporters.SolrJmxReporter@ca872d: rootName = null, domain = solr.core.collection1, service url = null, agent id = null] for registry solr.core.collection1 / com.codahale.metrics.MetricRegistry@18049c8
[junit4] 2> 1855398 INFO (TEST-TestRecovery.testLogReplayWithReorderedDBQUpdateWithDifferentChildCount-seed#[266A6FC4A1996F06]) [ ] o.a.s.c.SolrResourceLoader [null] Added 2 libs to classloader, from paths: [/C:/Users/jenkins/workspace/Lucene-Solr-7.4-Windows/solr/core/src/test-files/solr/collection1/lib, /C:/Users/jenkins/workspace/Lucene-Solr-7.4-Windows/solr/core/src/test-files/solr/collection1/lib/classes]
[junit4] 2> 1855439 INFO (TEST-TestRecovery.testLogReplayWithReorderedDBQUpdateWithDifferentChildCount-seed#[266A6FC4A1996F06]) [ ] o.a.s.c.SolrConfig Using Lucene MatchVersion: 7.4.0
[junit4] 2> 1855447 INFO (TEST-TestRecovery.testLogReplayWithReorderedDBQUpdateWithDifferentChildCount-seed#[266A6FC4A1996F06]) [ ] o.a.s.s.IndexSchema [null] Schema name=test
[junit4] 2> 1855497 INFO (TEST-TestRecovery.testLogReplayWithReorderedDBQUpdateWithDifferentChildCount-seed#[266A6FC4A1996F06]) [ ] o.a.s.s.IndexSchema Loaded schema test/1.6 with uniqueid field id
[junit4] 2> 1855914 INFO (TEST-TestRecovery.testLogReplayWithReorderedDBQUpdateWithDifferentChildCount-seed#[266A6FC4A1996F06]) [ ] o.a.s.c.TransientSolrCoreCacheDefault Allocating transient cache for 2147483647 transient cores
[junit4] 2> 1855914 INFO (TEST-TestRecovery.testLogReplayWithReorderedDBQUpdateWithDifferentChildCount-seed#[266A6FC4A1996F06]) [ ] o.a.s.h.a.MetricsHistoryHandler No .system collection, keeping metrics history in memory.
[junit4] 2> 1855934 INFO (TEST-TestRecovery.testLogReplayWithReorderedDBQUpdateWithDifferentChildCount-seed#[266A6FC4A1996F06]) [ ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr.node' (registry 'solr.node') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@999068
[junit4] 2> 1855939 INFO (TEST-TestRecovery.testLogReplayWithReorderedDBQUpdateWithDifferentChildCount-seed#[266A6FC4A1996F06]) [ ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr.jvm' (registry 'solr.jvm') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@999068
[junit4] 2> 1855939 INFO (TEST-TestRecovery.testLogReplayWithReorderedDBQUpdateWithDifferentChildCount-seed#[266A6FC4A1996F06]) [ ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr.jetty' (registry 'solr.jetty') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@999068
[junit4] 2> 1855941 INFO (coreLoadExecutor-7426-thread-1) [ x:collection1] o.a.s.c.SolrResourceLoader [null] Added 2 libs to classloader, from paths: [/C:/Users/jenkins/workspace/Lucene-Solr-7.4-Windows/solr/core/src/test-files/solr/collection1/lib, /C:/Users/jenkins/workspace/Lucene-Solr-7.4-Windows/solr/core/src/test-files/solr/collection1/lib/classes]
[junit4] 2> 1855990 INFO (coreLoadExecutor-7426-thread-1) [ x:collection1] o.a.s.c.SolrConfig Using Lucene MatchVersion: 7.4.0
[junit4] 2> 1856005 INFO (coreLoadExecutor-7426-thread-1) [ x:collection1] o.a.s.s.IndexSchema [collection1] Schema name=test
[junit4] 2> 1856053 INFO (coreLoadExecutor-7426-thread-1) [ x:collection1] o.a.s.s.IndexSchema Loaded schema test/1.6 with uniqueid field id
[junit4] 2> 1856059 INFO (coreLoadExecutor-7426-thread-1) [ x:collection1] o.a.s.c.CoreContainer Creating SolrCore 'collection1' using configuration from instancedir C:\Users\jenkins\workspace\Lucene-Solr-7.4-Windows\solr\core\src\test-files\solr\collection1, trusted=true
[junit4] 2> 1856060 INFO (coreLoadExecutor-7426-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@999068
[junit4] 2> 1856060 INFO (coreLoadExecutor-7426-thread-1) [ x:collection1] o.a.s.c.SolrCore solr.RecoveryStrategy.Builder
[junit4] 2> 1856060 INFO (coreLoadExecutor-7426-thread-1) [ x:collection1] o.a.s.c.SolrCore [[collection1] ] Opening new SolrCore at [C:\Users\jenkins\workspace\Lucene-Solr-7.4-Windows\solr\core\src\test-files\solr\collection1], dataDir=[C:\Users\jenkins\workspace\Lucene-Solr-7.4-Windows\solr\build\solr-core\test\J1\temp\solr.search.TestRecovery_266A6FC4A1996F06-001\init-core-data-001\]
[junit4] 2> 1856064 WARN (coreLoadExecutor-7426-thread-1) [ x:collection1] o.a.s.c.RequestHandlers INVALID paramSet a in requestHandler {type = requestHandler,name = /dump,class = DumpRequestHandler,attributes = {initParams=a, name=/dump, class=DumpRequestHandler},args = {defaults={a=A,b=B}}}
[junit4] 2> 1856141 INFO (coreLoadExecutor-7426-thread-1) [ x:collection1] o.a.s.u.UpdateHandler Using UpdateLog implementation: org.apache.solr.update.CdcrUpdateLog
[junit4] 2> 1856142 INFO (coreLoadExecutor-7426-thread-1) [ x:collection1] o.a.s.u.UpdateLog Initializing UpdateLog: dataDir= defaultSyncLevel=FLUSH numRecordsToKeep=100 maxNumLogsToKeep=10 numVersionBuckets=65536
[junit4] 2> 1856143 INFO (coreLoadExecutor-7426-thread-1) [ x:collection1] o.a.s.u.CommitTracker Hard AutoCommit: disabled
[junit4] 2> 1856143 INFO (coreLoadExecutor-7426-thread-1) [ x:collection1] o.a.s.u.CommitTracker Soft AutoCommit: disabled
[junit4] 2> 1856145 INFO (coreLoadExecutor-7426-thread-1) [ x:collection1] o.a.s.u.RandomMergePolicy RandomMergePolicy wrapping class org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: maxMergeAtOnce=44, maxMergeAtOnceExplicit=29, maxMergedSegmentMB=62.1201171875, floorSegmentMB=1.0625, forceMergeDeletesPctAllowed=18.25526037168861, segmentsPerTier=34.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.22628571333180184
[junit4] 2> 1856147 INFO (coreLoadExecutor-7426-thread-1) [ x:collection1] o.a.s.s.SolrIndexSearcher Opening [Searcher@14cf4e0[collection1] main]
[junit4] 2> 1856148 WARN (coreLoadExecutor-7426-thread-1) [ x:collection1] o.a.s.r.ManagedResourceStorage Cannot write to config directory C:\Users\jenkins\workspace\Lucene-Solr-7.4-Windows\solr\core\src\test-files\solr\collection1\conf; switching to use InMemory storage instead.
[junit4] 2> 1856148 INFO (coreLoadExecutor-7426-thread-1) [ x:collection1] o.a.s.h.ReplicationHandler Commits will be reserved for 10000ms.
[junit4] 2> 1856149 INFO (searcherExecutor-7427-thread-1-processing-x:collection1) [ x:collection1] o.a.s.c.SolrCore [collection1] Registered new searcher Searcher@14cf4e0[collection1] main{ExitableDirectoryReader(UninvertingDirectoryReader())}
[junit4] 2> 1856151 INFO (TEST-TestRecovery.testLogReplayWithReorderedDBQUpdateWithDifferentChildCount-seed#[266A6FC4A1996F06]) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={q=*:*&wt=xml} hits=0 status=0 QTime=0
[junit4] 2> 1856152 WARN (recoveryExecutor-7429-thread-1-processing-x:collection1) [ x:collection1] o.a.s.u.UpdateLog Starting log replay tlog{file=C:\Users\jenkins\workspace\Lucene-Solr-7.4-Windows\solr\build\solr-core\test\J1\temp\solr.search.TestRecovery_266A6FC4A1996F06-001\init-core-data-001\tlog\tlog.0000000000000000004.5 refcount=1} active=false starting pos=0 inSortedOrder=false
[junit4] 2> 1856667 INFO (recoveryExecutor-7429-thread-1-processing-x:collection1) [ x:collection1] o.a.s.s.SolrIndexSearcher Opening [Searcher@871ff7[collection1] realtime]
[junit4] 2> 1856668 INFO (replayUpdatesExecutor-7420-thread-1-processing-x:collection1) [ x:collection1] o.a.s.u.DirectUpdateHandler2 Reordered DBQs detected. Update=add{flags=a,_version_=8,id=RDBQ5_2} DBQs=[DBQ{version=9,q=id:RDBQ5_3}]
[junit4] 2> 1856676 INFO (replayUpdatesExecutor-7420-thread-1-processing-x:collection1) [ x:collection1] o.a.s.s.SolrIndexSearcher Opening [Searcher@ce3053[collection1] realtime]
[junit4] 2> 1857168 INFO (recoveryExecutor-7429-thread-1-processing-x:collection1) [ x:collection1] o.a.s.u.DirectUpdateHandler2 start commit{flags=2,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4] 2> 1857168 INFO (recoveryExecutor-7429-thread-1-processing-x:collection1) [ x:collection1] o.a.s.u.SolrIndexWriter Calling setCommitData with IW:org.apache.solr.update.SolrIndexWriter@ab1131 commitCommandVersion:0
[junit4] 2> 1857354 INFO (recoveryExecutor-7429-thread-1-processing-x:collection1) [ x:collection1] o.a.s.s.SolrIndexSearcher Opening [Searcher@15dea89[collection1] main]
[junit4] 2> 1857355 INFO (recoveryExecutor-7429-thread-1-processing-x:collection1) [ x:collection1] o.a.s.u.DirectUpdateHandler2 end_commit_flush
[junit4] 2> 1857356 INFO (searcherExecutor-7427-thread-1-processing-x:collection1) [ x:collection1] o.a.s.c.SolrCore [collection1] Registered new searcher Searcher@15dea89[collection1] main{ExitableDirectoryReader(UninvertingDirectoryReader(Uninverting(_6(7.4.0):c10/6:delGen=2) Uninverting(_7(7.4.0):c4)))}
[junit4] 2> 1857356 INFO (recoveryExecutor-7429-thread-1-processing-x:collection1) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] {add=[RDBQ5_1 (5), RDBQ5_1 (6), RDBQ5_2 (7), RDBQ5_2 (8)],deleteByQuery=id:RDBQ5_3 (-9)} 0 1204
[junit4] 2> 1857356 WARN (recoveryExecutor-7429-thread-1-processing-x:collection1) [ x:collection1] o.a.s.u.UpdateLog Log replay finished. recoveryInfo=RecoveryInfo{adds=4 deletes=0 deleteByQuery=1 errors=0 positionOfStart=0}
[junit4] 2> 1857356 INFO (TEST-TestRecovery.testLogReplayWithReorderedDBQUpdateWithDifferentChildCount-seed#[266A6FC4A1996F06]) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={q=*:*&wt=xml} hits=8 status=0 QTime=0
[junit4] 2> 1857361 INFO (TEST-TestRecovery.testBuffering-seed#[266A6FC4A1996F06]) [ ] o.a.s.u.DirectUpdateHandler2 [collection1] REMOVING ALL DOCUMENTS FROM INDEX
[junit4] 2> 1857362 INFO (TEST-TestRecovery.testBuffering-seed#[266A6FC4A1996F06]) [ ] o.a.s.s.SolrIndexSearcher Opening [Searcher@108134c[collection1] realtime]
[junit4] 2> 1857362 INFO (TEST-TestRecovery.testBuffering-seed#[266A6FC4A1996F06]) [ ] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=null path=null params={_version_=-9223372036854775807&update.distrib=FROMLEADER&versions=true&wt=json&indent=true}{deleteByQuery=*:* (-9223372036854775807)} 0 1
[junit4] 2> 1857363 INFO (TEST-TestRecovery.testBuffering-seed#[266A6FC4A1996F06]) [ ] o.a.s.u.DirectUpdateHandler2 start commit{_version_=1603648415402557440,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4] 2> 1857363 INFO (TEST-TestRecovery.testBuffering-seed#[266A6FC4A1996F06]) [ ] o.a.s.u.SolrIndexWriter Calling setCommitData with IW:org.apache.solr.update.SolrIndexWriter@ab1131 commitCommandVersion:1603648415402557440
[junit4] 2> 1857373 INFO (TEST-TestRecovery.testBuffering-seed#[266A6FC4A1996F06]) [ ] o.a.s.s.SolrIndexSearcher Opening [Searcher@573e55[collection1] main]
[junit4] 2> 1857375 INFO (searcherExecutor-7427-thread-1) [ ] o.a.s.c.SolrCore [collection1] Registered new searcher Searcher@573e55[collection1] main{ExitableDirectoryReader(UninvertingDirectoryReader())}
[junit4] 2> 1857375 INFO (TEST-TestRecovery.testBuffering-seed#[266A6FC4A1996F06]) [ ] o.a.s.u.DirectUpdateHandler2 end_commit_flush
[junit4] 2> 1857377 INFO (TEST-TestRecovery.testBuffering-seed#[266A6FC4A1996F06]) [ ] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=null path=null params={}{commit=} 0 14
[junit4] 2> 1857378 INFO (TEST-TestRecovery.testBuffering-seed#[266A6FC4A1996F06]) [ ] o.a.s.u.UpdateLog Starting to buffer updates. FSUpdateLog{state=ACTIVE, tlog=null}
[junit4] 2> 1857378 INFO (TEST-TestRecovery.testBuffering-seed#[266A6FC4A1996F06]) [ ] o.a.s.u.UpdateLog Starting to buffer updates. FSUpdateLog{state=ACTIVE, tlog=null}
[junit4] 2> 1857382 INFO (TEST-TestRecovery.testBuffering-seed#[266A6FC4A1996F06]) [ ] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=null path=null params={update.distrib=FROMLEADER&wt=json&indent=true}{add=[B1 (13)]} 0 3
[junit4] 2> 1857382 INFO (TEST-TestRecovery.testBuffering-seed#[266A6FC4A1996F06]) [ ] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=null path=null params={update.distrib=FROMLEADER&wt=json&indent=true}{add=[B11 (14)]} 0 0
[junit4] 2> 1857383 INFO (TEST-TestRecovery.testBuffering-seed#[266A6FC4A1996F06]) [ ] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=null path=null params={update.distrib=FROMLEADER&_version_=-15&wt=json&indent=true}{deleteByQuery=id:B1 id:B11 id:B2 id:B3 (-15)} 0 0
[junit4] 2> 1857383 INFO (TEST-TestRecovery.testBuffering-seed#[266A6FC4A1996F06]) [ ] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=null path=null params={update.distrib=FROMLEADER&wt=json&indent=true}{add=[B2 (16)]} 0 0
[junit4] 2> 1857383 INFO (TEST-TestRecovery.testBuffering-seed#[266A6FC4A1996F06]) [ ] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=null path=null params={update.distrib=FROMLEADER&wt=json&indent=true}{add=[B3 (17)]} 0 0
[junit4] 2> 1857383 INFO (TEST-TestRecovery.testBuffering-seed#[266A6FC4A1996F06]) [ ] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=null path=null params={update.distrib=FROMLEADER&_version_=-23&versions=true&wt=json&indent=true}{delete=[B1 (-23)]} 0 0
[junit4] 2> 1857383 INFO (TEST-TestRecovery.testBuffering-seed#[266A6FC4A1996F06]) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&getVersions=6&wt=xml} status=0 QTime=0
[junit4] 2> 1857385 INFO (TEST-TestRecovery.testBuffering-seed#[266A6FC4A1996F06]) [ ] o.a.s.u.p.DistributedUpdateProcessor Ignoring commit while not ACTIVE - state: BUFFERING replay: false
[junit4] 2> 1857385 INFO (TEST-TestRecovery.testBuffering-seed#[266A6FC4A1996F06]) [ ] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=null path=null params={}{commit=} 0 0
[junit4] 2> 1857385 INFO (TEST-TestRecovery.testBuffering-seed#[266A6FC4A1996F06]) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&getVersions=6&wt=xml} status=0 QTime=0
[junit4] 2> 1857385 INFO (TEST-TestRecovery.testBuffering-seed#[266A6FC4A1996F06]) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={q=*:*&wt=xml} hits=0 status=0 QTime=0
[junit4] 2> 1857385 INFO (TEST-TestRecovery.testBuffering-seed#[266A6FC4A1996F06]) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&id=B3&wt=xml} status=0 QTime=0
[junit4] 2> 1857386 WARN (recoveryExecutor-7429-thread-1) [ ] o.a.s.u.UpdateLog Starting log replay tlog{file=C:\Users\jenkins\workspace\Lucene-Solr-7.4-Windows\solr\build\solr-core\test\J1\temp\solr.search.TestRecovery_266A6FC4A1996F06-001\init-core-data-001\tlog\buffer.tlog.0000446711889325000 refcount=2} active=true starting pos=0 inSortedOrder=false
[junit4] 2> 1857893 INFO (recoveryExecutor-7429-thread-1) [ ] o.a.s.s.SolrIndexSearcher Opening [Searcher@848afe[collection1] realtime]
[junit4] 2> 1857893 INFO (recoveryExecutor-7429-thread-1) [ ] o.a.s.s.SolrIndexSearcher Opening [Searcher@1cb6a23[collection1] realtime]
[junit4] 2> 1858398 INFO (recoveryExecutor-7429-thread-1) [ ] o.a.s.u.DirectUpdateHandler2 start commit{flags=2,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4] 2> 1858398 INFO (recoveryExecutor-7429-thread-1) [ ] o.a.s.u.SolrIndexWriter Calling setCommitData with IW:org.apache.solr.update.SolrIndexWriter@ab1131 commitCommandVersion:0
[junit4] 2> 1858448 INFO (recoveryExecutor-7429-thread-1) [ ] o.a.s.s.SolrIndexSearcher Opening [Searcher@180e7fe[collection1] main]
[junit4] 2> 1858449 INFO (recoveryExecutor-7429-thread-1) [ ] o.a.s.u.DirectUpdateHandler2 end_commit_flush
[junit4] 2> 1858450 INFO (searcherExecutor-7427-thread-1) [ ] o.a.s.c.SolrCore [collection1] Registered new searcher Searcher@180e7fe[collection1] main{ExitableDirectoryReader(UninvertingDirectoryReader(Uninverting(_9(7.4.0):c2)))}
[junit4] 2> 1858450 INFO (recoveryExecutor-7429-thread-1) [ ] o.a.s.u.p.LogUpdateProcessorFactory [collection1] {add=[B1 (13), B11 (14), B2 (16), B3 (17)],deleteByQuery=id:B1 id:B11 id:B2 id:B3 (-15),delete=[B1 (-23)]} 0 1063
[junit4] 2> 1858450 INFO (recoveryExecutor-7429-thread-1) [ ] o.a.s.u.UpdateLog Re-computing max version from index after log re-play.
[junit4] 2> 1858451 WARN (recoveryExecutor-7429-thread-1) [ ] o.a.s.u.UpdateLog Log replay finished. recoveryInfo=RecoveryInfo{adds=4 deletes=1 deleteByQuery=1 errors=0 positionOfStart=0}
[junit4] 2> 1858452 INFO (TEST-TestRecovery.testBuffering-seed#[266A6FC4A1996F06]) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&getVersions=6&wt=xml} status=0 QTime=0
[junit4] 2> 1858452 INFO (TEST-TestRecovery.testBuffering-seed#[266A6FC4A1996F06]) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={q=*:*&wt=xml} hits=2 status=0 QTime=0
[junit4] 2> 1858453 INFO (TEST-TestRecovery.testBuffering-seed#[266A6FC4A1996F06]) [ ] o.a.s.u.UpdateLog Starting to buffer updates. FSUpdateLog{state=ACTIVE, tlog=null}
[junit4] 2> 1858453 INFO (TEST-TestRecovery.testBuffering-seed#[266A6FC4A1996F06]) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&id=B3&wt=xml} status=0 QTime=0
[junit4] 2> 1858455 INFO (TEST-TestRecovery.testBuffering-seed#[266A6FC4A1996F06]) [ ] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=null path=null params={update.distrib=FROMLEADER&wt=json&indent=true}{add=[B3 (10)]} 0 1
[junit4] 2> 1858455 INFO (TEST-TestRecovery.testBuffering-seed#[266A6FC4A1996F06]) [ ] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=null path=null params={update.distrib=FROMLEADER&wt=json&indent=true}{add=[B4 (18)]} 0 0
[junit4] 2> 1858455 INFO (TEST-TestRecovery.testBuffering-seed#[266A6FC4A1996F06]) [ ] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=null path=null params={update.distrib=FROMLEADER&_version_=-11&versions=true&wt=json&indent=true}{delete=[B4 (-11)]} 0 0
[junit4] 2> 1858455 INFO (TEST-TestRecovery.testBuffering-seed#[266A6FC4A1996F06]) [ ] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=null path=null params={update.distrib=FROMLEADER&wt=json&indent=true}{add=[B6 (20)]} 0 0
[junit4] 2> 1858455 INFO (TEST-TestRecovery.testBuffering-seed#[266A6FC4A1996F06]) [ ] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=null path=null params={update.distrib=FROMLEADER&wt=json&indent=true}{add=[B5 (19)]} 0 0
[junit4] 2> 1858455 INFO (TEST-TestRecovery.testBuffering-seed#[266A6FC4A1996F06]) [ ] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=null path=null params={update.distrib=FROMLEADER&wt=json&indent=true}{add=[B8 (22)]} 0 0
[junit4] 2> 1858456 INFO (TEST-TestRecovery.testBuffering-seed#[266A6FC4A1996F06]) [ ] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=null path=null params={update.distrib=FROMLEADER&_version_=-25&wt=json&indent=true}{deleteByQuery=id:B2 OR id:B8 (-25)} 0 0
[junit4] 2> 1858456 INFO (TEST-TestRecovery.testBuffering-seed#[266A6FC4A1996F06]) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&getVersions=13&wt=xml} status=0 QTime=0
[junit4] 2> 1858456 INFO (TEST-TestRecovery.testBuffering-seed#[266A6FC4A1996F06]) [ ] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=null path=null params={update.distrib=FROMLEADER&wt=json&indent=true}{add=[B7 (21)]} 0 0
[junit4] 2> 1858456 INFO (TEST-TestRecovery.testBuffering-seed#[266A6FC4A1996F06]) [ ] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=null path=null params={update.distrib=FROMLEADER&_version_=-12&versions=true&wt=json&indent=true}{delete=[B5 (-12)]} 0 0
[junit4] 2> 1858456 INFO (TEST-TestRecovery.testBuffering-seed#[266A6FC4A1996F06]) [ ] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=null path=null params={update.distrib=FROMLEADER&_version_=-24&versions=true&wt=json&indent=true}{delete=[B6 (-24)]} 0 0
[junit4] 2> 1858456 WARN (recoveryExecutor-7429-thread-1) [ ] o.a.s.u.UpdateLog Starting log replay tlog{file=C:\Users\jenkins\workspace\Lucene-Solr-7.4-Windows\solr\build\solr-core\test\J1\temp\solr.search.TestRecovery_266A6FC4A1996F06-001\init-core-data-001\tlog\buffer.tlog.0000446712961934600 refcount=2} active=true starting pos=0 inSortedOrder=false
[junit4] 2> 1858978 INFO (recoveryExecutor-7429-thread-1) [ ] o.a.s.s.SolrIndexSearcher Opening [Searcher@3b955b[collection1] realtime]
[junit4] 2> 1858979 INFO (recoveryExecutor-7429-thread-1) [ ] o.a.s.s.SolrIndexSearcher Opening [Searcher@1cf6fc9[collection1] realtime]
[junit4] 2> 1858979 INFO (replayUpdatesExecutor-7420-thread-1) [ ] o.a.s.u.DirectUpdateHandler2 Reordered DBQs detected. Update=add{flags=a,_version_=21,id=B7} DBQs=[DBQ{version=25,q=id:B2 OR id:B8}]
[junit4] 2> 1859024 INFO (replayUpdatesExecutor-7420-thread-1) [ ] o.a.s.s.SolrIndexSearcher Opening [Searcher@605507[collection1] realtime]
[junit4] 2> 1859482 INFO (recoveryExecutor-7429-thread-1) [ ] o.a.s.u.DirectUpdateHandler2 start commit{flags=2,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4] 2> 1859482 INFO (recoveryExecutor-7429-thread-1) [ ] o.a.s.u.SolrIndexWriter Calling setCommitData with IW:org.apache.solr.update.SolrIndexWriter@ab1131 commitCommandVersion:0
[junit4] 2> 1859599 INFO (recoveryExecutor-7429-thread-1) [ ] o.a.s.s.SolrIndexSearcher Opening [Searcher@126ef3b[collection1] main]
[junit4] 2> 1859601 INFO (searcherExecutor-7427-thread-1) [ ] o.a.s.c.SolrCore [collection1] Registered new searcher Searcher@126ef3b[collection1] main{ExitableDirectoryReader(UninvertingDirectoryReader(Uninverting(_9(7.4.0):c2/1:delGen=1) Uninverting(_a(7.4.0):c4/2:delGen=1) Uninverting(_b(7.4.0):c1)))}
[junit4] 2> 1859601 INFO (recoveryExecutor-7429-thread-1) [ ] o.a.s.u.DirectUpdateHandler2 end_commit_flush
[junit4] 2> 1859601 INFO (recoveryExecutor-7429-thread-1) [ ] o.a.s.u.p.LogUpdateProcessorFactory [collection1] {add=[B3 (10), B4 (18), B6 (20), B5 (19), B8 (22), B7 (21)],delete=[B4 (-11), B5 (-12), B6 (-24)],deleteByQuery=id:B2 OR id:B8 (-25)} 0 1145
[junit4] 2> 1859601 INFO (recoveryExecutor-7429-thread-1) [ ] o.a.s.u.UpdateLog Re-computing max version from index after log re-play.
[junit4] 2> 1859603 WARN (recoveryExecutor-7429-thread-1) [ ] o.a.s.u.UpdateLog Log replay finished. recoveryInfo=RecoveryInfo{adds=6 deletes=3 deleteByQuery=1 errors=0 positionOfStart=0}
[junit4] 2> 1859604 INFO (TEST-TestRecovery.testBuffering-seed#[266A6FC4A1996F06]) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={q=*:*&fl=id,_version_&sort=id+asc&wt=xml} hits=4 status=0 QTime=0
[junit4] 2> 1859607 INFO (TEST-TestRecovery.testTruncatedLog-seed#[266A6FC4A1996F06]) [ ] o.a.s.u.DirectUpdateHandler2 [collection1] REMOVING ALL DOCUMENTS FROM INDEX
[junit4] 2> 1859607 INFO (TEST-TestRecovery.testTruncatedLog-seed#[266A6FC4A1996F06]) [ ] o.a.s.s.SolrIndexSearcher Opening [Searcher@ef4696[collection1] realtime]
[junit4] 2> 1859608 INFO (TEST-TestRecovery.testTruncatedLog-seed#[266A6FC4A1996F06]) [ ] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=null path=null params={_version_=-9223372036854775807&update.distrib=FROMLEADER&versions=true&wt=json&indent=true}{deleteByQuery=*:* (-9223372036854775807)} 0 0
[junit4] 2> 1859608 INFO (TEST-TestRecovery.testTruncatedLog-seed#[266A6FC4A1996F06]) [ ] o.a.s.u.DirectUpdateHandler2 start commit{_version_=1603648417756610560,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4] 2> 1859608 INFO (TEST-TestRecovery.testTruncatedLog-seed#[266A6FC4A1996F06]) [ ] o.a.s.u.SolrIndexWriter Calling setCommitData with IW:org.apache.solr.update.SolrIndexWriter@ab1131 commitCommandVersion:1603648417756610560
[junit4] 2> 1859616 INFO (TEST-TestRecovery.testTruncatedLog-seed#[266A6FC4A1996F06]) [ ] o.a.s.s.SolrIndexSearcher Opening [Searcher@14498f4[collection1] main]
[junit4] 2> 1859616 INFO (searcherExecutor-7427-thread-1) [ ] o.a.s.c.SolrCore [collection1] Registered new searcher Searcher@14498f4[collection1] main{ExitableDirectoryReader(UninvertingDirectoryReader())}
[junit4] 2> 1859616 INFO (TEST-TestRecovery.testTruncatedLog-seed#[266A6FC4A1996F06]) [ ] o.a.s.u.DirectUpdateHandler2 end_commit_flush
[junit4] 2> 1859622 INFO (TEST-TestRecovery.testTruncatedLog-seed#[266A6FC4A1996F06]) [ ] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=null path=null params={}{commit=} 0 13
[junit4] 2> 1859624 INFO (TEST-TestRecovery.testTruncatedLog-seed#[266A6FC4A1996F06]) [ ] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=null path=null params={}{add=[F1 (1603648417772339200)]} 0 1
[junit4] 2> 1859624 INFO (TEST-TestRecovery.testTruncatedLog-seed#[266A6FC4A1996F06]) [ ] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=null path=null params={}{add=[F2 (1603648417773387776)]} 0 0
[junit4] 2> 1859625 INFO (TEST-TestRecovery.testTruncatedLog-seed#[266A6FC4A1996F06]) [ ] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=null path=null params={}{add=[F3 (1603648417774436352)]} 0 0
[junit4] 2> 1859625 INFO (TEST-TestRecovery.testTruncatedLog-seed#[266A6FC4A1996F06]) [ ] o.a.s.c.CoreContainer Shutting down CoreContainer instance=28108897
[junit4] 2> 1859625 INFO (TEST-TestRecovery.testTruncatedLog-seed#[266A6FC4A1996F06]) [ ] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.node, tag=null
[junit4] 2> 1859625 INFO (TEST-TestRecovery.testTruncatedLog-seed#[266A6FC4A1996F06]) [ ] o.a.s.m.r.SolrJmxReporter Closing reporter [org.apache.solr.metrics.reporters.SolrJmxReporter@1684fde: rootName = null, domain = solr.node, service url = null, agent id = null] for registry solr.node / com.codahale.metrics.MetricRegistry@a9c690
[junit4] 2> 1859628 INFO (TEST-TestRecovery.testTruncatedLog-seed#[266A6FC4A1996F06]) [ ] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.jvm, tag=null
[junit4] 2> 1859628 INFO (TEST-TestRecovery.testTruncatedLog-seed#[266A6FC4A1996F06]) [ ] o.a.s.m.r.SolrJmxReporter Closing reporter [org.apache.solr.metrics.reporters.SolrJmxReporter@4cfb5d: rootName = null, domain = solr.jvm, service url = null, agent id = null] for registry solr.jvm / com.codahale.metrics.MetricRegistry@134ee37
[junit4] 2> 1859630 INFO (TEST-TestRecovery.testTruncatedLog-seed#[266A6FC4A1996F06]) [ ] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.jetty, tag=null
[junit4] 2> 1859630 INFO (TEST-TestRecovery.testTruncatedLog-seed#[266A6FC4A1996F06]) [ ] o.a.s.m.r.SolrJmxReporter Closing reporter [org.apache.solr.metrics.reporters.SolrJmxReporter@4deed4: rootName = null, domain = solr.jetty, service url = null, agent id = null] for registry solr.jetty / com.codahale.metrics.MetricRegistry@27da6
[junit4] 2> 1859631 INFO (coreCloseExecutor-7432-thread-1) [ x:collection1] o.a.s.c.SolrCore [collection1] CLOSING SolrCore org.apache.solr.core.SolrCore@19afc4c
[junit4] 2> 1859631 INFO (coreCloseExecutor-7432-thread-1) [ x:collection1] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.core.collection1, tag=19afc4c
[junit4] 2> 1859631 INFO (coreCloseExecutor-7432-thread-1) [ x:collection1] o.a.s.m.r.SolrJmxReporter Closing reporter [org.apache.solr.metrics.reporters.SolrJmxReporter@1a4f0e7: rootName = null, domain = solr.core.collection1, service url = null, agent id = null] for registry solr.core.collection1 / com.codahale.metrics.MetricRegistry@192eca0
[junit4] 2> 1859652 INFO (TEST-TestRecovery.testTruncatedLog-seed#[266A6FC4A1996F06]) [ ] o.a.s.c.SolrResourceLoader [null] Added 2 libs to classloader, from paths: [/C:/Users/jenkins/workspace/Lucene-Solr-7.4-Windows/solr/core/src/test-files/solr/collection1/lib, /C:/Users/jenkins/workspace/Lucene-Solr-7.4-Windows/solr/core/src/test-files/solr/collection1/lib/classes]
[junit4] 2> 1859731 INFO (TEST-TestRecovery.testTruncatedLog-seed#[266A6FC4A1996F06]) [ ] o.a.s.c.SolrConfig Using Lucene MatchVersion: 7.4.0
[junit4] 2> 1859737 INFO (TEST-TestRecovery.testTruncatedLog-seed#[266A6FC4A1996F06]) [ ] o.a.s.s.IndexSchema [null] Schema name=test
[junit4] 2> 1859785 INFO (TEST-TestRecovery.testTruncatedLog-seed#[266A6FC4A1996F06]) [ ] o.a.s.s.IndexSchema Loaded schema test/1.6 with uniqueid field id
[junit4] 2> 1861728 INFO (TEST-TestRecovery.testTruncatedLog-seed#[266A6FC4A1996F06]) [ ] o.a.s.c.TransientSolrCoreCacheDefault Allocating transient cache for 2147483647 transient cores
[junit4] 2> 1861728 INFO (TEST-TestRecovery.testTruncatedLog-seed#[266A6FC4A1996F06]) [ ] o.a.s.h.a.MetricsHistoryHandler No .system collection, keeping metrics history in memory.
[junit4] 2> 1861750 INFO (TEST-TestRecovery.testTruncatedLog-seed#[266A6FC4A1996F06]) [ ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr.node' (registry 'solr.node') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@999068
[junit4] 2> 1861756 INFO (TEST-TestRecovery.testTruncatedLog-seed#[266A6FC4A1996F06]) [ ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr.jvm' (registry 'solr.jvm') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@999068
[junit4] 2> 1861756 INFO (TEST-TestRecovery.testTruncatedLog-seed#[266A6FC4A1996F06]) [ ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr.jetty' (registry 'solr.jetty') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@999068
[junit4] 2> 1861759 INFO (coreLoadExecutor-7442-thread-1) [ x:collection1] o.a.s.c.SolrResourceLoader [null] Added 2 libs to classloader, from paths: [/C:/Users/jenkins/workspace/Lucene-Solr-7.4-Windows/solr/core/src/test-files/solr/collection1/lib, /C:/Users/jenkins/workspace/Lucene-Solr-7.4-Windows/solr/core/src/test-files/solr/collection1/lib/classes]
[junit4] 2> 1861811 INFO (coreLoadExecutor-7442-thread-1) [ x:collection1] o.a.s.c.SolrConfig Using Lucene MatchVersion: 7.4.0
[junit4] 2> 1861818 INFO (coreLoadExecutor-7442-thread-1) [ x:collection1] o.a.s.s.IndexSchema [collection1] Schema name=test
[junit4] 2> 1861871 INFO (coreLoadExecutor-7442-thread-1) [ x:collection1] o.a.s.s.IndexSchema Loaded schema test/1.6 with uniqueid field id
[junit4] 2> 1861878 INFO (coreLoadExecutor-7442-thread-1) [ x:collection1] o.a.s.c.CoreContainer Creating SolrCore 'collection1' using configuration from instancedir C:\Users\jenkins\workspace\Lucene-Solr-7.4-Windows\solr\core\src\test-files\solr\collection1, trusted=true
[junit4] 2> 1861879 INFO (coreLoadExecutor-7442-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@999068
[junit4] 2> 1861879 INFO (coreLoadExecutor-7442-thread-1) [ x:collection1] o.a.s.c.SolrCore solr.RecoveryStrategy.Builder
[junit4] 2> 1861879 INFO (coreLoadExecutor-7442-thread-1) [ x:collection1] o.a.s.c.SolrCore [[collection1] ] Opening new SolrCore at [C:\Users\jenkins\workspace\Lucene-Solr-7.4-Windows\solr\core\src\test-files\solr\collection1], dataDir=[C:\Users\jenkins\workspace\Lucene-Solr-7.4-Windows\solr\build\solr-core\test\J1\temp\solr.search.TestRecovery_266A6FC4A1996F06-001\init-core-data-001\]
[junit4] 2> 1861884 WARN (coreLoadExecutor-7442-thread-1) [ x:collection1] o.a.s.c.RequestHandlers INVALID paramSet a in requestHandler {type = requestHandler,name = /dump,class = DumpRequestHandler,attributes = {initParams=a, name=/dump, class=DumpRequestHandler},args = {defaults={a=A,b=B}}}
[junit4] 2> 1861971 INFO (coreLoadExecutor-7442-thread-1) [ x:collection1] o.a.s.u.UpdateHandler Using UpdateLog implementation: org.apache.solr.update.CdcrUpdateLog
[junit4] 2> 1861971 INFO (coreLoadExecutor-7442-thread-1) [ x:collection1] o.a.s.u.UpdateLog Initializing UpdateLog: dataDir= defaultSyncLevel=FLUSH numRecordsToKeep=100 maxNumLogsToKeep=10 numVersionBuckets=65536
[junit4] 2> 1861974 INFO (coreLoadExecutor-7442-thread-1) [ x:collection1] o.a.s.u.CommitTracker Hard AutoCommit: disabled
[junit4] 2> 1861974 INFO (coreLoadExecutor-7442-thread-1) [ x:collection1] o.a.s.u.CommitTracker Soft AutoCommit: disabled
[junit4] 2> 1861975 INFO (coreLoadExecutor-7442-thread-1) [ x:collection1] o.a.s.u.RandomMergePolicy RandomMergePolicy wrapping class org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: maxMergeAtOnce=44, maxMergeAtOnceExplicit=29, maxMergedSegmentMB=62.1201171875, floorSegmentMB=1.0625, forceMergeDeletesPctAllowed=18.25526037168861, segmentsPerTier=34.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.22628571333180184
[junit4] 2> 1861976 INFO (coreLoadExecutor-7442-thread-1) [ x:collection1] o.a.s.s.SolrIndexSearcher Opening [Searcher@14e3a88[collection1] main]
[junit4] 2> 1861977 WARN (coreLoadExecutor-7442-thread-1) [ x:collection1] o.a.s.r.ManagedResourceStorage Cannot write to config directory C:\Users\jenkins\workspace\Lucene-Solr-7.4-Windows\solr\core\src\test-files\solr\collection1\conf; switching to use InMemory storage instead.
[junit4] 2> 1861977 INFO (coreLoadExecutor-7442-thread-1) [ x:collection1] o.a.s.h.ReplicationHandler Commits will be reserved for 10000ms.
[junit4] 2> 1861978 INFO (searcherExecutor-7443-thread-1-processing-x:collection1) [ x:collection1] o.a.s.c.SolrCore [collection1] Registered new searcher Searcher@14e3a88[collection1] main{ExitableDirectoryReader(UninvertingDirectoryReader())}
[junit4] 2> 1861980 WARN (recoveryExecutor-7445-thread-1-processing-x:collection1) [ x:collection1] o.a.s.u.UpdateLog Starting log replay tlog{file=C:\Users\jenkins\workspace\Lucene-Solr-7.4-Windows\solr\build\solr-core\test\J1\temp\solr.search.TestRecovery_266A6FC4A1996F06-001\init-core-data-001\tlog\tlog.0000000000000000010.1603648417772339200 refcount=1} active=false starting pos=0 inSortedOrder=false
[junit4] 2> 1861982 INFO (recoveryExecutor-7445-thread-1-processing-x:collection1) [ x:collection1] o.a.s.u.UpdateLog Ignoring exception matching OutOfBoundsException
[junit4] 2> 1862482 INFO (recoveryExecutor-7445-thread-1-processing-x:collection1) [ x:collection1] o.a.s.u.DirectUpdateHandler2 start commit{flags=2,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4] 2> 1862482 INFO (recoveryExecutor-7445-thread-1-processing-x:collection1) [ x:collection1] o.a.s.u.SolrIndexWriter Calling setCommitData with IW:org.apache.solr.update.SolrIndexWriter@735232 commitCommandVersion:0
[junit4] 2> 1862540 INFO (recoveryExecutor-7445-thread-1-processing-x:collection1) [ x:collection1] o.a.s.s.SolrIndexSearcher Opening [Searcher@a2c4a0[collection1] main]
[junit4] 2> 1862541 INFO (recoveryExecutor-7445-thread-1-processing-x:collection1) [ x:collection1] o.a.s.u.DirectUpdateHandler2 end_commit_flush
[junit4] 2> 1862541 INFO (searcherExecutor-7443-thread-1-processing-x:collection1) [ x:collection1] o.a.s.c.SolrCore [collection1] Registered new searcher Searcher@a2c4a0[collection1] main{ExitableDirectoryReader(UninvertingDirectoryReader(Uninverting(_c(7.4.0):c3)))}
[junit4] 2> 1862542 INFO (recoveryExecutor-7445-thread-1-processing-x:collection1) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] {add=[F1 (1603648417772339200), F2 (1603648417773387776), F3 (1603648417774436352)]} 0 561
[junit4] 2> 1862542 WARN (recoveryExecutor-7445-thread-1-processing-x:collection1) [ x:collection1] o.a.s.u.UpdateLog Log replay finished. recoveryInfo=RecoveryInfo{adds=3 deletes=0 deleteByQuery=0 errors=0 positionOfStart=0}
[junit4] 2> 1862542 INFO (TEST-TestRecovery.testTruncatedLog-seed#[266A6FC4A1996F06]) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={q=*:*&wt=xml} hits=3 status=0 QTime=0
[junit4] 2> 1862544 INFO (TEST-TestRecovery.testTruncatedLog-seed#[266A6FC4A1996F06]) [ ] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=null path=null params={update.distrib=FROMLEADER&wt=json&indent=true}{add=[F4 (26)]} 0 2
[junit4] 2> 1862544 INFO (TEST-TestRecovery.testTruncatedLog-seed#[266A6FC4A1996F06]) [ ] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=null path=null params={update.distrib=FROMLEADER&wt=json&indent=true}{add=[F5 (27)]} 0 0
[junit4] 2> 1862545 INFO (TEST-TestRecovery.testTruncatedLog-seed#[266A6FC4A1996F06]) [ ] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=null path=null params={update.distrib=FROMLEADER&wt=json&indent=true}{add=[F6 (28)]} 0 0
[junit4] 2> 1862545 INFO (TEST-TestRecovery.testTruncatedLog-seed#[266A6FC4A1996F06]) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&getVersions=3&wt=xml} status=0 QTime=0
[junit4] 2> 1862550 INFO (TEST-TestRecovery.testLogReplay-seed#[266A6FC4A1996F06]) [ ] o.a.s.u.DirectUpdateHandler2 [collection1] REMOVING ALL DOCUMENTS FROM INDEX
[junit4] 2> 1862551 INFO (TEST-TestRecovery.testLogReplay-seed#[266A6FC4A1996F06]) [ ] o.a.s.s.SolrIndexSearcher Opening [Searcher@16b6765[collection1] realtime]
[junit4] 2> 1862551 INFO (TEST-TestRecovery.testLogReplay-seed#[266A6FC4A1996F06]) [ ] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=null path=null params={_version_=-9223372036854775807&update.distrib=FROMLEADER&versions=true&wt=json&indent=true}{deleteByQuery=*:* (-9223372036854775807)} 0 1
[junit4] 2> 1862551 INFO (TEST-TestRecovery.testLogReplay-seed#[266A6FC4A1996F06]) [ ] o.a.s.u.DirectUpdateHandler2 start commit{_version_=1603648420842569728,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4] 2> 1862551 INFO (TEST-TestRecovery.testLogReplay-seed#[266A6FC4A1996F06]) [ ] o.a.s.u.SolrIndexWriter Calling setCommitData with IW:org.apache.solr.update.SolrIndexWriter@735232 commitCommandVersion:1603648420842569728
[junit4] 2> 1862559 INFO (TEST-TestRecovery.testLogReplay-seed#[266A6FC4A1996F06]) [ ] o.a.s.s.SolrIndexSearcher Opening [Searcher@445edf[collection1] main]
[junit4] 2> 1862559 INFO (TEST-TestRecovery.testLogReplay-seed#[266A6FC4A1996F06]) [ ] o.a.s.u.DirectUpdateHandler2 end_commit_flush
[junit4] 2> 1862560 INFO (searcherExecutor-7443-thread-1) [ ] o.a.s.c.SolrCore [collection1] Registered new searcher Searcher@445edf[collection1] main{ExitableDirectoryReader(UninvertingDirectoryReader())}
[junit4] 2> 1862561 INFO (TEST-TestRecovery.testLogReplay-seed#[266A6FC4A1996F06]) [ ] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=null path=null params={}{commit=} 0 10
[junit4] 2> 1862564 INFO (TEST-TestRecovery.testLogReplay-seed#[266A6FC4A1996F06]) [ ] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=null path=null params={versions=true&wt=json&indent=true}{add=[A1 (1603648420853055488)]} 0 1
[junit4] 2> 1862564 INFO (TEST-TestRecovery.testLogReplay-seed#[266A6FC4A1996F06]) [ ] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=null path=null params={versions=true&wt=json&indent=true}{add=[A11 (1603648420856201216)]} 0 0
[junit4] 2> 1862564 INFO (TEST-TestRecovery.testLogReplay-seed#[266A6FC4A1996F06]) [ ] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=null path=null params={versions=true&wt=json&indent=true}{add=[A12 (1603648420856201217)]} 0 0
[junit4] 2> 1862570 INFO (TEST-TestRecovery.testLogReplay-seed#[266A6FC4A1996F06]) [ ] o.a.s.s.SolrIndexSearcher Opening [Searcher@3f34f1[collection1] realtime]
[junit4] 2> 1862571 INFO (TEST-TestRecovery.testLogReplay-seed#[266A6FC4A1996F06]) [ ] o.a.s.s.SolrIndexSearcher Opening [Searcher@1ce8bf5[collection1] realtime]
[junit4] 2> 1862571 INFO (TEST-TestRecovery.testLogReplay-seed#[266A6FC4A1996F06]) [ ] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=null path=null params={versions=true&wt=json&indent=true}{deleteByQuery=id:A11 (-1603648420856201218)} 0 7
[junit4] 2> 1862572 INFO (TEST-TestRecovery.testLogReplay-seed#[266A6FC4A1996F06]) [ ] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=null path=null params={versions=true&wt=json&indent=true}{add=[A13 (1603648420863541248)]} 0 0
[junit4] 2> 1862573 INFO (TEST-TestRecovery.testLogReplay-seed#[266A6FC4A1996F06]) [ ] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=null path=null params={versions=true&wt=json&indent=true}{add=[A12 (1603648420865638400)]} 0 0
[junit4] 2> 1862574 INFO (TEST-TestRecovery.testLogReplay-seed#[266A6FC4A1996F06]) [ ] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=null path=null params={versions=true&wt=json&indent=true}{add=[A12 (1603648420865638401)]} 0 0
[junit4] 2> 1862574 INFO (TEST-TestRecovery.testLogReplay-seed#[266A6FC4A1996F06]) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={q=*:*&wt=xml} hits=0 status=0 QTime=0
[junit4] 2> 1862574 INFO (TEST-TestRecovery.testLogReplay-seed#[266A6FC4A1996F06]) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/get&getVersions=7&wt=xml} status=0 QTime=0
[junit4] 2> 1862574 INFO (TEST-TestRecovery.testLogReplay-seed#[266A6FC4A1996F06]) [ ] o.a.s.c.CoreContainer Shutting down CoreContainer instance=29519569
[junit4] 2> 1862575 INFO (TEST-TestRecovery.testLogReplay-seed#[266A6FC4A1996F06]) [ ] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.node, tag=null
[junit4] 2> 1862575 INFO (TEST-TestRecovery.testLogReplay-seed#[266A6FC4A1996F06]) [ ] o.a.s.m.r.SolrJmxReporter Closing reporter [org.apache.solr.metrics.reporters.SolrJmxReporter@1b5d29f: rootName = null, domain = solr.node, service url = null, agent id = null] for registry solr.node / com.codahale.metrics.MetricRegistry@89282a
[junit4] 2> 1862578 INFO (TEST-TestRecovery.testLogReplay-seed#[266A6FC4A1996F06]) [ ] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.jvm, tag=null
[junit4] 2> 1862578 INFO (TEST-TestRecovery.testLogReplay-seed#[266A6FC4A1996F06]) [ ] o.a.s.m.r.SolrJmxReporter Closing reporter [org.apache.solr.metrics.reporters.SolrJmxReporter@1212300: rootName = null, domain = solr.jvm, service url = null, agent id = null] for registry solr.jvm / com.codahale.metrics.MetricRegistry@134ee37
[junit4] 2> 1862580 INFO (TEST-TestRecovery.testLogReplay-seed#[266A6FC4A1996F06]) [ ] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.jetty, tag=null
[junit4] 2> 1862580 INFO (TEST-TestRecovery.testLogReplay-seed#[266A6FC4A1996F06]) [ ] o.a.s.m.r.SolrJmxReporter Closing reporter [org.apache.solr.metrics.reporters.SolrJmxReporter@18fb202: rootName = null, domain = solr.jetty, service url = null, agent id = null] for registry solr.jetty / com.codahale.metrics.MetricRegistry@27da6
[junit4] 2> 1862581 INFO (coreCloseExecutor-7448-thread-1) [ x:collection1] o.a.s.c.SolrCore [collection1] CLOSING SolrCore org.apache.solr.core.SolrCore@1cf8ad1
[junit4] 2> 1862581 INFO (coreCloseExecutor-7448-thread-1) [ x:collection1] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.core.collection1, tag=1cf8ad1
[junit4] 2> 1862581 INFO (coreCloseExecutor-7448-thread-1) [ x:collection1] o.a.s.m.r.SolrJmxReporter Closing reporter [org.apache.solr.metrics.reporters.SolrJmxReporter@d72777: rootName = null, domain = solr.core.collection1, service url = null, agent id = null] for registry solr.core.collection1 / com.codahale.metrics.MetricRegistry@1f1d778
[junit4] 2> 1862592 INFO (TEST-TestRecovery.testLogReplay-seed#[266A6FC4A1996F06]) [ ] o.a.s.c.SolrResourceLoader [null] Added 2 libs to classloader, from paths: [/C:/Users/jenkins/workspace/Lucene-Solr-7.4-Windows/solr/core/src/test-files/solr/collection1/lib, /C:/Users/jenkins/workspace/Lucene-Solr-7.4-Windows/solr/core/src/test-files/solr/collection1/lib/classes]
[junit4] 2> 1862639 INFO (TEST-TestRecovery.testLogReplay-seed#[266A6FC4A1996F06]) [ ] o.a.s.c.SolrConfig Using Lucene MatchVersion: 7.4.0
[junit4] 2> 1862645 INFO (TEST-TestRecovery.testLogReplay-seed#[266A6FC4A1996F
[...truncated too long message...]
lang.Throwable.fillInStackTrace(Native Method)
[junit4] 2> at java.lang.Throwable.fillInStackTrace(Throwable.java:783)
[junit4] 2> at java.lang.Throwable.<init>(Throwable.java:250)
[junit4] 2> at java.lang.Exception.<init>(Exception.java:54)
[junit4] 2> at java.lang.InterruptedException.<init>(InterruptedException.java:57)
[junit4] 2> at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.awaitNanos(AbstractQueuedSynchronizer.java:2067)
[junit4] 2> at java.util.concurrent.ThreadPoolExecutor.awaitTermination(ThreadPoolExecutor.java:1475)
[junit4] 2> at org.apache.solr.common.util.ExecutorUtil.awaitTermination(ExecutorUtil.java:84)
[junit4] 2> at org.apache.solr.common.util.ExecutorUtil.shutdownAndAwaitTermination(ExecutorUtil.java:76)
[junit4] 2> at org.apache.solr.core.SolrCores.close(SolrCores.java:154)
[junit4] 2> at org.apache.solr.core.CoreContainer.shutdown(CoreContainer.java:884)
[junit4] 2> at org.apache.solr.util.TestHarness.close(TestHarness.java:384)
[junit4] 2> at org.apache.solr.SolrTestCaseJ4.deleteCore(SolrTestCaseJ4.java:801)
[junit4] 2> at org.apache.solr.SolrTestCaseJ4.teardownTestCases(SolrTestCaseJ4.java:296)
[junit4] 2> at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
[junit4] 2> at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
[junit4] 2> at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
[junit4] 2> at java.lang.reflect.Method.invoke(Method.java:498)
[junit4] 2> at com.carrotsearch.randomizedtesting.RandomizedRunner.invoke(RandomizedRunner.java:1737)
[junit4] 2> at com.carrotsearch.randomizedtesting.RandomizedRunner$7.evaluate(RandomizedRunner.java:897)
[junit4] 2> at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
[junit4] 2> at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:57)
[junit4] 2> at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:45)
[junit4] 2> at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
[junit4] 2> at org.apache.lucene.util.TestRuleStoreClassName$1.evaluate(TestRuleStoreClassName.java:41)
[junit4] 2> at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:40)
[junit4] 2> at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:40)
[junit4] 2> at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
[junit4] 2> at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
[junit4] 2> at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
[junit4] 2> at org.apache.lucene.util.TestRuleAssertionsRequired$1.evaluate(TestRuleAssertionsRequired.java:53)
[junit4] 2> at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:47)
[junit4] 2> at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:64)
[junit4] 2> at org.apache.lucene.util.TestRuleIgnoreTestSuites$1.evaluate(TestRuleIgnoreTestSuites.java:54)
[junit4] 2> at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
[junit4] 2> at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:368)
[junit4] 2> at java.lang.Thread.run(Thread.java:748)
[junit4] 2> 4) Thread[id=373, name=coreCloseExecutor-419-thread-1-processing-x:collection1, state=RUNNABLE, group=TGRP-TestRecovery]
[junit4] 2> at java.lang.Thread.interrupt0(Native Method)
[junit4] 2> at java.lang.Thread.interrupt(Thread.java:926)
[junit4] 2> at org.apache.solr.common.util.ExecutorUtil.awaitTermination(ExecutorUtil.java:87)
[junit4] 2> at org.apache.solr.common.util.ExecutorUtil.shutdownAndAwaitTermination(ExecutorUtil.java:76)
[junit4] 2> at org.apache.solr.update.UpdateLog.close(UpdateLog.java:1369)
[junit4] 2> at org.apache.solr.update.CdcrUpdateLog.close(CdcrUpdateLog.java:478)
[junit4] 2> at org.apache.solr.update.UpdateLog.close(UpdateLog.java:1342)
[junit4] 2> at org.apache.solr.update.DirectUpdateHandler2.closeWriter(DirectUpdateHandler2.java:908)
[junit4] 2> at org.apache.solr.update.DefaultSolrCoreState.closeIndexWriter(DefaultSolrCoreState.java:105)
[junit4] 2> at org.apache.solr.update.DefaultSolrCoreState.close(DefaultSolrCoreState.java:399)
[junit4] 2> at org.apache.solr.update.SolrCoreState.decrefSolrCoreState(SolrCoreState.java:83)
[junit4] 2> at org.apache.solr.core.SolrCore.close(SolrCore.java:1572)
[junit4] 2> at org.apache.solr.core.SolrCores.lambda$close$0(SolrCores.java:141)
[junit4] 2> at org.apache.solr.core.SolrCores$$Lambda$245/10432972.call(Unknown Source)
[junit4] 2> at java.util.concurrent.FutureTask.run(FutureTask.java:266)
[junit4] 2> at org.apache.solr.common.util.ExecutorUtil$MDCAwareThreadPoolExecutor.lambda$execute$0(ExecutorUtil.java:209)
[junit4] 2> at org.apache.solr.common.util.ExecutorUtil$MDCAwareThreadPoolExecutor$$Lambda$127/7453271.run(Unknown Source)
[junit4] 2> at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)
[junit4] 2> at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
[junit4] 2> at java.lang.Thread.run(Thread.java:748)
[junit4] 2> NOTE: test params are: codec=Asserting(Lucene70): {val_i=FST50, _root_=PostingsFormat(name=LuceneFixedGap), id=FST50}, docValues:{_version_=DocValuesFormat(name=Lucene70), val_i_dvo=DocValuesFormat(name=Direct), id=DocValuesFormat(name=Asserting)}, maxPointsInLeafNode=474, maxMBSortInHeap=5.05866993592645, sim=RandomSimilarity(queryNorm=true): {}, locale=nl, timezone=Pacific/Guadalcanal
[junit4] 2> NOTE: Windows 10 10.0 x86/Oracle Corporation 1.8.0_172 (32-bit)/cpus=3,threads=5,free=20005072,total=85417984
[junit4] 2> NOTE: All tests run in this JVM: [TestRecovery]
[junit4] 2> NOTE: reproduce with: ant test -Dtestcase=TestRecovery -Dtests.seed=266A6FC4A1996F06 -Dtests.slow=true -Dtests.badapples=true -Dtests.locale=nl -Dtests.timezone=Pacific/Guadalcanal -Dtests.asserts=true -Dtests.file.encoding=Cp1252
[junit4] ERROR 0.00s J1 | TestRecovery (suite) <<<
[junit4] > Throwable #1: java.lang.Exception: Suite timeout exceeded (>= 7200000 msec).
[junit4] > at __randomizedtesting.SeedInfo.seed([266A6FC4A1996F06]:0)
[junit4] Completed [8/10 (1!)] on J1 in 7285.96s, 20 tests, 1 failure, 1 error <<< FAILURES!
[...truncated 17 lines...]
BUILD FAILED
C:\Users\jenkins\workspace\Lucene-Solr-7.4-Windows\lucene\common-build.xml:1568: The following error occurred while executing this line:
C:\Users\jenkins\workspace\Lucene-Solr-7.4-Windows\lucene\common-build.xml:1092: There were test failures: 10 suites, 110 tests, 1 suite-level error, 1 failure, 40 ignored [seed: 266A6FC4A1996F06]
Total time: 121 minutes 30 seconds
[repro] Setting last failure code to 1
[repro] Failures:
[repro] 0/5 failed: org.apache.solr.cloud.TestCloudRecovery
[repro] 1/5 failed: org.apache.solr.search.TestRecovery
[repro] Exiting with code 1
C:\Users\jenkins\workspace\Lucene-Solr-7.4-Windows>IF EXIST lucene\build move /y lucene\build lucene\build.repro
1 dir(s) moved.
C:\Users\jenkins\workspace\Lucene-Solr-7.4-Windows>IF EXIST solr\build move /y solr\build solr\build.repro
1 dir(s) moved.
C:\Users\jenkins\workspace\Lucene-Solr-7.4-Windows>IF EXIST lucene\build.orig move /y lucene\build.orig lucene\build
1 dir(s) moved.
C:\Users\jenkins\workspace\Lucene-Solr-7.4-Windows>IF EXIST solr\build.orig move /y solr\build.orig solr\build
1 dir(s) moved.
C:\Users\jenkins\workspace\Lucene-Solr-7.4-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=9060ac689c270b02143f375de0348b7f626adebc, workspace=C:\Users\jenkins\workspace\Lucene-Solr-7.4-Windows
[WARNINGS] Computing warning deltas based on reference build #3
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