You are viewing a plain text version of this content. The canonical link for it is here.
Posted to builds@lucene.apache.org by Policeman Jenkins Server <je...@thetaphi.de> on 2020/07/09 10:25:58 UTC
[JENKINS] Lucene-Solr-8.x-Linux (32bit/jdk1.8.0_201) - Build # 3666
- Unstable!
Build: https://jenkins.thetaphi.de/job/Lucene-Solr-8.x-Linux/3666/
Java: 32bit/jdk1.8.0_201 -server -XX:+UseG1GC
2 tests failed.
FAILED: org.apache.solr.handler.export.TestExportWriter.testExpr
Error Message:
expected:<18000.0> but was:<20512.0>
Stack Trace:
java.lang.AssertionError: expected:<18000.0> but was:<20512.0>
at __randomizedtesting.SeedInfo.seed([5CAAEC8FBDE8C026:EA351DCF9D617D73]:0)
at org.junit.Assert.fail(Assert.java:88)
at org.junit.Assert.failNotEquals(Assert.java:834)
at org.junit.Assert.assertEquals(Assert.java:553)
at org.junit.Assert.assertEquals(Assert.java:683)
at org.apache.solr.handler.export.TestExportWriter.testExpr(TestExportWriter.java:770)
at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
at java.lang.reflect.Method.invoke(Method.java:498)
at com.carrotsearch.randomizedtesting.RandomizedRunner.invoke(RandomizedRunner.java:1750)
at com.carrotsearch.randomizedtesting.RandomizedRunner$8.evaluate(RandomizedRunner.java:938)
at com.carrotsearch.randomizedtesting.RandomizedRunner$9.evaluate(RandomizedRunner.java:974)
at com.carrotsearch.randomizedtesting.RandomizedRunner$10.evaluate(RandomizedRunner.java:988)
at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:57)
at org.apache.lucene.util.TestRuleSetupTeardownChained$1.evaluate(TestRuleSetupTeardownChained.java:49)
at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:45)
at org.apache.lucene.util.TestRuleThreadAndTestName$1.evaluate(TestRuleThreadAndTestName.java:48)
at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:64)
at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:47)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:368)
at com.carrotsearch.randomizedtesting.ThreadLeakControl.forkTimeoutingTask(ThreadLeakControl.java:817)
at com.carrotsearch.randomizedtesting.ThreadLeakControl$3.evaluate(ThreadLeakControl.java:468)
at com.carrotsearch.randomizedtesting.RandomizedRunner.runSingleTest(RandomizedRunner.java:947)
at com.carrotsearch.randomizedtesting.RandomizedRunner$5.evaluate(RandomizedRunner.java:832)
at com.carrotsearch.randomizedtesting.RandomizedRunner$6.evaluate(RandomizedRunner.java:883)
at com.carrotsearch.randomizedtesting.RandomizedRunner$7.evaluate(RandomizedRunner.java:894)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:57)
at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:45)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at org.apache.lucene.util.TestRuleStoreClassName$1.evaluate(TestRuleStoreClassName.java:41)
at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:40)
at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:40)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at org.apache.lucene.util.TestRuleAssertionsRequired$1.evaluate(TestRuleAssertionsRequired.java:53)
at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:47)
at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:64)
at org.apache.lucene.util.TestRuleIgnoreTestSuites$1.evaluate(TestRuleIgnoreTestSuites.java:54)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:368)
at java.lang.Thread.run(Thread.java:748)
FAILED: org.apache.solr.handler.export.TestExportWriter.testExpr
Error Message:
expected:<18000.0> but was:<20512.0>
Stack Trace:
java.lang.AssertionError: expected:<18000.0> but was:<20512.0>
at __randomizedtesting.SeedInfo.seed([5CAAEC8FBDE8C026:EA351DCF9D617D73]:0)
at org.junit.Assert.fail(Assert.java:88)
at org.junit.Assert.failNotEquals(Assert.java:834)
at org.junit.Assert.assertEquals(Assert.java:553)
at org.junit.Assert.assertEquals(Assert.java:683)
at org.apache.solr.handler.export.TestExportWriter.testExpr(TestExportWriter.java:770)
at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
at java.lang.reflect.Method.invoke(Method.java:498)
at com.carrotsearch.randomizedtesting.RandomizedRunner.invoke(RandomizedRunner.java:1750)
at com.carrotsearch.randomizedtesting.RandomizedRunner$8.evaluate(RandomizedRunner.java:938)
at com.carrotsearch.randomizedtesting.RandomizedRunner$9.evaluate(RandomizedRunner.java:974)
at com.carrotsearch.randomizedtesting.RandomizedRunner$10.evaluate(RandomizedRunner.java:988)
at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:57)
at org.apache.lucene.util.TestRuleSetupTeardownChained$1.evaluate(TestRuleSetupTeardownChained.java:49)
at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:45)
at org.apache.lucene.util.TestRuleThreadAndTestName$1.evaluate(TestRuleThreadAndTestName.java:48)
at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:64)
at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:47)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:368)
at com.carrotsearch.randomizedtesting.ThreadLeakControl.forkTimeoutingTask(ThreadLeakControl.java:817)
at com.carrotsearch.randomizedtesting.ThreadLeakControl$3.evaluate(ThreadLeakControl.java:468)
at com.carrotsearch.randomizedtesting.RandomizedRunner.runSingleTest(RandomizedRunner.java:947)
at com.carrotsearch.randomizedtesting.RandomizedRunner$5.evaluate(RandomizedRunner.java:832)
at com.carrotsearch.randomizedtesting.RandomizedRunner$6.evaluate(RandomizedRunner.java:883)
at com.carrotsearch.randomizedtesting.RandomizedRunner$7.evaluate(RandomizedRunner.java:894)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:57)
at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:45)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at org.apache.lucene.util.TestRuleStoreClassName$1.evaluate(TestRuleStoreClassName.java:41)
at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:40)
at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:40)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at org.apache.lucene.util.TestRuleAssertionsRequired$1.evaluate(TestRuleAssertionsRequired.java:53)
at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:47)
at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:64)
at org.apache.lucene.util.TestRuleIgnoreTestSuites$1.evaluate(TestRuleIgnoreTestSuites.java:54)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:368)
at java.lang.Thread.run(Thread.java:748)
Build Log:
[...truncated 13438 lines...]
[junit4] Suite: org.apache.solr.handler.export.TestExportWriter
[junit4] 2> 8448 INFO (SUITE-TestExportWriter-seed#[5CAAEC8FBDE8C026]-worker) [ ] o.a.s.SolrTestCase Setting 'solr.default.confdir' system property to test-framework derived value of '/home/jenkins/workspace/Lucene-Solr-8.x-Linux/solr/server/solr/configsets/_default/conf'
[junit4] 2> 8449 INFO (SUITE-TestExportWriter-seed#[5CAAEC8FBDE8C026]-worker) [ ] o.a.s.SolrTestCaseJ4 Created dataDir: /home/jenkins/workspace/Lucene-Solr-8.x-Linux/solr/build/solr-core/test/J3/temp/solr.handler.export.TestExportWriter_5CAAEC8FBDE8C026-001/data-dir-2-001
[junit4] 2> 8449 WARN (SUITE-TestExportWriter-seed#[5CAAEC8FBDE8C026]-worker) [ ] o.a.s.SolrTestCaseJ4 startTrackingSearchers: numOpens=1 numCloses=1
[junit4] 2> 8450 INFO (SUITE-TestExportWriter-seed#[5CAAEC8FBDE8C026]-worker) [ ] o.a.s.SolrTestCaseJ4 Using PointFields (NUMERIC_POINTS_SYSPROP=true) w/NUMERIC_DOCVALUES_SYSPROP=true
[junit4] 2> 8451 INFO (SUITE-TestExportWriter-seed#[5CAAEC8FBDE8C026]-worker) [ ] o.a.s.SolrTestCaseJ4 Randomized ssl (true) and clientAuth (true) via: @org.apache.solr.util.RandomizeSSL(reason=, ssl=NaN, value=NaN, clientAuth=NaN)
[junit4] 2> 8499 INFO (SUITE-TestExportWriter-seed#[5CAAEC8FBDE8C026]-worker) [ ] o.a.s.SolrTestCaseJ4 SecureRandom sanity checks: test.solr.allowed.securerandom=null & java.security.egd=file:/dev/./urandom
[junit4] 2> 8500 INFO (SUITE-TestExportWriter-seed#[5CAAEC8FBDE8C026]-worker) [ ] o.a.s.SolrTestCaseJ4 ####initCore
[junit4] 2> 8513 INFO (SUITE-TestExportWriter-seed#[5CAAEC8FBDE8C026]-worker) [ ] o.a.s.c.SolrConfig Using Lucene MatchVersion: 8.7.0
[junit4] 2> 8577 INFO (SUITE-TestExportWriter-seed#[5CAAEC8FBDE8C026]-worker) [ ] o.a.s.s.IndexSchema Schema name=schema-docValuesMulti
[junit4] 2> 8899 INFO (SUITE-TestExportWriter-seed#[5CAAEC8FBDE8C026]-worker) [ ] o.a.s.s.IndexSchema Loaded schema schema-docValuesMulti/1.6 with uniqueid field id
[junit4] 2> 8903 INFO (SUITE-TestExportWriter-seed#[5CAAEC8FBDE8C026]-worker) [ ] o.a.s.c.SolrPaths Using system property solr.solr.home: /home/jenkins/workspace/Lucene-Solr-8.x-Linux/solr/core/src/test-files/solr
[junit4] 2> 9812 WARN (SUITE-TestExportWriter-seed#[5CAAEC8FBDE8C026]-worker) [ ] o.a.s.c.CoreContainer Unable to create [/home/jenkins/workspace/Lucene-Solr-8.x-Linux/solr/core/src/test-files/solr/userfiles]. Features requiring this directory may fail.
[junit4] 2> => java.security.AccessControlException: access denied ("java.io.FilePermission" "/home/jenkins/workspace/Lucene-Solr-8.x-Linux/solr/core/src/test-files/solr/userfiles" "write")
[junit4] 2> at java.security.AccessControlContext.checkPermission(AccessControlContext.java:472)
[junit4] 2> java.security.AccessControlException: access denied ("java.io.FilePermission" "/home/jenkins/workspace/Lucene-Solr-8.x-Linux/solr/core/src/test-files/solr/userfiles" "write")
[junit4] 2> at java.security.AccessControlContext.checkPermission(AccessControlContext.java:472) ~[?:1.8.0_201]
[junit4] 2> at java.security.AccessController.checkPermission(AccessController.java:884) ~[?:1.8.0_201]
[junit4] 2> at java.lang.SecurityManager.checkPermission(SecurityManager.java:549) ~[?:1.8.0_201]
[junit4] 2> at java.lang.SecurityManager.checkWrite(SecurityManager.java:979) ~[?:1.8.0_201]
[junit4] 2> at sun.nio.fs.UnixPath.checkWrite(UnixPath.java:801) ~[?:?]
[junit4] 2> at sun.nio.fs.UnixFileSystemProvider.createDirectory(UnixFileSystemProvider.java:376) ~[?:?]
[junit4] 2> at java.nio.file.Files.createDirectory(Files.java:674) ~[?:1.8.0_201]
[junit4] 2> at java.nio.file.Files.createAndCheckIsDirectory(Files.java:781) ~[?:1.8.0_201]
[junit4] 2> at java.nio.file.Files.createDirectories(Files.java:727) ~[?:1.8.0_201]
[junit4] 2> at org.apache.solr.core.CoreContainer.<init>(CoreContainer.java:366) [java/:?]
[junit4] 2> at org.apache.solr.core.CoreContainer.<init>(CoreContainer.java:331) [java/:?]
[junit4] 2> at org.apache.solr.util.TestHarness.<init>(TestHarness.java:169) [java/:?]
[junit4] 2> at org.apache.solr.util.TestHarness.<init>(TestHarness.java:142) [java/:?]
[junit4] 2> at org.apache.solr.util.TestHarness.<init>(TestHarness.java:148) [java/:?]
[junit4] 2> at org.apache.solr.util.TestHarness.<init>(TestHarness.java:111) [java/:?]
[junit4] 2> at org.apache.solr.SolrTestCaseJ4.createCore(SolrTestCaseJ4.java:816) [java/:?]
[junit4] 2> at org.apache.solr.SolrTestCaseJ4.initCore(SolrTestCaseJ4.java:806) [java/:?]
[junit4] 2> at org.apache.solr.SolrTestCaseJ4.initCore(SolrTestCaseJ4.java:667) [java/:?]
[junit4] 2> at org.apache.solr.SolrTestCaseJ4.initCore(SolrTestCaseJ4.java:656) [java/:?]
[junit4] 2> at org.apache.solr.handler.export.TestExportWriter.beforeClass(TestExportWriter.java:54) [test/:?]
[junit4] 2> at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method) ~[?:1.8.0_201]
[junit4] 2> at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62) ~[?:1.8.0_201]
[junit4] 2> at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) ~[?:1.8.0_201]
[junit4] 2> at java.lang.reflect.Method.invoke(Method.java:498) ~[?:1.8.0_201]
[junit4] 2> at com.carrotsearch.randomizedtesting.RandomizedRunner.invoke(RandomizedRunner.java:1750) [randomizedtesting-runner-2.7.2.jar:?]
[junit4] 2> at com.carrotsearch.randomizedtesting.RandomizedRunner$6.evaluate(RandomizedRunner.java:878) [randomizedtesting-runner-2.7.2.jar:?]
[junit4] 2> at com.carrotsearch.randomizedtesting.RandomizedRunner$7.evaluate(RandomizedRunner.java:894) [randomizedtesting-runner-2.7.2.jar:?]
[junit4] 2> at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36) [randomizedtesting-runner-2.7.2.jar:?]
[junit4] 2> at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:57) [randomizedtesting-runner-2.7.2.jar:?]
[junit4] 2> at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:45) [java/:?]
[junit4] 2> at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36) [randomizedtesting-runner-2.7.2.jar:?]
[junit4] 2> at org.apache.lucene.util.TestRuleStoreClassName$1.evaluate(TestRuleStoreClassName.java:41) [java/:?]
[junit4] 2> at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:40) [randomizedtesting-runner-2.7.2.jar:?]
[junit4] 2> at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:40) [randomizedtesting-runner-2.7.2.jar:?]
[junit4] 2> at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36) [randomizedtesting-runner-2.7.2.jar:?]
[junit4] 2> at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36) [randomizedtesting-runner-2.7.2.jar:?]
[junit4] 2> at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36) [randomizedtesting-runner-2.7.2.jar:?]
[junit4] 2> at org.apache.lucene.util.TestRuleAssertionsRequired$1.evaluate(TestRuleAssertionsRequired.java:53) [java/:?]
[junit4] 2> at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:47) [java/:?]
[junit4] 2> at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:64) [java/:?]
[junit4] 2> at org.apache.lucene.util.TestRuleIgnoreTestSuites$1.evaluate(TestRuleIgnoreTestSuites.java:54) [java/:?]
[junit4] 2> at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36) [randomizedtesting-runner-2.7.2.jar:?]
[junit4] 2> at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:368) [randomizedtesting-runner-2.7.2.jar:?]
[junit4] 2> at java.lang.Thread.run(Thread.java:748) [?:1.8.0_201]
[junit4] 2> 9821 WARN (SUITE-TestExportWriter-seed#[5CAAEC8FBDE8C026]-worker) [ ] o.a.s.f.DistribPackageStore Unable to create [/home/jenkins/workspace/Lucene-Solr-8.x-Linux/solr/core/src/test-files/solr/filestore] directory in SOLR_HOME [/home/jenkins/workspace/Lucene-Solr-8.x-Linux/solr/core/src/test-files/solr]. Features requiring this directory may fail.
[junit4] 2> => java.security.AccessControlException: access denied ("java.io.FilePermission" "/home/jenkins/workspace/Lucene-Solr-8.x-Linux/solr/core/src/test-files/solr/filestore" "write")
[junit4] 2> at java.security.AccessControlContext.checkPermission(AccessControlContext.java:472)
[junit4] 2> java.security.AccessControlException: access denied ("java.io.FilePermission" "/home/jenkins/workspace/Lucene-Solr-8.x-Linux/solr/core/src/test-files/solr/filestore" "write")
[junit4] 2> at java.security.AccessControlContext.checkPermission(AccessControlContext.java:472) ~[?:1.8.0_201]
[junit4] 2> at java.security.AccessController.checkPermission(AccessController.java:884) ~[?:1.8.0_201]
[junit4] 2> at java.lang.SecurityManager.checkPermission(SecurityManager.java:549) ~[?:1.8.0_201]
[junit4] 2> at java.lang.SecurityManager.checkWrite(SecurityManager.java:979) ~[?:1.8.0_201]
[junit4] 2> at java.io.File.mkdir(File.java:1311) ~[?:1.8.0_201]
[junit4] 2> at java.io.File.mkdirs(File.java:1343) ~[?:1.8.0_201]
[junit4] 2> at org.apache.solr.filestore.DistribPackageStore.ensurePackageStoreDir(DistribPackageStore.java:523) [java/:?]
[junit4] 2> at org.apache.solr.filestore.DistribPackageStore.<init>(DistribPackageStore.java:77) [java/:?]
[junit4] 2> at org.apache.solr.filestore.PackageStoreAPI.<init>(PackageStoreAPI.java:78) [java/:?]
[junit4] 2> at org.apache.solr.core.CoreContainer.load(CoreContainer.java:667) [java/:?]
[junit4] 2> at org.apache.solr.util.TestHarness.<init>(TestHarness.java:170) [java/:?]
[junit4] 2> at org.apache.solr.util.TestHarness.<init>(TestHarness.java:142) [java/:?]
[junit4] 2> at org.apache.solr.util.TestHarness.<init>(TestHarness.java:148) [java/:?]
[junit4] 2> at org.apache.solr.util.TestHarness.<init>(TestHarness.java:111) [java/:?]
[junit4] 2> at org.apache.solr.SolrTestCaseJ4.createCore(SolrTestCaseJ4.java:816) [java/:?]
[junit4] 2> at org.apache.solr.SolrTestCaseJ4.initCore(SolrTestCaseJ4.java:806) [java/:?]
[junit4] 2> at org.apache.solr.SolrTestCaseJ4.initCore(SolrTestCaseJ4.java:667) [java/:?]
[junit4] 2> at org.apache.solr.SolrTestCaseJ4.initCore(SolrTestCaseJ4.java:656) [java/:?]
[junit4] 2> at org.apache.solr.handler.export.TestExportWriter.beforeClass(TestExportWriter.java:54) [test/:?]
[junit4] 2> at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method) ~[?:1.8.0_201]
[junit4] 2> at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62) ~[?:1.8.0_201]
[junit4] 2> at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) ~[?:1.8.0_201]
[junit4] 2> at java.lang.reflect.Method.invoke(Method.java:498) ~[?:1.8.0_201]
[junit4] 2> at com.carrotsearch.randomizedtesting.RandomizedRunner.invoke(RandomizedRunner.java:1750) [randomizedtesting-runner-2.7.2.jar:?]
[junit4] 2> at com.carrotsearch.randomizedtesting.RandomizedRunner$6.evaluate(RandomizedRunner.java:878) [randomizedtesting-runner-2.7.2.jar:?]
[junit4] 2> at com.carrotsearch.randomizedtesting.RandomizedRunner$7.evaluate(RandomizedRunner.java:894) [randomizedtesting-runner-2.7.2.jar:?]
[junit4] 2> at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36) [randomizedtesting-runner-2.7.2.jar:?]
[junit4] 2> at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:57) [randomizedtesting-runner-2.7.2.jar:?]
[junit4] 2> at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:45) [java/:?]
[junit4] 2> at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36) [randomizedtesting-runner-2.7.2.jar:?]
[junit4] 2> at org.apache.lucene.util.TestRuleStoreClassName$1.evaluate(TestRuleStoreClassName.java:41) [java/:?]
[junit4] 2> at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:40) [randomizedtesting-runner-2.7.2.jar:?]
[junit4] 2> at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:40) [randomizedtesting-runner-2.7.2.jar:?]
[junit4] 2> at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36) [randomizedtesting-runner-2.7.2.jar:?]
[junit4] 2> at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36) [randomizedtesting-runner-2.7.2.jar:?]
[junit4] 2> at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36) [randomizedtesting-runner-2.7.2.jar:?]
[junit4] 2> at org.apache.lucene.util.TestRuleAssertionsRequired$1.evaluate(TestRuleAssertionsRequired.java:53) [java/:?]
[junit4] 2> at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:47) [java/:?]
[junit4] 2> at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:64) [java/:?]
[junit4] 2> at org.apache.lucene.util.TestRuleIgnoreTestSuites$1.evaluate(TestRuleIgnoreTestSuites.java:54) [java/:?]
[junit4] 2> at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36) [randomizedtesting-runner-2.7.2.jar:?]
[junit4] 2> at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:368) [randomizedtesting-runner-2.7.2.jar:?]
[junit4] 2> at java.lang.Thread.run(Thread.java:748) [?:1.8.0_201]
[junit4] 2> 9825 INFO (SUITE-TestExportWriter-seed#[5CAAEC8FBDE8C026]-worker) [ ] o.a.s.h.c.HttpShardHandlerFactory Host whitelist initialized: WhitelistHostChecker [whitelistHosts=null, whitelistHostCheckingEnabled=true]
[junit4] 2> 9827 WARN (SUITE-TestExportWriter-seed#[5CAAEC8FBDE8C026]-worker) [ ] o.a.s.c.s.i.Http2SolrClient Create Http2SolrClient with HTTP/1.1 transport since Java 8 or lower versions does not support SSL + HTTP/2
[junit4] 2> 9841 WARN (SUITE-TestExportWriter-seed#[5CAAEC8FBDE8C026]-worker) [ ] o.e.j.u.s.S.config Trusting all certificates configured for Client@1d47e75[provider=null,keyStore=null,trustStore=null]
[junit4] 2> 9841 WARN (SUITE-TestExportWriter-seed#[5CAAEC8FBDE8C026]-worker) [ ] o.e.j.u.s.S.config No Client EndPointIdentificationAlgorithm configured for Client@1d47e75[provider=null,keyStore=null,trustStore=null]
[junit4] 2> 9863 WARN (SUITE-TestExportWriter-seed#[5CAAEC8FBDE8C026]-worker) [ ] o.a.s.c.s.i.Http2SolrClient Create Http2SolrClient with HTTP/1.1 transport since Java 8 or lower versions does not support SSL + HTTP/2
[junit4] 2> 9865 WARN (SUITE-TestExportWriter-seed#[5CAAEC8FBDE8C026]-worker) [ ] o.e.j.u.s.S.config Trusting all certificates configured for Client@8082a3[provider=null,keyStore=null,trustStore=null]
[junit4] 2> 9865 WARN (SUITE-TestExportWriter-seed#[5CAAEC8FBDE8C026]-worker) [ ] o.e.j.u.s.S.config No Client EndPointIdentificationAlgorithm configured for Client@8082a3[provider=null,keyStore=null,trustStore=null]
[junit4] 2> 9867 WARN (SUITE-TestExportWriter-seed#[5CAAEC8FBDE8C026]-worker) [ ] o.a.s.c.CoreContainer Not all security plugins configured! authentication=disabled authorization=disabled. Solr is only as secure as you make it. Consider configuring authentication/authorization before exposing Solr to users internal or external. See https://s.apache.org/solrsecurity for more info
[junit4] 2> 9889 INFO (SUITE-TestExportWriter-seed#[5CAAEC8FBDE8C026]-worker) [ ] o.a.s.c.TransientSolrCoreCacheDefault Allocating transient cache for 2147483647 transient cores
[junit4] 2> 9889 INFO (SUITE-TestExportWriter-seed#[5CAAEC8FBDE8C026]-worker) [ ] o.a.s.h.a.MetricsHistoryHandler No .system collection, keeping metrics history in memory.
[junit4] 2> 9926 INFO (SUITE-TestExportWriter-seed#[5CAAEC8FBDE8C026]-worker) [ ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr.node' (registry 'solr.node') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@d43e6
[junit4] 2> 9935 INFO (SUITE-TestExportWriter-seed#[5CAAEC8FBDE8C026]-worker) [ ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr.jvm' (registry 'solr.jvm') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@d43e6
[junit4] 2> 9935 INFO (SUITE-TestExportWriter-seed#[5CAAEC8FBDE8C026]-worker) [ ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr.jetty' (registry 'solr.jetty') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@d43e6
[junit4] 2> 9958 INFO (coreLoadExecutor-37-thread-1) [ x:collection1 ] o.a.s.c.SolrConfig Using Lucene MatchVersion: 8.7.0
[junit4] 2> 10006 INFO (coreLoadExecutor-37-thread-1) [ x:collection1 ] o.a.s.s.IndexSchema Schema name=schema-docValuesMulti
[junit4] 2> 10057 INFO (coreLoadExecutor-37-thread-1) [ x:collection1 ] o.a.s.s.IndexSchema Loaded schema schema-docValuesMulti/1.6 with uniqueid field id
[junit4] 2> 10057 INFO (coreLoadExecutor-37-thread-1) [ x:collection1 ] o.a.s.c.CoreContainer Creating SolrCore 'collection1' using configuration from instancedir /home/jenkins/workspace/Lucene-Solr-8.x-Linux/solr/core/src/test-files/solr/collection1, trusted=true
[junit4] 2> 10057 INFO (coreLoadExecutor-37-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@d43e6
[junit4] 2> 10057 INFO (coreLoadExecutor-37-thread-1) [ x:collection1 ] o.a.s.c.SolrCore [[collection1] ] Opening new SolrCore at [/home/jenkins/workspace/Lucene-Solr-8.x-Linux/solr/core/src/test-files/solr/collection1], dataDir=[/home/jenkins/workspace/Lucene-Solr-8.x-Linux/solr/build/solr-core/test/J3/temp/solr.handler.export.TestExportWriter_5CAAEC8FBDE8C026-001/data-dir-2-001/]
[junit4] 2> 10110 INFO (coreLoadExecutor-37-thread-1) [ x:collection1 ] o.a.s.u.CommitTracker Hard AutoCommit: disabled
[junit4] 2> 10116 INFO (coreLoadExecutor-37-thread-1) [ x:collection1 ] o.a.s.u.CommitTracker Soft AutoCommit: disabled
[junit4] 2> 10120 WARN (coreLoadExecutor-37-thread-1) [ x:collection1 ] o.a.s.r.ManagedResourceStorage Cannot write to config directory /home/jenkins/workspace/Lucene-Solr-8.x-Linux/solr/core/src/test-files/solr/collection1/conf ; switching to use InMemory storage instead.
[junit4] 2> 10127 INFO (coreLoadExecutor-37-thread-1) [ x:collection1 ] o.a.s.h.ReplicationHandler Commits will be reserved for 10000 ms
[junit4] 2> 10129 INFO (searcherExecutor-39-thread-1-processing-x:collection1) [ x:collection1 ] o.a.s.c.SolrCore [collection1] Registered new searcher autowarm time: 0 ms
[junit4] 2> 10129 INFO (SUITE-TestExportWriter-seed#[5CAAEC8FBDE8C026]-worker) [ ] o.a.s.SolrTestCaseJ4 ####initCore end
[junit4] 2> 10133 INFO (TEST-TestExportWriter.testSortingOnFieldWithNoValues-seed#[5CAAEC8FBDE8C026]) [ ] o.a.s.SolrTestCaseJ4 ###Starting testSortingOnFieldWithNoValues
[junit4] 2> 10240 INFO (TEST-TestExportWriter.testSortingOnFieldWithNoValues-seed#[5CAAEC8FBDE8C026]) [ x:collection1 ] o.a.s.u.DirectUpdateHandler2 [collection1] REMOVING ALL DOCUMENTS FROM INDEX
[junit4] 2> 10243 INFO (TEST-TestExportWriter.testSortingOnFieldWithNoValues-seed#[5CAAEC8FBDE8C026]) [ x:collection1 ] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=null path=null params={}{deleteByQuery=*:*} 0 107
[junit4] 2> 10258 INFO (searcherExecutor-39-thread-1-processing-x:collection1) [ x:collection1 ] o.a.s.c.SolrCore [collection1] Registered new searcher autowarm time: 0 ms
[junit4] 2> 10259 INFO (TEST-TestExportWriter.testSortingOnFieldWithNoValues-seed#[5CAAEC8FBDE8C026]) [ x:collection1 ] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=null path=null params={}{commit=} 0 7
[junit4] 2> 10260 INFO (TEST-TestExportWriter.testSortingOnFieldWithNoValues-seed#[5CAAEC8FBDE8C026]) [ x:collection1 ] o.a.s.u.DirectUpdateHandler2 [collection1] REMOVING ALL DOCUMENTS FROM INDEX
[junit4] 2> 10261 INFO (TEST-TestExportWriter.testSortingOnFieldWithNoValues-seed#[5CAAEC8FBDE8C026]) [ x:collection1 ] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=null path=null params={}{deleteByQuery=*:*} 0 0
[junit4] 2> 10265 INFO (searcherExecutor-39-thread-1-processing-x:collection1) [ x:collection1 ] o.a.s.c.SolrCore [collection1] Registered new searcher autowarm time: 0 ms
[junit4] 2> 10265 INFO (TEST-TestExportWriter.testSortingOnFieldWithNoValues-seed#[5CAAEC8FBDE8C026]) [ x:collection1 ] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=null path=null params={}{commit=} 0 4
[junit4] 2> 10417 INFO (TEST-TestExportWriter.testSortingOnFieldWithNoValues-seed#[5CAAEC8FBDE8C026]) [ x:collection1 ] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=null path=null params={}{add=[1]} 0 150
[junit4] 2> 10653 INFO (searcherExecutor-39-thread-1-processing-x:collection1) [ x:collection1 ] o.a.s.c.SolrCore [collection1] Registered new searcher autowarm time: 0 ms
[junit4] 2> 10653 INFO (TEST-TestExportWriter.testSortingOnFieldWithNoValues-seed#[5CAAEC8FBDE8C026]) [ x:collection1 ] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=null path=null params={}{commit=} 0 234
[junit4] 2> 10717 INFO (TEST-TestExportWriter.testSortingOnFieldWithNoValues-seed#[5CAAEC8FBDE8C026]) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={q=*:*&qt=/export&fl=id,floatdv&sort=floatdv+desc&wt=xml} hits=1 status=0 QTime=62
[junit4] 2> 10750 INFO (TEST-TestExportWriter.testSortingOnFieldWithNoValues-seed#[5CAAEC8FBDE8C026]) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={q=*:*&qt=/export&fl=id,intdv&sort=intdv+desc&wt=xml} hits=1 status=0 QTime=1
[junit4] 2> 10755 INFO (TEST-TestExportWriter.testSortingOnFieldWithNoValues-seed#[5CAAEC8FBDE8C026]) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={q=*:*&qt=/export&fl=id,stringdv&sort=stringdv+desc&wt=xml} hits=1 status=0 QTime=0
[junit4] 2> 10761 INFO (TEST-TestExportWriter.testSortingOnFieldWithNoValues-seed#[5CAAEC8FBDE8C026]) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={q=*:*&qt=/export&fl=id,longdv&sort=longdv+desc&wt=xml} hits=1 status=0 QTime=0
[junit4] 2> 10764 INFO (TEST-TestExportWriter.testSortingOnFieldWithNoValues-seed#[5CAAEC8FBDE8C026]) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={q=*:*&qt=/export&fl=id,doubledv&sort=doubledv+desc&wt=xml} hits=1 status=0 QTime=0
[junit4] 2> 10777 INFO (TEST-TestExportWriter.testSortingOnFieldWithNoValues-seed#[5CAAEC8FBDE8C026]) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={q=*:*&qt=/export&fl=id,datedv&sort=datedv+desc&wt=xml} hits=1 status=0 QTime=0
[junit4] 2> 10783 INFO (TEST-TestExportWriter.testSortingOnFieldWithNoValues-seed#[5CAAEC8FBDE8C026]) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={q=*:*&qt=/export&fl=id,booleandv&sort=booleandv+desc&wt=xml} hits=1 status=0 QTime=0
[junit4] 2> 10796 INFO (TEST-TestExportWriter.testSortingOnFieldWithNoValues-seed#[5CAAEC8FBDE8C026]) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={q=*:*&qt=/export&fl=id,field1_s_dv&sort=field1_s_dv+desc&wt=xml} hits=1 status=0 QTime=1
[junit4] 2> 10801 INFO (TEST-TestExportWriter.testSortingOnFieldWithNoValues-seed#[5CAAEC8FBDE8C026]) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={q=*:*&qt=/export&fl=id,field2_i_p&sort=field2_i_p+desc&wt=xml} hits=1 status=0 QTime=0
[junit4] 2> 10806 INFO (TEST-TestExportWriter.testSortingOnFieldWithNoValues-seed#[5CAAEC8FBDE8C026]) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={q=*:*&qt=/export&fl=id,field3_l_p&sort=field3_l_p+desc&wt=xml} hits=1 status=0 QTime=1
[junit4] 2> 10817 INFO (TEST-TestExportWriter.testSortingOnFieldWithNoValues-seed#[5CAAEC8FBDE8C026]) [ ] o.a.s.SolrTestCaseJ4 ###Ending testSortingOnFieldWithNoValues
[junit4] 2> 10820 INFO (TEST-TestExportWriter.testBooleanField-seed#[5CAAEC8FBDE8C026]) [ ] o.a.s.SolrTestCaseJ4 ###Starting testBooleanField
[junit4] 2> 10821 INFO (TEST-TestExportWriter.testBooleanField-seed#[5CAAEC8FBDE8C026]) [ x:collection1 ] o.a.s.u.DirectUpdateHandler2 [collection1] REMOVING ALL DOCUMENTS FROM INDEX
[junit4] 2> 10821 INFO (TEST-TestExportWriter.testBooleanField-seed#[5CAAEC8FBDE8C026]) [ x:collection1 ] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=null path=null params={}{deleteByQuery=*:*} 0 0
[junit4] 2> 10829 INFO (searcherExecutor-39-thread-1-processing-x:collection1) [ x:collection1 ] o.a.s.c.SolrCore [collection1] Registered new searcher autowarm time: 0 ms
[junit4] 2> 10847 INFO (TEST-TestExportWriter.testBooleanField-seed#[5CAAEC8FBDE8C026]) [ x:collection1 ] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=null path=null params={}{commit=} 0 25
[junit4] 2> 10852 INFO (TEST-TestExportWriter.testBooleanField-seed#[5CAAEC8FBDE8C026]) [ ] o.a.s.u.DirectUpdateHandler2 [collection1] REMOVING ALL DOCUMENTS FROM INDEX
[junit4] 2> 10853 INFO (TEST-TestExportWriter.testBooleanField-seed#[5CAAEC8FBDE8C026]) [ ] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=null path=null params={_version_=-9223372036854775807&update.distrib=FROMLEADER&versions=true&wt=json&indent=true}{deleteByQuery=*:*} 0 4
[junit4] 2> 10854 INFO (TEST-TestExportWriter.testBooleanField-seed#[5CAAEC8FBDE8C026]) [ x:collection1 ] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=null path=null params={}{add=[1]} 0 0
[junit4] 2> 10862 INFO (searcherExecutor-39-thread-1-processing-x:collection1) [ x:collection1 ] o.a.s.c.SolrCore [collection1] Registered new searcher autowarm time: 0 ms
[junit4] 2> 10862 INFO (TEST-TestExportWriter.testBooleanField-seed#[5CAAEC8FBDE8C026]) [ x:collection1 ] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=null path=null params={}{commit=} 0 8
[junit4] 2> 10864 INFO (TEST-TestExportWriter.testBooleanField-seed#[5CAAEC8FBDE8C026]) [ x:collection1 ] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=null path=null params={}{add=[2]} 0 0
[junit4] 2> 10879 INFO (searcherExecutor-39-thread-1-processing-x:collection1) [ x:collection1 ] o.a.s.c.SolrCore [collection1] Registered new searcher autowarm time: 0 ms
[junit4] 2> 10880 INFO (TEST-TestExportWriter.testBooleanField-seed#[5CAAEC8FBDE8C026]) [ x:collection1 ] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=null path=null params={}{commit=} 0 15
[junit4] 2> 10883 INFO (TEST-TestExportWriter.testBooleanField-seed#[5CAAEC8FBDE8C026]) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={q=*:*&qt=/export&fl=id&sort=booleandv+asc&wt=xml} hits=2 status=0 QTime=2
[junit4] 2> 10924 INFO (TEST-TestExportWriter.testBooleanField-seed#[5CAAEC8FBDE8C026]) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={q=*:*&qt=/export&fl=id&sort=booleandv+desc&wt=xml} hits=2 status=0 QTime=0
[junit4] 2> 10926 INFO (TEST-TestExportWriter.testBooleanField-seed#[5CAAEC8FBDE8C026]) [ ] o.a.s.SolrTestCaseJ4 ###Ending testBooleanField
[junit4] 2> 10928 INFO (TEST-TestExportWriter.testExpr-seed#[5CAAEC8FBDE8C026]) [ ] o.a.s.SolrTestCaseJ4 ###Starting testExpr
[junit4] 2> 10929 INFO (TEST-TestExportWriter.testExpr-seed#[5CAAEC8FBDE8C026]) [ x:collection1 ] o.a.s.u.DirectUpdateHandler2 [collection1] REMOVING ALL DOCUMENTS FROM INDEX
[junit4] 2> 10929 INFO (TEST-TestExportWriter.testExpr-seed#[5CAAEC8FBDE8C026]) [ x:collection1 ] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=null path=null params={}{deleteByQuery=*:*} 0 0
[junit4] 2> 10933 INFO (searcherExecutor-39-thread-1-processing-x:collection1) [ x:collection1 ] o.a.s.c.SolrCore [collection1] Registered new searcher autowarm time: 0 ms
[junit4] 2> 10940 INFO (TEST-TestExportWriter.testExpr-seed#[5CAAEC8FBDE8C026]) [ x:collection1 ] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=null path=null params={}{commit=} 0 10
[junit4] 2> 10943 INFO (TEST-TestExportWriter.testExpr-seed#[5CAAEC8FBDE8C026]) [ x:collection1 ] o.a.s.u.DirectUpdateHandler2 [collection1] REMOVING ALL DOCUMENTS FROM INDEX
[junit4] 2> 10943 INFO (TEST-TestExportWriter.testExpr-seed#[5CAAEC8FBDE8C026]) [ x:collection1 ] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=null path=null params={}{deleteByQuery=*:*} 0 0
[junit4] 2> 10947 INFO (searcherExecutor-39-thread-1-processing-x:collection1) [ x:collection1 ] o.a.s.c.SolrCore [collection1] Registered new searcher autowarm time: 0 ms
[junit4] 2> 10947 INFO (TEST-TestExportWriter.testExpr-seed#[5CAAEC8FBDE8C026]) [ x:collection1 ] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=null path=null params={}{commit=} 0 3
[junit4] 2> 11501 INFO (TEST-TestExportWriter.testExpr-seed#[5CAAEC8FBDE8C026]) [ ] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=null path=null params={wt=json&indent=true}{add=[0, 1, 2, 3, 4, 5, 6, 7, 8, 9, ... (5000 adds)]} 0 370
[junit4] 2> 11778 INFO (TEST-TestExportWriter.testExpr-seed#[5CAAEC8FBDE8C026]) [ ] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=null path=null params={wt=json&indent=true}{add=[5000, 5001, 5002, 5003, 5004, 5005, 5006, 5007, 5008, 5009, ... (5000 adds)]} 0 131
[junit4] 2> 11980 INFO (TEST-TestExportWriter.testExpr-seed#[5CAAEC8FBDE8C026]) [ ] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=null path=null params={wt=json&indent=true}{add=[10000, 10001, 10002, 10003, 10004, 10005, 10006, 10007, 10008, 10009, ... (5000 adds)]} 0 88
[junit4] 2> 12092 INFO (TEST-TestExportWriter.testExpr-seed#[5CAAEC8FBDE8C026]) [ ] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=null path=null params={wt=json&indent=true}{add=[15000, 15001, 15002, 15003, 15004, 15005, 15006, 15007, 15008, 15009, ... (5000 adds)]} 0 83
[junit4] 2> 12206 INFO (TEST-TestExportWriter.testExpr-seed#[5CAAEC8FBDE8C026]) [ ] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=null path=null params={wt=json&indent=true}{add=[20000, 20001, 20002, 20003, 20004, 20005, 20006, 20007, 20008, 20009, ... (5000 adds)]} 0 70
[junit4] 2> 12302 INFO (TEST-TestExportWriter.testExpr-seed#[5CAAEC8FBDE8C026]) [ ] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=null path=null params={wt=json&indent=true}{add=[25000, 25001, 25002, 25003, 25004, 25005, 25006, 25007, 25008, 25009, ... (5000 adds)]} 0 64
[junit4] 2> 12407 INFO (TEST-TestExportWriter.testExpr-seed#[5CAAEC8FBDE8C026]) [ ] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=null path=null params={wt=json&indent=true}{add=[30000, 30001, 30002, 30003, 30004, 30005, 30006, 30007, 30008, 30009, ... (5000 adds)]} 0 65
[junit4] 2> 13348 INFO (TEST-TestExportWriter.testExpr-seed#[5CAAEC8FBDE8C026]) [ ] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=null path=null params={wt=json&indent=true}{add=[35000, 35001, 35002, 35003, 35004, 35005, 35006, 35007, 35008, 35009, ... (5000 adds)]} 0 841
[junit4] 2> 13486 INFO (TEST-TestExportWriter.testExpr-seed#[5CAAEC8FBDE8C026]) [ ] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=null path=null params={wt=json&indent=true}{add=[40000, 40001, 40002, 40003, 40004, 40005, 40006, 40007, 40008, 40009, ... (5000 adds)]} 0 71
[junit4] 2> 13551 INFO (TEST-TestExportWriter.testExpr-seed#[5CAAEC8FBDE8C026]) [ ] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=null path=null params={wt=json&indent=true}{add=[45000, 45001, 45002, 45003, 45004, 45005, 45006, 45007, 45008, 45009, ... (5000 adds)]} 0 50
[junit4] 2> 13654 INFO (TEST-TestExportWriter.testExpr-seed#[5CAAEC8FBDE8C026]) [ ] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=null path=null params={wt=json&indent=true}{add=[50000, 50001, 50002, 50003, 50004, 50005, 50006, 50007, 50008, 50009, ... (5000 adds)]} 0 92
[junit4] 2> 13716 INFO (TEST-TestExportWriter.testExpr-seed#[5CAAEC8FBDE8C026]) [ ] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=null path=null params={wt=json&indent=true}{add=[55000, 55001, 55002, 55003, 55004, 55005, 55006, 55007, 55008, 55009, ... (5000 adds)]} 0 47
[junit4] 2> 13768 INFO (TEST-TestExportWriter.testExpr-seed#[5CAAEC8FBDE8C026]) [ ] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=null path=null params={wt=json&indent=true}{add=[60000, 60001, 60002, 60003, 60004, 60005, 60006, 60007, 60008, 60009, ... (5000 adds)]} 0 43
[junit4] 2> 13819 INFO (TEST-TestExportWriter.testExpr-seed#[5CAAEC8FBDE8C026]) [ ] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=null path=null params={wt=json&indent=true}{add=[65000, 65001, 65002, 65003, 65004, 65005, 65006, 65007, 65008, 65009, ... (5000 adds)]} 0 41
[junit4] 2> 13912 INFO (TEST-TestExportWriter.testExpr-seed#[5CAAEC8FBDE8C026]) [ ] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=null path=null params={wt=json&indent=true}{add=[70000, 70001, 70002, 70003, 70004, 70005, 70006, 70007, 70008, 70009, ... (5000 adds)]} 0 52
[junit4] 2> 14369 INFO (TEST-TestExportWriter.testExpr-seed#[5CAAEC8FBDE8C026]) [ ] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=null path=null params={wt=json&indent=true}{add=[75000, 75001, 75002, 75003, 75004, 75005, 75006, 75007, 75008, 75009, ... (5000 adds)]} 0 449
[junit4] 2> 14445 INFO (TEST-TestExportWriter.testExpr-seed#[5CAAEC8FBDE8C026]) [ ] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=null path=null params={wt=json&indent=true}{add=[80000, 80001, 80002, 80003, 80004, 80005, 80006, 80007, 80008, 80009, ... (5000 adds)]} 0 66
[junit4] 2> 14502 INFO (TEST-TestExportWriter.testExpr-seed#[5CAAEC8FBDE8C026]) [ ] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=null path=null params={wt=json&indent=true}{add=[85000, 85001, 85002, 85003, 85004, 85005, 85006, 85007, 85008, 85009, ... (5000 adds)]} 0 44
[junit4] 2> 14556 INFO (TEST-TestExportWriter.testExpr-seed#[5CAAEC8FBDE8C026]) [ ] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=null path=null params={wt=json&indent=true}{add=[90000, 90001, 90002, 90003, 90004, 90005, 90006, 90007, 90008, 90009, ... (5000 adds)]} 0 46
[junit4] 2> 14611 INFO (TEST-TestExportWriter.testExpr-seed#[5CAAEC8FBDE8C026]) [ ] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=null path=null params={wt=json&indent=true}{add=[95000, 95001, 95002, 95003, 95004, 95005, 95006, 95007, 95008, 95009, ... (5000 adds)]} 0 45
[junit4] 2> 14802 INFO (searcherExecutor-39-thread-1-processing-x:collection1) [ x:collection1 ] o.a.s.c.SolrCore [collection1] Registered new searcher autowarm time: 0 ms
[junit4] 2> 14803 INFO (TEST-TestExportWriter.testExpr-seed#[5CAAEC8FBDE8C026]) [ x:collection1 ] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=null path=null params={}{commit=} 0 190
[junit4] 2> 14813 INFO (TEST-TestExportWriter.testExpr-seed#[5CAAEC8FBDE8C026]) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={q=*:*&qt=/export&fl=id&expr=top(n%3D2,input(),sort%3D"id+desc")&sort=id+asc&wt=xml} hits=100000 status=0 QTime=9
[junit4] 2> 15219 INFO (TEST-TestExportWriter.testExpr-seed#[5CAAEC8FBDE8C026]) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={q=*:*&qt=/export&fl=id,sortabledv_udvas&expr=unique(input(),over%3D"sortabledv_udvas")&sort=sortabledv_udvas+asc&wt=xml} hits=100000 status=0 QTime=1
[junit4] 2> 15551 INFO (TEST-TestExportWriter.testExpr-seed#[5CAAEC8FBDE8C026]) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={q=*:*&qt=/export&fl=id,sortabledv_udvas,small_i_p&expr=rollup(input(),over%3D"sortabledv_udvas",+sum(small_i_p),avg(small_i_p),min(small_i_p),count(*))&sort=sortabledv_udvas+asc&wt=xml} hits=100000 status=0 QTime=1
[junit4] 2> 15919 INFO (TEST-TestExportWriter.testExpr-seed#[5CAAEC8FBDE8C026]) [ ] o.a.s.SolrTestCaseJ4 ###Ending testExpr
[junit4] 2> NOTE: reproduce with: ant test -Dtestcase=TestExportWriter -Dtests.method=testExpr -Dtests.seed=5CAAEC8FBDE8C026 -Dtests.multiplier=3 -Dtests.slow=true -Dtests.locale=ja -Dtests.timezone=America/Santo_Domingo -Dtests.asserts=true -Dtests.file.encoding=ISO-8859-1
[junit4] FAILURE 5.00s J3 | TestExportWriter.testExpr <<<
[junit4] > Throwable #1: java.lang.AssertionError: expected:<18000.0> but was:<20512.0>
[junit4] > at __randomizedtesting.SeedInfo.seed([5CAAEC8FBDE8C026:EA351DCF9D617D73]:0)
[junit4] > at org.apache.solr.handler.export.TestExportWriter.testExpr(TestExportWriter.java:770)
[junit4] > at java.lang.Thread.run(Thread.java:748)
[junit4] 2> 15929 INFO (TEST-TestExportWriter.testStringWithCase-seed#[5CAAEC8FBDE8C026]) [ ] o.a.s.SolrTestCaseJ4 ###Starting testStringWithCase
[junit4] 2> 15929 INFO (TEST-TestExportWriter.testStringWithCase-seed#[5CAAEC8FBDE8C026]) [ x:collection1 ] o.a.s.u.DirectUpdateHandler2 [collection1] REMOVING ALL DOCUMENTS FROM INDEX
[junit4] 2> 15929 INFO (TEST-TestExportWriter.testStringWithCase-seed#[5CAAEC8FBDE8C026]) [ x:collection1 ] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=null path=null params={}{deleteByQuery=*:*} 0 0
[junit4] 2> 15932 INFO (searcherExecutor-39-thread-1-processing-x:collection1) [ x:collection1 ] o.a.s.c.SolrCore [collection1] Registered new searcher autowarm time: 0 ms
[junit4] 2> 15935 INFO (TEST-TestExportWriter.testStringWithCase-seed#[5CAAEC8FBDE8C026]) [ x:collection1 ] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=null path=null params={}{commit=} 0 4
[junit4] 2> 15936 INFO (TEST-TestExportWriter.testStringWithCase-seed#[5CAAEC8FBDE8C026]) [ ] o.a.s.u.DirectUpdateHandler2 [collection1] REMOVING ALL DOCUMENTS FROM INDEX
[junit4] 2> 15936 INFO (TEST-TestExportWriter.testStringWithCase-seed#[5CAAEC8FBDE8C026]) [ ] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=null path=null params={_version_=-9223372036854775807&update.distrib=FROMLEADER&versions=true&wt=json&indent=true}{deleteByQuery=*:*} 0 0
[junit4] 2> 15937 INFO (TEST-TestExportWriter.testStringWithCase-seed#[5CAAEC8FBDE8C026]) [ x:collection1 ] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=null path=null params={}{add=[1]} 0 0
[junit4] 2> 15938 INFO (TEST-TestExportWriter.testStringWithCase-seed#[5CAAEC8FBDE8C026]) [ x:collection1 ] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=null path=null params={}{add=[2]} 0 0
[junit4] 2> 15943 INFO (searcherExecutor-39-thread-1-processing-x:collection1) [ x:collection1 ] o.a.s.c.SolrCore [collection1] Registered new searcher autowarm time: 0 ms
[junit4] 2> 15944 INFO (TEST-TestExportWriter.testStringWithCase-seed#[5CAAEC8FBDE8C026]) [ x:collection1 ] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=null path=null params={}{commit=} 0 5
[junit4] 2> 15946 INFO (TEST-TestExportWriter.testStringWithCase-seed#[5CAAEC8FBDE8C026]) [ x:collection1 ] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=null path=null params={}{add=[3]} 0 0
[junit4] 2> 15947 INFO (TEST-TestExportWriter.testStringWithCase-seed#[5CAAEC8FBDE8C026]) [ x:collection1 ] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=null path=null params={}{add=[4]} 0 0
[junit4] 2> 15951 INFO (searcherExecutor-39-thread-1-processing-x:collection1) [ x:collection1 ] o.a.s.c.SolrCore [collection1] Registered new searcher autowarm time: 0 ms
[junit4] 2> 15952 INFO (TEST-TestExportWriter.testStringWithCase-seed#[5CAAEC8FBDE8C026]) [ x:collection1 ] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=null path=null params={}{commit=} 0 4
[junit4] 2> 15953 INFO (TEST-TestExportWriter.testStringWithCase-seed#[5CAAEC8FBDE8C026]) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={q=*:*&qt=/export&fl=id&sort=stringdv+desc&wt=xml} hits=4 status=0 QTime=0
[junit4] 2> 15974 INFO (TEST-TestExportWriter.testStringWithCase-seed#[5CAAEC8FBDE8C026]) [ ] o.a.s.SolrTestCaseJ4 ###Ending testStringWithCase
[junit4] 2> 15978 INFO (TEST-TestExportWriter.testSmallChains-seed#[5CAAEC8FBDE8C026]) [ ] o.a.s.SolrTestCaseJ4 ###Starting testSmallChains
[junit4] 2> 15979 INFO (TEST-TestExportWriter.testSmallChains-seed#[5CAAEC8FBDE8C026]) [ x:collection1 ] o.a.s.u.DirectUpdateHandler2 [collection1] REMOVING ALL DOCUMENTS FROM INDEX
[junit4] 2> 15979 INFO (TEST-TestExportWriter.testSmallChains-seed#[5CAAEC8FBDE8C026]) [ x:collection1 ] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=null path=null params={}{deleteByQuery=*:*} 0 0
[junit4] 2> 15982 INFO (searcherExecutor-39-thread-1-processing-x:collection1) [ x:collection1 ] o.a.s.c.SolrCore [collection1] Registered new searcher autowarm time: 0 ms
[junit4] 2> 15983 INFO (TEST-TestExportWriter.testSmallChains-seed#[5CAAEC8FBDE8C026]) [ x:collection1 ] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=null path=null params={}{commit=} 0 3
[junit4] 2> 15984 INFO (TEST-TestExportWriter.testSmallChains-seed#[5CAAEC8FBDE8C026]) [ ] o.a.s.u.DirectUpdateHandler2 [collection1] REMOVING ALL DOCUMENTS FROM INDEX
[junit4] 2> 15984 INFO (TEST-TestExportWriter.testSmallChains-seed#[5CAAEC8FBDE8C026]) [ ] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=null path=null params={_version_=-9223372036854775807&update.distrib=FROMLEADER&versions=true&wt=json&indent=true}{deleteByQuery=*:*} 0 0
[junit4] 2> 15985 INFO (TEST-TestExportWriter.testSmallChains-seed#[5CAAEC8FBDE8C026]) [ x:collection1 ] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=null path=null params={}{add=[1]} 0 0
[junit4] 2> 15991 INFO (searcherExecutor-39-thread-1-processing-x:collection1) [ x:collection1 ] o.a.s.c.SolrCore [collection1] Registered new searcher autowarm time: 0 ms
[junit4] 2> 15991 INFO (TEST-TestExportWriter.testSmallChains-seed#[5CAAEC8FBDE8C026]) [ x:collection1 ] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=null path=null params={}{commit=} 0 5
[junit4] 2> 15992 INFO (TEST-TestExportWriter.testSmallChains-seed#[5CAAEC8FBDE8C026]) [ x:collection1 ] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=null path=null params={}{add=[2]} 0 0
[junit4] 2> 15998 INFO (searcherExecutor-39-thread-1-processing-x:collection1) [ x:collection1 ] o.a.s.c.SolrCore [collection1] Registered new searcher autowarm time: 0 ms
[junit4] 2> 15999 INFO (TEST-TestExportWriter.testSmallChains-seed#[5CAAEC8FBDE8C026]) [ x:collection1 ] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=null path=null params={}{commit=} 0 5
[junit4] 2> 16000 INFO (TEST-TestExportWriter.testSmallChains-seed#[5CAAEC8FBDE8C026]) [ x:collection1 ] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=null path=null params={}{add=[3]} 0 0
[junit4] 2> 16005 INFO (searcherExecutor-39-thread-1-processing-x:collection1) [ x:collection1 ] o.a.s.c.SolrCore [collection1] Registered new searcher autowarm time: 0 ms
[junit4] 2> 16006 INFO (TEST-TestExportWriter.testSmallChains-seed#[5CAAEC8FBDE8C026]) [ x:collection1 ] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=null path=null params={}{commit=} 0 4
[junit4] 2> 16007 INFO (TEST-TestExportWriter.testSmallChains-seed#[5CAAEC8FBDE8C026]) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={q=*:*&qt=/export&fl=id&sort=field1_i_p+asc,field2_i_p+asc&wt=xml} hits=3 status=0 QTime=0
[junit4] 2> 16009 INFO (TEST-TestExportWriter.testSmallChains-seed#[5CAAEC8FBDE8C026]) [ ] o.a.s.u.DirectUpdateHandler2 [collection1] REMOVING ALL DOCUMENTS FROM INDEX
[junit4] 2> 16021 INFO (TEST-TestExportWriter.testSmallChains-seed#[5CAAEC8FBDE8C026]) [ ] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=null path=null params={_version_=-9223372036854775807&update.distrib=FROMLEADER&versions=true&wt=json&indent=true}{deleteByQuery=*:*} 0 12
[junit4] 2> 16023 INFO (TEST-TestExportWriter.testSmallChains-seed#[5CAAEC8FBDE8C026]) [ x:collection1 ] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=null path=null params={}{add=[1]} 0 1
[junit4] 2> 16030 INFO (searcherExecutor-39-thread-1-processing-x:collection1) [ x:collection1 ] o.a.s.c.SolrCore [collection1] Registered new searcher autowarm time: 0 ms
[junit4] 2> 16032 INFO (TEST-TestExportWriter.testSmallChains-seed#[5CAAEC8FBDE8C026]) [ x:collection1 ] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=null path=null params={}{commit=} 0 8
[junit4] 2> 16037 INFO (TEST-TestExportWriter.testSmallChains-seed#[5CAAEC8FBDE8C026]) [ x:collection1 ] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=null path=null params={}{add=[2]} 0 4
[junit4] 2> 16043 INFO (searcherExecutor-39-thread-1-processing-x:collection1) [ x:collection1 ] o.a.s.c.SolrCore [collection1] Registered new searcher autowarm time: 0 ms
[junit4] 2> 16043 INFO (TEST-TestExportWriter.testSmallChains-seed#[5CAAEC8FBDE8C026]) [ x:collection1 ] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=null path=null params={}{commit=} 0 5
[junit4] 2> 16044 INFO (TEST-TestExportWriter.testSmallChains-seed#[5CAAEC8FBDE8C026]) [ x:collection1 ] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=null path=null params={}{add=[3]} 0 0
[junit4] 2> 16054 INFO (searcherExecutor-39-thread-1-processing-x:collection1) [ x:collection1 ] o.a.s.c.SolrCore [collection1] Registered new searcher autowarm time: 0 ms
[junit4] 2> 16055 INFO (TEST-TestExportWriter.testSmallChains-seed#[5CAAEC8FBDE8C026]) [ x:collection1 ] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=null path=null params={}{commit=} 0 9
[junit4] 2> 16056 INFO (TEST-TestExportWriter.testSmallChains-seed#[5CAAEC8FBDE8C026]) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={q=*:*&qt=/export&fl=id&sort=field1_i_p+asc,field2_i_p+asc,field3_i_p+asc,field4_i_p+asc,field5_i_p+desc,field6_i_p+desc,field7_i_p+desc,field8_i_p+asc&wt=xml} hits=3 status=0 QTime=0
[junit4] 2> 16057 INFO (TEST-TestExportWriter.testSmallChains-seed#[5CAAEC8FBDE8C026]) [ ] o.a.s.SolrTestCaseJ4 ###Ending testSmallChains
[junit4] 2> 16060 INFO (TEST-TestExportWriter.testIndexOrder-seed#[5CAAEC8FBDE8C026]) [ ] o.a.s.SolrTestCaseJ4 ###Starting testIndexOrder
[junit4] 2> 16060 INFO (TEST-TestExportWriter.testIndexOrder-seed#[5CAAEC8FBDE8C026]) [ x:collection1 ] o.a.s.u.DirectUpdateHandler2 [collection1] REMOVING ALL DOCUMENTS FROM INDEX
[junit4] 2> 16060 INFO (TEST-TestExportWriter.testIndexOrder-seed#[5CAAEC8FBDE8C026]) [ x:collection1 ] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=null path=null params={}{deleteByQuery=*:*} 0 0
[junit4] 2> 16063 INFO (searcherExecutor-39-thread-1-processing-x:collection1) [ x:collection1 ] o.a.s.c.SolrCore [collection1] Registered new searcher autowarm time: 0 ms
[junit4] 2> 16065 INFO (TEST-TestExportWriter.testIndexOrder-seed#[5CAAEC8FBDE8C026]) [ x:collection1 ] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=null path=null params={}{commit=} 0 3
[junit4] 2> 16070 INFO (TEST-TestExportWriter.testIndexOrder-seed#[5CAAEC8FBDE8C026]) [ ] o.a.s.u.DirectUpdateHandler2 [collection1] REMOVING ALL DOCUMENTS FROM INDEX
[junit4] 2> 16070 INFO (TEST-TestExportWriter.testIndexOrder-seed#[5CAAEC8FBDE8C026]) [ ] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=null path=null params={_version_=-9223372036854775807&update.distrib=FROMLEADER&versions=true&wt=json&indent=true}{deleteByQuery=*:*} 0 0
[junit4] 2> 16071 INFO (TEST-TestExportWriter.testIndexOrder-seed#[5CAAEC8FBDE8C026]) [ x:collection1 ] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=null path=null params={}{add=[1]} 0 0
[junit4] 2> 16072 INFO (TEST-TestExportWriter.testIndexOrder-seed#[5CAAEC8FBDE8C026]) [ x:collection1 ] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=null path=null params={}{add=[2]} 0 0
[junit4] 2> 16076 INFO (searcherExecutor-39-thread-1-processing-x:collection1) [ x:collection1 ] o.a.s.c.SolrCore [collection1] Registered new searcher autowarm time: 0 ms
[junit4] 2> 16076 INFO (TEST-TestExportWriter.testIndexOrder-seed#[5CAAEC8FBDE8C026]) [ x:collection1 ] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=null path=null params={}{commit=} 0 4
[junit4] 2> 16086 INFO (TEST-TestExportWriter.testIndexOrder-seed#[5CAAEC8FBDE8C026]) [ x:collection1 ] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=null path=null params={}{add=[3]} 0 8
[junit4] 2> 16087 INFO (TEST-TestExportWriter.testIndexOrder-seed#[5CAAEC8FBDE8C026]) [ x:collection1 ] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=null path=null params={}{add=[4]} 0 0
[junit4] 2> 16092 INFO (searcherExecutor-39-thread-1-processing-x:collection1) [ x:collection1 ] o.a.s.c.SolrCore [collection1] Registered new searcher autowarm time: 0 ms
[junit4] 2> 16092 INFO (TEST-TestExportWriter.testIndexOrder-seed#[5CAAEC8FBDE8C026]) [ x:collection1 ] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=null path=null params={}{commit=} 0 4
[junit4] 2> 16093 INFO (TEST-TestExportWriter.testIndexOrder-seed#[5CAAEC8FBDE8C026]) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={q=*:*&qt=/export&fl=id&sort=stringdv+asc&wt=xml} hits=4 status=0 QTime=0
[junit4] 2> 16102 INFO (TEST-TestExportWriter.testIndexOrder-seed#[5CAAEC8FBDE8C026]) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={q=*:*&qt=/export&fl=id&sort=stringdv+desc&wt=xml} hits=4 status=0 QTime=0
[junit4] 2> 16115 INFO (TEST-TestExportWriter.testIndexOrder-seed#[5CAAEC8FBDE8C026]) [ ] o.a.s.SolrTestCaseJ4 ###Ending testIndexOrder
[junit4] 2> 16118 INFO (TEST-TestExportWriter.testEmptyValues-seed#[5CAAEC8FBDE8C026]) [ ] o.a.s.SolrTestCaseJ4 ###Starting testEmptyValues
[junit4] 2> 16118 INFO (TEST-TestExportWriter.testEmptyValues-seed#[5CAAEC8FBDE8C026]) [ x:collection1 ] o.a.s.u.DirectUpdateHandler2 [collection1] REMOVING ALL DOCUMENTS FROM INDEX
[junit4] 2> 16119 INFO (TEST-TestExportWriter.testEmptyValues-seed#[5CAAEC8FBDE8C026]) [ x:collection1 ] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=null path=null params={}{deleteByQuery=*:*} 0 0
[junit4] 2> 16122 INFO (searcherExecutor-39-thread-1-processing-x:collection1) [ x:collection1 ] o.a.s.c.SolrCore [collection1] Registered new searcher autowarm time: 0 ms
[junit4] 2> 16123 INFO (TEST-TestExportWriter.testEmptyValues-seed#[5CAAEC8FBDE8C026]) [ x:collection1 ] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=null path=null params={}{commit=} 0 3
[junit4] 2> 16124 INFO (TEST-TestExportWriter.testEmptyValues-seed#[5CAAEC8FBDE8C026]) [ x:collection1 ] o.a.s.u.DirectUpdateHandler2 [collection1] REMOVING ALL DOCUMENTS FROM INDEX
[junit4] 2> 16124 INFO (TEST-TestExportWriter.testEmptyValues-seed#[5CAAEC8FBDE8C026]) [ x:collection1 ] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=null path=null params={}{deleteByQuery=*:*} 0 0
[junit4] 2> 16128 INFO (searcherExecutor-39-thread-1-processing-x:collection1) [ x:collection1 ] o.a.s.c.SolrCore [collection1] Registered new searcher autowarm time: 0 ms
[junit4] 2> 16128 INFO (TEST-TestExportWriter.testEmptyValues-seed#[5CAAEC8FBDE8C026]) [ x:collection1 ] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=null path=null params={}{commit=} 0 3
[junit4] 2> 16130 INFO (TEST-TestExportWriter.testEmptyValues-seed#[5CAAEC8FBDE8C026]) [ x:collection1 ] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=null path=null params={}{add=[1]} 0 0
[junit4] 2> 16130 INFO (TEST-TestExportWriter.testEmptyValues-seed#[5CAAEC8FBDE8C026]) [ x:collection1 ] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=null path=null params={}{add=[2]} 0 0
[junit4] 2> 16136 INFO (searcherExecutor-39-thread-1-processing-x:collection1) [ x:collection1 ] o.a.s.c.SolrCore [collection1] Registered new searcher autowarm time: 0 ms
[junit4] 2> 16136 INFO (TEST-TestExportWriter.testEmptyValues-seed#[5CAAEC8FBDE8C026]) [ x:collection1 ] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=null path=null params={}{commit=} 0 5
[junit4] 2> 16137 INFO (TEST-TestExportWriter.testEmptyValues-seed#[5CAAEC8FBDE8C026]) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={q=*:*&qt=/export&fl=id,field2_i_p&sort=field2_i_p+asc&wt=xml} hits=2 status=0 QTime=0
[junit4] 2> 16149 INFO (TEST-TestExportWriter.testEmptyValues-seed#[5CAAEC8FBDE8C026]) [ ] o.a.s.SolrTestCaseJ4 ###Ending testEmptyValues
[junit4] 2> 16152 INFO (TEST-TestExportWriter.test-seed#[5CAAEC8FBDE8C026]) [ ] o.a.s.SolrTestCaseJ4 ###Starting test
[junit4] 2> 16153 INFO (TEST-TestExportWriter.test-seed#[5CAAEC8FBDE8C026]) [ x:collection1 ] o.a.s.u.DirectUpdateHandler2 [collection1] REMOVING ALL DOCUMENTS FROM INDEX
[junit4] 2> 16153 INFO (TEST-TestExportWriter.test-seed#[5CAAEC8FBDE8C026]) [ x:collection1 ] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=null path=null params={}{deleteByQuery=*:*} 0 0
[junit4] 2> 16156 INFO (searcherExecutor-39-thread-1-processing-x:collection1) [ x:collection1 ] o.a.s.c.SolrCore [collection1] Registered new searcher autowarm time: 0 ms
[junit4] 2> 16157 INFO (TEST-TestExportWriter.test-seed#[5CAAEC8FBDE8C026]) [ x:collection1 ] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=null path=null params={}{commit=} 0 3
[junit4] 2> 16158 INFO (TEST-TestExportWriter.test-seed#[5CAAEC8FBDE8C026]) [ ] o.a.s.u.DirectUpdateHandler2 [collection1] REMOVING ALL DOCUMENTS FROM INDEX
[junit4] 2> 16159 INFO (TEST-TestExportWriter.test-seed#[5CAAEC8FBDE8C026]) [ ] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=null path=null params={_version_=-9223372036854775807&update.distrib=FROMLEADER&versions=true&wt=json&indent=true}{deleteByQuery=*:*} 0 0
[junit4] 2> 16179 INFO (TEST-TestExportWriter.test-seed#[5CAAEC8FBDE8C026]) [ x:collection1 ] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=null path=null params={}{add=[1]} 0 20
[junit4] 2> 16181 INFO (TEST-TestExportWriter.test-seed#[5CAAEC8FBDE8C026]) [ x:collection1 ] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=null path=null params={}{add=[7]} 0 0
[junit4] 2> 16190 INFO (searcherExecutor-39-thread-1-processing-x:collection1) [ x:collection1 ] o.a.s.c.SolrCore [collection1] Registered new searcher autowarm time: 0 ms
[junit4] 2> 16191 INFO (TEST-TestExportWriter.test-seed#[5CAAEC8FBDE8C026]) [ x:collection1 ] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=null path=null params={}{commit=} 0 9
[junit4] 2> 16193 INFO (TEST-TestExportWriter.test-seed#[5CAAEC8FBDE8C026]) [ x:collection1 ] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=null path=null params={}{add=[2]} 0 0
[junit4] 2> 16198 INFO (searcherExecutor-39-thread-1-processing-x:collection1) [ x:collection1 ] o.a.s.c.SolrCore [collection1] Registered new searcher autowarm time: 0 ms
[junit4] 2> 16200 INFO (TEST-TestExportWriter.test-seed#[5CAAEC8FBDE8C026]) [ x:collection1 ] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=null path=null params={}{commit=} 0 5
[junit4] 2> 16202 INFO (TEST-TestExportWriter.test-seed#[5CAAEC8FBDE8C026]) [ x:collection1 ] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=null path=null params={}{add=[3]} 0 1
[junit4] 2> 16209 INFO (searcherExecutor-39-thread-1-processing-x:collection1) [ x:collection1 ] o.a.s.c.SolrCore [collection1] Registered new searcher autowarm time: 0 ms
[junit4] 2> 16210 INFO (TEST-TestExportWriter.test-seed#[5CAAEC8FBDE8C026]) [ x:collection1 ] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=null path=null params={}{commit=} 0 6
[junit4] 2> 16212 INFO (TEST-TestExportWriter.test-seed#[5CAAEC8FBDE8C026]) [ x:collection1 ] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=null path=null params={}{add=[8]} 0 1
[junit4] 2> 16218 INFO (searcherExecutor-39-thread-1-processing-x:collection1) [ x:collection1 ] o.a.s.c.SolrCore [collection1] Registered new searcher autowarm time: 0 ms
[junit4] 2> 16218 INFO (TEST-TestExportWriter.test-seed#[5CAAEC8FBDE8C026]) [ x:collection1 ] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=null path=null params={}{commit=} 0 6
[junit4] 2> 16230 INFO (TEST-TestExportWriter.test-seed#[5CAAEC8FBDE8C026]) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={q=id:1&qt=/export&fl=floatdv,intdv,stringdv,longdv,doubledv&sort=intdv+asc&wt=xml} hits=1 status=0 QTime=10
[junit4] 2> 16233 INFO (TEST-TestExportWriter.test-seed#[5CAAEC8FBDE8C026]) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={q=id:7&qt=/export&fl=floatdv,intdv,stringdv,longdv,doubledv&sort=intdv+asc&wt=xml} hits=1 status=0 QTime=0
[junit4] 2> 16238 INFO (TEST-TestExportWriter.test-seed#[5CAAEC8FBDE8C026]) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={q=id:1&qt=/export&fl=intdv_m,floatdv_m,doubledv_m,longdv_m,stringdv_m&sort=intdv+asc&wt=xml} hits=1 status=0 QTime=0
[junit4] 2> 16247 INFO (TEST-TestExportWriter.test-seed#[5CAAEC8FBDE8C026]) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={q=id:7&qt=/export&fl=intdv_m,floatdv_m,doubledv_m,longdv_m,stringdv_m&sort=intdv+asc&wt=xml} hits=1 status=0 QTime=0
[junit4] 2> 16265 INFO (TEST-TestExportWriter.test-seed#[5CAAEC8FBDE8C026]) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={q=id:(1+2)&qt=/export&fl=intdv&sort=intdv+desc&wt=xml} hits=2 status=0 QTime=7
[junit4] 2> 16270 INFO (TEST-TestExportWriter.test-seed#[5CAAEC8FBDE8C026]) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={q=id:(1+2)&qt=/export&fl=intdv&sort=intdv+asc&wt=xml} hits=2 status=0 QTime=0
[junit4] 2> 16294 INFO (TEST-TestExportWriter.test-seed#[5CAAEC8FBDE8C026]) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={q=id:(1+7)&qt=/export&fl=intdv&sort=stringdv+desc&wt=xml} hits=2 status=0 QTime=22
[junit4] 2> 16299 INFO (TEST-TestExportWriter.test-seed#[5CAAEC8FBDE8C026]) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={q=id:(1+7)&qt=/export&fl=intdv&sort=stringdv+asc&wt=xml} hits=2 status=0 QTime=1
[junit4] 2> 16300 INFO (TEST-TestExportWriter.test-seed#[5CAAEC8FBDE8C026]) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={q=id:(1+2)&qt=/export&fl=intdv&sort=floatdv+asc,intdv+desc&wt=xml} hits=2 status=0 QTime=0
[junit4] 2> 16303 INFO (TEST-TestExportWriter.test-seed#[5CAAEC8FBDE8C026]) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={q=id:(1+2)&qt=/export&fl=intdv&sort=floatdv+desc,intdv+asc&wt=xml} hits=2 status=0 QTime=0
[junit4] 2> 16306 INFO (TEST-TestExportWriter.test-seed#[5CAAEC8FBDE8C026]) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={q=id:(1+2+3)&qt=/export&fl=intdv&sort=floatdv+asc,stringdv+asc,intdv+desc&wt=xml} hits=3 status=0 QTime=0
[junit4] 2> 16308 INFO (TEST-TestExportWriter.test-seed#[5CAAEC8FBDE8C026]) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={q=id:(1+2+3)&qt=/export&fl=intdv&sort=floatdv+asc,stringdv+desc,intdv+asc&wt=xml} hits=3 status=0 QTime=0
[junit4] 2> 16310 INFO (TEST-TestExportWriter.test-seed#[5CAAEC8FBDE8C026]) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={q=id:(1+2+3)&qt=/export&fl=intdv&sort=floatdv+asc,floatdv+desc,floatdv+asc,intdv+desc&wt=xml} hits=3 status=0 QTime=0
[junit4] 2> 16326 INFO (TEST-TestExportWriter.test-seed#[5CAAEC8FBDE8C026]) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={q=id:(1+2+3)&qt=/export&fl=intdv&sort=intdv+desc,floatdv+asc,floatdv+desc,floatdv+asc,intdv+desc&wt=xml} hits=3 status=0 QTime=0
[junit4] 2> 16328 INFO (TEST-TestExportWriter.test-seed#[5CAAEC8FBDE8C026]) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={q=id:(1+2+3)&qt=/export&fl=intdv&sort=floatdv+desc,intdv+asc,floatdv+desc,floatdv+desc,intdv+desc&wt=xml} hits=3 status=0 QTime=0
[junit4] 2> 16330 INFO (TEST-TestExportWriter.test-seed#[5CAAEC8FBDE8C026]) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={q=id:(1+2+3)&qt=/export&fl=intdv&sort=floatdv+asc,intdv+desc,floatdv+asc,floatdv+desc,floatdv+asc,intdv+asc&wt=xml} hits=3 status=0 QTime=0
[junit4] 2> 16337 INFO (TEST-TestExportWriter.test-seed#[5CAAEC8FBDE8C026]) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={q=id:(1+2+3)&qt=/export&fl=intdv&sort=floatdv+desc,intdv+asc,floatdv+desc,floatdv+asc,floatdv+desc,floatdv+asc,intdv+desc&wt=xml} hits=3 status=0 QTime=0
[junit4] 2> 16342 INFO (TEST-TestExportWriter.test-seed#[5CAAEC8FBDE8C026]) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={q=id:(1+2+3)&qt=/export&fl=intdv&sort=floatdv+asc,intdv+desc,floatdv+asc,floatdv+desc,floatdv+asc,floatdv+desc,floatdv+asc,intdv+asc&wt=xml} hits=3 status=0 QTime=0
[junit4] 2> 16343 INFO (TEST-TestExportWriter.test-seed#[5CAAEC8FBDE8C026]) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={q=id:(1+2+3)&qt=/export&fl=intdv&sort=intdv+asc,floatdv+desc,floatdv+asc,floatdv+desc,floatdv+asc,floatdv+desc,floatdv+asc,intdv+desc&wt=xml} hits=3 status=0 QTime=0
[junit4] 2> 16344 INFO (TEST-TestExportWriter.test-seed#[5CAAEC8FBDE8C026]) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={q=id:(1+2+3)&qt=/export&fl=intdv&sort=intdv+asc,floatdv+desc,floatdv+asc,floatdv+desc,floatdv+asc,floatdv+desc,intdv+asc,intdv+desc,floatdv+asc&wt=xml} hits=3 status=0 QTime=0
[junit4] 2> 16346 INFO (TEST-TestExportWriter.test-seed#[5CAAEC8FBDE8C026]) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={q=id:(1+2+3)&qt=/export&fl=intdv&sort=floatdv+asc,intdv+desc,floatdv+asc,floatdv+desc,floatdv+asc,floatdv+desc,intdv+desc,intdv+asc,floatdv+asc&wt=xml} hits=3 status=0 QTime=0
[junit4] 2> 16347 INFO (TEST-TestExportWriter.test-seed#[5CAAEC8FBDE8C026]) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={q=id:(1+2+3)&qt=/export&fl=intdv&sort=intdv+asc,floatdv+desc,floatdv+asc,floatdv+desc,floatdv+asc,floatdv+desc,intdv+asc,intdv+desc,floatdv+desc,floatdv+asc&wt=xml} hits=3 status=0 QTime=0
[junit4] 2> 16349 INFO (TEST-TestExportWriter.test-seed#[5CAAEC8FBDE8C026]) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={q=id:(1+2+3)&qt=/export&fl=intdv&sort=floatdv+asc,intdv+desc,floatdv+asc,floatdv+desc,floatdv+asc,floatdv+desc,intdv+desc,intdv+asc,floatdv+desc,floatdv+asc&wt=xml} hits=3 status=0 QTime=0
[junit4] 2> 16350 INFO (TEST-TestExportWriter.test-seed#[5CAAEC8FBDE8C026]) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={q=id:(1+2+3)&qt=/export&fl=intdv&sort=doubledv+desc&wt=xml} hits=3 status=0 QTime=0
[junit4] 2> 16356 INFO (TEST-TestExportWriter.test-seed#[5CAAEC8FBDE8C026]) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={q=intdv:[2+TO+1000]&qt=/export&fl=intdv&sort=doubledv+desc&wt=xml} hits=3 status=0 QTime=4
[junit4] 2> 16360 INFO (TEST-TestExportWriter.test-seed#[5CAAEC8FBDE8C026]) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={q=stringdv:blah&qt=/export&fl=intdv&sort=doubledv+desc&wt=xml} hits=0 status=0 QTime=2
[junit4] 2> 16361 INFO (TEST-TestExportWriter.test-seed#[5CAAEC8FBDE8C026]) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={q=id:8&qt=/export&fl=stringdv&sort=intdv+asc&wt=xml} hits=1 status=0 QTime=0
[junit4] 2> 16366 INFO (TEST-TestExportWriter.test-seed#[5CAAEC8FBDE8C026]) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={q=id:(1+OR+3+OR+8)&qt=/export&fl=sortabledv_m_udvas,sortabledv_udvas&sort=sortabledv_udvas+asc&wt=xml} hits=3 status=0 QTime=0
[junit4] 2> 16370 INFO (TEST-TestExportWriter.test-seed#[5CAAEC8FBDE8C026]) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={q=id:(1+OR+3+OR+8)&qt=/export&fl=sortabledv_m&sort=sortabledv_udvas+asc&wt=xml} hits=3 status=0 QTime=0
[junit4] 2> 16371 ERROR (TEST-TestExportWriter.test-seed#[5CAAEC8FBDE8C026]) [ ] o.a.s.h.e.ExportWriter java.io.IOException: sortabledv_m{type=text_gen_sort,properties=indexed,tokenized,stored,multiValued,docValues,uninvertible} Must have useDocValuesAsStored='true' to be used with export writer
[junit4] 2> at org.apache.solr.handler.export.ExportWriter.getFieldWriters(ExportWriter.java:477)
[junit4] 2> at org.apache.solr.handler.export.ExportWriter.write(ExportWriter.java:249)
[junit4] 2> at org.apache.solr.core.SolrCore$4.write(SolrCore.java:2755)
[junit4] 2> at org.apache.solr.util.TestHarness.query(TestHarness.java:336)
[junit4] 2> at org.apache.solr.util.TestHarness.query(TestHarness.java:310)
[junit4] 2> at org.apache.solr.handler.export.TestExportWriter.testSortingOutput(TestExportWriter.java:535)
[junit4] 2> at org.apache.solr.handler.export.TestExportWriter.test(TestExportWriter.java:227)
[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:1750)
[junit4] 2> at com.carrotsearch.randomizedtesting.RandomizedRunner$8.evaluate(RandomizedRunner.java:938)
[junit4] 2> at com.carrotsearch.randomizedtesting.RandomizedRunner$9.evaluate(RandomizedRunner.java:974)
[junit4] 2> at com.carrotsearch.randomizedtesting.RandomizedRunner$10.evaluate(RandomizedRunner.java:988)
[junit4] 2> at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:57)
[junit4] 2> at org.apache.lucene.util.TestRuleSetupTeardownChained$1.evaluate(TestRuleSetupTeardownChained.java:49)
[junit4] 2> at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:45)
[junit4] 2> at org.apache.lucene.util.TestRuleThreadAndTestName$1.evaluate(TestRuleThreadAndTestName.java:48)
[junit4] 2> at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:64)
[junit4] 2> at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:47)
[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 com.carrotsearch.randomizedtesting.ThreadLeakControl.forkTimeoutingTask(ThreadLeakControl.java:817)
[junit4] 2> at com.carrotsearch.randomizedtesting.ThreadLeakControl$3.evaluate(ThreadLeakControl.java:468)
[junit4] 2> at com.carrotsearch.randomizedtesting.RandomizedRunner.runSingleTest(RandomizedRunner.java:947)
[junit4] 2> at com.carrotsearch.randomizedtesting.RandomizedRunner$5.evaluate(RandomizedRunner.java:832)
[junit4] 2> at com.carrotsearch.randomizedtesting.RandomizedRunner$6.evaluate(RandomizedRunner.java:883)
[junit4] 2> at com.carrotsearch.randomizedtesting.RandomizedRunner$7.evaluate(RandomizedRunner.java:894)
[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>
[junit4] 2> 16371 INFO (TEST-TestExportWriter.test-seed#[5CAAEC8FBDE8C026]) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={q=id:(1+OR+3+OR+8)&qt=/export&fl=sortabledv&sort=sortabledv_udvas+asc&wt=xml} hits=3 status=0 QTime=0
[junit4] 2> 16371 ERROR (TEST-TestExportWriter.test-seed#[5CAAEC8FBDE8C026]) [ ] o.a.s.h.e.ExportWriter java.io.IOException: sortabledv{type=text_gen_sort,properties=indexed,tokenized,stored,docValues,uninvertible} Must have useDocValuesAsStored='true' to be used with export writer
[junit4] 2> at org.apache.solr.handler.export.ExportWriter.getFieldWriters(ExportWriter.java:477)
[junit4] 2> at org.apache.solr.handler.export.ExportWriter.write(ExportWriter.java:249)
[junit4] 2> at org.apache.solr.core.SolrCore$4.write(SolrCore.java:2755)
[junit4] 2> at org.apache.solr.util.TestHarness.query(TestHarness.java:336)
[junit4] 2> at org.apache.solr.util.TestHarness.query(TestHarness.java:310)
[junit4] 2> at org.apache.solr.handler.export.TestExportWriter.testSortingOutput(TestExportWriter.java:539)
[junit4] 2> at org.apache.solr.handler.export.TestExportWriter.test(TestExportWriter.java:227)
[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:1750)
[junit4] 2> at com.carrotsearch.randomizedtesting.RandomizedRunner$8.evaluate(RandomizedRunner.java:938)
[junit4] 2> at com.carrotsearch.randomizedtesting.RandomizedRunner$9.evaluate(RandomizedRunner.java:974)
[junit4] 2> at com.carrotsearch.randomizedtesting.RandomizedRunner$10.evaluate(RandomizedRunner.java:988)
[junit4] 2> at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:57)
[junit4] 2> at org.apache.lucene.util.TestRuleSetupTeardownChained$1.evaluate(TestRuleSetupTeardownChained.java:49)
[junit4] 2> at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:45)
[junit4] 2> at org.apache.lucene.util.TestRuleThreadAndTestName$1.evaluate(TestRuleThreadAndTestName.java:48)
[junit4] 2> at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:64)
[junit4] 2> at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:47)
[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 com.carrotsearch.randomizedtesting.ThreadLeakControl.forkTimeoutingTask(ThreadLeakControl.java:817)
[junit4] 2> at com.carrotsearch.randomizedtesting.ThreadLeakControl$3.evaluate(ThreadLeakControl.java:468)
[junit4] 2> at com.carrotsearch.randomizedtesting.RandomizedRunner.runSingleTest(RandomizedRunner.java:947)
[junit4] 2> at com.carrotsearch.randomizedtesting.RandomizedRunner$5.evaluate(RandomizedRunner.java:832)
[junit4] 2> at com.carrotsearch.randomizedtesting.RandomizedRunner$6.evaluate(RandomizedRunner.java:883)
[junit4] 2> at com.carrotsearch.randomizedtesting.RandomizedRunner$7.evaluate(RandomizedRunner.java:894)
[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>
[junit4] 2> 16372 INFO (TEST-TestExportWriter.test-seed#[5CAAEC8FBDE8C026]) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={qt=/export&wt=xml} hits=0 status=0 QTime=0
[junit4] 2> 16373 ERROR (TEST-TestExportWriter.test-seed#[5CAAEC8FBDE8C026]) [ ] o.a.s.h.e.ExportWriter java.io.IOException: org.apache.solr.search.SyntaxError: No sort criteria was provided.
[junit4] 2> at org.apache.solr.handler.export.ExportWriter.write(ExportWriter.java:200)
[junit4] 2> at org.apache.solr.core.SolrCore$4.write(SolrCore.java:2755)
[junit4] 2> at org.apache.solr.util.TestHarness.query(TestHarness.java:336)
[junit4] 2> at org.apache.solr.util.TestHarness.query(TestHarness.java:310)
[junit4] 2> at org.apache.solr.handler.export.TestExportWriter.testExportRequiredParams(TestExportWriter.java:555)
[junit4] 2> at org.apache.solr.handler.export.TestExportWriter.test(TestExportWriter.java:228)
[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:1750)
[junit4] 2> at com.carrotsearch.randomizedtesting.RandomizedRunner$8.evaluate(RandomizedRunner.java:938)
[junit4] 2> at com.carrotsearch.randomizedtesting.RandomizedRunner$9.evaluate(RandomizedRunner.java:974)
[junit4] 2> at com.carrotsearch.randomizedtesting.RandomizedRunner$10.evaluate(RandomizedRunner.java:988)
[junit4] 2> at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:57)
[junit4] 2> at org.apache.lucene.util.TestRuleSetupTeardownChained$1.evaluate(TestRuleSetupTeardownChained.java:49)
[junit4] 2> at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:45)
[junit4] 2> at org.apache.lucene.util.TestRuleThreadAndTestName$1.evaluate(TestRuleThreadAndTestName.java:48)
[junit4] 2> at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:64)
[junit4] 2> at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:47)
[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 com.carrotsearch.randomizedtesting.ThreadLeakControl.forkTimeoutingTask(ThreadLeakControl.java:817)
[junit4] 2> at com.carrotsearch.randomizedtesting.ThreadLeakControl$3.evaluate(ThreadLeakControl.java:468)
[junit4] 2> at com.carrotsearch.randomizedtesting.RandomizedRunner.runSingleTest(RandomizedRunner.java:947)
[junit4] 2> at com.carrotsearch.randomizedtesting.RandomizedRunner$5.evaluate(RandomizedRunner.java:832)
[junit4] 2> at com.carrotsearch.randomizedtesting.RandomizedRunner$6.evaluate(RandomizedRunner.java:883)
[junit4] 2> at com.carrotsearch.randomizedtesting.RandomizedRunner$7.evaluate(RandomizedRunner.java:894)
[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)
[j
[...truncated too long message...]
ocessorFactory [collection1] webapp=null path=null params={}{add=[990]} 0 0
[junit4] 2> 20121 INFO (TEST-TestExportWriter.testMultipleSorts-seed#[5CAAEC8FBDE8C026]) [ x:collection1 ] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=null path=null params={}{add=[991]} 0 0
[junit4] 2> 20121 INFO (TEST-TestExportWriter.testMultipleSorts-seed#[5CAAEC8FBDE8C026]) [ x:collection1 ] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=null path=null params={}{add=[992]} 0 0
[junit4] 2> 20121 INFO (TEST-TestExportWriter.testMultipleSorts-seed#[5CAAEC8FBDE8C026]) [ x:collection1 ] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=null path=null params={}{add=[993]} 0 0
[junit4] 2> 20122 INFO (TEST-TestExportWriter.testMultipleSorts-seed#[5CAAEC8FBDE8C026]) [ x:collection1 ] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=null path=null params={}{add=[994]} 0 0
[junit4] 2> 20122 INFO (TEST-TestExportWriter.testMultipleSorts-seed#[5CAAEC8FBDE8C026]) [ x:collection1 ] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=null path=null params={}{add=[995]} 0 0
[junit4] 2> 20122 INFO (TEST-TestExportWriter.testMultipleSorts-seed#[5CAAEC8FBDE8C026]) [ x:collection1 ] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=null path=null params={}{add=[996]} 0 0
[junit4] 2> 20122 INFO (TEST-TestExportWriter.testMultipleSorts-seed#[5CAAEC8FBDE8C026]) [ x:collection1 ] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=null path=null params={}{add=[997]} 0 0
[junit4] 2> 20123 INFO (TEST-TestExportWriter.testMultipleSorts-seed#[5CAAEC8FBDE8C026]) [ x:collection1 ] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=null path=null params={}{add=[998]} 0 0
[junit4] 2> 20123 INFO (TEST-TestExportWriter.testMultipleSorts-seed#[5CAAEC8FBDE8C026]) [ x:collection1 ] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=null path=null params={}{add=[999]} 0 0
[junit4] 2> 20136 INFO (searcherExecutor-16-thread-1-processing-x:collection1) [ x:collection1 ] o.a.s.c.SolrCore [collection1] Registered new searcher autowarm time: 0 ms
[junit4] 2> 20137 INFO (TEST-TestExportWriter.testMultipleSorts-seed#[5CAAEC8FBDE8C026]) [ x:collection1 ] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=null path=null params={}{commit=} 0 13
[junit4] 2> 20139 INFO (TEST-TestExportWriter.testMultipleSorts-seed#[5CAAEC8FBDE8C026]) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={q=*:*&qt=/export&fl=id,longdv,datedv,field2_i_p,stringdv&sort=longdv+asc,datedv+desc,field2_i_p+asc,stringdv+desc&wt=xml} hits=1000 status=0 QTime=1
[junit4] 2> 20177 INFO (TEST-TestExportWriter.testMultipleSorts-seed#[5CAAEC8FBDE8C026]) [ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={q=*:*&qt=/select&fl=id,longdv,datedv,field2_i_p,stringdv&sort=longdv+asc,datedv+desc,field2_i_p+asc,stringdv+desc&rows=1000&wt=json} hits=1000 status=0 QTime=16
[junit4] 2> 20217 INFO (TEST-TestExportWriter.testMultipleSorts-seed#[5CAAEC8FBDE8C026]) [ ] o.a.s.SolrTestCaseJ4 ###Ending testMultipleSorts
[junit4] OK 0.39s J4 | TestExportWriter.testMultipleSorts
[junit4] 2> 20218 INFO (SUITE-TestExportWriter-seed#[5CAAEC8FBDE8C026]-worker) [ ] o.a.s.SolrTestCaseJ4 ###deleteCore
[junit4] 2> 20218 INFO (SUITE-TestExportWriter-seed#[5CAAEC8FBDE8C026]-worker) [ ] o.a.s.c.CoreContainer Shutting down CoreContainer instance=29020747
[junit4] 2> 20219 INFO (coreCloseExecutor-86-thread-1) [ ] o.a.s.c.SolrCore [collection1] CLOSING SolrCore org.apache.solr.core.SolrCore@56b091
[junit4] 2> 20219 INFO (coreCloseExecutor-86-thread-1) [ ] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.core.collection1 tag=SolrCore@56b091
[junit4] 2> 20219 INFO (coreCloseExecutor-86-thread-1) [ ] o.a.s.m.r.SolrJmxReporter Closing reporter [org.apache.solr.metrics.reporters.SolrJmxReporter@861b8e: rootName = null, domain = solr.core.collection1, service url = null, agent id = null] for registry solr.core.collection1/com.codahale.metrics.MetricRegistry@a4cc8
[junit4] 2> 20234 INFO (coreCloseExecutor-86-thread-1) [ ] o.a.s.u.DirectUpdateHandler2 Committing on IndexWriter.close() ... SKIPPED (unnecessary).
[junit4] 2> 20237 INFO (SUITE-TestExportWriter-seed#[5CAAEC8FBDE8C026]-worker) [ ] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.node tag=null
[junit4] 2> 20237 INFO (SUITE-TestExportWriter-seed#[5CAAEC8FBDE8C026]-worker) [ ] o.a.s.m.r.SolrJmxReporter Closing reporter [org.apache.solr.metrics.reporters.SolrJmxReporter@1ac6bd4: rootName = null, domain = solr.node, service url = null, agent id = null] for registry solr.node/com.codahale.metrics.MetricRegistry@e2bbd1
[junit4] 2> 20243 INFO (SUITE-TestExportWriter-seed#[5CAAEC8FBDE8C026]-worker) [ ] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.jvm tag=null
[junit4] 2> 20243 INFO (SUITE-TestExportWriter-seed#[5CAAEC8FBDE8C026]-worker) [ ] o.a.s.m.r.SolrJmxReporter Closing reporter [org.apache.solr.metrics.reporters.SolrJmxReporter@1ff935c: rootName = null, domain = solr.jvm, service url = null, agent id = null] for registry solr.jvm/com.codahale.metrics.MetricRegistry@69261d
[junit4] 2> 20243 INFO (SUITE-TestExportWriter-seed#[5CAAEC8FBDE8C026]-worker) [ ] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.jetty tag=null
[junit4] 2> 20243 INFO (SUITE-TestExportWriter-seed#[5CAAEC8FBDE8C026]-worker) [ ] o.a.s.m.r.SolrJmxReporter Closing reporter [org.apache.solr.metrics.reporters.SolrJmxReporter@62027f: rootName = null, domain = solr.jetty, service url = null, agent id = null] for registry solr.jetty/com.codahale.metrics.MetricRegistry@16b6181
[junit4] 2> NOTE: leaving temporary files on disk at: /home/jenkins/workspace/Lucene-Solr-8.x-Linux/solr/build/solr-core/test/J4/temp/solr.handler.export.TestExportWriter_5CAAEC8FBDE8C026-001
[junit4] 2> NOTE: test params are: codec=Lucene86, sim=Asserting(RandomSimilarity(queryNorm=true): {}), locale=ja, timezone=America/Santo_Domingo
[junit4] 2> NOTE: Linux 5.3.0-59-generic i386/Oracle Corporation 1.8.0_201 (32-bit)/cpus=16,threads=1,free=141658136,total=303038464
[junit4] 2> NOTE: All tests run in this JVM: [TestExportWriter]
[junit4] Completed [5/5 (5!)] on J4 in 19.67s, 10 tests, 1 failure <<< FAILURES!
[...truncated 17 lines...]
BUILD FAILED
/home/jenkins/workspace/Lucene-Solr-8.x-Linux/lucene/common-build.xml:1599: The following error occurred while executing this line:
/home/jenkins/workspace/Lucene-Solr-8.x-Linux/lucene/common-build.xml:1126: There were test failures: 5 suites, 50 tests, 5 failures [seed: 5CAAEC8FBDE8C026]
Total time: 21 seconds
[repro] Setting last failure code to 256
[repro] Failures w/original seeds:
[repro] 5/5 failed: org.apache.solr.handler.export.TestExportWriter
[repro] Exiting with code 256
+ mv lucene/build lucene/build.repro
+ mv solr/build solr/build.repro
+ mv lucene/build.orig lucene/build
+ mv solr/build.orig solr/build
Setting ANT_1_8_2_HOME=/home/jenkins/tools/hudson.tasks.Ant_AntInstallation/ANT_1.8.2
Archiving artifacts
[Java] Sleeping for 5 seconds due to JENKINS-32191...
[Java] Parsing console log (workspace: '/home/jenkins/workspace/Lucene-Solr-8.x-Linux')
[Java] Successfully parsed console log
[Java] -> found 113 issues (skipped 104 duplicates)
[Java] Post processing issues on 'Master' with source code encoding 'UTF-8'
[Java] Creating SCM blamer to obtain author and commit information for affected files
[Java] Creating SCM miner to obtain statistics for affected repository files
[Java] Resolving file names for all issues in source directory '/home/jenkins/workspace/Lucene-Solr-8.x-Linux'
[Java] -> resolved paths in source directory (54 found, 0 not found)
[Java] Resolving module names from module definitions (build.xml, pom.xml, or Manifest.mf files)
[Java] -> resolved module names for 113 issues
[Java] Resolving package names (or namespaces) by parsing the affected files
[Java] -> resolved package names of 54 affected files
[Java] No filter has been set, publishing all 113 issues
[Java] Creating fingerprints for all affected code blocks to track issues over different builds
[Java] -> created fingerprints for 113 issues (skipped 0 issues)
[Java] Copying affected files to Jenkins' build folder '/home/jenkins/jobs/Lucene-Solr-8.x-Linux/builds/3666/files-with-issues'
[Java] -> 54 copied, 0 not in workspace, 0 not-found, 0 with I/O error
[Java] Using reference build 'Lucene-Solr-8.x-Linux #3665' to compute new, fixed, and outstanding issues
[Java] Issues delta (vs. reference build): outstanding: 113, new: 0, fixed: 0
[Java] No quality gates have been set - skipping
[Java] Health report is disabled - skipping
[Java] Created analysis result for 113 issues (found 0 new issues, fixed 0 issues)
[Java] Attaching ResultAction with ID 'java' to run 'Lucene-Solr-8.x-Linux #3666'.
Setting ANT_1_8_2_HOME=/home/jenkins/tools/hudson.tasks.Ant_AntInstallation/ANT_1.8.2
Recording test results
Setting ANT_1_8_2_HOME=/home/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=/home/jenkins/tools/hudson.tasks.Ant_AntInstallation/ANT_1.8.2
Setting ANT_1_8_2_HOME=/home/jenkins/tools/hudson.tasks.Ant_AntInstallation/ANT_1.8.2
Setting ANT_1_8_2_HOME=/home/jenkins/tools/hudson.tasks.Ant_AntInstallation/ANT_1.8.2
Setting ANT_1_8_2_HOME=/home/jenkins/tools/hudson.tasks.Ant_AntInstallation/ANT_1.8.2
Setting ANT_1_8_2_HOME=/home/jenkins/tools/hudson.tasks.Ant_AntInstallation/ANT_1.8.2
Setting ANT_1_8_2_HOME=/home/jenkins/tools/hudson.tasks.Ant_AntInstallation/ANT_1.8.2
[JENKINS] Lucene-Solr-8.x-Linux (64bit/jdk1.8.0_201) - Build # 3667
- Still Unstable!
Posted by Policeman Jenkins Server <je...@thetaphi.de>.
Build: https://jenkins.thetaphi.de/job/Lucene-Solr-8.x-Linux/3667/
Java: 64bit/jdk1.8.0_201 -XX:+UseCompressedOops -XX:+UseG1GC
1 tests failed.
FAILED: org.apache.solr.cloud.autoscaling.sim.TestSimScenario.testSplitShard
Error Message:
java.util.concurrent.TimeoutException: OverseerTriggerThread never caught up to the latest znodeVersion
Stack Trace:
java.lang.AssertionError: java.util.concurrent.TimeoutException: OverseerTriggerThread never caught up to the latest znodeVersion
at __randomizedtesting.SeedInfo.seed([3D303496D17F3619:E63A99FACF8A0AA6]:0)
at org.junit.Assert.fail(Assert.java:88)
at org.junit.Assert.assertTrue(Assert.java:41)
at org.apache.solr.cloud.autoscaling.sim.TestSimScenario.testSplitShard(TestSimScenario.java:163)
at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
at java.lang.reflect.Method.invoke(Method.java:498)
at com.carrotsearch.randomizedtesting.RandomizedRunner.invoke(RandomizedRunner.java:1750)
at com.carrotsearch.randomizedtesting.RandomizedRunner$8.evaluate(RandomizedRunner.java:938)
at com.carrotsearch.randomizedtesting.RandomizedRunner$9.evaluate(RandomizedRunner.java:974)
at com.carrotsearch.randomizedtesting.RandomizedRunner$10.evaluate(RandomizedRunner.java:988)
at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:57)
at org.apache.lucene.util.TestRuleSetupTeardownChained$1.evaluate(TestRuleSetupTeardownChained.java:49)
at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:45)
at org.apache.lucene.util.TestRuleThreadAndTestName$1.evaluate(TestRuleThreadAndTestName.java:48)
at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:64)
at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:47)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:368)
at com.carrotsearch.randomizedtesting.ThreadLeakControl.forkTimeoutingTask(ThreadLeakControl.java:817)
at com.carrotsearch.randomizedtesting.ThreadLeakControl$3.evaluate(ThreadLeakControl.java:468)
at com.carrotsearch.randomizedtesting.RandomizedRunner.runSingleTest(RandomizedRunner.java:947)
at com.carrotsearch.randomizedtesting.RandomizedRunner$5.evaluate(RandomizedRunner.java:832)
at com.carrotsearch.randomizedtesting.RandomizedRunner$6.evaluate(RandomizedRunner.java:883)
at com.carrotsearch.randomizedtesting.RandomizedRunner$7.evaluate(RandomizedRunner.java:894)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:57)
at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:45)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at org.apache.lucene.util.TestRuleStoreClassName$1.evaluate(TestRuleStoreClassName.java:41)
at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:40)
at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:40)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at org.apache.lucene.util.TestRuleAssertionsRequired$1.evaluate(TestRuleAssertionsRequired.java:53)
at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:47)
at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:64)
at org.apache.lucene.util.TestRuleIgnoreTestSuites$1.evaluate(TestRuleIgnoreTestSuites.java:54)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:368)
at java.lang.Thread.run(Thread.java:748)
Build Log:
[...truncated 14132 lines...]
[junit4] Suite: org.apache.solr.cloud.autoscaling.sim.TestSimScenario
[junit4] 2> 256448 INFO (SUITE-TestSimScenario-seed#[3D303496D17F3619]-worker) [ ] o.a.s.SolrTestCase Setting 'solr.default.confdir' system property to test-framework derived value of '/home/jenkins/workspace/Lucene-Solr-8.x-Linux/solr/server/solr/configsets/_default/conf'
[junit4] 2> 256448 INFO (SUITE-TestSimScenario-seed#[3D303496D17F3619]-worker) [ ] o.a.s.SolrTestCaseJ4 SecureRandom sanity checks: test.solr.allowed.securerandom=null & java.security.egd=file:/dev/./urandom
[junit4] 2> 256449 INFO (SUITE-TestSimScenario-seed#[3D303496D17F3619]-worker) [ ] o.a.s.SolrTestCaseJ4 Created dataDir: /home/jenkins/workspace/Lucene-Solr-8.x-Linux/solr/build/solr-core/test/J3/temp/solr.cloud.autoscaling.sim.TestSimScenario_3D303496D17F3619-001/data-dir-22-001
[junit4] 2> 256449 WARN (SUITE-TestSimScenario-seed#[3D303496D17F3619]-worker) [ ] o.a.s.SolrTestCaseJ4 startTrackingSearchers: numOpens=1 numCloses=1
[junit4] 2> 256449 INFO (SUITE-TestSimScenario-seed#[3D303496D17F3619]-worker) [ ] o.a.s.SolrTestCaseJ4 Using TrieFields (NUMERIC_POINTS_SYSPROP=false) w/NUMERIC_DOCVALUES_SYSPROP=false
[junit4] 2> 256450 INFO (SUITE-TestSimScenario-seed#[3D303496D17F3619]-worker) [ ] o.a.s.SolrTestCaseJ4 Randomized ssl (false) and clientAuth (true) via: @org.apache.solr.util.RandomizeSSL(reason=, value=NaN, ssl=NaN, clientAuth=NaN)
[junit4] 2> 256451 INFO (TEST-TestSimScenario.testIndexing-seed#[3D303496D17F3619]) [ ] o.a.s.SolrTestCaseJ4 ###Starting testIndexing
[junit4] 2> 256464 INFO (TEST-TestSimScenario.testIndexing-seed#[3D303496D17F3619]) [ ] o.a.s.c.a.s.SimScenario 1. CreateCluster numNodes=100
[junit4] 2> 256464 INFO (TEST-TestSimScenario.testIndexing-seed#[3D303496D17F3619]) [ ] o.a.s.c.a.s.SimScenario CreateCluster numNodes=100
[junit4] 2> 256478 DEBUG (TEST-TestSimScenario.testIndexing-seed#[3D303496D17F3619]) [ ] o.a.s.c.a.s.SimClusterStateProvider --- new Overseer leader: 127.0.0.1:10000_solr
[junit4] 2> 256479 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Adding .auto_add_replicas and .scheduled_maintenance triggers
[junit4] 2> 256479 DEBUG (TEST-TestSimScenario.testIndexing-seed#[3D303496D17F3619]) [ ] o.a.s.c.a.s.SimClusterStateProvider ** creating new collection states, currentVersion=0
[junit4] 2> 256479 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Refreshing /autoscaling.json with znode version 1
[junit4] 2> 256479 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Current znodeVersion 1, lastZnodeVersion 0
[junit4] 2> 256479 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Processed trigger updates upto znodeVersion 1
[junit4] 2> 256479 DEBUG (TEST-TestSimScenario.testIndexing-seed#[3D303496D17F3619]) [ ] o.a.s.c.a.s.SimClusterStateProvider ** saved cluster state version 0
[junit4] 2> 256479 INFO (TEST-TestSimScenario.testIndexing-seed#[3D303496D17F3619]) [ ] o.a.s.h.a.MetricsHistoryHandler No .system collection, keeping metrics history in memory.
[junit4] 2> 256481 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.NodeLostTrigger NodeLostTrigger .auto_add_replicas - Initial livenodes: [127.0.0.1:10001_solr, 127.0.0.1:10004_solr, 127.0.0.1:10018_solr, 127.0.0.1:10017_solr, 127.0.0.1:10002_solr, 127.0.0.1:10012_solr, 127.0.0.1:10007_solr, 127.0.0.1:10015_solr, 127.0.0.1:10006_solr, 127.0.0.1:10010_solr, 127.0.0.1:10016_solr, 127.0.0.1:10005_solr, 127.0.0.1:10009_solr, 127.0.0.1:10013_solr, 127.0.0.1:10000_solr, 127.0.0.1:10008_solr, 127.0.0.1:10014_solr, 127.0.0.1:10003_solr, 127.0.0.1:10019_solr, 127.0.0.1:10011_solr]
[junit4] 2> 256481 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread -- deactivating old nodeLost / nodeAdded markers
[junit4] 2> 256481 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Current znodeVersion 1, lastZnodeVersion 1
[junit4] 2> 256482 DEBUG (ScheduledTrigger-1678-thread-2) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 33 and last live nodes: 20
[junit4] 2> 256487 INFO (TEST-TestSimScenario.testIndexing-seed#[3D303496D17F3619]) [ ] o.a.s.c.a.s.SimScenario 2. LoadAutoscaling json={'cluster-policy':[]}
[junit4] 2> 256487 INFO (TEST-TestSimScenario.testIndexing-seed#[3D303496D17F3619]) [ ] o.a.s.c.a.s.SimScenario LoadAutoscaling json={'cluster-policy':[]}
[junit4] 2> 256487 DEBUG (TEST-TestSimScenario.testIndexing-seed#[3D303496D17F3619]) [ ] o.a.s.c.a.OverseerTriggerThread Refreshing /autoscaling.json with znode version 2
[junit4] 2> 256488 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Processed trigger updates upto znodeVersion 2
[junit4] 2> 256488 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread -- deactivating old nodeLost / nodeAdded markers
[junit4] 2> 256488 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Current znodeVersion 2, lastZnodeVersion 2
[junit4] 2> 256488 INFO (TEST-TestSimScenario.testIndexing-seed#[3D303496D17F3619]) [ ] o.a.s.c.a.s.SimScenario 3. RunSolrRequest path=/admin/collections&action=CREATE&autoAddReplicas=true&name=testCollection&numShards=2&replicationFactor=2&maxShardsPerNode=2
[junit4] 2> 256488 INFO (TEST-TestSimScenario.testIndexing-seed#[3D303496D17F3619]) [ ] o.a.s.c.a.s.SimScenario RunSolrRequest path=/admin/collections&action=CREATE&autoAddReplicas=true&name=testCollection&numShards=2&replicationFactor=2&maxShardsPerNode=2
[junit4] 2> 256489 DEBUG (simCloudManagerPool-1677-thread-1) [ ] o.a.s.c.a.s.SimClusterStateProvider -- simCreateCollection testCollection, currentVersion=1
[junit4] 2> 256490 DEBUG (simCloudManagerPool-1677-thread-1) [ ] o.a.s.c.a.s.SimClusterStateProvider ** creating new collection states, currentVersion=1
[junit4] 2> 256490 DEBUG (simCloudManagerPool-1677-thread-1) [ ] o.a.s.c.a.s.SimClusterStateProvider ** saved cluster state version 1
[junit4] 2> 256501 DEBUG (simCloudManagerPool-1677-thread-1) [ ] o.a.s.c.a.s.SimClusterStateProvider ** creating new collection states, currentVersion=2
[junit4] 2> 256502 DEBUG (ScheduledTrigger-1678-thread-2) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 100 and last live nodes: 33
[junit4] 2> 256502 DEBUG (simCloudManagerPool-1677-thread-1) [ ] o.a.s.c.a.s.SimClusterStateProvider ** saved cluster state version 2
[junit4] 2> 256518 DEBUG (simCloudManagerPool-1677-thread-2) [ ] o.a.s.c.a.s.SimClusterStateProvider ** creating new collection states, currentVersion=3
[junit4] 2> 256519 DEBUG (simCloudManagerPool-1677-thread-2) [ ] o.a.s.c.a.s.SimClusterStateProvider ** saved cluster state version 3
[junit4] 2> 256519 DEBUG (simCloudManagerPool-1677-thread-2) [ ] o.a.s.c.a.s.SimClusterStateProvider Running leader election (testCollection / shard1)
[junit4] 2> 256519 DEBUG (simCloudManagerPool-1677-thread-2) [ ] o.a.s.c.a.s.SimClusterStateProvider -- elected new leader for testCollection / shard1 (currentVersion=4): {"core_node1":{
[junit4] 2> "core":"testCollection_shard1_replica_n1",
[junit4] 2> "shard":"shard1",
[junit4] 2> "collection":"testCollection",
[junit4] 2> "node_name":"127.0.0.1:10080_solr",
[junit4] 2> "type":"NRT",
[junit4] 2> "leader":"true",
[junit4] 2> "SEARCHER.searcher.maxDoc":0,
[junit4] 2> "SEARCHER.searcher.deletedDocs":0,
[junit4] 2> "INDEX.sizeInBytes":10240,
[junit4] 2> "state":"active",
[junit4] 2> "INDEX.sizeInGB":9.5367431640625E-6,
[junit4] 2> "SEARCHER.searcher.numDocs":0}}
[junit4] 2> 256522 DEBUG (ScheduledTrigger-1678-thread-4) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 100 and last live nodes: 100
[junit4] 2> 256532 DEBUG (simCloudManagerPool-1677-thread-3) [ ] o.a.s.c.a.s.SimClusterStateProvider ** creating new collection states, currentVersion=4
[junit4] 2> 256532 DEBUG (simCloudManagerPool-1677-thread-3) [ ] o.a.s.c.a.s.SimClusterStateProvider ** saved cluster state version 4
[junit4] 2> 256542 DEBUG (simCloudManagerPool-1677-thread-4) [ ] o.a.s.c.a.s.SimClusterStateProvider ** creating new collection states, currentVersion=5
[junit4] 2> 256542 DEBUG (simCloudManagerPool-1677-thread-4) [ ] o.a.s.c.a.s.SimClusterStateProvider ** saved cluster state version 5
[junit4] 2> 256542 DEBUG (simCloudManagerPool-1677-thread-4) [ ] o.a.s.c.a.s.SimClusterStateProvider Running leader election (testCollection / shard2)
[junit4] 2> 256543 DEBUG (ScheduledTrigger-1678-thread-2) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 100 and last live nodes: 100
[junit4] 2> 256542 DEBUG (simCloudManagerPool-1677-thread-4) [ ] o.a.s.c.a.s.SimClusterStateProvider -- elected new leader for testCollection / shard2 (currentVersion=6): {"core_node3":{
[junit4] 2> "core":"testCollection_shard2_replica_n3",
[junit4] 2> "shard":"shard2",
[junit4] 2> "collection":"testCollection",
[junit4] 2> "node_name":"127.0.0.1:10097_solr",
[junit4] 2> "type":"NRT",
[junit4] 2> "leader":"true",
[junit4] 2> "SEARCHER.searcher.maxDoc":0,
[junit4] 2> "SEARCHER.searcher.deletedDocs":0,
[junit4] 2> "INDEX.sizeInBytes":10240,
[junit4] 2> "state":"active",
[junit4] 2> "INDEX.sizeInGB":9.5367431640625E-6,
[junit4] 2> "SEARCHER.searcher.numDocs":0}}
[junit4] 2> 256543 DEBUG (simCloudManagerPool-1677-thread-1) [ ] o.a.s.c.a.s.SimClusterStateProvider -- finished createCollection testCollection, currentVersion=6
[junit4] 2> 256543 INFO (TEST-TestSimScenario.testIndexing-seed#[3D303496D17F3619]) [ ] o.a.s.c.a.s.SimScenario 4. WaitCollection collection=testCollection&shards=2&replicas=2
[junit4] 2> 256543 INFO (TEST-TestSimScenario.testIndexing-seed#[3D303496D17F3619]) [ ] o.a.s.c.a.s.SimScenario WaitCollection collection=testCollection&shards=2&replicas=2
[junit4] 2> 256553 DEBUG (simCloudManagerPool-1677-thread-5) [ ] o.a.s.c.a.s.SimClusterStateProvider ** creating new collection states, currentVersion=6
[junit4] 2> 256553 DEBUG (simCloudManagerPool-1677-thread-5) [ ] o.a.s.c.a.s.SimClusterStateProvider ** saved cluster state version 6
[junit4] 2> 256554 DEBUG (TEST-TestSimScenario.testIndexing-seed#[3D303496D17F3619]) [ ] o.a.s.c.a.s.SimClusterStateProvider ** creating new collection states, currentVersion=7
[junit4] 2> 256554 DEBUG (TEST-TestSimScenario.testIndexing-seed#[3D303496D17F3619]) [ ] o.a.s.c.a.s.SimClusterStateProvider ** saved cluster state version 7
[junit4] 2> 256554 INFO (TEST-TestSimScenario.testIndexing-seed#[3D303496D17F3619]) [ ] o.a.s.c.a.s.SimScenario 5. RunSolrRequest path=/admin/autoscaling&httpMethod=POST&stream.body={'set-trigger':{'name':'indexSizeTrigger','event':'indexSize','waitFor':'10s','aboveDocs':1000,'enabled':true,'actions':[{'name':'compute_plan','class':'solr.ComputePlanAction'},{'name':'execute_plan','class':'solr.ExecutePlanAction'}]}}
[junit4] 2> 256554 INFO (TEST-TestSimScenario.testIndexing-seed#[3D303496D17F3619]) [ ] o.a.s.c.a.s.SimScenario RunSolrRequest path=/admin/autoscaling&httpMethod=POST&stream.body={'set-trigger':{'name':'indexSizeTrigger','event':'indexSize','waitFor':'10s','aboveDocs':1000,'enabled':true,'actions':[{'name':'compute_plan','class':'solr.ComputePlanAction'},{'name':'execute_plan','class':'solr.ExecutePlanAction'}]}}
[junit4] 2> 256563 DEBUG (ScheduledTrigger-1678-thread-4) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 100 and last live nodes: 100
[junit4] 2> 256574 DEBUG (simCloudManagerPool-1677-thread-6) [ ] o.a.s.c.a.AutoScalingHandler Verified autoscaling configuration
[junit4] 2> 256574 DEBUG (simCloudManagerPool-1677-thread-6) [ ] o.a.s.c.a.OverseerTriggerThread Refreshing /autoscaling.json with znode version 3
[junit4] 2> 256574 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Processed trigger updates upto znodeVersion 3
[junit4] 2> 256575 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread -- deactivating old nodeLost / nodeAdded markers
[junit4] 2> 256575 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Current znodeVersion 3, lastZnodeVersion 3
[junit4] 2> 256575 INFO (TEST-TestSimScenario.testIndexing-seed#[3D303496D17F3619]) [ ] o.a.s.c.a.s.SimScenario 6. SetEventListener trigger=indexSizeTrigger&stage=SUCCEEDED
[junit4] 2> 256575 INFO (TEST-TestSimScenario.testIndexing-seed#[3D303496D17F3619]) [ ] o.a.s.c.a.s.SimScenario SetEventListener trigger=indexSizeTrigger&stage=SUCCEEDED
[junit4] 2> 256575 INFO (TEST-TestSimScenario.testIndexing-seed#[3D303496D17F3619]) [ ] o.a.s.c.a.s.SimScenario 7. IndexDocs collection=testCollection&numDocs=3000
[junit4] 2> 256575 INFO (TEST-TestSimScenario.testIndexing-seed#[3D303496D17F3619]) [ ] o.a.s.c.a.s.SimScenario IndexDocs collection=testCollection&numDocs=3000
[junit4] 2> 256579 INFO (TEST-TestSimScenario.testIndexing-seed#[3D303496D17F3619]) [ ] o.a.s.c.a.s.SimScenario 8. RunSimulator
[junit4] 2> 256580 INFO (TEST-TestSimScenario.testIndexing-seed#[3D303496D17F3619]) [ ] o.a.s.c.a.s.SimScenario RunSimulator
[junit4] 2> 256583 DEBUG (ScheduledTrigger-1678-thread-3) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 100 and last live nodes: 100
[junit4] 2> 256604 DEBUG (ScheduledTrigger-1678-thread-4) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 100 and last live nodes: 100
[junit4] 2> 256624 DEBUG (ScheduledTrigger-1678-thread-2) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 100 and last live nodes: 100
[junit4] 2> 256644 DEBUG (ScheduledTrigger-1678-thread-1) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 100 and last live nodes: 100
[junit4] 2> 256664 DEBUG (ScheduledTrigger-1678-thread-3) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 100 and last live nodes: 100
[junit4] 2> 256685 DEBUG (ScheduledTrigger-1678-thread-4) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 100 and last live nodes: 100
[junit4] 2> 256705 DEBUG (ScheduledTrigger-1678-thread-2) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 100 and last live nodes: 100
[junit4] 2> 256725 DEBUG (ScheduledTrigger-1678-thread-1) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 100 and last live nodes: 100
[junit4] 2> 256746 DEBUG (ScheduledTrigger-1678-thread-4) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 100 and last live nodes: 100
[junit4] 2> 256766 DEBUG (ScheduledTrigger-1678-thread-2) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 100 and last live nodes: 100
[junit4] 2> 256786 DEBUG (ScheduledTrigger-1678-thread-4) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 100 and last live nodes: 100
[junit4] 2> 256807 DEBUG (ScheduledTrigger-1678-thread-1) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 100 and last live nodes: 100
[junit4] 2> 256809 DEBUG (ScheduledTrigger-1678-thread-4) [ ] o.a.s.c.a.ScheduledTriggers ++++++++ Cooldown inactive - processing event: {
[junit4] 2> "id":"8db30929ba798Tmnza24cysiyw7ekayqz7vhm2",
[junit4] 2> "source":"indexSizeTrigger",
[junit4] 2> "eventTime":2492801478272920,
[junit4] 2> "eventType":"INDEXSIZE",
[junit4] 2> "properties":{
[junit4] 2> "aboveSize":{
[junit4] 2> "testCollection_shard1_replica_n1":"docs=1500, bytes=3082240",
[junit4] 2> "testCollection_shard2_replica_n3":"docs=1500, bytes=3082240"},
[junit4] 2> "belowSize":{},
[junit4] 2> "requestedOps":[
[junit4] 2> {
[junit4] 2> "action":"SPLITSHARD",
[junit4] 2> "hints":{
[junit4] 2> "COLL_SHARD":[{
[junit4] 2> "first":"testCollection",
[junit4] 2> "second":"shard1"}],
[junit4] 2> "PARAMS":{
[junit4] 2> "splitByPrefix":false,
[junit4] 2> "splitMethod":"link"}}},
[junit4] 2> {
[junit4] 2> "action":"SPLITSHARD",
[junit4] 2> "hints":{
[junit4] 2> "COLL_SHARD":[{
[junit4] 2> "first":"testCollection",
[junit4] 2> "second":"shard2"}],
[junit4] 2> "PARAMS":{
[junit4] 2> "splitByPrefix":false,
[junit4] 2> "splitMethod":"link"}}}]}}
[junit4] 2> 256809 DEBUG (ScheduledTrigger-1678-thread-4) [ ] o.a.s.c.a.ScheduledTriggers Pausing all triggers: [.auto_add_replicas, .scheduled_maintenance, indexSizeTrigger]
[junit4] 2> 256809 DEBUG (ScheduledTrigger-1678-thread-4) [ ] o.a.s.c.a.SystemLogListener Collection .system missing, skip sending event {
[junit4] 2> "id":"8db30929ba798Tmnza24cysiyw7ekayqz7vhm2",
[junit4] 2> "source":"indexSizeTrigger",
[junit4] 2> "eventTime":2492801478272920,
[junit4] 2> "eventType":"INDEXSIZE",
[junit4] 2> "properties":{
[junit4] 2> "aboveSize":{
[junit4] 2> "testCollection_shard1_replica_n1":"docs=1500, bytes=3082240",
[junit4] 2> "testCollection_shard2_replica_n3":"docs=1500, bytes=3082240"},
[junit4] 2> "belowSize":{},
[junit4] 2> "_enqueue_time_":2492811910558770,
[junit4] 2> "requestedOps":[
[junit4] 2> {
[junit4] 2> "action":"SPLITSHARD",
[junit4] 2> "hints":{
[junit4] 2> "COLL_SHARD":[{
[junit4] 2> "first":"testCollection",
[junit4] 2> "second":"shard1"}],
[junit4] 2> "PARAMS":{
[junit4] 2> "splitByPrefix":false,
[junit4] 2> "splitMethod":"link"}}},
[junit4] 2> {
[junit4] 2> "action":"SPLITSHARD",
[junit4] 2> "hints":{
[junit4] 2> "COLL_SHARD":[{
[junit4] 2> "first":"testCollection",
[junit4] 2> "second":"shard2"}],
[junit4] 2> "PARAMS":{
[junit4] 2> "splitByPrefix":false,
[junit4] 2> "splitMethod":"link"}}}]}}
[junit4] 2> 256809 DEBUG (AutoscalingActionExecutor-1679-thread-1) [ ] o.a.s.c.a.ScheduledTriggers -- processing actions for {
[junit4] 2> "id":"8db30929ba798Tmnza24cysiyw7ekayqz7vhm2",
[junit4] 2> "source":"indexSizeTrigger",
[junit4] 2> "eventTime":2492801478272920,
[junit4] 2> "eventType":"INDEXSIZE",
[junit4] 2> "properties":{
[junit4] 2> "aboveSize":{
[junit4] 2> "testCollection_shard1_replica_n1":"docs=1500, bytes=3082240",
[junit4] 2> "testCollection_shard2_replica_n3":"docs=1500, bytes=3082240"},
[junit4] 2> "belowSize":{},
[junit4] 2> "_enqueue_time_":2492811910558770,
[junit4] 2> "requestedOps":[
[junit4] 2> {
[junit4] 2> "action":"SPLITSHARD",
[junit4] 2> "hints":{
[junit4] 2> "COLL_SHARD":[{
[junit4] 2> "first":"testCollection",
[junit4] 2> "second":"shard1"}],
[junit4] 2> "PARAMS":{
[junit4] 2> "splitByPrefix":false,
[junit4] 2> "splitMethod":"link"}}},
[junit4] 2> {
[junit4] 2> "action":"SPLITSHARD",
[junit4] 2> "hints":{
[junit4] 2> "COLL_SHARD":[{
[junit4] 2> "first":"testCollection",
[junit4] 2> "second":"shard2"}],
[junit4] 2> "PARAMS":{
[junit4] 2> "splitByPrefix":false,
[junit4] 2> "splitMethod":"link"}}}]}}
[junit4] 2> 256810 DEBUG (AutoscalingActionExecutor-1679-thread-1) [ ] o.a.s.c.a.ComputePlanAction -- processing event: {
[junit4] 2> "id":"8db30929ba798Tmnza24cysiyw7ekayqz7vhm2",
[junit4] 2> "source":"indexSizeTrigger",
[junit4] 2> "eventTime":2492801478272920,
[junit4] 2> "eventType":"INDEXSIZE",
[junit4] 2> "properties":{
[junit4] 2> "aboveSize":{
[junit4] 2> "testCollection_shard1_replica_n1":"docs=1500, bytes=3082240",
[junit4] 2> "testCollection_shard2_replica_n3":"docs=1500, bytes=3082240"},
[junit4] 2> "belowSize":{},
[junit4] 2> "_enqueue_time_":2492811910558770,
[junit4] 2> "requestedOps":[
[junit4] 2> {
[junit4] 2> "action":"SPLITSHARD",
[junit4] 2> "hints":{
[junit4] 2> "COLL_SHARD":[{
[junit4] 2> "first":"testCollection",
[junit4] 2> "second":"shard1"}],
[junit4] 2> "PARAMS":{
[junit4] 2> "splitByPrefix":false,
[junit4] 2> "splitMethod":"link"}}},
[junit4] 2> {
[junit4] 2> "action":"SPLITSHARD",
[junit4] 2> "hints":{
[junit4] 2> "COLL_SHARD":[{
[junit4] 2> "first":"testCollection",
[junit4] 2> "second":"shard2"}],
[junit4] 2> "PARAMS":{
[junit4] 2> "splitByPrefix":false,
[junit4] 2> "splitMethod":"link"}}}]}} with context properties: {BEFORE_ACTION=[compute_plan]}
[junit4] 2> 256813 DEBUG (AutoscalingActionExecutor-1679-thread-1) [ ] o.a.s.c.a.ComputePlanAction Computed Plan: action=SPLITSHARD&collection=testCollection&shard=shard1&splitMethod=link&splitByPrefix=false
[junit4] 2> 256814 DEBUG (AutoscalingActionExecutor-1679-thread-1) [ ] o.a.s.c.a.ComputePlanAction Computed Plan: action=SPLITSHARD&collection=testCollection&shard=shard2&splitMethod=link&splitByPrefix=false
[junit4] 2> 256814 DEBUG (AutoscalingActionExecutor-1679-thread-1) [ ] o.a.s.c.a.ExecutePlanAction -- processing event: {
[junit4] 2> "id":"8db30929ba798Tmnza24cysiyw7ekayqz7vhm2",
[junit4] 2> "source":"indexSizeTrigger",
[junit4] 2> "eventTime":2492801478272920,
[junit4] 2> "eventType":"INDEXSIZE",
[junit4] 2> "properties":{
[junit4] 2> "__start__":2,
[junit4] 2> "aboveSize":{
[junit4] 2> "testCollection_shard1_replica_n1":"docs=1500, bytes=3082240",
[junit4] 2> "testCollection_shard2_replica_n3":"docs=1500, bytes=3082240"},
[junit4] 2> "belowSize":{},
[junit4] 2> "_enqueue_time_":2492811910558770,
[junit4] 2> "requestedOps":[
[junit4] 2> {
[junit4] 2> "action":"SPLITSHARD",
[junit4] 2> "hints":{
[junit4] 2> "COLL_SHARD":[{
[junit4] 2> "first":"testCollection",
[junit4] 2> "second":"shard1"}],
[junit4] 2> "PARAMS":{
[junit4] 2> "splitByPrefix":false,
[junit4] 2> "splitMethod":"link"}}},
[junit4] 2> {
[junit4] 2> "action":"SPLITSHARD",
[junit4] 2> "hints":{
[junit4] 2> "COLL_SHARD":[{
[junit4] 2> "first":"testCollection",
[junit4] 2> "second":"shard2"}],
[junit4] 2> "PARAMS":{
[junit4] 2> "splitByPrefix":false,
[junit4] 2> "splitMethod":"link"}}}]}} with context properties: {operations=[{
[junit4] 2> "class":"org.apache.solr.client.solrj.request.CollectionAdminRequest$SplitShard",
[junit4] 2> "method":"GET",
[junit4] 2> "params.action":"SPLITSHARD",
[junit4] 2> "params.collection":"testCollection",
[junit4] 2> "params.shard":"shard1",
[junit4] 2> "params.splitMethod":"link",
[junit4] 2> "params.splitByPrefix":"false"}, {
[junit4] 2> "class":"org.apache.solr.client.solrj.request.CollectionAdminRequest$SplitShard",
[junit4] 2> "method":"GET",
[junit4] 2> "params.action":"SPLITSHARD",
[junit4] 2> "params.collection":"testCollection",
[junit4] 2> "params.shard":"shard2",
[junit4] 2> "params.splitMethod":"link",
[junit4] 2> "params.splitByPrefix":"false"}], AFTER_ACTION=[compute_plan], BEFORE_ACTION=[compute_plan, execute_plan]}
[junit4] 2> 256814 DEBUG (AutoscalingActionExecutor-1679-thread-1) [ ] o.a.s.c.a.ExecutePlanAction Executing operation: action=SPLITSHARD&collection=testCollection&shard=shard1&splitMethod=link&splitByPrefix=false
[junit4] 2> 256915 INFO (simCloudManagerPool-1677-thread-8) [ ] o.a.s.c.a.c.SplitShardCmd numSubShards set at: 2
[junit4] 2> 256958 DEBUG (simCloudManagerPool-1677-thread-8) [ ] o.a.s.c.a.s.SimClusterStateProvider ** creating new collection states, currentVersion=8
[junit4] 2> 256958 DEBUG (simCloudManagerPool-1677-thread-8) [ ] o.a.s.c.a.s.SimClusterStateProvider ** saved cluster state version 8
[junit4] 2> 256960 DEBUG (simCloudManagerPool-1677-thread-11) [ ] o.a.s.c.a.s.SimClusterStateProvider ** creating new collection states, currentVersion=9
[junit4] 2> 256960 DEBUG (simCloudManagerPool-1677-thread-11) [ ] o.a.s.c.a.s.SimClusterStateProvider ** saved cluster state version 9
[junit4] 2> 256960 DEBUG (simCloudManagerPool-1677-thread-11) [ ] o.a.s.c.a.s.SimClusterStateProvider Running leader election (testCollection / shard1_1)
[junit4] 2> 256960 DEBUG (simCloudManagerPool-1677-thread-11) [ ] o.a.s.c.a.s.SimClusterStateProvider -- elected new leader for testCollection / shard1_1 (currentVersion=10): {"core_node12":{
[junit4] 2> "core":"testCollection_shard1_1_replica_n11",
[junit4] 2> "shard":"shard1_1",
[junit4] 2> "collection":"testCollection",
[junit4] 2> "node_name":"127.0.0.1:10018_solr",
[junit4] 2> "type":"NRT",
[junit4] 2> "leader":"true",
[junit4] 2> "SEARCHER.searcher.maxDoc":750,
[junit4] 2> "SEARCHER.searcher.deletedDocs":0,
[junit4] 2> "INDEX.sizeInBytes":1546240,
[junit4] 2> "base_url":"http://127.0.0.1:10018/solr",
[junit4] 2> "state":"active",
[junit4] 2> "INDEX.sizeInGB":0.0014400482177734375,
[junit4] 2> "SEARCHER.searcher.numDocs":750}}
[junit4] 2> 256960 DEBUG (simCloudManagerPool-1677-thread-10) [ ] o.a.s.c.a.s.SimClusterStateProvider ** creating new collection states, currentVersion=10
[junit4] 2> 256961 DEBUG (simCloudManagerPool-1677-thread-10) [ ] o.a.s.c.a.s.SimClusterStateProvider ** saved cluster state version 10
[junit4] 2> 256961 DEBUG (simCloudManagerPool-1677-thread-12) [ ] o.a.s.c.a.s.SimClusterStateProvider ** creating new collection states, currentVersion=11
[junit4] 2> 256961 DEBUG (simCloudManagerPool-1677-thread-12) [ ] o.a.s.c.a.s.SimClusterStateProvider ** saved cluster state version 11
[junit4] 2> 256961 DEBUG (simCloudManagerPool-1677-thread-12) [ ] o.a.s.c.a.s.SimClusterStateProvider Running leader election (testCollection / shard1_0)
[junit4] 2> 256961 DEBUG (simCloudManagerPool-1677-thread-12) [ ] o.a.s.c.a.s.SimClusterStateProvider -- elected new leader for testCollection / shard1_0 (currentVersion=12): {"core_node10":{
[junit4] 2> "core":"testCollection_shard1_0_replica_n9",
[junit4] 2> "shard":"shard1_0",
[junit4] 2> "collection":"testCollection",
[junit4] 2> "node_name":"127.0.0.1:10004_solr",
[junit4] 2> "type":"NRT",
[junit4] 2> "leader":"true",
[junit4] 2> "SEARCHER.searcher.maxDoc":750,
[junit4] 2> "SEARCHER.searcher.deletedDocs":0,
[junit4] 2> "INDEX.sizeInBytes":1556480,
[junit4] 2> "base_url":"http://127.0.0.1:10004/solr",
[junit4] 2> "state":"active",
[junit4] 2> "INDEX.sizeInGB":0.0014495849609375,
[junit4] 2> "SEARCHER.searcher.numDocs":750}}
[junit4] 2> 256961 DEBUG (simCloudManagerPool-1677-thread-8) [ ] o.a.s.c.a.s.SimClusterStateProvider ** creating new collection states, currentVersion=12
[junit4] 2> 256961 DEBUG (simCloudManagerPool-1677-thread-8) [ ] o.a.s.c.a.s.SimClusterStateProvider ** saved cluster state version 12
[junit4] 2> 256962 DEBUG (AutoscalingActionExecutor-1679-thread-1) [ ] o.a.s.c.a.ExecutePlanAction Executing operation: action=SPLITSHARD&collection=testCollection&shard=shard2&splitMethod=link&splitByPrefix=false
[junit4] 2> 256962 DEBUG (simCloudManagerPool-1677-thread-15) [ ] o.a.s.c.a.s.SimClusterStateProvider ** creating new collection states, currentVersion=13
[junit4] 2> 256963 DEBUG (simCloudManagerPool-1677-thread-15) [ ] o.a.s.c.a.s.SimClusterStateProvider ** saved cluster state version 13
[junit4] 2> 257063 INFO (simCloudManagerPool-1677-thread-15) [ ] o.a.s.c.a.c.SplitShardCmd numSubShards set at: 2
[junit4] 2> 257105 DEBUG (simCloudManagerPool-1677-thread-15) [ ] o.a.s.c.a.s.SimClusterStateProvider ** creating new collection states, currentVersion=14
[junit4] 2> 257106 DEBUG (simCloudManagerPool-1677-thread-15) [ ] o.a.s.c.a.s.SimClusterStateProvider ** saved cluster state version 14
[junit4] 2> 257115 DEBUG (simCloudManagerPool-1677-thread-17) [ ] o.a.s.c.a.s.SimClusterStateProvider ** creating new collection states, currentVersion=15
[junit4] 2> 257132 DEBUG (simCloudManagerPool-1677-thread-17) [ ] o.a.s.c.a.s.SimClusterStateProvider ** saved cluster state version 15
[junit4] 2> 257132 DEBUG (simCloudManagerPool-1677-thread-18) [ ] o.a.s.c.a.s.SimClusterStateProvider ** creating new collection states, currentVersion=16
[junit4] 2> 257132 DEBUG (simCloudManagerPool-1677-thread-18) [ ] o.a.s.c.a.s.SimClusterStateProvider ** saved cluster state version 16
[junit4] 2> 257132 DEBUG (simCloudManagerPool-1677-thread-18) [ ] o.a.s.c.a.s.SimClusterStateProvider Running leader election (testCollection / shard2_1)
[junit4] 2> 257132 DEBUG (simCloudManagerPool-1677-thread-18) [ ] o.a.s.c.a.s.SimClusterStateProvider -- elected new leader for testCollection / shard2_1 (currentVersion=17): {"core_node22":{
[junit4] 2> "core":"testCollection_shard2_1_replica_n21",
[junit4] 2> "shard":"shard2_1",
[junit4] 2> "collection":"testCollection",
[junit4] 2> "node_name":"127.0.0.1:10018_solr",
[junit4] 2> "type":"NRT",
[junit4] 2> "leader":"true",
[junit4] 2> "SEARCHER.searcher.maxDoc":750,
[junit4] 2> "SEARCHER.searcher.deletedDocs":0,
[junit4] 2> "INDEX.sizeInBytes":1546240,
[junit4] 2> "base_url":"http://127.0.0.1:10018/solr",
[junit4] 2> "state":"active",
[junit4] 2> "INDEX.sizeInGB":0.0014400482177734375,
[junit4] 2> "SEARCHER.searcher.numDocs":750}}
[junit4] 2> 257132 DEBUG (simCloudManagerPool-1677-thread-15) [ ] o.a.s.c.a.s.SimClusterStateProvider ** creating new collection states, currentVersion=17
[junit4] 2> 257132 DEBUG (simCloudManagerPool-1677-thread-15) [ ] o.a.s.c.a.s.SimClusterStateProvider ** saved cluster state version 17
[junit4] 2> 257132 DEBUG (simCloudManagerPool-1677-thread-21) [ ] o.a.s.c.a.s.SimClusterStateProvider Running leader election (testCollection / shard2_0)
[junit4] 2> 257132 DEBUG (simCloudManagerPool-1677-thread-15) [ ] o.a.s.c.a.s.SimClusterStateProvider ** no leader in testCollection / shard2_0:{
[junit4] 2> "parent":"shard2",
[junit4] 2> "stateTimestamp":"1594296345577512150",
[junit4] 2> "range":"0-3fffffff",
[junit4] 2> "state":"construction",
[junit4] 2> "replicas":{
[junit4] 2> "core_node18":{
[junit4] 2> "core":"testCollection_shard2_0_replica_n17",
[junit4] 2> "SEARCHER.searcher.maxDoc":750,
[junit4] 2> "SEARCHER.searcher.deletedDocs":0,
[junit4] 2> "INDEX.sizeInBytes":1556480,
[junit4] 2> "node_name":"127.0.0.1:10082_solr",
[junit4] 2> "base_url":"http://127.0.0.1:10082/solr",
[junit4] 2> "state":"active",
[junit4] 2> "type":"NRT",
[junit4] 2> "INDEX.sizeInGB":0.0014495849609375,
[junit4] 2> "SEARCHER.searcher.numDocs":750},
[junit4] 2> "core_node20":{
[junit4] 2> "core":"testCollection_shard2_0_replica_n19",
[junit4] 2> "SEARCHER.searcher.maxDoc":750,
[junit4] 2> "SEARCHER.searcher.deletedDocs":0,
[junit4] 2> "INDEX.sizeInBytes":1556480,
[junit4] 2> "node_name":"127.0.0.1:10004_solr",
[junit4] 2> "base_url":"http://127.0.0.1:10004/solr",
[junit4] 2> "state":"active",
[junit4] 2> "type":"NRT",
[junit4] 2> "INDEX.sizeInGB":0.0014495849609375,
[junit4] 2> "SEARCHER.searcher.numDocs":750}}}
[junit4] 2> 257132 DEBUG (simCloudManagerPool-1677-thread-21) [ ] o.a.s.c.a.s.SimClusterStateProvider -- elected new leader for testCollection / shard2_0 (currentVersion=18): {"core_node18":{
[junit4] 2> "core":"testCollection_shard2_0_replica_n17",
[junit4] 2> "shard":"shard2_0",
[junit4] 2> "collection":"testCollection",
[junit4] 2> "node_name":"127.0.0.1:10082_solr",
[junit4] 2> "type":"NRT",
[junit4] 2> "leader":"true",
[junit4] 2> "SEARCHER.searcher.maxDoc":750,
[junit4] 2> "SEARCHER.searcher.deletedDocs":0,
[junit4] 2> "INDEX.sizeInBytes":1556480,
[junit4] 2> "base_url":"http://127.0.0.1:10082/solr",
[junit4] 2> "state":"active",
[junit4] 2> "INDEX.sizeInGB":0.0014495849609375,
[junit4] 2> "SEARCHER.searcher.numDocs":750}}
[junit4] 2> 257132 DEBUG (simCloudManagerPool-1677-thread-19) [ ] o.a.s.c.a.s.SimClusterStateProvider ** creating new collection states, currentVersion=18
[junit4] 2> 257133 DEBUG (simCloudManagerPool-1677-thread-19) [ ] o.a.s.c.a.s.SimClusterStateProvider ** saved cluster state version 18
[junit4] 2> 257133 DEBUG (simCloudManagerPool-1677-thread-20) [ ] o.a.s.c.a.s.SimClusterStateProvider ** creating new collection states, currentVersion=19
[junit4] 2> 257133 DEBUG (simCloudManagerPool-1677-thread-20) [ ] o.a.s.c.a.s.SimClusterStateProvider ** saved cluster state version 19
[junit4] 2> 257135 DEBUG (simCloudManagerPool-1677-thread-15) [ ] o.a.s.c.a.s.SimClusterStateProvider ** creating new collection states, currentVersion=20
[junit4] 2> 257135 DEBUG (simCloudManagerPool-1677-thread-15) [ ] o.a.s.c.a.s.SimClusterStateProvider ** saved cluster state version 20
[junit4] 2> 257139 DEBUG (AutoscalingActionExecutor-1679-thread-1) [ ] o.a.s.c.a.s.SimClusterStateProvider ** creating new collection states, currentVersion=21
[junit4] 2> 257140 DEBUG (AutoscalingActionExecutor-1679-thread-1) [ ] o.a.s.c.a.s.SimClusterStateProvider ** saved cluster state version 21
[junit4] 2> 257140 DEBUG (AutoscalingActionExecutor-1679-thread-1) [ ] o.a.s.c.a.SystemLogListener Collection .system missing, skip sending event {
[junit4] 2> "id":"8db30929ba798Tmnza24cysiyw7ekayqz7vhm2",
[junit4] 2> "source":"indexSizeTrigger",
[junit4] 2> "eventTime":2492801478272920,
[junit4] 2> "eventType":"INDEXSIZE",
[junit4] 2> "properties":{
[junit4] 2> "__start__":2,
[junit4] 2> "aboveSize":{
[junit4] 2> "testCollection_shard1_replica_n1":"docs=1500, bytes=3082240",
[junit4] 2> "testCollection_shard2_replica_n3":"docs=1500, bytes=3082240"},
[junit4] 2> "belowSize":{},
[junit4] 2> "_enqueue_time_":2492811910558770,
[junit4] 2> "requestedOps":[
[junit4] 2> {
[junit4] 2> "action":"SPLITSHARD",
[junit4] 2> "hints":{
[junit4] 2> "COLL_SHARD":[{
[junit4] 2> "first":"testCollection",
[junit4] 2> "second":"shard1"}],
[junit4] 2> "PARAMS":{
[junit4] 2> "splitByPrefix":false,
[junit4] 2> "splitMethod":"link"}}},
[junit4] 2> {
[junit4] 2> "action":"SPLITSHARD",
[junit4] 2> "hints":{
[junit4] 2> "COLL_SHARD":[{
[junit4] 2> "first":"testCollection",
[junit4] 2> "second":"shard2"}],
[junit4] 2> "PARAMS":{
[junit4] 2> "splitByPrefix":false,
[junit4] 2> "splitMethod":"link"}}}]}}
[junit4] 2> 257140 DEBUG (AutoscalingActionExecutor-1679-thread-1) [ ] o.a.s.c.a.ScheduledTriggers Resuming trigger: .auto_add_replicas after 100ms
[junit4] 2> 257140 DEBUG (AutoscalingActionExecutor-1679-thread-1) [ ] o.a.s.c.a.ScheduledTriggers Resuming trigger: .scheduled_maintenance after 100ms
[junit4] 2> 257140 DEBUG (AutoscalingActionExecutor-1679-thread-1) [ ] o.a.s.c.a.ScheduledTriggers Resuming trigger: indexSizeTrigger after 100ms
[junit4] 2> 257140 DEBUG (AutoscalingActionExecutor-1679-thread-1) [ ] o.a.s.c.a.ScheduledTriggers -- processing took 16527 ms for event id=8db30929ba798Tmnza24cysiyw7ekayqz7vhm2
[junit4] 2> 257240 DEBUG (ScheduledTrigger-1678-thread-2) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 100 and last live nodes: 100
[junit4] 2> 257260 DEBUG (ScheduledTrigger-1678-thread-3) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 100 and last live nodes: 100
[junit4] 2> 257281 DEBUG (ScheduledTrigger-1678-thread-1) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 100 and last live nodes: 100
[junit4] 2> 257301 DEBUG (ScheduledTrigger-1678-thread-4) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 100 and last live nodes: 100
[junit4] 2> 257321 DEBUG (ScheduledTrigger-1678-thread-2) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 100 and last live nodes: 100
[junit4] 2> 257341 DEBUG (ScheduledTrigger-1678-thread-3) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 100 and last live nodes: 100
[junit4] 2> 257362 DEBUG (ScheduledTrigger-1678-thread-3) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 100 and last live nodes: 100
[junit4] 2> 257382 DEBUG (ScheduledTrigger-1678-thread-4) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 100 and last live nodes: 100
[junit4] 2> 257402 DEBUG (ScheduledTrigger-1678-thread-1) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 100 and last live nodes: 100
[junit4] 2> 257422 DEBUG (ScheduledTrigger-1678-thread-2) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 100 and last live nodes: 100
[junit4] 2> 257443 DEBUG (ScheduledTrigger-1678-thread-3) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 100 and last live nodes: 100
[junit4] 2> 257463 DEBUG (ScheduledTrigger-1678-thread-4) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 100 and last live nodes: 100
[junit4] 2> 257483 DEBUG (ScheduledTrigger-1678-thread-1) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 100 and last live nodes: 100
[junit4] 2> 257507 DEBUG (ScheduledTrigger-1678-thread-2) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 100 and last live nodes: 100
[junit4] 2> 257527 DEBUG (ScheduledTrigger-1678-thread-3) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 100 and last live nodes: 100
[junit4] 2> 257548 DEBUG (ScheduledTrigger-1678-thread-4) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 100 and last live nodes: 100
[junit4] 2> 257568 DEBUG (ScheduledTrigger-1678-thread-1) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 100 and last live nodes: 100
[junit4] 2> 257589 DEBUG (ScheduledTrigger-1678-thread-2) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 100 and last live nodes: 100
[junit4] 2> 257609 DEBUG (ScheduledTrigger-1678-thread-3) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 100 and last live nodes: 100
[junit4] 2> 257629 DEBUG (ScheduledTrigger-1678-thread-4) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 100 and last live nodes: 100
[junit4] 2> 257650 DEBUG (ScheduledTrigger-1678-thread-1) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 100 and last live nodes: 100
[junit4] 2> 257670 DEBUG (ScheduledTrigger-1678-thread-2) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 100 and last live nodes: 100
[junit4] 2> 257690 DEBUG (ScheduledTrigger-1678-thread-4) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 100 and last live nodes: 100
[junit4] 2> 257710 DEBUG (ScheduledTrigger-1678-thread-3) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 100 and last live nodes: 100
[junit4] 2> 257731 DEBUG (ScheduledTrigger-1678-thread-1) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 100 and last live nodes: 100
[junit4] 2> 257751 DEBUG (ScheduledTrigger-1678-thread-2) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 100 and last live nodes: 100
[junit4] 2> 257771 DEBUG (ScheduledTrigger-1678-thread-4) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 100 and last live nodes: 100
[junit4] 2> 257780 INFO (TEST-TestSimScenario.testIndexing-seed#[3D303496D17F3619]) [ ] o.a.s.c.a.s.SimScenario 9. WaitEvent trigger=indexSizeTrigger&wait=60
[junit4] 2> 257780 INFO (TEST-TestSimScenario.testIndexing-seed#[3D303496D17F3619]) [ ] o.a.s.c.a.s.SimScenario WaitEvent trigger=indexSizeTrigger&wait=60
[junit4] 2> 257781 INFO (TEST-TestSimScenario.testIndexing-seed#[3D303496D17F3619]) [ ] o.a.s.c.a.s.SimScenario 10. Assert condition=not_null&key=_trigger_event_indexSizeTrigger
[junit4] 2> 257781 INFO (TEST-TestSimScenario.testIndexing-seed#[3D303496D17F3619]) [ ] o.a.s.c.a.s.SimScenario Assert condition=not_null&key=_trigger_event_indexSizeTrigger
[junit4] 2> 257782 INFO (TEST-TestSimScenario.testIndexing-seed#[3D303496D17F3619]) [ ] o.a.s.c.a.s.SimScenario 11. Assert condition=equals&key=_trigger_event_indexSizeTrigger/eventType&expected=INDEXSIZE
[junit4] 2> 257782 INFO (TEST-TestSimScenario.testIndexing-seed#[3D303496D17F3619]) [ ] o.a.s.c.a.s.SimScenario Assert condition=equals&key=_trigger_event_indexSizeTrigger/eventType&expected=INDEXSIZE
[junit4] 2> 257782 INFO (TEST-TestSimScenario.testIndexing-seed#[3D303496D17F3619]) [ ] o.a.s.c.a.s.SimScenario 12. Assert condition=equals&key=_trigger_event_indexSizeTrigger/properties/requestedOps[0]/action&expected=SPLITSHARD
[junit4] 2> 257782 INFO (TEST-TestSimScenario.testIndexing-seed#[3D303496D17F3619]) [ ] o.a.s.c.a.s.SimScenario Assert condition=equals&key=_trigger_event_indexSizeTrigger/properties/requestedOps[0]/action&expected=SPLITSHARD
[junit4] 2> 257782 INFO (TEST-TestSimScenario.testIndexing-seed#[3D303496D17F3619]) [ ] o.a.s.c.a.s.SimScenario 13. WaitCollection collection=testCollection&shards=6&withInactive=true&requireLeaders=false&replicas=2
[junit4] 2> 257782 INFO (TEST-TestSimScenario.testIndexing-seed#[3D303496D17F3619]) [ ] o.a.s.c.a.s.SimScenario WaitCollection collection=testCollection&shards=6&withInactive=true&requireLeaders=false&replicas=2
[junit4] 2> 257783 DEBUG (TEST-TestSimScenario.testIndexing-seed#[3D303496D17F3619]) [ ] o.a.s.c.a.ScheduledTriggers Shutting down scheduled thread pool executor now
[junit4] 2> 257783 INFO (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread OverseerTriggerThread woken up but we are closed, exiting.
[junit4] 2> 257783 DEBUG (TEST-TestSimScenario.testIndexing-seed#[3D303496D17F3619]) [ ] o.a.s.c.a.ScheduledTriggers Shutting down action executor now
[junit4] 2> 257783 DEBUG (TEST-TestSimScenario.testIndexing-seed#[3D303496D17F3619]) [ ] o.a.s.c.a.ScheduledTriggers Awaiting termination for action executor
[junit4] 2> 257783 DEBUG (TEST-TestSimScenario.testIndexing-seed#[3D303496D17F3619]) [ ] o.a.s.c.a.ScheduledTriggers Awaiting termination for scheduled thread pool executor
[junit4] 2> 257783 DEBUG (TEST-TestSimScenario.testIndexing-seed#[3D303496D17F3619]) [ ] o.a.s.c.a.ScheduledTriggers ScheduledTriggers closed completely
[junit4] 2> 257783 DEBUG (TEST-TestSimScenario.testIndexing-seed#[3D303496D17F3619]) [ ] o.a.s.c.a.OverseerTriggerThread OverseerTriggerThread has been closed explicitly
[junit4] 2> 257784 INFO (TEST-TestSimScenario.testIndexing-seed#[3D303496D17F3619]) [ ] o.a.s.SolrTestCaseJ4 ###Ending testIndexing
[junit4] 2> 257786 INFO (TEST-TestSimScenario.testSuggestions-seed#[3D303496D17F3619]) [ ] o.a.s.SolrTestCaseJ4 ###Starting testSuggestions
[junit4] 2> 257786 INFO (TEST-TestSimScenario.testSuggestions-seed#[3D303496D17F3619]) [ ] o.a.s.c.a.s.SimScenario 1. CreateCluster numNodes=2
[junit4] 2> 257786 INFO (TEST-TestSimScenario.testSuggestions-seed#[3D303496D17F3619]) [ ] o.a.s.c.a.s.SimScenario CreateCluster numNodes=2
[junit4] 2> 257790 DEBUG (TEST-TestSimScenario.testSuggestions-seed#[3D303496D17F3619]) [ ] o.a.s.c.a.s.SimClusterStateProvider --- new Overseer leader: 127.0.0.1:10100_solr
[junit4] 2> 257790 DEBUG (TEST-TestSimScenario.testSuggestions-seed#[3D303496D17F3619]) [ ] o.a.s.c.a.s.SimClusterStateProvider ** creating new collection states, currentVersion=0
[junit4] 2> 257790 DEBUG (TEST-TestSimScenario.testSuggestions-seed#[3D303496D17F3619]) [ ] o.a.s.c.a.s.SimClusterStateProvider ** saved cluster state version 0
[junit4] 2> 257790 INFO (TEST-TestSimScenario.testSuggestions-seed#[3D303496D17F3619]) [ ] o.a.s.h.a.MetricsHistoryHandler No .system collection, keeping metrics history in memory.
[junit4] 2> 257790 INFO (TEST-TestSimScenario.testSuggestions-seed#[3D303496D17F3619]) [ ] o.a.s.c.a.s.SimScenario 2. LoadAutoscaling json={'cluster-policy':[]}
[junit4] 2> 257790 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Adding .auto_add_replicas and .scheduled_maintenance triggers
[junit4] 2> 257790 INFO (TEST-TestSimScenario.testSuggestions-seed#[3D303496D17F3619]) [ ] o.a.s.c.a.s.SimScenario LoadAutoscaling json={'cluster-policy':[]}
[junit4] 2> 257791 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Refreshing /autoscaling.json with znode version 1
[junit4] 2> 257791 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Current znodeVersion 1, lastZnodeVersion 0
[junit4] 2> 257791 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Processed trigger updates upto znodeVersion 1
[junit4] 2> 257791 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.NodeLostTrigger NodeLostTrigger .auto_add_replicas - Initial livenodes: [127.0.0.1:10100_solr, 127.0.0.1:10101_solr]
[junit4] 2> 257793 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread -- deactivating old nodeLost / nodeAdded markers
[junit4] 2> 257793 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Current znodeVersion 1, lastZnodeVersion 1
[junit4] 2> 257793 DEBUG (ScheduledTrigger-1684-thread-2) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 2 and last live nodes: 2
[junit4] 2> 257795 INFO (TEST-TestSimScenario.testSuggestions-seed#[3D303496D17F3619]) [ ] o.a.s.c.a.s.SimScenario 3. RunSolrRequest path=/admin/collections&action=CREATE&autoAddReplicas=true&name=testCollection&numShards=2&replicationFactor=2&maxShardsPerNode=2
[junit4] 2> 257796 INFO (TEST-TestSimScenario.testSuggestions-seed#[3D303496D17F3619]) [ ] o.a.s.c.a.s.SimScenario RunSolrRequest path=/admin/collections&action=CREATE&autoAddReplicas=true&name=testCollection&numShards=2&replicationFactor=2&maxShardsPerNode=2
[junit4] 2> 257799 DEBUG (simCloudManagerPool-1683-thread-1) [ ] o.a.s.c.a.s.SimClusterStateProvider -- simCreateCollection testCollection, currentVersion=1
[junit4] 2> 257799 DEBUG (simCloudManagerPool-1683-thread-1) [ ] o.a.s.c.a.s.SimClusterStateProvider ** creating new collection states, currentVersion=1
[junit4] 2> 257799 DEBUG (simCloudManagerPool-1683-thread-1) [ ] o.a.s.c.a.s.SimClusterStateProvider ** saved cluster state version 1
[junit4] 2> 257810 DEBUG (simCloudManagerPool-1683-thread-1) [ ] o.a.s.c.a.s.SimClusterStateProvider ** creating new collection states, currentVersion=2
[junit4] 2> 257810 DEBUG (simCloudManagerPool-1683-thread-1) [ ] o.a.s.c.a.s.SimClusterStateProvider ** saved cluster state version 2
[junit4] 2> 257813 DEBUG (ScheduledTrigger-1684-thread-3) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 2 and last live nodes: 2
[junit4] 2> 257820 DEBUG (simCloudManagerPool-1683-thread-2) [ ] o.a.s.c.a.s.SimClusterStateProvider ** creating new collection states, currentVersion=3
[junit4] 2> 257821 DEBUG (simCloudManagerPool-1683-thread-2) [ ] o.a.s.c.a.s.SimClusterStateProvider ** saved cluster state version 3
[junit4] 2> 257821 DEBUG (simCloudManagerPool-1683-thread-2) [ ] o.a.s.c.a.s.SimClusterStateProvider Running leader election (testCollection / shard1)
[junit4] 2> 257821 DEBUG (simCloudManagerPool-1683-thread-2) [ ] o.a.s.c.a.s.SimClusterStateProvider -- elected new leader for testCollection / shard1 (currentVersion=4): {"core_node1":{
[junit4] 2> "core":"testCollection_shard1_replica_n1",
[junit4] 2> "shard":"shard1",
[junit4] 2> "collection":"testCollection",
[junit4] 2> "node_name":"127.0.0.1:10100_solr",
[junit4] 2> "type":"NRT",
[junit4] 2> "leader":"true",
[junit4] 2> "SEARCHER.searcher.maxDoc":0,
[junit4] 2> "SEARCHER.searcher.deletedDocs":0,
[junit4] 2> "INDEX.sizeInBytes":10240,
[junit4] 2> "state":"active",
[junit4] 2> "INDEX.sizeInGB":9.5367431640625E-6,
[junit4] 2> "SEARCHER.searcher.numDocs":0}}
[junit4] 2> 257831 DEBUG (simCloudManagerPool-1683-thread-3) [ ] o.a.s.c.a.s.SimClusterStateProvider ** creating new collection states, currentVersion=4
[junit4] 2> 257831 DEBUG (simCloudManagerPool-1683-thread-3) [ ] o.a.s.c.a.s.SimClusterStateProvider ** saved cluster state version 4
[junit4] 2> 257833 DEBUG (ScheduledTrigger-1684-thread-4) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 2 and last live nodes: 2
[junit4] 2> 257842 DEBUG (simCloudManagerPool-1683-thread-4) [ ] o.a.s.c.a.s.SimClusterStateProvider ** creating new collection states, currentVersion=5
[junit4] 2> 257842 DEBUG (simCloudManagerPool-1683-thread-4) [ ] o.a.s.c.a.s.SimClusterStateProvider ** saved cluster state version 5
[junit4] 2> 257842 DEBUG (simCloudManagerPool-1683-thread-4) [ ] o.a.s.c.a.s.SimClusterStateProvider Running leader election (testCollection / shard2)
[junit4] 2> 257842 DEBUG (simCloudManagerPool-1683-thread-4) [ ] o.a.s.c.a.s.SimClusterStateProvider -- elected new leader for testCollection / shard2 (currentVersion=6): {"core_node3":{
[junit4] 2> "core":"testCollection_shard2_replica_n3",
[junit4] 2> "shard":"shard2",
[junit4] 2> "collection":"testCollection",
[junit4] 2> "node_name":"127.0.0.1:10100_solr",
[junit4] 2> "type":"NRT",
[junit4] 2> "leader":"true",
[junit4] 2> "SEARCHER.searcher.maxDoc":0,
[junit4] 2> "SEARCHER.searcher.deletedDocs":0,
[junit4] 2> "INDEX.sizeInBytes":10240,
[junit4] 2> "state":"active",
[junit4] 2> "INDEX.sizeInGB":9.5367431640625E-6,
[junit4] 2> "SEARCHER.searcher.numDocs":0}}
[junit4] 2> 257842 DEBUG (simCloudManagerPool-1683-thread-1) [ ] o.a.s.c.a.s.SimClusterStateProvider -- finished createCollection testCollection, currentVersion=6
[junit4] 2> 257842 INFO (TEST-TestSimScenario.testSuggestions-seed#[3D303496D17F3619]) [ ] o.a.s.c.a.s.SimScenario 4. WaitCollection collection=testCollection&shards=2&replicas=2
[junit4] 2> 257842 INFO (TEST-TestSimScenario.testSuggestions-seed#[3D303496D17F3619]) [ ] o.a.s.c.a.s.SimScenario WaitCollection collection=testCollection&shards=2&replicas=2
[junit4] 2> 257852 DEBUG (simCloudManagerPool-1683-thread-5) [ ] o.a.s.c.a.s.SimClusterStateProvider ** creating new collection states, currentVersion=6
[junit4] 2> 257853 DEBUG (simCloudManagerPool-1683-thread-5) [ ] o.a.s.c.a.s.SimClusterStateProvider ** saved cluster state version 6
[junit4] 2> 257853 DEBUG (TEST-TestSimScenario.testSuggestions-seed#[3D303496D17F3619]) [ ] o.a.s.c.a.s.SimClusterStateProvider ** creating new collection states, currentVersion=7
[junit4] 2> 257853 DEBUG (TEST-TestSimScenario.testSuggestions-seed#[3D303496D17F3619]) [ ] o.a.s.c.a.s.SimClusterStateProvider ** saved cluster state version 7
[junit4] 2> 257853 DEBUG (ScheduledTrigger-1684-thread-3) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 2 and last live nodes: 2
[junit4] 2> 257853 INFO (TEST-TestSimScenario.testSuggestions-seed#[3D303496D17F3619]) [ ] o.a.s.c.a.s.SimScenario 5. CtxSet key=myNode&value=${_random_node_}
[junit4] 2> 257854 INFO (TEST-TestSimScenario.testSuggestions-seed#[3D303496D17F3619]) [ ] o.a.s.c.a.s.SimScenario CtxSet key=myNode&value=127.0.0.1:10101_solr
[junit4] 2> 257854 INFO (TEST-TestSimScenario.testSuggestions-seed#[3D303496D17F3619]) [ ] o.a.s.c.a.s.SimScenario 6. RunSolrRequest path=/admin/collections&action=ADDREPLICA&collection=testCollection&shard=shard1&node=${myNode}
[junit4] 2> 257854 INFO (TEST-TestSimScenario.testSuggestions-seed#[3D303496D17F3619]) [ ] o.a.s.c.a.s.SimScenario RunSolrRequest path=/admin/collections&action=ADDREPLICA&collection=testCollection&shard=shard1&node=127.0.0.1:10101_solr
[junit4] 2> 257855 INFO (simCloudManagerPool-1683-thread-6) [ ] o.a.s.c.a.c.AddReplicaCmd Node Identified 127.0.0.1:10101_solr for creating new replica of shard shard1 for collection testCollection
[junit4] 2> 257855 INFO (simCloudManagerPool-1683-thread-6) [ ] o.a.s.c.a.c.AddReplicaCmd Returning CreateReplica command.
[junit4] 2> 257865 DEBUG (simCloudManagerPool-1683-thread-6) [ ] o.a.s.c.a.s.SimClusterStateProvider ** creating new collection states, currentVersion=8
[junit4] 2> 257865 DEBUG (simCloudManagerPool-1683-thread-6) [ ] o.a.s.c.a.s.SimClusterStateProvider ** saved cluster state version 8
[junit4] 2> 257865 INFO (TEST-TestSimScenario.testSuggestions-seed#[3D303496D17F3619]) [ ] o.a.s.c.a.s.SimScenario 7. RunSolrRequest path=/admin/collections&action=ADDREPLICA&collection=testCollection&shard=shard1&node=${myNode}
[junit4] 2> 257865 INFO (TEST-TestSimScenario.testSuggestions-seed#[3D303496D17F3619]) [ ] o.a.s.c.a.s.SimScenario RunSolrRequest path=/admin/collections&action=ADDREPLICA&collection=testCollection&shard=shard1&node=127.0.0.1:10101_solr
[junit4] 2> 257865 DEBUG (simCloudManagerPool-1683-thread-7) [ ] o.a.s.c.a.s.SimClusterStateProvider ** creating new collection states, currentVersion=9
[junit4] 2> 257866 DEBUG (simCloudManagerPool-1683-thread-7) [ ] o.a.s.c.a.s.SimClusterStateProvider ** saved cluster state version 9
[junit4] 2> 257866 INFO (simCloudManagerPool-1683-thread-7) [ ] o.a.s.c.a.c.AddReplicaCmd Node Identified 127.0.0.1:10101_solr for creating new replica of shard shard1 for collection testCollection
[junit4] 2> 257866 INFO (simCloudManagerPool-1683-thread-7) [ ] o.a.s.c.a.c.AddReplicaCmd Returning CreateReplica command.
[junit4] 2> 257874 DEBUG (ScheduledTrigger-1684-thread-4) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 2 and last live nodes: 2
[junit4] 2> 257876 DEBUG (simCloudManagerPool-1683-thread-7) [ ] o.a.s.c.a.s.SimClusterStateProvider ** creating new collection states, currentVersion=10
[junit4] 2> 257876 DEBUG (simCloudManagerPool-1683-thread-7) [ ] o.a.s.c.a.s.SimClusterStateProvider ** saved cluster state version 10
[junit4] 2> 257876 INFO (TEST-TestSimScenario.testSuggestions-seed#[3D303496D17F3619]) [ ] o.a.s.c.a.s.SimScenario 8. LoopOp iterations=${iterative}
[junit4] 2> 257876 INFO (TEST-TestSimScenario.testSuggestions-seed#[3D303496D17F3619]) [ ] o.a.s.c.a.s.SimScenario LoopOp iterations=0
[junit4] 2> 257876 INFO (TEST-TestSimScenario.testSuggestions-seed#[3D303496D17F3619]) [ ] o.a.s.c.a.s.SimScenario 9. LoopOp iterations=${justCalc}
[junit4] 2> 257876 INFO (TEST-TestSimScenario.testSuggestions-seed#[3D303496D17F3619]) [ ] o.a.s.c.a.s.SimScenario LoopOp iterations=1
[junit4] 2> 257876 INFO (TEST-TestSimScenario.testSuggestions-seed#[3D303496D17F3619]) [ ] o.a.s.c.a.s.SimScenario * iter 1 :
[junit4] 2> 257877 INFO (TEST-TestSimScenario.testSuggestions-seed#[3D303496D17F3619]) [ ] o.a.s.c.a.s.SimScenario - CalculateSuggestions )
[junit4] 2> 257877 DEBUG (TEST-TestSimScenario.testSuggestions-seed#[3D303496D17F3619]) [ ] o.a.s.c.a.s.SimClusterStateProvider ** creating new collection states, currentVersion=11
[junit4] 2> 257878 DEBUG (TEST-TestSimScenario.testSuggestions-seed#[3D303496D17F3619]) [ ] o.a.s.c.a.s.SimClusterStateProvider ** saved cluster state version 11
[junit4] 2> 257885 INFO (TEST-TestSimScenario.testSuggestions-seed#[3D303496D17F3619]) [ ] o.a.s.c.a.s.SimScenario - 1 suggestions
[junit4] 2> 257886 INFO (TEST-TestSimScenario.testSuggestions-seed#[3D303496D17F3619]) [ ] o.a.s.c.a.s.SimScenario - SaveSnapshot path=/home/jenkins/workspace/Lucene-Solr-8.x-Linux/solr/build/solr-core/test/J3/temp/solr.cloud.autoscaling.sim.TestSimScenario_3D303496D17F3619-001/tempDir-001/snapshot/0)
[junit4] 2> 257891 WARN (TEST-TestSimScenario.testSuggestions-seed#[3D303496D17F3619]) [ ] o.a.s.c.a.s.SimUtils V2 action SET_CLUSTER_PROPERTY_OBJ has no equivalent V1 action
[junit4] 2> 257891 WARN (TEST-TestSimScenario.testSuggestions-seed#[3D303496D17F3619]) [ ] o.a.s.c.a.s.SimUtils V2 action GET_NODES has no equivalent V1 action
[junit4] 2> 257894 DEBUG (TEST-TestSimScenario.testSuggestions-seed#[3D303496D17F3619]) [ ] o.a.s.c.a.s.SnapshotDistribStateManager - copying 22 resources from SimDistribStateManager
[junit4] 2> 257894 DEBUG (ScheduledTrigger-1684-thread-3) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 2 and last live nodes: 2
[junit4] 2> 257904 INFO (TEST-TestSimScenario.testSuggestions-seed#[3D303496D17F3619]) [ ] o.a.s.c.a.s.SimScenario 10. Dump redact=true
[junit4] 2> 257904 INFO (TEST-TestSimScenario.testSuggestions-seed#[3D303496D17F3619]) [ ] o.a.s.c.a.s.SimScenario Dump redact=true
[junit4] 2> 257904 DEBUG (TEST-TestSimScenario.testSuggestions-seed#[3D303496D17F3619]) [ ] o.a.s.c.a.s.SnapshotDistribStateManager - copying 22 resources from SimDistribStateManager
[junit4] 2> 257909 INFO (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread OverseerTriggerThread woken up but we are closed, exiting.
[junit4] 2> 257909 DEBUG (TEST-TestSimScenario.testSuggestions-seed#[3D303496D17F3619]) [ ] o.a.s.c.a.ScheduledTriggers Shutting down scheduled thread pool executor now
[junit4] 2> 257909 DEBUG (TEST-TestSimScenario.testSuggestions-seed#[3D303496D17F3619]) [ ] o.a.s.c.a.ScheduledTriggers Shutting down action executor now
[junit4] 2> 257909 DEBUG (TEST-TestSimScenario.testSuggestions-seed#[3D303496D17F3619]) [ ] o.a.s.c.a.ScheduledTriggers Awaiting termination for action executor
[junit4] 2> 257909 DEBUG (TEST-TestSimScenario.testSuggestions-seed#[3D303496D17F3619]) [ ] o.a.s.c.a.ScheduledTriggers Awaiting termination for scheduled thread pool executor
[junit4] 2> 257909 DEBUG (TEST-TestSimScenario.testSuggestions-seed#[3D303496D17F3619]) [ ] o.a.s.c.a.ScheduledTriggers ScheduledTriggers closed completely
[junit4] 2> 257909 DEBUG (TEST-TestSimScenario.testSuggestions-seed#[3D303496D17F3619]) [ ] o.a.s.c.a.OverseerTriggerThread OverseerTriggerThread has been closed explicitly
[junit4] 2> 257909 INFO (TEST-TestSimScenario.testSuggestions-seed#[3D303496D17F3619]) [ ] o.a.s.c.a.s.SimScenario 1. CreateCluster numNodes=2
[junit4] 2> 257909 INFO (TEST-TestSimScenario.testSuggestions-seed#[3D303496D17F3619]) [ ] o.a.s.c.a.s.SimScenario CreateCluster numNodes=2
[junit4] 2> 257911 DEBUG (TEST-TestSimScenario.testSuggestions-seed#[3D303496D17F3619]) [ ] o.a.s.c.a.s.SimClusterStateProvider --- new Overseer leader: 127.0.0.1:10102_solr
[junit4] 2> 257911 DEBUG (TEST-TestSimScenario.testSuggestions-seed#[3D303496D17F3619]) [ ] o.a.s.c.a.s.SimClusterStateProvider ** creating new collection states, currentVersion=0
[junit4] 2> 257911 DEBUG (TEST-TestSimScenario.testSuggestions-seed#[3D303496D17F3619]) [ ] o.a.s.c.a.s.SimClusterStateProvider ** saved cluster state version 0
[junit4] 2> 257911 INFO (TEST-TestSimScenario.testSuggestions-seed#[3D303496D17F3619]) [ ] o.a.s.h.a.MetricsHistoryHandler No .system collection, keeping metrics history in memory.
[junit4] 2> 257912 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Adding .auto_add_replicas and .scheduled_maintenance triggers
[junit4] 2> 257912 INFO (TEST-TestSimScenario.testSuggestions-seed#[3D303496D17F3619]) [ ] o.a.s.c.a.s.SimScenario 2. LoadAutoscaling json={'cluster-policy':[]}
[junit4] 2> 257912 INFO (TEST-TestSimScenario.testSuggestions-seed#[3D303496D17F3619]) [ ] o.a.s.c.a.s.SimScenario LoadAutoscaling json={'cluster-policy':[]}
[junit4] 2> 257912 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Refreshing /autoscaling.json with znode version 1
[junit4] 2> 257912 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Current znodeVersion 1, lastZnodeVersion 0
[junit4] 2> 257912 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Processed trigger updates upto znodeVersion 1
[junit4] 2> 257912 DEBUG (TEST-TestSimScenario.testSuggestions-seed#[3D303496D17F3619]) [ ] o.a.s.c.a.OverseerTriggerThread Refreshing /autoscaling.json with znode version 2
[junit4] 2> 257913 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.NodeLostTrigger NodeLostTrigger .auto_add_replicas - Initial livenodes: [127.0.0.1:10102_solr, 127.0.0.1:10103_solr]
[junit4] 2> 257913 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread -- deactivating old nodeLost / nodeAdded markers
[junit4] 2> 257913 DEBUG (ScheduledTrigger-1690-thread-2) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 2 and last live nodes: 2
[junit4] 2> 257913 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Current znodeVersion 2, lastZnodeVersion 1
[junit4] 2> 257913 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Processed trigger updates upto znodeVersion 2
[junit4] 2> 257913 INFO (TEST-TestSimScenario.testSuggestions-seed#[3D303496D17F3619]) [ ] o.a.s.c.a.s.SimScenario 3. RunSolrRequest path=/admin/collections&action=CREATE&autoAddReplicas=true&name=testCollection&numShards=2&replicationFactor=2&maxShardsPerNode=2
[junit4] 2> 257913 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread -- deactivating old nodeLost / nodeAdded markers
[junit4] 2> 257913 INFO (TEST-TestSimScenario.testSuggestions-seed#[3D303496D17F3619]) [ ] o.a.s.c.a.s.SimScenario RunSolrRequest path=/admin/collections&action=CREATE&autoAddReplicas=true&name=testCollection&numShards=2&replicationFactor=2&maxShardsPerNode=2
[junit4] 2> 257913 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Current znodeVersion 2, lastZnodeVersion 2
[junit4] 2> 257913 DEBUG (simCloudManagerPool-1689-thread-1) [ ] o.a.s.c.a.s.SimClusterStateProvider -- simCreateCollection testCollection, currentVersion=1
[junit4] 2> 257913 DEBUG (simCloudManagerPool-1689-thread-1) [ ] o.a.s.c.a.s.SimClusterStateProvider ** creating new collection states, currentVersion=1
[junit4] 2> 257913 DEBUG (simCloudManagerPool-1689-thread-1) [ ] o.a.s.c.a.s.SimClusterStateProvider ** saved cluster state version 1
[junit4] 2> 257924 DEBUG (simCloudManagerPool-1689-thread-1) [ ] o.a.s.c.a.s.SimClusterStateProvider ** creating new collection states, currentVersion=2
[junit4] 2> 257924 DEBUG (simCloudManagerPool-1689-thread-1) [ ] o.a.s.c.a.s.SimClusterStateProvider ** saved cluster state version 2
[junit4] 2> 257933 DEBUG (ScheduledTrigger-1690-thread-3) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 2 and last live nodes: 2
[junit4] 2> 257934 DEBUG (simCloudManagerPool-1689-thread-2) [ ] o.a.s.c.a.s.SimClusterStateProvider ** creating new collection states, currentVersion=3
[junit4] 2> 257934 DEBUG (simCloudManagerPool-1689-thread-2) [ ] o.a.s.c.a.s.SimClusterStateProvider ** saved cluster state version 3
[junit4] 2> 257934 DEBUG (simCloudManagerPool-1689-thread-2) [ ] o.a.s.c.a.s.SimClusterStateProvider Running leader election (testCollection / shard1)
[junit4] 2> 257934 DEBUG (simCloudManagerPool-1689-thread-2) [ ] o.a.s.c.a.s.SimClusterStateProvider -- elected new leader for testCollection / shard1 (currentVersion=4): {"core_node1":{
[junit4] 2> "core":"testCollection_shard1_replica_n1",
[junit4] 2> "shard":"shard1",
[junit4] 2> "collection":"testCollection",
[junit4] 2> "node_name":"127.0.0.1:10103_solr",
[junit4] 2> "type":"NRT",
[junit4] 2> "leader":"true",
[junit4] 2> "SEARCHER.searcher.maxDoc":0,
[junit4] 2> "SEARCHER.searcher.deletedDocs":0,
[junit4] 2> "INDEX.sizeInBytes":10240,
[junit4] 2> "state":"active",
[junit4] 2> "INDEX.sizeInGB":9.5367431640625E-6,
[junit4] 2> "SEARCHER.searcher.numDocs":0}}
[junit4] 2> 257945 DEBUG (simCloudManagerPool-1689-thread-3) [ ] o.a.s.c.a.s.SimClusterStateProvider ** creating new collection states, currentVersion=4
[junit4] 2> 257945 DEBUG (simCloudManagerPool-1689-thread-3) [ ] o.a.s.c.a.s.SimClusterStateProvider ** saved cluster state version 4
[junit4] 2> 257953 DEBUG (ScheduledTrigger-1690-thread-4) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 2 and last live nodes: 2
[junit4] 2> 257955 DEBUG (simCloudManagerPool-1689-thread-4) [ ] o.a.s.c.a.s.SimClusterStateProvider ** creating new collection states, currentVersion=5
[junit4] 2> 257955 DEBUG (simCloudManagerPool-1689-thread-4) [ ] o.a.s.c.a.s.SimClusterStateProvider ** saved cluster state version 5
[junit4] 2> 257955 DEBUG (simCloudManagerPool-1689-thread-4) [ ] o.a.s.c.a.s.SimClusterStateProvider Running leader election (testCollection / shard2)
[junit4] 2> 257955 DEBUG (simCloudManagerPool-1689-thread-4) [ ] o.a.s.c.a.s.SimClusterStateProvider -- elected new leader for testCollection / shard2 (currentVersion=6): {"core_node3":{
[junit4] 2> "core":"testCollection_shard2_replica_n3",
[junit4] 2> "shard":"shard2",
[junit4] 2> "collection":"testCollection",
[junit4] 2> "node_name":"127.0.0.1:10103_solr",
[junit4] 2> "type":"NRT",
[junit4] 2> "leader":"true",
[junit4] 2> "SEARCHER.searcher.maxDoc":0,
[junit4] 2> "SEARCHER.searcher.deletedDocs":0,
[junit4] 2> "INDEX.sizeInBytes":10240,
[junit4] 2> "state":"active",
[junit4] 2> "INDEX.sizeInGB":9.5367431640625E-6,
[junit4] 2> "SEARCHER.searcher.numDocs":0}}
[junit4] 2> 257955 DEBUG (simCloudManagerPool-1689-thread-1) [ ] o.a.s.c.a.s.SimClusterStateProvider -- finished createCollection testCollection, currentVersion=6
[junit4] 2> 257955 INFO (TEST-TestSimScenario.testSuggestions-seed#[3D303496D17F3619]) [ ] o.a.s.c.a.s.SimScenario 4. WaitCollection collection=testCollection&shards=2&replicas=2
[junit4] 2> 257955 INFO (TEST-TestSimScenario.testSuggestions-seed#[3D303496D17F3619]) [ ] o.a.s.c.a.s.SimScenario WaitCollection collection=testCollection&shards=2&replicas=2
[junit4] 2> 257965 DEBUG (simCloudManagerPool-1689-thread-5) [ ] o.a.s.c.a.s.SimClusterStateProvider ** creating new collection states, currentVersion=6
[junit4] 2> 257966 DEBUG (simCloudManagerPool-1689-thread-5) [ ] o.a.s.c.a.s.SimClusterStateProvider ** saved cluster state version 6
[junit4] 2> 257966 DEBUG (TEST-TestSimScenario.testSuggestions-seed#[3D303496D17F3619]) [ ] o.a.s.c.a.s.SimClusterStateProvider ** creating new collection states, currentVersion=7
[junit4] 2> 257966 DEBUG (TEST-TestSimScenario.testSuggestions-seed#[3D303496D17F3619]) [ ] o.a.s.c.a.s.SimClusterStateProvider ** saved cluster state version 7
[junit4] 2> 257966 INFO (TEST-TestSimScenario.testSuggestions-seed#[3D303496D17F3619]) [ ] o.a.s.c.a.s.SimScenario 5. CtxSet key=myNode&value=${_random_node_}
[junit4] 2> 257966 INFO (TEST-TestSimScenario.testSuggestions-seed#[3D303496D17F3619]) [ ] o.a.s.c.a.s.SimScenario CtxSet key=myNode&value=127.0.0.1:10103_solr
[junit4] 2> 257966 INFO (TEST-TestSimScenario.testSuggestions-seed#[3D303496D17F3619]) [ ] o.a.s.c.a.s.SimScenario 6. RunSolrRequest path=/admin/collections&action=ADDREPLICA&collection=testCollection&shard=shard1&node=${myNode}
[junit4] 2> 257966 INFO (TEST-TestSimScenario.testSuggestions-seed#[3D303496D17F3619]) [ ] o.a.s.c.a.s.SimScenario RunSolrRequest path=/admin/collections&action=ADDREPLICA&collection=testCollection&shard=shard1&node=127.0.0.1:10103_solr
[junit4] 2> 257967 INFO (simCloudManagerPool-1689-thread-6) [ ] o.a.s.c.a.c.AddReplicaCmd Node Identified 127.0.0.1:10103_solr for creating new replica of shard shard1 for collection testCollection
[junit4] 2> 257967 INFO (simCloudManagerPool-1689-thread-6) [ ] o.a.s.c.a.c.AddReplicaCmd Returning CreateReplica command.
[junit4] 2> 257973 DEBUG (ScheduledTrigger-1690-thread-3) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 2 and last live nodes: 2
[junit4] 2> 257977 DEBUG (simCloudManagerPool-1689-thread-6) [ ] o.a.s.c.a.s.SimClusterStateProvider ** creating new collection states, currentVersion=8
[junit4] 2> 257977 DEBUG (simCloudManagerPool-1689-thread-6) [ ] o.a.s.c.a.s.SimClusterStateProvider ** saved cluster state version 8
[junit4] 2> 257978 INFO (TEST-TestSimScenario.testSuggestions-seed#[3D303496D17F3619]) [ ] o.a.s.c.a.s.SimScenario 7. RunSolrRequest path=/admin/collections&action=ADDREPLICA&collection=testCollection&shard=shard1&node=${myNode}
[junit4] 2> 257978 INFO (TEST-TestSimScenario.testSuggestions-seed#[3D303496D17F3619]) [ ] o.a.s.c.a.s.SimScenario RunSolrRequest path=/admin/collections&action=ADDREPLICA&collection=testCollection&shard=shard1&node=127.0.0.1:10103_solr
[junit4] 2> 257978 DEBUG (simCloudManagerPool-1689-thread-7) [ ] o.a.s.c.a.s.SimClusterStateProvider ** creating new collection states, currentVersion=9
[junit4] 2> 257979 DEBUG (simCloudManagerPool-1689-thread-7) [ ] o.a.s.c.a.s.SimClusterStateProvider ** saved cluster state version 9
[junit4] 2> 257979 INFO (simCloudManagerPool-1689-thread-7) [ ] o.a.s.c.a.c.AddReplicaCmd Node Identified 127.0.0.1:10103_solr for creating new replica of shard shard1 for collection testCollection
[junit4] 2> 257979 INFO (simCloudManagerPool-1689-thread-7) [ ] o.a.s.c.a.c.AddReplicaCmd Returning CreateReplica command.
[junit4] 2> 257989 DEBUG (simCloudManagerPool-1689-thread-7) [ ] o.a.s.c.a.s.SimClusterStateProvider ** creating new collection states, currentVersion=10
[junit4] 2> 257989 DEBUG (simCloudManagerPool-1689-thread-7) [ ] o.a.s.c.a.s.SimClusterStateProvider ** saved cluster state version 10
[junit4] 2> 257989 INFO (TEST-TestSimScenario.testSuggestions-seed#[3D303496D17F3619]) [ ] o.a.s.c.a.s.SimScenario 8. LoopOp iterations=${iterative}
[junit4] 2> 257989 INFO (TEST-TestSimScenario.testSuggestions-seed#[3D303496D17F3619]) [ ] o.a.s.c.a.s.SimScenario LoopOp iterations=10
[junit4] 2> 257989 INFO (TEST-TestSimScenario.testSuggestions-seed#[3D303496D17F3619]) [ ] o.a.s.c.a.s.SimScenario * iter 1 :
[junit4] 2> 257989 INFO (TEST-TestSimScenario.testSuggestions-seed#[3D303496D17F3619]) [ ] o.a.s.c.a.s.SimScenario - CalculateSuggestions )
[junit4] 2> 257990 DEBUG (TEST-TestSimScenario.testSuggestions-seed#[3D303496D17F3619]) [ ] o.a.s.c.a.s.SimClusterStateProvider ** creating new collection states, currentVersion=11
[junit4] 2> 257990 DEBUG (TEST-TestSimScenario.testSuggestions-seed#[3D303496D17F3619]) [ ] o.a.s.c.a.s.SimClusterStateProvider ** saved cluster state version 11
[junit4] 2> 257990 INFO (TEST-TestSimScenario.testSuggestions-seed#[3D303496D17F3619]) [ ] o.a.s.c.a.s.SimScenario - 1 suggestions
[junit4] 2> 257990 INFO (TEST-TestSimScenario.testSuggestions-seed#[3D303496D17F3619]) [ ] o.a.s.c.a.s.SimScenario - ApplySuggestions )
[junit4] 2> 257994 DEBUG (ScheduledTrigger-1690-thread-3) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 2 and last live nodes: 2
[junit4] 2> 258014 DEBUG (ScheduledTrigger-1690-thread-1) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 2 and last live nodes: 2
[junit4] 2> 258034 DEBUG (ScheduledTrigger-1690-thread-3) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 2 and last live nodes: 2
[junit4] 2> 258054 DEBUG (ScheduledTrigger-1690-thread-1) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 2 and last live nodes: 2
[junit4] 2> 258074 DEBUG (ScheduledTrigger-1690-thread-3) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 2 and last live nodes: 2
[junit4] 2> 258092 DEBUG (simCloudManagerPool-1689-thread-8) [ ] o.a.s.c.a.s.SimClusterStateProvider -- new replica: {"core_node10":{
[junit4] 2> "core":"testCollection_shard2_replica_n9",
[junit4] 2> "shard":"shard2",
[junit4] 2> "collection":"testCollection",
[junit4] 2> "node_name":"127.0.0.1:10102_solr",
[junit4] 2> "type":"NRT",
[junit4] 2> "leader":"true",
[junit4] 2> "SEARCHER.searcher.maxDoc":0,
[junit4] 2> "INDEX.sizeInBytes":10240,
[junit4] 2> "SEARCHER.searcher.deletedDocs":0,
[junit4] 2> "state":"active",
[junit4] 2> "INDEX.sizeInGB":9.5367431640625E-6,
[junit4] 2> "SEARCHER.searcher.numDocs":0}}
[junit4] 2> 258095 DEBUG (ScheduledTrigger-1690-thread-1) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 2 and last live nodes: 2
[junit4] 2> 258115 DEBUG (ScheduledTrigger-1690-thread-3) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 2 and last live nodes: 2
[junit4] 2> 258135 DEBUG (ScheduledTrigger-1690-thread-1) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 2 and last live nodes: 2
[junit4] 2> 258155 DEBUG (ScheduledTrigger-1690-thread-3) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 2 and last live nodes: 2
[junit4] 2> 258175 DEBUG (ScheduledTrigger-1690-thread-4) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 2 and last live nodes: 2
[junit4] 2> 258195 DEBUG (ScheduledTrigger-1690-thread-1) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 2 and last live nodes: 2
[junit4] 2> 258203 DEBUG (simCloudManagerPool-1689-thread-8) [ ] o.a.s.c.a.s.SimClusterStateProvider ** creating new collection states, currentVersion=12
[junit4] 2> 258203 DEBUG (simCloudManagerPool-1689-thread-8) [ ] o.a.s.c.a.s.SimClusterStateProvider ** saved cluster state version 12
[junit4] 2> 258203 INFO (TEST-TestSimScenario.testSuggestions-seed#[3D303496D17F3619]) [ ] o.a.s.c.a.s.SimScenario - RunSolrRequest path=/admin/collections&action=ADDREPLICA&collection=testCollection&shard=shard1&node=127.0.0.1:10103_solr)
[junit4] 2> 258203 DEBUG (simCloudManagerPool-1689-thread-9) [ ] o.a.s.c.a.s.SimClusterStateProvider ** creating new collection states, currentVersion=13
[junit4] 2> 258203 DEBUG (simCloudManagerPool-1689-thread-9) [ ] o.a.s.c.a.s.SimClusterStateProvider ** saved cluster state version 13
[junit4] 2> 258204 INFO (simCloudManagerPool-1689-thread-9) [ ] o.a.s.c.a.c.AddReplicaCmd Node Identified 127.0.0.1:10103_solr for creating new replica of shard shard1 for collection testCollection
[junit4] 2> 258204 INFO (simCloudManagerPool-1689-thread-9) [ ] o.a.s.c.a.c.AddReplicaCmd Returning CreateReplica command.
[junit4] 2> 258214 DEBUG (simCloudManagerPool-1689-thread-9) [ ] o.a.s.c.a.s.SimClusterStateProvider ** creating new collection states, currentVersion=14
[junit4] 2> 258214 DEBUG (simCloudManagerPool-1689-thread-9) [ ] o.a.s.c.a.s.SimClusterStateProvider ** saved cluster state version 14
[junit4] 2> 258214 INFO (TEST-TestSimScenario.testSuggestions-seed#[3D303496D17F3619]) [ ] o.a.s.c.a.s.SimScenario - RunSolrRequest path=/admin/collections&action=ADDREPLICA&collection=testCollection&shard=shard1&node=127.0.0.1:10103_solr)
[junit4] 2> 258214 DEBUG (simCloudManagerPool-1689-thread-10) [ ] o.a.s.c.a.s.SimClusterStateProvider ** creating new collection states, currentVersion=15
[junit4] 2> 258214 DEBUG (simCloudManagerPool-1689-thread-10) [ ] o.a.s.c.a.s.SimClusterStateProvider ** saved cluster state version 15
[junit4] 2> 258215 INFO (simCloudManagerPool-1689-thread-10) [ ] o.a.s.c.a.c.AddReplicaCmd Node Identified 127.0.0.1:10103_solr for creating new replica of shard shard1 for collection testCollection
[junit4] 2> 258215 INFO (simCloudManagerPool-1689-thread-10) [ ] o.a.s.c.a.c.AddReplicaCmd Returning CreateReplica command.
[junit4] 2> 258216 DEBUG (ScheduledTrigger-1690-thread-4) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 2 and last live nodes: 2
[junit4] 2> 258225 DEBUG (simCloudManagerPool-1689-thread-10) [ ] o.a.s.c.a.s.SimClusterStateProvider ** creating new collection states, currentVersion=16
[junit4] 2> 258225 DEBUG (simCloudManagerPool-1689-thread-10) [ ] o.a.s.c.a.s.SimClusterStateProvider ** saved cluster state version 16
[junit4] 2> 258225 INFO (TEST-TestSimScenario.testSuggestions-seed#[3D303496D17F3619]) [ ] o.a.s.c.a.s.SimScenario * iter 2 :
[junit4] 2> 258225 INFO (TEST-TestSimScenario.testSuggestions-seed#[3D303496D17F3619]) [ ] o.a.s.c.a.s.SimScenario - CalculateSuggestions )
[junit4] 2> 258225 DEBUG (TEST-TestSimScenario.testSuggestions-seed#[3D303496D17F3619]) [ ] o.a.s.c.a.s.SimClusterStateProvider ** creating new collection states, currentVersion=17
[junit4] 2> 258225 DEBUG (TEST-TestSimScenario.testSuggestions-seed#[3D303496D17F3619]) [ ] o.a.s.c.a.s.SimClusterStateProvider ** saved cluster state version 17
[junit4] 2> 258226 INFO (TEST-TestSimScenario.testSuggestions-seed#[3D303496D17F3619]) [ ] o.a.s.c.a.s.SimScenario - 1 suggestions
[junit4] 2> 258226 INFO (TEST-TestSimScenario.testSuggestions-seed#[3D303496D17F3619]) [ ] o.a.s.c.a.s.SimScenario - ApplySuggestions )
[junit4] 2> 258236 DEBUG (ScheduledTrigger-1690-thread-3) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 2 and last live nodes: 2
[junit4] 2> 258256 DEBUG (ScheduledTrigger-1690-thread-1) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 2 and last live nodes: 2
[junit4] 2> 258276 DEBUG (ScheduledTrigger-1690-thread-3) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 2 and last live nodes: 2
[junit4] 2> 258296 DEBUG (ScheduledTrigger-1690-thread-4) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 2 and last live nodes: 2
[junit4] 2> 258316 DEBUG (ScheduledTrigger-1690-thread-1) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 2 and last live nodes: 2
[junit4] 2> 258326 DEBUG (simCloudManagerPool-1689-thread-11) [ ] o.a.s.c.a.s.SimClusterStateProvider -- new replica: {"core_node16":{
[junit4] 2> "core":"testCollection_shard1_replica_n15",
[junit4] 2> "shard":"shard1",
[junit4] 2> "collection":"testCollection",
[junit4] 2> "node_name":"127.0.0.1:10102_solr",
[junit4] 2> "type":"NRT",
[junit4] 2> "leader":"true",
[junit4] 2> "SEARCHER.searcher.maxDoc":0,
[junit4] 2> "INDEX.sizeInBytes":10240,
[junit4] 2> "SEARCHER.searcher.deletedDocs":0,
[junit4] 2> "state":"active",
[junit4] 2> "INDEX.sizeInGB":9.5367431640625E-6,
[junit4] 2> "SEARCHER.searcher.num
[...truncated too long message...]
ove":"true",
[junit4] 2> "params.replica":"core_node1"}, {
[junit4] 2> "class":"org.apache.solr.client.solrj.request.CollectionAdminRequest$MoveReplica",
[junit4] 2> "method":"GET",
[junit4] 2> "params.action":"MOVEREPLICA",
[junit4] 2> "params.collection":"testCollection",
[junit4] 2> "params.targetNode":"127.0.0.1:10106_solr",
[junit4] 2> "params.inPlaceMove":"true",
[junit4] 2> "params.replica":"core_node4"}], AFTER_ACTION=[auto_add_replicas_plan], BEFORE_ACTION=[auto_add_replicas_plan, execute_plan]}
[junit4] 2> 261223 DEBUG (AutoscalingActionExecutor-1703-thread-1) [ ] o.a.s.c.a.ExecutePlanAction Executing operation: action=MOVEREPLICA&collection=testCollection&targetNode=127.0.0.1:10106_solr&inPlaceMove=true&replica=core_node1
[junit4] 2> 261323 DEBUG (simCloudManagerPool-1701-thread-8) [ ] o.a.s.c.a.s.SimClusterStateProvider -- new replica: {"core_node6":{
[junit4] 2> "core":"testCollection_shard1_replica_n5",
[junit4] 2> "shard":"shard1",
[junit4] 2> "collection":"testCollection",
[junit4] 2> "node_name":"127.0.0.1:10106_solr",
[junit4] 2> "type":"NRT",
[junit4] 2> "SEARCHER.searcher.maxDoc":0,
[junit4] 2> "INDEX.sizeInBytes":10240,
[junit4] 2> "SEARCHER.searcher.deletedDocs":0,
[junit4] 2> "state":"down",
[junit4] 2> "INDEX.sizeInGB":9.5367431640625E-6,
[junit4] 2> "SEARCHER.searcher.numDocs":0}}
[junit4] 2> 261434 DEBUG (simCloudManagerPool-1701-thread-8) [ ] o.a.s.c.a.s.SimClusterStateProvider ** creating new collection states, currentVersion=11
[junit4] 2> 261434 DEBUG (simCloudManagerPool-1701-thread-8) [ ] o.a.s.c.a.s.SimClusterStateProvider ** saved cluster state version 11
[junit4] 2> 261434 DEBUG (AutoscalingActionExecutor-1703-thread-1) [ ] o.a.s.c.a.ExecutePlanAction Executing operation: action=MOVEREPLICA&collection=testCollection&targetNode=127.0.0.1:10106_solr&inPlaceMove=true&replica=core_node4
[junit4] 2> 261435 DEBUG (simCloudManagerPool-1701-thread-11) [ ] o.a.s.c.a.s.SimClusterStateProvider ** creating new collection states, currentVersion=12
[junit4] 2> 261435 DEBUG (simCloudManagerPool-1701-thread-11) [ ] o.a.s.c.a.s.SimClusterStateProvider ** saved cluster state version 12
[junit4] 2> 261536 DEBUG (simCloudManagerPool-1701-thread-11) [ ] o.a.s.c.a.s.SimClusterStateProvider -- new replica: {"core_node8":{
[junit4] 2> "core":"testCollection_shard2_replica_n7",
[junit4] 2> "shard":"shard2",
[junit4] 2> "collection":"testCollection",
[junit4] 2> "node_name":"127.0.0.1:10106_solr",
[junit4] 2> "type":"NRT",
[junit4] 2> "SEARCHER.searcher.maxDoc":0,
[junit4] 2> "INDEX.sizeInBytes":10240,
[junit4] 2> "SEARCHER.searcher.deletedDocs":0,
[junit4] 2> "state":"down",
[junit4] 2> "INDEX.sizeInGB":9.5367431640625E-6,
[junit4] 2> "SEARCHER.searcher.numDocs":0}}
[junit4] 2> 261646 DEBUG (simCloudManagerPool-1701-thread-11) [ ] o.a.s.c.a.s.SimClusterStateProvider ** creating new collection states, currentVersion=13
[junit4] 2> 261646 DEBUG (simCloudManagerPool-1701-thread-11) [ ] o.a.s.c.a.s.SimClusterStateProvider ** saved cluster state version 13
[junit4] 2> 261647 DEBUG (AutoscalingActionExecutor-1703-thread-1) [ ] o.a.s.c.a.s.SimClusterStateProvider ** creating new collection states, currentVersion=14
[junit4] 2> 261647 DEBUG (AutoscalingActionExecutor-1703-thread-1) [ ] o.a.s.c.a.s.SimClusterStateProvider ** saved cluster state version 14
[junit4] 2> 261647 DEBUG (AutoscalingActionExecutor-1703-thread-1) [ ] o.a.s.c.a.SystemLogListener Collection .system missing, skip sending event {
[junit4] 2> "id":"8db6403b1b610Tmnza24cysiyw7ekayqz7vhm7",
[junit4] 2> "source":".auto_add_replicas",
[junit4] 2> "eventTime":2493022418875920,
[junit4] 2> "eventType":"NODELOST",
[junit4] 2> "properties":{
[junit4] 2> "eventTimes":[2493022418875920],
[junit4] 2> "preferredOperation":"movereplica",
[junit4] 2> "_enqueue_time_":2493032525588620,
[junit4] 2> "nodeNames":["127.0.0.1:10107_solr"]}}
[junit4] 2> 261647 INFO (TEST-TestSimScenario.testAutoAddReplicas-seed#[3D303496D17F3619]) [ ] o.a.s.c.a.s.SimScenario 8. WaitCollection collection=testCollection&shards=2&replicas=2
[junit4] 2> 261647 DEBUG (AutoscalingActionExecutor-1703-thread-1) [ ] o.a.s.c.a.ScheduledTriggers Resuming trigger: .auto_add_replicas after 100ms
[junit4] 2> 261647 DEBUG (AutoscalingActionExecutor-1703-thread-1) [ ] o.a.s.c.a.ScheduledTriggers Resuming trigger: .scheduled_maintenance after 100ms
[junit4] 2> 261647 DEBUG (AutoscalingActionExecutor-1703-thread-1) [ ] o.a.s.c.a.ScheduledTriggers -- processing took 21260 ms for event id=8db6403b1b610Tmnza24cysiyw7ekayqz7vhm7
[junit4] 2> 261647 INFO (TEST-TestSimScenario.testAutoAddReplicas-seed#[3D303496D17F3619]) [ ] o.a.s.c.a.s.SimScenario WaitCollection collection=testCollection&shards=2&replicas=2
[junit4] 2> 261647 INFO (TEST-TestSimScenario.testAutoAddReplicas-seed#[3D303496D17F3619]) [ ] o.a.s.c.a.s.SimScenario 9. SaveSnapshot path=${snapshotPath}
[junit4] 2> 261647 INFO (TEST-TestSimScenario.testAutoAddReplicas-seed#[3D303496D17F3619]) [ ] o.a.s.c.a.s.SimScenario SaveSnapshot path=/home/jenkins/workspace/Lucene-Solr-8.x-Linux/solr/build/solr-core/test/J3/temp/solr.cloud.autoscaling.sim.TestSimScenario_3D303496D17F3619-001/tempDir-002/snapshot
[junit4] 2> 261647 DEBUG (TEST-TestSimScenario.testAutoAddReplicas-seed#[3D303496D17F3619]) [ ] o.a.s.c.a.s.SnapshotDistribStateManager - copying 23 resources from SimDistribStateManager
[junit4] 2> 261650 DEBUG (TEST-TestSimScenario.testAutoAddReplicas-seed#[3D303496D17F3619]) [ ] o.a.s.c.a.ScheduledTriggers Shutting down scheduled thread pool executor now
[junit4] 2> 261650 INFO (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread OverseerTriggerThread woken up but we are closed, exiting.
[junit4] 2> 261650 DEBUG (TEST-TestSimScenario.testAutoAddReplicas-seed#[3D303496D17F3619]) [ ] o.a.s.c.a.ScheduledTriggers Shutting down action executor now
[junit4] 2> 261650 DEBUG (TEST-TestSimScenario.testAutoAddReplicas-seed#[3D303496D17F3619]) [ ] o.a.s.c.a.ScheduledTriggers Awaiting termination for action executor
[junit4] 2> 261650 DEBUG (TEST-TestSimScenario.testAutoAddReplicas-seed#[3D303496D17F3619]) [ ] o.a.s.c.a.ScheduledTriggers Awaiting termination for scheduled thread pool executor
[junit4] 2> 261650 DEBUG (TEST-TestSimScenario.testAutoAddReplicas-seed#[3D303496D17F3619]) [ ] o.a.s.c.a.ScheduledTriggers ScheduledTriggers closed completely
[junit4] 2> 261650 DEBUG (TEST-TestSimScenario.testAutoAddReplicas-seed#[3D303496D17F3619]) [ ] o.a.s.c.a.OverseerTriggerThread OverseerTriggerThread has been closed explicitly
[junit4] 2> 261653 DEBUG (TEST-TestSimScenario.testAutoAddReplicas-seed#[3D303496D17F3619]) [ ] o.a.s.c.a.s.SnapshotDistribStateManager - loaded snapshot of 23 resources
[junit4] 2> 261654 INFO (TEST-TestSimScenario.testAutoAddReplicas-seed#[3D303496D17F3619]) [ ] o.a.s.SolrTestCaseJ4 ###Ending testAutoAddReplicas
[junit4] 2> NOTE: leaving temporary files on disk at: /home/jenkins/workspace/Lucene-Solr-8.x-Linux/solr/build/solr-core/test/J3/temp/solr.cloud.autoscaling.sim.TestSimScenario_3D303496D17F3619-001
[junit4] 2> NOTE: test params are: codec=Lucene86, sim=Asserting(RandomSimilarity(queryNorm=true): {}), locale=ar-AE, timezone=America/Boa_Vista
[junit4] 2> NOTE: Linux 5.3.0-59-generic amd64/Oracle Corporation 1.8.0_201 (64-bit)/cpus=16,threads=1,free=264280016,total=536870912
[junit4] 2> NOTE: All tests run in this JVM: [TestConfigSets, TestIntervalFaceting, TestSimExtremeIndexing, LoggingHandlerTest, TriggerSetPropertiesIntegrationTest, TestCustomSort, TestFieldTypeCollectionResource, TestDistribPackageStore, ZkSolrClientTest, XsltUpdateRequestHandlerTest, TestRawTransformer, DistributedSpellCheckComponentTest, TestCloudInspectUtil, TestJmxIntegration, TestGeoJSONResponseWriter, TestSkipOverseerOperations, TestMultiValuedNumericRangeQuery, TestEmbeddedSolrServerSchemaAPI, LeaderElectionTest, WrapperMergePolicyFactoryTest, PeerSyncWithLeaderTest, MetricTriggerIntegrationTest, DefaultValueUpdateProcessorTest, TestSimScenario]
[junit4] Completed [221/914 (1!)] on J3 in 5.25s, 4 tests, 1 failure <<< FAILURES!
[...truncated 54458 lines...]
[repro] Jenkins log URL: https://jenkins.thetaphi.de/job/Lucene-Solr-8.x-Linux/3667/consoleText
[repro] Revision: 35d39ee097c7160b7f8d86f321d245fc77af9be6
[repro] Ant options: "-Dargs=-XX:+UseCompressedOops -XX:+UseG1GC"
[repro] Repro line: ant test -Dtestcase=TestSimScenario -Dtests.method=testSplitShard -Dtests.seed=3D303496D17F3619 -Dtests.multiplier=3 -Dtests.slow=true -Dtests.locale=ar-AE -Dtests.timezone=America/Boa_Vista -Dtests.asserts=true -Dtests.file.encoding=UTF-8
[repro] JUnit rest result XML files will be moved to: ./repro-reports
[repro] ant clean
[...truncated 6 lines...]
[repro] Test suites by module:
[repro] solr/core
[repro] TestSimScenario
[repro] ant compile-test
[...truncated 3445 lines...]
[repro] ant test-nocompile -Dtests.dups=5 -Dtests.maxfailures=5 -Dtests.class="*.TestSimScenario" -Dtests.showOutput=onerror "-Dargs=-XX:+UseCompressedOops -XX:+UseG1GC" -Dtests.seed=3D303496D17F3619 -Dtests.multiplier=3 -Dtests.slow=true -Dtests.locale=ar-AE -Dtests.timezone=America/Boa_Vista -Dtests.asserts=true -Dtests.file.encoding=UTF-8
[...truncated 91 lines...]
[repro] Failures w/original seeds:
[repro] 0/5 failed: org.apache.solr.cloud.autoscaling.sim.TestSimScenario
[repro] Exiting with code 0
[...truncated 61 lines...]