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/05/26 17:13:51 UTC
[JENKINS] Lucene-Solr-8.x-MacOSX (64bit/jdk-11.0.6) - Build # 1048
- Still Unstable!
Build: https://jenkins.thetaphi.de/job/Lucene-Solr-8.x-MacOSX/1048/
Java: 64bit/jdk-11.0.6 -XX:+UseCompressedOops -XX:+UseG1GC
1 tests failed.
FAILED: org.apache.solr.cloud.TestLockTree.testLocks
Error Message:
expected:<2> but was:<3>
Stack Trace:
java.lang.AssertionError: expected:<2> but was:<3>
at __randomizedtesting.SeedInfo.seed([F15B3027CC8605F9:88914ADEC456EE12]:0)
at org.junit.Assert.fail(Assert.java:88)
at org.junit.Assert.failNotEquals(Assert.java:834)
at org.junit.Assert.assertEquals(Assert.java:645)
at org.junit.Assert.assertEquals(Assert.java:631)
at org.apache.solr.cloud.TestLockTree.testLocks(TestLockTree.java:99)
at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
at java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
at java.base/java.lang.reflect.Method.invoke(Method.java:566)
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 org.apache.lucene.util.TestRuleAssertionsRequired$1.evaluate(TestRuleAssertionsRequired.java:53)
at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:47)
at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:64)
at org.apache.lucene.util.TestRuleIgnoreTestSuites$1.evaluate(TestRuleIgnoreTestSuites.java:54)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:368)
at java.base/java.lang.Thread.run(Thread.java:834)
Build Log:
[...truncated 15121 lines...]
[junit4] Suite: org.apache.solr.cloud.TestLockTree
[junit4] 2> 1533112 INFO (SUITE-TestLockTree-seed#[F15B3027CC8605F9]-worker) [ ] o.a.s.SolrTestCase Setting 'solr.default.confdir' system property to test-framework derived value of '/Users/jenkins/workspace/Lucene-Solr-8.x-MacOSX/solr/server/solr/configsets/_default/conf'
[junit4] 2> 1533112 INFO (SUITE-TestLockTree-seed#[F15B3027CC8605F9]-worker) [ ] o.a.s.SolrTestCaseJ4 SecureRandom sanity checks: test.solr.allowed.securerandom=null & java.security.egd=file:/dev/./urandom
[junit4] 2> 1533113 INFO (SUITE-TestLockTree-seed#[F15B3027CC8605F9]-worker) [ ] o.a.s.SolrTestCaseJ4 Created dataDir: /Users/jenkins/workspace/Lucene-Solr-8.x-MacOSX/solr/build/solr-core/test/J1/temp/solr.cloud.TestLockTree_F15B3027CC8605F9-001/data-dir-82-001
[junit4] 2> 1533113 WARN (SUITE-TestLockTree-seed#[F15B3027CC8605F9]-worker) [ ] o.a.s.SolrTestCaseJ4 startTrackingSearchers: numOpens=16 numCloses=16
[junit4] 2> 1533114 INFO (SUITE-TestLockTree-seed#[F15B3027CC8605F9]-worker) [ ] o.a.s.SolrTestCaseJ4 Using TrieFields (NUMERIC_POINTS_SYSPROP=false) w/NUMERIC_DOCVALUES_SYSPROP=true
[junit4] 2> 1533116 INFO (SUITE-TestLockTree-seed#[F15B3027CC8605F9]-worker) [ ] o.a.s.SolrTestCaseJ4 Randomized ssl (false) and clientAuth (false) via: @org.apache.solr.util.RandomizeSSL(reason="", value=0.0/0.0, ssl=0.0/0.0, clientAuth=0.0/0.0) w/ MAC_OS_X supressed clientAuth
[junit4] 2> 1533152 INFO (TEST-TestLockTree.testLocks-seed#[F15B3027CC8605F9]) [ ] o.a.s.SolrTestCaseJ4 ###Starting testLocks
[junit4] 2> 1533241 INFO (TEST-TestLockTree.testLocks-seed#[F15B3027CC8605F9]) [ ] o.a.s.c.TestLockTree counter : 0 , expected : [coll1/shard1/core_node2, coll2/shard2], actual : [coll1/shard1/core_node2, coll2/shard2, coll2]
[junit4] 2> 1533242 INFO (TEST-TestLockTree.testLocks-seed#[F15B3027CC8605F9]) [ ] o.a.s.SolrTestCaseJ4 ###Ending testLocks
[junit4] 2> NOTE: reproduce with: ant test -Dtestcase=TestLockTree -Dtests.method=testLocks -Dtests.seed=F15B3027CC8605F9 -Dtests.slow=true -Dtests.locale=yo-BJ -Dtests.timezone=Atlantic/Cape_Verde -Dtests.asserts=true -Dtests.file.encoding=ISO-8859-1
[junit4] FAILURE 0.13s J1 | TestLockTree.testLocks <<<
[junit4] > Throwable #1: java.lang.AssertionError: expected:<2> but was:<3>
[junit4] > at __randomizedtesting.SeedInfo.seed([F15B3027CC8605F9:88914ADEC456EE12]:0)
[junit4] > at org.apache.solr.cloud.TestLockTree.testLocks(TestLockTree.java:99)
[junit4] > at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
[junit4] > at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
[junit4] > at java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
[junit4] > at java.base/java.lang.reflect.Method.invoke(Method.java:566)
[junit4] > at java.base/java.lang.Thread.run(Thread.java:834)
[junit4] 2> NOTE: leaving temporary files on disk at: /Users/jenkins/workspace/Lucene-Solr-8.x-MacOSX/solr/build/solr-core/test/J1/temp/solr.cloud.TestLockTree_F15B3027CC8605F9-001
[junit4] 2> NOTE: test params are: codec=Asserting(Lucene86), sim=Asserting(org.apache.lucene.search.similarities.AssertingSimilarity@5cbf46f9), locale=yo-BJ, timezone=Atlantic/Cape_Verde
[junit4] 2> NOTE: Mac OS X 10.14.6 x86_64/AdoptOpenJDK 11.0.6 (64-bit)/cpus=6,threads=1,free=228803856,total=467664896
[junit4] 2> NOTE: All tests run in this JVM: [TestDeprecatedFilters, ZkStateWriterTest, SpatialFilterTest, NodeLostTriggerTest, TestAtomicUpdateErrorCases, TestClassicSimilarityFactory, OverseerStatusTest, TestSimComputePlanAction, TestZkChroot, TransactionLogTest, TestSubQueryTransformerCrossCore, SyncSliceTest, ZkCLITest, TestSimpleTextCodec, SOLR749Test, TestManagedSynonymFilterFactory, TestSimScenario, RegexBytesRefFilterTest, TestRandomDVFaceting, TestCodecSupport, DistanceUnitsTest, JsonLoaderTest, XMLAtomicUpdateMultivalueTest, TestDistributedSearch, OpenExchangeRatesOrgProviderTest, JWTVerificationkeyResolverTest, TestDistribPackageStore, DataDrivenBlockJoinTest, TermsComponentTest, AtomicUpdateProcessorFactoryTest, ScheduledTriggerTest, TestDirectoryFactory, ConfigureRecoveryStrategyTest, CdcrBidirectionalTest, DistributedQueryComponentOptimizationTest, CdcrVersionReplicationTest, TestStandardQParsers, SSLMigrationTest, TestSolrXml, TestSolrQueryResponse, CoreAdminRequestStatusTest, RequiredFieldsTest, InfoHandlerTest, TestInfoStreamLogging, TestInPlaceUpdatesRequiredField, TestSizeLimitedDistributedMap, TestTolerantUpdateProcessorCloud, Tagger2Test, FuzzySearchTest, TestJsonFacets, LeaderVoteWaitTimeoutTest, TestStressCloudBlindAtomicUpdates, SolrMetricReporterTest, OverseerCollectionConfigSetProcessorTest, HdfsChaosMonkeyNothingIsSafeTest, AdminHandlersProxyTest, BasicAuthOnSingleNodeTest, BJQParserTest, SpellingQueryConverterTest, SynonymTokenizerTest, TestPayloadScoreQParserPlugin, JavaBinAtomicUpdateMultivalueTest, TestSolrCLIRunExample, PluginInfoTest, TemplateUpdateProcessorTest, CreateRoutedAliasTest, TestSolrCoreParser, SuggesterTest, TestDownShardTolerantSearch, TestSweetSpotSimilarityFactory, MultiThreadedOCPTest, TestLegacyTerms, TestCollectionsAPIViaSolrCloudCluster, PrimUtilsTest, FacetPivotSmallTest, TestExternalRoleRuleBasedAuthorizationPlugin, TestTolerantSearch, TestCloudNestedDocsSort, TestLogWatcher, TestTrackingShardHandlerFactory, MetricTriggerIntegrationTest, TestSQLHandler, TestLFUCache, FullSolrCloudDistribCmdsTest, TestUnifiedSolrHighlighter, TestPHPSerializedResponseWriter, TestDocTermOrds, TestConfigSetsAPIZkFailure, StatsComponentTest, DocValuesNotIndexedTest, ForceLeaderTest, LeaderElectionIntegrationTest, PeerSyncReplicationTest, SolrCloudExampleTest, TestCloudRecovery2, TestLockTree]
[junit4] Completed [544/910 (1!)] on J1 in 0.27s, 1 test, 1 failure <<< FAILURES!
[...truncated 49056 lines...]
[repro] Jenkins log URL: https://jenkins.thetaphi.de/job/Lucene-Solr-8.x-MacOSX/1048/consoleText
[repro] Revision: 96e3c25d4432a36f4a49afe17542797c2db690d4
[repro] Ant options: "-Dargs=-XX:+UseCompressedOops -XX:+UseG1GC"
[repro] Repro line: ant test -Dtestcase=TestLockTree -Dtests.method=testLocks -Dtests.seed=F15B3027CC8605F9 -Dtests.slow=true -Dtests.locale=yo-BJ -Dtests.timezone=Atlantic/Cape_Verde -Dtests.asserts=true -Dtests.file.encoding=ISO-8859-1
[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] TestLockTree
[repro] ant compile-test
[...truncated 3486 lines...]
[repro] ant test-nocompile -Dtests.dups=5 -Dtests.maxfailures=5 -Dtests.class="*.TestLockTree" -Dtests.showOutput=onerror "-Dargs=-XX:+UseCompressedOops -XX:+UseG1GC" -Dtests.seed=F15B3027CC8605F9 -Dtests.slow=true -Dtests.locale=yo-BJ -Dtests.timezone=Atlantic/Cape_Verde -Dtests.asserts=true -Dtests.file.encoding=ISO-8859-1
[...truncated 81 lines...]
[repro] Failures w/original seeds:
[repro] 0/5 failed: org.apache.solr.cloud.TestLockTree
[repro] Exiting with code 0
[...truncated 73 lines...]
[JENKINS] Lucene-Solr-8.x-MacOSX (64bit/jdk-14) - Build # 1049 -
Still Unstable!
Posted by Policeman Jenkins Server <je...@thetaphi.de>.
Build: https://jenkins.thetaphi.de/job/Lucene-Solr-8.x-MacOSX/1049/
Java: 64bit/jdk-14 -XX:-UseCompressedOops -XX:+UseSerialGC
2 tests failed.
FAILED: org.apache.solr.cloud.api.collections.SplitByPrefixTest.doTest
Error Message:
Timed out waiting for sub shards to be active. Timeout waiting to see state for collection=c1 :DocCollection(c1//collections/c1/state.json/19)={ "pullReplicas":"0", "replicationFactor":"1", "shards":{"shard1":{ "range":"80000000-7fffffff", "state":"active", "replicas":{"core_node2":{ "core":"c1_shard1_replica_n1", "base_url":"http://127.0.0.1:55639/solr", "node_name":"127.0.0.1:55639_solr", "state":"active", "type":"NRT", "force_set_state":"false", "leader":"true"}}}}, "router":{"name":"compositeId"}, "maxShardsPerNode":"100", "autoAddReplicas":"false", "nrtReplicas":"1", "tlogReplicas":"0"} Live Nodes: [127.0.0.1:55639_solr] Last available state: DocCollection(c1//collections/c1/state.json/19)={ "pullReplicas":"0", "replicationFactor":"1", "shards":{"shard1":{ "range":"80000000-7fffffff", "state":"active", "replicas":{"core_node2":{ "core":"c1_shard1_replica_n1", "base_url":"http://127.0.0.1:55639/solr", "node_name":"127.0.0.1:55639_solr", "state":"active", "type":"NRT", "force_set_state":"false", "leader":"true"}}}}, "router":{"name":"compositeId"}, "maxShardsPerNode":"100", "autoAddReplicas":"false", "nrtReplicas":"1", "tlogReplicas":"0"}
Stack Trace:
java.lang.AssertionError: Timed out waiting for sub shards to be active.
Timeout waiting to see state for collection=c1 :DocCollection(c1//collections/c1/state.json/19)={
"pullReplicas":"0",
"replicationFactor":"1",
"shards":{"shard1":{
"range":"80000000-7fffffff",
"state":"active",
"replicas":{"core_node2":{
"core":"c1_shard1_replica_n1",
"base_url":"http://127.0.0.1:55639/solr",
"node_name":"127.0.0.1:55639_solr",
"state":"active",
"type":"NRT",
"force_set_state":"false",
"leader":"true"}}}},
"router":{"name":"compositeId"},
"maxShardsPerNode":"100",
"autoAddReplicas":"false",
"nrtReplicas":"1",
"tlogReplicas":"0"}
Live Nodes: [127.0.0.1:55639_solr]
Last available state: DocCollection(c1//collections/c1/state.json/19)={
"pullReplicas":"0",
"replicationFactor":"1",
"shards":{"shard1":{
"range":"80000000-7fffffff",
"state":"active",
"replicas":{"core_node2":{
"core":"c1_shard1_replica_n1",
"base_url":"http://127.0.0.1:55639/solr",
"node_name":"127.0.0.1:55639_solr",
"state":"active",
"type":"NRT",
"force_set_state":"false",
"leader":"true"}}}},
"router":{"name":"compositeId"},
"maxShardsPerNode":"100",
"autoAddReplicas":"false",
"nrtReplicas":"1",
"tlogReplicas":"0"}
at __randomizedtesting.SeedInfo.seed([3A6128D520290F62:9D2590714D921CDB]:0)
at org.junit.Assert.fail(Assert.java:88)
at org.apache.solr.cloud.SolrCloudTestCase.waitForState(SolrCloudTestCase.java:324)
at org.apache.solr.cloud.SolrCloudTestCase.waitForState(SolrCloudTestCase.java:301)
at org.apache.solr.cloud.api.collections.SplitByPrefixTest.doTest(SplitByPrefixTest.java:176)
at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
at java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
at java.base/java.lang.reflect.Method.invoke(Method.java:564)
at com.carrotsearch.randomizedtesting.RandomizedRunner.invoke(RandomizedRunner.java: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 org.apache.lucene.util.TestRuleAssertionsRequired$1.evaluate(TestRuleAssertionsRequired.java:53)
at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:47)
at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:64)
at org.apache.lucene.util.TestRuleIgnoreTestSuites$1.evaluate(TestRuleIgnoreTestSuites.java:54)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:368)
at java.base/java.lang.Thread.run(Thread.java:832)
FAILED: org.apache.solr.cloud.autoscaling.TriggerCooldownIntegrationTest.testCooldown
Error Message:
The trigger did not fire at all
Stack Trace:
java.lang.AssertionError: The trigger did not fire at all
at __randomizedtesting.SeedInfo.seed([3A6128D520290F62:BDF45315E837A90]:0)
at org.junit.Assert.fail(Assert.java:88)
at org.junit.Assert.assertTrue(Assert.java:41)
at org.apache.solr.cloud.autoscaling.TriggerCooldownIntegrationTest.testCooldown(TriggerCooldownIntegrationTest.java:160)
at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
at java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
at java.base/java.lang.reflect.Method.invoke(Method.java:564)
at com.carrotsearch.randomizedtesting.RandomizedRunner.invoke(RandomizedRunner.java: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 org.apache.lucene.util.TestRuleAssertionsRequired$1.evaluate(TestRuleAssertionsRequired.java:53)
at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:47)
at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:64)
at org.apache.lucene.util.TestRuleIgnoreTestSuites$1.evaluate(TestRuleIgnoreTestSuites.java:54)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:368)
at java.base/java.lang.Thread.run(Thread.java:832)
Build Log:
[...truncated 13776 lines...]
[junit4] Suite: org.apache.solr.cloud.autoscaling.TriggerCooldownIntegrationTest
[junit4] 2> 249147 INFO (SUITE-TriggerCooldownIntegrationTest-seed#[3A6128D520290F62]-worker) [ ] o.a.s.SolrTestCase Setting 'solr.default.confdir' system property to test-framework derived value of '/Users/jenkins/workspace/Lucene-Solr-8.x-MacOSX/solr/server/solr/configsets/_default/conf'
[junit4] 2> 249147 INFO (SUITE-TriggerCooldownIntegrationTest-seed#[3A6128D520290F62]-worker) [ ] o.a.s.SolrTestCaseJ4 SecureRandom sanity checks: test.solr.allowed.securerandom=null & java.security.egd=file:/dev/./urandom
[junit4] 2> 249148 INFO (SUITE-TriggerCooldownIntegrationTest-seed#[3A6128D520290F62]-worker) [ ] o.a.s.SolrTestCaseJ4 Created dataDir: /Users/jenkins/workspace/Lucene-Solr-8.x-MacOSX/solr/build/solr-core/test/J1/temp/solr.cloud.autoscaling.TriggerCooldownIntegrationTest_3A6128D520290F62-001/data-dir-21-001
[junit4] 2> 249148 WARN (SUITE-TriggerCooldownIntegrationTest-seed#[3A6128D520290F62]-worker) [ ] o.a.s.SolrTestCaseJ4 startTrackingSearchers: numOpens=5 numCloses=5
[junit4] 2> 249149 INFO (SUITE-TriggerCooldownIntegrationTest-seed#[3A6128D520290F62]-worker) [ ] o.a.s.SolrTestCaseJ4 Using PointFields (NUMERIC_POINTS_SYSPROP=true) w/NUMERIC_DOCVALUES_SYSPROP=false
[junit4] 2> 249150 INFO (SUITE-TriggerCooldownIntegrationTest-seed#[3A6128D520290F62]-worker) [ ] o.a.s.SolrTestCaseJ4 Randomized ssl (false) and clientAuth (false) via: @org.apache.solr.util.RandomizeSSL(reason="", value=0.0/0.0, ssl=0.0/0.0, clientAuth=0.0/0.0) w/ MAC_OS_X supressed clientAuth
[junit4] 2> 249150 INFO (SUITE-TriggerCooldownIntegrationTest-seed#[3A6128D520290F62]-worker) [ ] o.a.s.c.MiniSolrCloudCluster Starting cluster of 2 servers in /Users/jenkins/workspace/Lucene-Solr-8.x-MacOSX/solr/build/solr-core/test/J1/temp/solr.cloud.autoscaling.TriggerCooldownIntegrationTest_3A6128D520290F62-001/tempDir-001
[junit4] 2> 249154 INFO (SUITE-TriggerCooldownIntegrationTest-seed#[3A6128D520290F62]-worker) [ ] o.a.s.c.ZkTestServer STARTING ZK TEST SERVER
[junit4] 2> 249155 INFO (ZkTestServer Run Thread) [ ] o.a.s.c.ZkTestServer client port: 0.0.0.0/0.0.0.0:0
[junit4] 2> 249155 INFO (ZkTestServer Run Thread) [ ] o.a.s.c.ZkTestServer Starting server
[junit4] 2> 249256 INFO (SUITE-TriggerCooldownIntegrationTest-seed#[3A6128D520290F62]-worker) [ ] o.a.s.c.ZkTestServer start zk server on port: 57046
[junit4] 2> 249256 INFO (SUITE-TriggerCooldownIntegrationTest-seed#[3A6128D520290F62]-worker) [ ] o.a.s.c.ZkTestServer waitForServerUp: 127.0.0.1:57046
[junit4] 2> 249256 INFO (SUITE-TriggerCooldownIntegrationTest-seed#[3A6128D520290F62]-worker) [ ] o.a.s.c.ZkTestServer parse host and port list: 127.0.0.1:57046
[junit4] 2> 249256 INFO (SUITE-TriggerCooldownIntegrationTest-seed#[3A6128D520290F62]-worker) [ ] o.a.s.c.ZkTestServer connecting to 127.0.0.1 57046
[junit4] 2> 249258 INFO (SUITE-TriggerCooldownIntegrationTest-seed#[3A6128D520290F62]-worker) [ ] o.a.s.c.c.ConnectionManager Waiting for client to connect to ZooKeeper
[junit4] 2> 249272 INFO (zkConnectionManagerCallback-1700-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 249272 INFO (SUITE-TriggerCooldownIntegrationTest-seed#[3A6128D520290F62]-worker) [ ] o.a.s.c.c.ConnectionManager Client is connected to ZooKeeper
[junit4] 2> 249278 INFO (SUITE-TriggerCooldownIntegrationTest-seed#[3A6128D520290F62]-worker) [ ] o.a.s.c.c.ConnectionManager Waiting for client to connect to ZooKeeper
[junit4] 2> 249282 INFO (zkConnectionManagerCallback-1702-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 249282 INFO (SUITE-TriggerCooldownIntegrationTest-seed#[3A6128D520290F62]-worker) [ ] o.a.s.c.c.ConnectionManager Client is connected to ZooKeeper
[junit4] 2> 249284 INFO (SUITE-TriggerCooldownIntegrationTest-seed#[3A6128D520290F62]-worker) [ ] o.a.s.c.c.ConnectionManager Waiting for client to connect to ZooKeeper
[junit4] 2> 249291 INFO (zkConnectionManagerCallback-1704-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 249291 INFO (SUITE-TriggerCooldownIntegrationTest-seed#[3A6128D520290F62]-worker) [ ] o.a.s.c.c.ConnectionManager Client is connected to ZooKeeper
[junit4] 2> 249405 WARN (jetty-launcher-1705-thread-2) [ ] o.e.j.s.h.g.GzipHandler minGzipSize of 0 is inefficient for short content, break even is size 23
[junit4] 2> 249405 INFO (jetty-launcher-1705-thread-2) [ ] o.a.s.c.s.e.JettySolrRunner Start Jetty (configured port=0, binding port=0)
[junit4] 2> 249405 INFO (jetty-launcher-1705-thread-2) [ ] o.a.s.c.s.e.JettySolrRunner Trying to start Jetty on port 0 try number 2 ...
[junit4] 2> 249405 WARN (jetty-launcher-1705-thread-1) [ ] o.e.j.s.h.g.GzipHandler minGzipSize of 0 is inefficient for short content, break even is size 23
[junit4] 2> 249405 INFO (jetty-launcher-1705-thread-1) [ ] o.a.s.c.s.e.JettySolrRunner Start Jetty (configured port=0, binding port=0)
[junit4] 2> 249405 INFO (jetty-launcher-1705-thread-1) [ ] o.a.s.c.s.e.JettySolrRunner Trying to start Jetty on port 0 try number 2 ...
[junit4] 2> 249405 INFO (jetty-launcher-1705-thread-2) [ ] o.e.j.s.Server jetty-9.4.27.v20200227; built: 2020-02-27T18:37:21.340Z; git: a304fd9f351f337e7c0e2a7c28878dd536149c6c; jvm 14+36
[junit4] 2> 249405 INFO (jetty-launcher-1705-thread-1) [ ] o.e.j.s.Server jetty-9.4.27.v20200227; built: 2020-02-27T18:37:21.340Z; git: a304fd9f351f337e7c0e2a7c28878dd536149c6c; jvm 14+36
[junit4] 2> 249410 INFO (jetty-launcher-1705-thread-1) [ ] o.e.j.s.session DefaultSessionIdManager workerName=node0
[junit4] 2> 249410 INFO (jetty-launcher-1705-thread-1) [ ] o.e.j.s.session No SessionScavenger set, using defaults
[junit4] 2> 249410 INFO (jetty-launcher-1705-thread-1) [ ] o.e.j.s.session node0 Scavenging every 660000ms
[junit4] 2> 249411 INFO (jetty-launcher-1705-thread-1) [ ] o.e.j.s.h.ContextHandler Started o.e.j.s.ServletContextHandler@2d3efb1{/solr,null,AVAILABLE}
[junit4] 2> 249411 INFO (jetty-launcher-1705-thread-2) [ ] o.e.j.s.session DefaultSessionIdManager workerName=node0
[junit4] 2> 249411 INFO (jetty-launcher-1705-thread-2) [ ] o.e.j.s.session No SessionScavenger set, using defaults
[junit4] 2> 249411 INFO (jetty-launcher-1705-thread-2) [ ] o.e.j.s.session node0 Scavenging every 600000ms
[junit4] 2> 249411 INFO (jetty-launcher-1705-thread-2) [ ] o.e.j.s.h.ContextHandler Started o.e.j.s.ServletContextHandler@1fda784a{/solr,null,AVAILABLE}
[junit4] 2> 249412 INFO (jetty-launcher-1705-thread-1) [ ] o.e.j.s.AbstractConnector Started ServerConnector@2e80267a{HTTP/1.1, (http/1.1, h2c)}{127.0.0.1:57052}
[junit4] 2> 249412 INFO (jetty-launcher-1705-thread-1) [ ] o.e.j.s.Server Started @249505ms
[junit4] 2> 249412 INFO (jetty-launcher-1705-thread-1) [ ] o.a.s.c.s.e.JettySolrRunner Jetty properties: {hostContext=/solr, hostPort=57052}
[junit4] 2> 249412 ERROR (jetty-launcher-1705-thread-1) [ ] o.a.s.u.StartupLoggingUtils Missing Java Option solr.log.dir. Logging may be missing or incomplete.
[junit4] 2> 249412 INFO (jetty-launcher-1705-thread-1) [ ] o.a.s.s.SolrDispatchFilter Using logger factory org.apache.logging.slf4j.Log4jLoggerFactory
[junit4] 2> 249412 INFO (jetty-launcher-1705-thread-1) [ ] o.a.s.s.SolrDispatchFilter ___ _ Welcome to Apache Solr™ version 8.6.0
[junit4] 2> 249412 INFO (jetty-launcher-1705-thread-1) [ ] o.a.s.s.SolrDispatchFilter / __| ___| |_ _ Starting in cloud mode on port null
[junit4] 2> 249412 INFO (jetty-launcher-1705-thread-1) [ ] o.a.s.s.SolrDispatchFilter \__ \/ _ \ | '_| Install dir: /Users/jenkins/workspace/Lucene-Solr-8.x-MacOSX/solr
[junit4] 2> 249412 INFO (jetty-launcher-1705-thread-1) [ ] o.a.s.s.SolrDispatchFilter |___/\___/_|_| Start time: 2020-05-26T22:19:22.420739Z
[junit4] 2> 249413 INFO (jetty-launcher-1705-thread-2) [ ] o.e.j.s.AbstractConnector Started ServerConnector@79e404f1{HTTP/1.1, (http/1.1, h2c)}{127.0.0.1:57053}
[junit4] 2> 249413 INFO (jetty-launcher-1705-thread-2) [ ] o.e.j.s.Server Started @249506ms
[junit4] 2> 249413 INFO (jetty-launcher-1705-thread-2) [ ] o.a.s.c.s.e.JettySolrRunner Jetty properties: {hostContext=/solr, hostPort=57053}
[junit4] 2> 249413 ERROR (jetty-launcher-1705-thread-2) [ ] o.a.s.u.StartupLoggingUtils Missing Java Option solr.log.dir. Logging may be missing or incomplete.
[junit4] 2> 249413 INFO (jetty-launcher-1705-thread-2) [ ] o.a.s.s.SolrDispatchFilter Using logger factory org.apache.logging.slf4j.Log4jLoggerFactory
[junit4] 2> 249413 INFO (jetty-launcher-1705-thread-2) [ ] o.a.s.s.SolrDispatchFilter ___ _ Welcome to Apache Solr™ version 8.6.0
[junit4] 2> 249413 INFO (jetty-launcher-1705-thread-1) [ ] o.a.s.c.c.ConnectionManager Waiting for client to connect to ZooKeeper
[junit4] 2> 249413 INFO (jetty-launcher-1705-thread-2) [ ] o.a.s.s.SolrDispatchFilter / __| ___| |_ _ Starting in cloud mode on port null
[junit4] 2> 249413 INFO (jetty-launcher-1705-thread-2) [ ] o.a.s.s.SolrDispatchFilter \__ \/ _ \ | '_| Install dir: /Users/jenkins/workspace/Lucene-Solr-8.x-MacOSX/solr
[junit4] 2> 249413 INFO (jetty-launcher-1705-thread-2) [ ] o.a.s.s.SolrDispatchFilter |___/\___/_|_| Start time: 2020-05-26T22:19:22.421644Z
[junit4] 2> 249414 INFO (jetty-launcher-1705-thread-2) [ ] o.a.s.c.c.ConnectionManager Waiting for client to connect to ZooKeeper
[junit4] 2> 249420 INFO (zkConnectionManagerCallback-1707-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 249420 INFO (jetty-launcher-1705-thread-1) [ ] o.a.s.c.c.ConnectionManager Client is connected to ZooKeeper
[junit4] 2> 249420 INFO (zkConnectionManagerCallback-1709-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 249420 INFO (jetty-launcher-1705-thread-2) [ ] o.a.s.c.c.ConnectionManager Client is connected to ZooKeeper
[junit4] 2> 249424 INFO (jetty-launcher-1705-thread-1) [ ] o.a.s.s.SolrDispatchFilter solr.xml found in ZooKeeper. Loading...
[junit4] 2> 249425 INFO (jetty-launcher-1705-thread-2) [ ] o.a.s.s.SolrDispatchFilter solr.xml found in ZooKeeper. Loading...
[junit4] 2> 249640 INFO (jetty-launcher-1705-thread-2) [ ] o.a.s.h.c.HttpShardHandlerFactory Host whitelist initialized: WhitelistHostChecker [whitelistHosts=null, whitelistHostCheckingEnabled=true]
[junit4] 2> 249643 WARN (jetty-launcher-1705-thread-2) [ ] o.e.j.u.s.S.config Trusting all certificates configured for Client@75f5871d[provider=null,keyStore=null,trustStore=null]
[junit4] 2> 249643 WARN (jetty-launcher-1705-thread-2) [ ] o.e.j.u.s.S.config No Client EndPointIdentificationAlgorithm configured for Client@75f5871d[provider=null,keyStore=null,trustStore=null]
[junit4] 2> 249651 WARN (jetty-launcher-1705-thread-2) [ ] o.e.j.u.s.S.config Trusting all certificates configured for Client@4a2c229f[provider=null,keyStore=null,trustStore=null]
[junit4] 2> 249651 WARN (jetty-launcher-1705-thread-2) [ ] o.e.j.u.s.S.config No Client EndPointIdentificationAlgorithm configured for Client@4a2c229f[provider=null,keyStore=null,trustStore=null]
[junit4] 2> 249652 INFO (jetty-launcher-1705-thread-2) [ ] o.a.s.c.ZkContainer Zookeeper client=127.0.0.1:57046/solr
[junit4] 2> 249656 INFO (jetty-launcher-1705-thread-2) [ ] o.a.s.c.c.ConnectionManager Waiting for client to connect to ZooKeeper
[junit4] 2> 249659 INFO (zkConnectionManagerCallback-1723-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 249659 INFO (jetty-launcher-1705-thread-2) [ ] o.a.s.c.c.ConnectionManager Client is connected to ZooKeeper
[junit4] 2> 249763 INFO (jetty-launcher-1705-thread-2) [n:127.0.0.1:57053_solr ] o.a.s.c.c.ConnectionManager Waiting for client to connect to ZooKeeper
[junit4] 2> 249769 INFO (zkConnectionManagerCallback-1725-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 249769 INFO (jetty-launcher-1705-thread-2) [n:127.0.0.1:57053_solr ] o.a.s.c.c.ConnectionManager Client is connected to ZooKeeper
[junit4] 2> 249899 INFO (jetty-launcher-1705-thread-1) [ ] o.a.s.h.c.HttpShardHandlerFactory Host whitelist initialized: WhitelistHostChecker [whitelistHosts=null, whitelistHostCheckingEnabled=true]
[junit4] 2> 249901 WARN (jetty-launcher-1705-thread-1) [ ] o.e.j.u.s.S.config Trusting all certificates configured for Client@66c28b6[provider=null,keyStore=null,trustStore=null]
[junit4] 2> 249901 WARN (jetty-launcher-1705-thread-1) [ ] o.e.j.u.s.S.config No Client EndPointIdentificationAlgorithm configured for Client@66c28b6[provider=null,keyStore=null,trustStore=null]
[junit4] 2> 249906 WARN (jetty-launcher-1705-thread-1) [ ] o.e.j.u.s.S.config Trusting all certificates configured for Client@1f2297a0[provider=null,keyStore=null,trustStore=null]
[junit4] 2> 249906 WARN (jetty-launcher-1705-thread-1) [ ] o.e.j.u.s.S.config No Client EndPointIdentificationAlgorithm configured for Client@1f2297a0[provider=null,keyStore=null,trustStore=null]
[junit4] 2> 249907 INFO (jetty-launcher-1705-thread-1) [ ] o.a.s.c.ZkContainer Zookeeper client=127.0.0.1:57046/solr
[junit4] 2> 249910 INFO (jetty-launcher-1705-thread-1) [ ] o.a.s.c.c.ConnectionManager Waiting for client to connect to ZooKeeper
[junit4] 2> 249915 INFO (zkConnectionManagerCallback-1735-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 249915 INFO (jetty-launcher-1705-thread-1) [ ] o.a.s.c.c.ConnectionManager Client is connected to ZooKeeper
[junit4] 2> 250023 INFO (jetty-launcher-1705-thread-1) [n:127.0.0.1:57052_solr ] o.a.s.c.c.ConnectionManager Waiting for client to connect to ZooKeeper
[junit4] 2> 250030 INFO (zkConnectionManagerCallback-1737-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 250032 INFO (jetty-launcher-1705-thread-1) [n:127.0.0.1:57052_solr ] o.a.s.c.c.ConnectionManager Client is connected to ZooKeeper
[junit4] 2> 250142 INFO (jetty-launcher-1705-thread-1) [n:127.0.0.1:57052_solr ] o.a.s.c.OverseerElectionContext I am going to be the leader 127.0.0.1:57052_solr
[junit4] 2> 250146 INFO (jetty-launcher-1705-thread-1) [n:127.0.0.1:57052_solr ] o.a.s.c.Overseer Overseer (id=72110443312644104-127.0.0.1:57052_solr-n_0000000000) starting
[junit4] 2> 250183 INFO (OverseerStateUpdate-72110443312644104-127.0.0.1:57052_solr-n_0000000000) [n:127.0.0.1:57052_solr ] o.a.s.c.Overseer Starting to work on the main queue : 127.0.0.1:57052_solr
[junit4] 2> 250184 DEBUG (OverseerAutoScalingTriggerThread-72110443312644104-127.0.0.1:57052_solr-n_0000000000) [ ] o.a.s.c.a.OverseerTriggerThread Adding .auto_add_replicas and .scheduled_maintenance triggers
[junit4] 2> 250184 INFO (jetty-launcher-1705-thread-1) [n:127.0.0.1:57052_solr ] o.a.s.c.ZkController Register node as live in ZooKeeper:/live_nodes/127.0.0.1:57052_solr
[junit4] 2> 250188 DEBUG (OverseerAutoScalingTriggerThread-72110443312644104-127.0.0.1:57052_solr-n_0000000000) [ ] o.a.s.c.a.OverseerTriggerThread Refreshing /autoscaling.json with znode version 1
[junit4] 2> 250188 DEBUG (OverseerAutoScalingTriggerThread-72110443312644104-127.0.0.1:57052_solr-n_0000000000) [ ] o.a.s.c.a.OverseerTriggerThread Current znodeVersion 1, lastZnodeVersion 0
[junit4] 2> 250188 DEBUG (OverseerAutoScalingTriggerThread-72110443312644104-127.0.0.1:57052_solr-n_0000000000) [ ] o.a.s.c.a.OverseerTriggerThread Processed trigger updates upto znodeVersion 1
[junit4] 2> 250189 INFO (OverseerStateUpdate-72110443312644104-127.0.0.1:57052_solr-n_0000000000) [n:127.0.0.1:57052_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (1)
[junit4] 2> 250205 INFO (jetty-launcher-1705-thread-1) [n:127.0.0.1:57052_solr ] o.a.s.p.PackageLoader /packages.json updated to version -1
[junit4] 2> 250206 WARN (jetty-launcher-1705-thread-1) [n:127.0.0.1:57052_solr ] 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> 250208 DEBUG (OverseerAutoScalingTriggerThread-72110443312644104-127.0.0.1:57052_solr-n_0000000000) [ ] o.a.s.c.a.NodeLostTrigger NodeLostTrigger .auto_add_replicas - Initial livenodes: [127.0.0.1:57052_solr]
[junit4] 2> 250211 DEBUG (OverseerAutoScalingTriggerThread-72110443312644104-127.0.0.1:57052_solr-n_0000000000) [ ] o.a.s.c.a.OverseerTriggerThread -- deactivating old nodeLost / nodeAdded markers
[junit4] 2> 250229 DEBUG (ScheduledTrigger-1742-thread-1) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 1 and last live nodes: 1
[junit4] 2> 250229 DEBUG (OverseerAutoScalingTriggerThread-72110443312644104-127.0.0.1:57052_solr-n_0000000000) [ ] o.a.s.c.a.OverseerTriggerThread Current znodeVersion 1, lastZnodeVersion 1
[junit4] 2> 250250 INFO (jetty-launcher-1705-thread-2) [n:127.0.0.1:57053_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (1)
[junit4] 2> 250257 INFO (jetty-launcher-1705-thread-1) [n:127.0.0.1:57052_solr ] o.a.s.h.a.MetricsHistoryHandler No .system collection, keeping metrics history in memory.
[junit4] 2> 250283 INFO (jetty-launcher-1705-thread-2) [n:127.0.0.1:57053_solr ] o.a.s.c.ZkController Publish node=127.0.0.1:57053_solr as DOWN
[junit4] 2> 250286 INFO (jetty-launcher-1705-thread-2) [n:127.0.0.1:57053_solr ] o.a.s.c.TransientSolrCoreCacheDefault Allocating transient cache for 2147483647 transient cores
[junit4] 2> 250286 INFO (jetty-launcher-1705-thread-2) [n:127.0.0.1:57053_solr ] o.a.s.c.ZkController Register node as live in ZooKeeper:/live_nodes/127.0.0.1:57053_solr
[junit4] 2> 250291 INFO (zkCallback-1724-thread-1) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (1) -> (2)
[junit4] 2> 250293 INFO (zkCallback-1736-thread-1) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (1) -> (2)
[junit4] 2> 250296 INFO (jetty-launcher-1705-thread-1) [n:127.0.0.1:57052_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_57052.solr.node' (registry 'solr.node') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@15123b7d
[junit4] 2> 250297 INFO (jetty-launcher-1705-thread-2) [n:127.0.0.1:57053_solr ] o.a.s.p.PackageLoader /packages.json updated to version -1
[junit4] 2> 250297 WARN (jetty-launcher-1705-thread-2) [n:127.0.0.1:57053_solr ] 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> 250303 INFO (jetty-launcher-1705-thread-1) [n:127.0.0.1:57052_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_57052.solr.jvm' (registry 'solr.jvm') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@15123b7d
[junit4] 2> 250303 INFO (jetty-launcher-1705-thread-1) [n:127.0.0.1:57052_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_57052.solr.jetty' (registry 'solr.jetty') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@15123b7d
[junit4] 2> 250306 INFO (jetty-launcher-1705-thread-1) [n:127.0.0.1:57052_solr ] o.a.s.c.CorePropertiesLocator Found 0 core definitions underneath /Users/jenkins/workspace/Lucene-Solr-8.x-MacOSX/solr/build/solr-core/test/J1/temp/solr.cloud.autoscaling.TriggerCooldownIntegrationTest_3A6128D520290F62-001/tempDir-001/node1/.
[junit4] 2> 250329 INFO (jetty-launcher-1705-thread-2) [n:127.0.0.1:57053_solr ] o.a.s.h.a.MetricsHistoryHandler No .system collection, keeping metrics history in memory.
[junit4] 2> 250346 INFO (jetty-launcher-1705-thread-2) [n:127.0.0.1:57053_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_57053.solr.node' (registry 'solr.node') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@15123b7d
[junit4] 2> 250359 INFO (jetty-launcher-1705-thread-2) [n:127.0.0.1:57053_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_57053.solr.jvm' (registry 'solr.jvm') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@15123b7d
[junit4] 2> 250360 INFO (jetty-launcher-1705-thread-2) [n:127.0.0.1:57053_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_57053.solr.jetty' (registry 'solr.jetty') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@15123b7d
[junit4] 2> 250361 INFO (jetty-launcher-1705-thread-2) [n:127.0.0.1:57053_solr ] o.a.s.c.CorePropertiesLocator Found 0 core definitions underneath /Users/jenkins/workspace/Lucene-Solr-8.x-MacOSX/solr/build/solr-core/test/J1/temp/solr.cloud.autoscaling.TriggerCooldownIntegrationTest_3A6128D520290F62-001/tempDir-001/node2/.
[junit4] 2> 250370 INFO (SUITE-TriggerCooldownIntegrationTest-seed#[3A6128D520290F62]-worker) [ ] o.a.s.c.MiniSolrCloudCluster waitForAllNodes: numServers=2
[junit4] 2> 250371 INFO (SUITE-TriggerCooldownIntegrationTest-seed#[3A6128D520290F62]-worker) [ ] o.a.s.c.c.ConnectionManager Waiting for client to connect to ZooKeeper
[junit4] 2> 250379 INFO (zkConnectionManagerCallback-1760-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 250379 INFO (SUITE-TriggerCooldownIntegrationTest-seed#[3A6128D520290F62]-worker) [ ] o.a.s.c.c.ConnectionManager Client is connected to ZooKeeper
[junit4] 2> 250385 INFO (SUITE-TriggerCooldownIntegrationTest-seed#[3A6128D520290F62]-worker) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (2)
[junit4] 2> 250390 INFO (SUITE-TriggerCooldownIntegrationTest-seed#[3A6128D520290F62]-worker) [ ] o.a.s.c.s.i.ZkClientClusterStateProvider Cluster at 127.0.0.1:57046/solr ready
[junit4] 2> 250413 INFO (qtp541580290-3045) [n:127.0.0.1:57052_solr ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/cluster/autoscaling params={wt=javabin&version=2} status=0 QTime=4
[junit4] 2> 250424 INFO (qtp541580290-3047) [n:127.0.0.1:57052_solr ] o.a.s.c.TransientSolrCoreCacheDefault Allocating transient cache for 2147483647 transient cores
[junit4] 2> 250425 INFO (qtp541580290-3047) [n:127.0.0.1:57052_solr ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/metrics params={prefix=CONTAINER.fs.usableSpace,CONTAINER.fs.totalSpace,CONTAINER.cores&wt=javabin&version=2&group=solr.node} status=0 QTime=0
[junit4] 2> 250428 INFO (qtp1998845029-3053) [n:127.0.0.1:57053_solr ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/metrics params={prefix=CONTAINER.fs.usableSpace,CONTAINER.fs.totalSpace,CONTAINER.cores&wt=javabin&version=2&group=solr.node} status=0 QTime=0
[junit4] 2> 250429 DEBUG (qtp1998845029-3050) [n:127.0.0.1:57053_solr ] o.a.s.c.a.AutoScalingHandler Verified autoscaling configuration
[junit4] 2> 250431 INFO (qtp1998845029-3050) [n:127.0.0.1:57053_solr ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/cluster/autoscaling params={wt=javabin&version=2} status=0 QTime=13
[junit4] 2> 250433 DEBUG (zkCallback-1736-thread-1) [ ] o.a.s.c.a.OverseerTriggerThread Refreshing /autoscaling.json with znode version 2
[junit4] 2> 250433 DEBUG (OverseerAutoScalingTriggerThread-72110443312644104-127.0.0.1:57052_solr-n_0000000000) [ ] o.a.s.c.a.OverseerTriggerThread Processed trigger updates upto znodeVersion 2
[junit4] 2> 250446 DEBUG (OverseerAutoScalingTriggerThread-72110443312644104-127.0.0.1:57052_solr-n_0000000000) [ ] o.a.s.c.a.OverseerTriggerThread -- deactivating old nodeLost / nodeAdded markers
[junit4] 2> 250450 DEBUG (OverseerAutoScalingTriggerThread-72110443312644104-127.0.0.1:57052_solr-n_0000000000) [ ] o.a.s.c.a.OverseerTriggerThread Current znodeVersion 2, lastZnodeVersion 2
[junit4] 2> 250470 INFO (TEST-TriggerCooldownIntegrationTest.testCooldown-seed#[3A6128D520290F62]) [ ] o.a.s.SolrTestCaseJ4 ###Starting testCooldown
[junit4] 2> 250480 INFO (qtp541580290-3044) [n:127.0.0.1:57052_solr ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/metrics params={prefix=CONTAINER.fs.usableSpace,CONTAINER.fs.totalSpace,CONTAINER.cores&wt=javabin&version=2&group=solr.node} status=0 QTime=0
[junit4] 2> 250481 INFO (qtp1998845029-3053) [n:127.0.0.1:57053_solr ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/metrics params={prefix=CONTAINER.fs.usableSpace,CONTAINER.fs.totalSpace,CONTAINER.cores&wt=javabin&version=2&group=solr.node} status=0 QTime=0
[junit4] 2> 250482 DEBUG (qtp1998845029-3052) [n:127.0.0.1:57053_solr ] o.a.s.c.a.AutoScalingHandler Verified autoscaling configuration
[junit4] 2> 250484 INFO (qtp1998845029-3052) [n:127.0.0.1:57053_solr ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/autoscaling params={wt=javabin&version=2} status=0 QTime=10
[junit4] 2> 250485 DEBUG (zkCallback-1736-thread-1) [ ] o.a.s.c.a.OverseerTriggerThread Refreshing /autoscaling.json with znode version 3
[junit4] 2> 250486 DEBUG (OverseerAutoScalingTriggerThread-72110443312644104-127.0.0.1:57052_solr-n_0000000000) [ ] o.a.s.c.a.OverseerTriggerThread Processed trigger updates upto znodeVersion 3
[junit4] 2> 250489 INFO (qtp541580290-3045) [n:127.0.0.1:57052_solr ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/metrics params={prefix=CONTAINER.fs.usableSpace,CONTAINER.fs.totalSpace,CONTAINER.cores&wt=javabin&version=2&group=solr.node} status=0 QTime=0
[junit4] 2> 250490 INFO (qtp1998845029-3049) [n:127.0.0.1:57053_solr ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/metrics params={prefix=CONTAINER.fs.usableSpace,CONTAINER.fs.totalSpace,CONTAINER.cores&wt=javabin&version=2&group=solr.node} status=0 QTime=0
[junit4] 2> 250491 DEBUG (qtp1998845029-3050) [n:127.0.0.1:57053_solr ] o.a.s.c.a.AutoScalingHandler Verified autoscaling configuration
[junit4] 2> 250493 INFO (qtp1998845029-3050) [n:127.0.0.1:57053_solr ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/autoscaling params={wt=javabin&version=2} status=0 QTime=7
[junit4] 2> 250494 WARN (TEST-TriggerCooldownIntegrationTest.testCooldown-seed#[3A6128D520290F62]) [ ] o.e.j.s.h.g.GzipHandler minGzipSize of 0 is inefficient for short content, break even is size 23
[junit4] 2> 250494 INFO (TEST-TriggerCooldownIntegrationTest.testCooldown-seed#[3A6128D520290F62]) [ ] o.a.s.c.s.e.JettySolrRunner Start Jetty (configured port=0, binding port=0)
[junit4] 2> 250494 INFO (TEST-TriggerCooldownIntegrationTest.testCooldown-seed#[3A6128D520290F62]) [ ] o.a.s.c.s.e.JettySolrRunner Trying to start Jetty on port 0 try number 2 ...
[junit4] 2> 250494 INFO (TEST-TriggerCooldownIntegrationTest.testCooldown-seed#[3A6128D520290F62]) [ ] o.e.j.s.Server jetty-9.4.27.v20200227; built: 2020-02-27T18:37:21.340Z; git: a304fd9f351f337e7c0e2a7c28878dd536149c6c; jvm 14+36
[junit4] 2> 250496 INFO (OverseerAutoScalingTriggerThread-72110443312644104-127.0.0.1:57052_solr-n_0000000000) [ ] o.a.s.c.a.TriggerCooldownIntegrationTest TestTriggerAction init
[junit4] 2> 250496 DEBUG (OverseerAutoScalingTriggerThread-72110443312644104-127.0.0.1:57052_solr-n_0000000000) [ ] o.a.s.c.a.NodeAddedTrigger NodeAddedTrigger node_added_cooldown_trigger - Initial livenodes: [127.0.0.1:57052_solr, 127.0.0.1:57053_solr]
[junit4] 2> 250496 DEBUG (zkCallback-1736-thread-1) [ ] o.a.s.c.a.OverseerTriggerThread Refreshing /autoscaling.json with znode version 4
[junit4] 2> 250496 DEBUG (OverseerAutoScalingTriggerThread-72110443312644104-127.0.0.1:57052_solr-n_0000000000) [ ] o.a.s.c.a.NodeAddedTrigger NodeAddedTrigger node_added_cooldown_trigger instantiated with properties: {event=nodeAdded, waitFor=1, actions=[{name=test, class=org.apache.solr.cloud.autoscaling.TriggerCooldownIntegrationTest$TestTriggerAction}], enabled=true}
[junit4] 2> 250498 INFO (TEST-TriggerCooldownIntegrationTest.testCooldown-seed#[3A6128D520290F62]) [ ] o.e.j.s.session DefaultSessionIdManager workerName=node0
[junit4] 2> 250498 INFO (TEST-TriggerCooldownIntegrationTest.testCooldown-seed#[3A6128D520290F62]) [ ] o.e.j.s.session No SessionScavenger set, using defaults
[junit4] 2> 250498 INFO (TEST-TriggerCooldownIntegrationTest.testCooldown-seed#[3A6128D520290F62]) [ ] o.e.j.s.session node0 Scavenging every 660000ms
[junit4] 2> 250499 INFO (TEST-TriggerCooldownIntegrationTest.testCooldown-seed#[3A6128D520290F62]) [ ] o.e.j.s.h.ContextHandler Started o.e.j.s.ServletContextHandler@ca5e09b{/solr,null,AVAILABLE}
[junit4] 2> 250500 DEBUG (OverseerAutoScalingTriggerThread-72110443312644104-127.0.0.1:57052_solr-n_0000000000) [ ] o.a.s.c.a.OverseerTriggerThread -- deactivating old nodeLost / nodeAdded markers
[junit4] 2> 250501 INFO (TEST-TriggerCooldownIntegrationTest.testCooldown-seed#[3A6128D520290F62]) [ ] o.e.j.s.AbstractConnector Started ServerConnector@72fd352{HTTP/1.1, (http/1.1, h2c)}{127.0.0.1:57073}
[junit4] 2> 250501 INFO (TEST-TriggerCooldownIntegrationTest.testCooldown-seed#[3A6128D520290F62]) [ ] o.e.j.s.Server Started @250594ms
[junit4] 2> 250501 INFO (TEST-TriggerCooldownIntegrationTest.testCooldown-seed#[3A6128D520290F62]) [ ] o.a.s.c.s.e.JettySolrRunner Jetty properties: {hostContext=/solr, hostPort=57073}
[junit4] 2> 250501 ERROR (TEST-TriggerCooldownIntegrationTest.testCooldown-seed#[3A6128D520290F62]) [ ] o.a.s.u.StartupLoggingUtils Missing Java Option solr.log.dir. Logging may be missing or incomplete.
[junit4] 2> 250501 INFO (TEST-TriggerCooldownIntegrationTest.testCooldown-seed#[3A6128D520290F62]) [ ] o.a.s.s.SolrDispatchFilter Using logger factory org.apache.logging.slf4j.Log4jLoggerFactory
[junit4] 2> 250501 INFO (TEST-TriggerCooldownIntegrationTest.testCooldown-seed#[3A6128D520290F62]) [ ] o.a.s.s.SolrDispatchFilter ___ _ Welcome to Apache Solr™ version 8.6.0
[junit4] 2> 250501 INFO (TEST-TriggerCooldownIntegrationTest.testCooldown-seed#[3A6128D520290F62]) [ ] o.a.s.s.SolrDispatchFilter / __| ___| |_ _ Starting in cloud mode on port null
[junit4] 2> 250501 INFO (TEST-TriggerCooldownIntegrationTest.testCooldown-seed#[3A6128D520290F62]) [ ] o.a.s.s.SolrDispatchFilter \__ \/ _ \ | '_| Install dir: /Users/jenkins/workspace/Lucene-Solr-8.x-MacOSX/solr
[junit4] 2> 250501 INFO (TEST-TriggerCooldownIntegrationTest.testCooldown-seed#[3A6128D520290F62]) [ ] o.a.s.s.SolrDispatchFilter |___/\___/_|_| Start time: 2020-05-26T22:19:23.509759Z
[junit4] 2> 250502 INFO (TEST-TriggerCooldownIntegrationTest.testCooldown-seed#[3A6128D520290F62]) [ ] o.a.s.c.c.ConnectionManager Waiting for client to connect to ZooKeeper
[junit4] 2> 250503 DEBUG (ScheduledTrigger-1742-thread-2) [ ] o.a.s.c.a.NodeAddedTrigger Running NodeAddedTrigger node_added_cooldown_trigger
[junit4] 2> 250503 DEBUG (ScheduledTrigger-1742-thread-2) [ ] o.a.s.c.a.NodeAddedTrigger Found livenodes: 2
[junit4] 2> 250510 INFO (zkConnectionManagerCallback-1762-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 250510 DEBUG (OverseerAutoScalingTriggerThread-72110443312644104-127.0.0.1:57052_solr-n_0000000000) [ ] o.a.s.c.a.OverseerTriggerThread Current znodeVersion 4, lastZnodeVersion 3
[junit4] 2> 250510 DEBUG (OverseerAutoScalingTriggerThread-72110443312644104-127.0.0.1:57052_solr-n_0000000000) [ ] o.a.s.c.a.OverseerTriggerThread Processed trigger updates upto znodeVersion 4
[junit4] 2> 250510 INFO (TEST-TriggerCooldownIntegrationTest.testCooldown-seed#[3A6128D520290F62]) [ ] o.a.s.c.c.ConnectionManager Client is connected to ZooKeeper
[junit4] 2> 250512 INFO (TEST-TriggerCooldownIntegrationTest.testCooldown-seed#[3A6128D520290F62]) [ ] o.a.s.s.SolrDispatchFilter solr.xml found in ZooKeeper. Loading...
[junit4] 2> 250514 DEBUG (OverseerAutoScalingTriggerThread-72110443312644104-127.0.0.1:57052_solr-n_0000000000) [ ] o.a.s.c.a.OverseerTriggerThread -- deactivating old nodeLost / nodeAdded markers
[junit4] 2> 250518 DEBUG (OverseerAutoScalingTriggerThread-72110443312644104-127.0.0.1:57052_solr-n_0000000000) [ ] o.a.s.c.a.OverseerTriggerThread Current znodeVersion 4, lastZnodeVersion 4
[junit4] 2> 250659 INFO (TEST-TriggerCooldownIntegrationTest.testCooldown-seed#[3A6128D520290F62]) [ ] o.a.s.h.c.HttpShardHandlerFactory Host whitelist initialized: WhitelistHostChecker [whitelistHosts=null, whitelistHostCheckingEnabled=true]
[junit4] 2> 250662 WARN (TEST-TriggerCooldownIntegrationTest.testCooldown-seed#[3A6128D520290F62]) [ ] o.e.j.u.s.S.config Trusting all certificates configured for Client@2a3dfaf8[provider=null,keyStore=null,trustStore=null]
[junit4] 2> 250663 WARN (TEST-TriggerCooldownIntegrationTest.testCooldown-seed#[3A6128D520290F62]) [ ] o.e.j.u.s.S.config No Client EndPointIdentificationAlgorithm configured for Client@2a3dfaf8[provider=null,keyStore=null,trustStore=null]
[junit4] 2> 250671 WARN (TEST-TriggerCooldownIntegrationTest.testCooldown-seed#[3A6128D520290F62]) [ ] o.e.j.u.s.S.config Trusting all certificates configured for Client@dd539f1[provider=null,keyStore=null,trustStore=null]
[junit4] 2> 250672 WARN (TEST-TriggerCooldownIntegrationTest.testCooldown-seed#[3A6128D520290F62]) [ ] o.e.j.u.s.S.config No Client EndPointIdentificationAlgorithm configured for Client@dd539f1[provider=null,keyStore=null,trustStore=null]
[junit4] 2> 250678 INFO (TEST-TriggerCooldownIntegrationTest.testCooldown-seed#[3A6128D520290F62]) [ ] o.a.s.c.ZkContainer Zookeeper client=127.0.0.1:57046/solr
[junit4] 2> 250679 INFO (TEST-TriggerCooldownIntegrationTest.testCooldown-seed#[3A6128D520290F62]) [ ] o.a.s.c.c.ConnectionManager Waiting for client to connect to ZooKeeper
[junit4] 2> 250687 INFO (zkConnectionManagerCallback-1773-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 250688 INFO (TEST-TriggerCooldownIntegrationTest.testCooldown-seed#[3A6128D520290F62]) [ ] o.a.s.c.c.ConnectionManager Client is connected to ZooKeeper
[junit4] 2> 250803 INFO (TEST-TriggerCooldownIntegrationTest.testCooldown-seed#[3A6128D520290F62]) [n:127.0.0.1:57073_solr ] o.a.s.c.c.ConnectionManager Waiting for client to connect to ZooKeeper
[junit4] 2> 250808 INFO (zkConnectionManagerCallback-1775-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 250808 INFO (TEST-TriggerCooldownIntegrationTest.testCooldown-seed#[3A6128D520290F62]) [n:127.0.0.1:57073_solr ] o.a.s.c.c.ConnectionManager Client is connected to ZooKeeper
[junit4] 2> 250852 INFO (TEST-TriggerCooldownIntegrationTest.testCooldown-seed#[3A6128D520290F62]) [n:127.0.0.1:57073_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (2)
[junit4] 2> 250884 INFO (TEST-TriggerCooldownIntegrationTest.testCooldown-seed#[3A6128D520290F62]) [n:127.0.0.1:57073_solr ] o.a.s.c.ZkController Publish node=127.0.0.1:57073_solr as DOWN
[junit4] 2> 250886 INFO (TEST-TriggerCooldownIntegrationTest.testCooldown-seed#[3A6128D520290F62]) [n:127.0.0.1:57073_solr ] o.a.s.c.TransientSolrCoreCacheDefault Allocating transient cache for 2147483647 transient cores
[junit4] 2> 250886 INFO (TEST-TriggerCooldownIntegrationTest.testCooldown-seed#[3A6128D520290F62]) [n:127.0.0.1:57073_solr ] o.a.s.c.ZkController Register node as live in ZooKeeper:/live_nodes/127.0.0.1:57073_solr
[junit4] 2> 250900 INFO (zkCallback-1724-thread-1) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (2) -> (3)
[junit4] 2> 250900 INFO (zkCallback-1736-thread-1) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (2) -> (3)
[junit4] 2> 250901 INFO (zkCallback-1774-thread-1) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (2) -> (3)
[junit4] 2> 250902 INFO (zkCallback-1759-thread-1) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (2) -> (3)
[junit4] 2> 250905 INFO (TEST-TriggerCooldownIntegrationTest.testCooldown-seed#[3A6128D520290F62]) [n:127.0.0.1:57073_solr ] o.a.s.p.PackageLoader /packages.json updated to version -1
[junit4] 2> 250905 WARN (TEST-TriggerCooldownIntegrationTest.testCooldown-seed#[3A6128D520290F62]) [n:127.0.0.1:57073_solr ] 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> 250931 INFO (TEST-TriggerCooldownIntegrationTest.testCooldown-seed#[3A6128D520290F62]) [n:127.0.0.1:57073_solr ] o.a.s.h.a.MetricsHistoryHandler No .system collection, keeping metrics history in memory.
[junit4] 2> 250954 INFO (TEST-TriggerCooldownIntegrationTest.testCooldown-seed#[3A6128D520290F62]) [n:127.0.0.1:57073_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_57073.solr.node' (registry 'solr.node') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@15123b7d
[junit4] 2> 250962 INFO (TEST-TriggerCooldownIntegrationTest.testCooldown-seed#[3A6128D520290F62]) [n:127.0.0.1:57073_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_57073.solr.jvm' (registry 'solr.jvm') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@15123b7d
[junit4] 2> 250979 INFO (TEST-TriggerCooldownIntegrationTest.testCooldown-seed#[3A6128D520290F62]) [n:127.0.0.1:57073_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_57073.solr.jetty' (registry 'solr.jetty') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@15123b7d
[junit4] 2> 250984 INFO (TEST-TriggerCooldownIntegrationTest.testCooldown-seed#[3A6128D520290F62]) [n:127.0.0.1:57073_solr ] o.a.s.c.CorePropertiesLocator Found 0 core definitions underneath /Users/jenkins/workspace/Lucene-Solr-8.x-MacOSX/solr/build/solr-core/test/J1/temp/solr.cloud.autoscaling.TriggerCooldownIntegrationTest_3A6128D520290F62-001/tempDir-001/node3/.
[junit4] 2> 251011 INFO (TEST-TriggerCooldownIntegrationTest.testCooldown-seed#[3A6128D520290F62]) [ ] o.a.s.c.MiniSolrCloudCluster waitForAllNodes: numServers=3
[junit4] 2> 251236 DEBUG (ScheduledTrigger-1742-thread-3) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 3 and last live nodes: 1
[junit4] 2> 251511 DEBUG (ScheduledTrigger-1742-thread-1) [ ] o.a.s.c.a.NodeAddedTrigger Running NodeAddedTrigger node_added_cooldown_trigger
[junit4] 2> 251511 DEBUG (ScheduledTrigger-1742-thread-1) [ ] o.a.s.c.a.NodeAddedTrigger Found livenodes: 3
[junit4] 2> 251511 DEBUG (ScheduledTrigger-1742-thread-1) [ ] o.a.s.c.a.NodeAddedTrigger Tracking new node: 127.0.0.1:57073_solr at time 806418285333020
[junit4] 2> 252240 DEBUG (ScheduledTrigger-1742-thread-4) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 3 and last live nodes: 3
[junit4] 2> 252524 DEBUG (ScheduledTrigger-1742-thread-2) [ ] o.a.s.c.a.NodeAddedTrigger Running NodeAddedTrigger node_added_cooldown_trigger
[junit4] 2> 252524 DEBUG (ScheduledTrigger-1742-thread-2) [ ] o.a.s.c.a.NodeAddedTrigger Found livenodes: 3
[junit4] 2> 252524 DEBUG (ScheduledTrigger-1742-thread-2) [ ] o.a.s.c.a.NodeAddedTrigger NodeAddedTrigger node_added_cooldown_trigger firing registered processor for nodes: [127.0.0.1:57073_solr] added at times [806418285333020], now=806419298167367
[junit4] 2> 252524 DEBUG (ScheduledTrigger-1742-thread-2) [ ] o.a.s.c.a.ScheduledTriggers ++++++++ Cooldown inactive - processing event: {
[junit4] 2> "id":"2dd6ee3700a1cT5f59nw2qmypt7i9jcdpj9xy8y",
[junit4] 2> "source":"node_added_cooldown_trigger",
[junit4] 2> "eventTime":806418285333020,
[junit4] 2> "eventType":"NODEADDED",
[junit4] 2> "properties":{
[junit4] 2> "eventTimes":[806418285333020],
[junit4] 2> "preferredOperation":"movereplica",
[junit4] 2> "nodeNames":["127.0.0.1:57073_solr"],
[junit4] 2> "replicaType":"NRT"}}
[junit4] 2> 252525 DEBUG (ScheduledTrigger-1742-thread-2) [ ] o.a.s.c.a.ScheduledTriggers Pausing all triggers: [.auto_add_replicas, node_added_cooldown_trigger]
[junit4] 2> 252526 DEBUG (ScheduledTrigger-1742-thread-2) [ ] o.a.s.c.a.SystemLogListener Collection .system missing, skip sending event {
[junit4] 2> "id":"2dd6ee3700a1cT5f59nw2qmypt7i9jcdpj9xy8y",
[junit4] 2> "source":"node_added_cooldown_trigger",
[junit4] 2> "eventTime":806418285333020,
[junit4] 2> "eventType":"NODEADDED",
[junit4] 2> "properties":{
[junit4] 2> "eventTimes":[806418285333020],
[junit4] 2> "preferredOperation":"movereplica",
[junit4] 2> "_enqueue_time_":806419298863813,
[junit4] 2> "nodeNames":["127.0.0.1:57073_solr"],
[junit4] 2> "replicaType":"NRT"}}
[junit4] 2> 252527 DEBUG (AutoscalingActionExecutor-1743-thread-1) [ ] o.a.s.c.a.ScheduledTriggers -- processing actions for {
[junit4] 2> "id":"2dd6ee3700a1cT5f59nw2qmypt7i9jcdpj9xy8y",
[junit4] 2> "source":"node_added_cooldown_trigger",
[junit4] 2> "eventTime":806418285333020,
[junit4] 2> "eventType":"NODEADDED",
[junit4] 2> "properties":{
[junit4] 2> "eventTimes":[806418285333020],
[junit4] 2> "preferredOperation":"movereplica",
[junit4] 2> "_enqueue_time_":806419298863813,
[junit4] 2> "nodeNames":["127.0.0.1:57073_solr"],
[junit4] 2> "replicaType":"NRT"}}
[junit4] 2> 252527 DEBUG (ScheduledTrigger-1742-thread-2) [ ] o.a.s.c.a.NodeAddedTrigger Removing new node from tracking: 127.0.0.1:57073_solr
[junit4] 2> 252540 DEBUG (AutoscalingActionExecutor-1743-thread-1) [ ] o.a.s.c.a.SystemLogListener Collection .system missing, skip sending event {
[junit4] 2> "id":"2dd6ee3700a1cT5f59nw2qmypt7i9jcdpj9xy8y",
[junit4] 2> "source":"node_added_cooldown_trigger",
[junit4] 2> "eventTime":806418285333020,
[junit4] 2> "eventType":"NODEADDED",
[junit4] 2> "properties":{
[junit4] 2> "eventTimes":[806418285333020],
[junit4] 2> "preferredOperation":"movereplica",
[junit4] 2> "_enqueue_time_":806419298863813,
[junit4] 2> "nodeNames":["127.0.0.1:57073_solr"],
[junit4] 2> "replicaType":"NRT"}}
[junit4] 2> 252541 DEBUG (AutoscalingActionExecutor-1743-thread-1) [ ] o.a.s.c.a.ScheduledTriggers Resuming trigger: node_added_cooldown_trigger after 5000ms
[junit4] 2> 252541 DEBUG (AutoscalingActionExecutor-1743-thread-1) [ ] o.a.s.c.a.ScheduledTriggers Resuming trigger: .auto_add_replicas after 5000ms
[junit4] 2> 252541 DEBUG (AutoscalingActionExecutor-1743-thread-1) [ ] o.a.s.c.a.ScheduledTriggers -- processing took 14 ms for event id=2dd6ee3700a1cT5f59nw2qmypt7i9jcdpj9xy8y
[junit4] 2> 259553 WARN (TEST-TriggerCooldownIntegrationTest.testCooldown-seed#[3A6128D520290F62]) [ ] o.e.j.s.h.g.GzipHandler minGzipSize of 0 is inefficient for short content, break even is size 23
[junit4] 2> 259553 INFO (TEST-TriggerCooldownIntegrationTest.testCooldown-seed#[3A6128D520290F62]) [ ] o.a.s.c.s.e.JettySolrRunner Start Jetty (configured port=0, binding port=0)
[junit4] 2> 259554 INFO (TEST-TriggerCooldownIntegrationTest.testCooldown-seed#[3A6128D520290F62]) [ ] o.a.s.c.s.e.JettySolrRunner Trying to start Jetty on port 0 try number 2 ...
[junit4] 2> 259554 INFO (TEST-TriggerCooldownIntegrationTest.testCooldown-seed#[3A6128D520290F62]) [ ] o.e.j.s.Server jetty-9.4.27.v20200227; built: 2020-02-27T18:37:21.340Z; git: a304fd9f351f337e7c0e2a7c28878dd536149c6c; jvm 14+36
[junit4] 2> 259554 DEBUG (ScheduledTrigger-1742-thread-1) [ ] o.a.s.c.a.NodeAddedTrigger Running NodeAddedTrigger node_added_cooldown_trigger
[junit4] 2> 259554 DEBUG (ScheduledTrigger-1742-thread-1) [ ] o.a.s.c.a.NodeAddedTrigger Found livenodes: 3
[junit4] 2> 259554 DEBUG (ScheduledTrigger-1742-thread-1) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 3 and last live nodes: 3
[junit4] 2> 259564 INFO (TEST-TriggerCooldownIntegrationTest.testCooldown-seed#[3A6128D520290F62]) [ ] o.e.j.s.session DefaultSessionIdManager workerName=node0
[junit4] 2> 259564 INFO (TEST-TriggerCooldownIntegrationTest.testCooldown-seed#[3A6128D520290F62]) [ ] o.e.j.s.session No SessionScavenger set, using defaults
[junit4] 2> 259564 INFO (TEST-TriggerCooldownIntegrationTest.testCooldown-seed#[3A6128D520290F62]) [ ] o.e.j.s.session node0 Scavenging every 660000ms
[junit4] 2> 259565 INFO (TEST-TriggerCooldownIntegrationTest.testCooldown-seed#[3A6128D520290F62]) [ ] o.e.j.s.h.ContextHandler Started o.e.j.s.ServletContextHandler@45c8af3b{/solr,null,AVAILABLE}
[junit4] 2> 259567 INFO (TEST-TriggerCooldownIntegrationTest.testCooldown-seed#[3A6128D520290F62]) [ ] o.e.j.s.AbstractConnector Started ServerConnector@783bf315{HTTP/1.1, (http/1.1, h2c)}{127.0.0.1:57124}
[junit4] 2> 259567 INFO (TEST-TriggerCooldownIntegrationTest.testCooldown-seed#[3A6128D520290F62]) [ ] o.e.j.s.Server Started @259660ms
[junit4] 2> 259567 INFO (TEST-TriggerCooldownIntegrationTest.testCooldown-seed#[3A6128D520290F62]) [ ] o.a.s.c.s.e.JettySolrRunner Jetty properties: {hostContext=/solr, hostPort=57124}
[junit4] 2> 259567 ERROR (TEST-TriggerCooldownIntegrationTest.testCooldown-seed#[3A6128D520290F62]) [ ] o.a.s.u.StartupLoggingUtils Missing Java Option solr.log.dir. Logging may be missing or incomplete.
[junit4] 2> 259567 INFO (TEST-TriggerCooldownIntegrationTest.testCooldown-seed#[3A6128D520290F62]) [ ] o.a.s.s.SolrDispatchFilter Using logger factory org.apache.logging.slf4j.Log4jLoggerFactory
[junit4] 2> 259567 INFO (TEST-TriggerCooldownIntegrationTest.testCooldown-seed#[3A6128D520290F62]) [ ] o.a.s.s.SolrDispatchFilter ___ _ Welcome to Apache Solr™ version 8.6.0
[junit4] 2> 259567 INFO (TEST-TriggerCooldownIntegrationTest.testCooldown-seed#[3A6128D520290F62]) [ ] o.a.s.s.SolrDispatchFilter / __| ___| |_ _ Starting in cloud mode on port null
[junit4] 2> 259567 INFO (TEST-TriggerCooldownIntegrationTest.testCooldown-seed#[3A6128D520290F62]) [ ] o.a.s.s.SolrDispatchFilter \__ \/ _ \ | '_| Install dir: /Users/jenkins/workspace/Lucene-Solr-8.x-MacOSX/solr
[junit4] 2> 259567 INFO (TEST-TriggerCooldownIntegrationTest.testCooldown-seed#[3A6128D520290F62]) [ ] o.a.s.s.SolrDispatchFilter |___/\___/_|_| Start time: 2020-05-26T22:19:32.575908Z
[junit4] 2> 259569 INFO (TEST-TriggerCooldownIntegrationTest.testCooldown-seed#[3A6128D520290F62]) [ ] o.a.s.c.c.ConnectionManager Waiting for client to connect to ZooKeeper
[junit4] 2> 259575 INFO (zkConnectionManagerCallback-1785-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 259576 INFO (TEST-TriggerCooldownIntegrationTest.testCooldown-seed#[3A6128D520290F62]) [ ] o.a.s.c.c.ConnectionManager Client is connected to ZooKeeper
[junit4] 2> 259579 INFO (TEST-TriggerCooldownIntegrationTest.testCooldown-seed#[3A6128D520290F62]) [ ] o.a.s.s.SolrDispatchFilter solr.xml found in ZooKeeper. Loading...
[junit4] 2> 259807 INFO (TEST-TriggerCooldownIntegrationTest.testCooldown-seed#[3A6128D520290F62]) [ ] o.a.s.h.c.HttpShardHandlerFactory Host whitelist initialized: WhitelistHostChecker [whitelistHosts=null, whitelistHostCheckingEnabled=true]
[junit4] 2> 259809 WARN (TEST-TriggerCooldownIntegrationTest.testCooldown-seed#[3A6128D520290F62]) [ ] o.e.j.u.s.S.config Trusting all certificates configured for Client@28afd312[provider=null,keyStore=null,trustStore=null]
[junit4] 2> 259809 WARN (TEST-TriggerCooldownIntegrationTest.testCooldown-seed#[3A6128D520290F62]) [ ] o.e.j.u.s.S.config No Client EndPointIdentificationAlgorithm configured for Client@28afd312[provider=null,keyStore=null,trustStore=null]
[junit4] 2> 259817 WARN (TEST-TriggerCooldownIntegrationTest.testCooldown-seed#[3A6128D520290F62]) [ ] o.e.j.u.s.S.config Trusting all certificates configured for Client@1a4fc115[provider=null,keyStore=null,trustStore=null]
[junit4] 2> 259817 WARN (TEST-TriggerCooldownIntegrationTest.testCooldown-seed#[3A6128D520290F62]) [ ] o.e.j.u.s.S.config No Client EndPointIdentificationAlgorithm configured for Client@1a4fc115[provider=null,keyStore=null,trustStore=null]
[junit4] 2> 259819 INFO (TEST-TriggerCooldownIntegrationTest.testCooldown-seed#[3A6128D520290F62]) [ ] o.a.s.c.ZkContainer Zookeeper client=127.0.0.1:57046/solr
[junit4] 2> 259820 INFO (TEST-TriggerCooldownIntegrationTest.testCooldown-seed#[3A6128D520290F62]) [ ] o.a.s.c.c.ConnectionManager Waiting for client to connect to ZooKeeper
[junit4] 2> 259827 INFO (zkConnectionManagerCallback-1796-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 259827 INFO (TEST-TriggerCooldownIntegrationTest.testCooldown-seed#[3A6128D520290F62]) [ ] o.a.s.c.c.ConnectionManager Client is connected to ZooKeeper
[junit4] 2> 259938 INFO (TEST-TriggerCooldownIntegrationTest.testCooldown-seed#[3A6128D520290F62]) [n:127.0.0.1:57124_solr ] o.a.s.c.c.ConnectionManager Waiting for client to connect to ZooKeeper
[junit4] 2> 259942 INFO (zkConnectionManagerCallback-1798-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 259942 INFO (TEST-TriggerCooldownIntegrationTest.testCooldown-seed#[3A6128D520290F62]) [n:127.0.0.1:57124_solr ] o.a.s.c.c.ConnectionManager Client is connected to ZooKeeper
[junit4] 2> 259962 INFO (TEST-TriggerCooldownIntegrationTest.testCooldown-seed#[3A6128D520290F62]) [n:127.0.0.1:57124_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (3)
[junit4] 2> 259986 INFO (TEST-TriggerCooldownIntegrationTest.testCooldown-seed#[3A6128D520290F62]) [n:127.0.0.1:57124_solr ] o.a.s.c.ZkController Publish node=127.0.0.1:57124_solr as DOWN
[junit4] 2> 259989 INFO (TEST-TriggerCooldownIntegrationTest.testCooldown-seed#[3A6128D520290F62]) [n:127.0.0.1:57124_solr ] o.a.s.c.TransientSolrCoreCacheDefault Allocating transient cache for 2147483647 transient cores
[junit4] 2> 259990 INFO (TEST-TriggerCooldownIntegrationTest.testCooldown-seed#[3A6128D520290F62]) [n:127.0.0.1:57124_solr ] o.a.s.c.ZkController Register node as live in ZooKeeper:/live_nodes/127.0.0.1:57124_solr
[junit4] 2> 260000 INFO (zkCallback-1759-thread-1) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (3) -> (4)
[junit4] 2> 260000 INFO (zkCallback-1774-thread-1) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (3) -> (4)
[junit4] 2> 260000 INFO (zkCallback-1797-thread-1) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (3) -> (4)
[junit4] 2> 260000 INFO (zkCallback-1724-thread-1) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (3) -> (4)
[junit4] 2> 260000 INFO (zkCallback-1736-thread-1) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (3) -> (4)
[junit4] 2> 260006 INFO (TEST-TriggerCooldownIntegrationTest.testCooldown-seed#[3A6128D520290F62]) [n:127.0.0.1:57124_solr ] o.a.s.p.PackageLoader /packages.json updated to version -1
[junit4] 2> 260007 WARN (TEST-TriggerCooldownIntegrationTest.testCooldown-seed#[3A6128D520290F62]) [n:127.0.0.1:57124_solr ] 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> 260030 INFO (TEST-TriggerCooldownIntegrationTest.testCooldown-seed#[3A6128D520290F62]) [n:127.0.0.1:57124_solr ] o.a.s.h.a.MetricsHistoryHandler No .system collection, keeping metrics history in memory.
[junit4] 2> 260052 INFO (TEST-TriggerCooldownIntegrationTest.testCooldown-seed#[3A6128D520290F62]) [n:127.0.0.1:57124_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_57124.solr.node' (registry 'solr.node') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@15123b7d
[junit4] 2> 260059 INFO (TEST-TriggerCooldownIntegrationTest.testCooldown-seed#[3A6128D520290F62]) [n:127.0.0.1:57124_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_57124.solr.jvm' (registry 'solr.jvm') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@15123b7d
[junit4] 2> 260059 INFO (TEST-TriggerCooldownIntegrationTest.testCooldown-seed#[3A6128D520290F62]) [n:127.0.0.1:57124_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_57124.solr.jetty' (registry 'solr.jetty') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@15123b7d
[junit4] 2> 260060 INFO (TEST-TriggerCooldownIntegrationTest.testCooldown-seed#[3A6128D520290F62]) [n:127.0.0.1:57124_solr ] o.a.s.c.CorePropertiesLocator Found 0 core definitions underneath /Users/jenkins/workspace/Lucene-Solr-8.x-MacOSX/solr/build/solr-core/test/J1/temp/solr.cloud.autoscaling.TriggerCooldownIntegrationTest_3A6128D520290F62-001/tempDir-001/node4/.
[junit4] 2> 260572 DEBUG (ScheduledTrigger-1742-thread-1) [ ] o.a.s.c.a.NodeAddedTrigger Running NodeAddedTrigger node_added_cooldown_trigger
[junit4] 2> 260572 DEBUG (ScheduledTrigger-1742-thread-1) [ ] o.a.s.c.a.NodeAddedTrigger Found livenodes: 4
[junit4] 2> 260572 DEBUG (ScheduledTrigger-1742-thread-3) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 4 and last live nodes: 3
[junit4] 2> 260572 DEBUG (ScheduledTrigger-1742-thread-1) [ ] o.a.s.c.a.NodeAddedTrigger Tracking new node: 127.0.0.1:57124_solr at time 806427345863123
[junit4] 2> 261740 DEBUG (ScheduledTrigger-1742-thread-3) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 4 and last live nodes: 4
[junit4] 2> 261742 DEBUG (ScheduledTrigger-1742-thread-3) [ ] o.a.s.c.a.NodeAddedTrigger Running NodeAddedTrigger node_added_cooldown_trigger
[junit4] 2> 261743 DEBUG (ScheduledTrigger-1742-thread-3) [ ] o.a.s.c.a.NodeAddedTrigger Found livenodes: 4
[junit4] 2> 261743 DEBUG (ScheduledTrigger-1742-thread-3) [ ] o.a.s.c.a.NodeAddedTrigger NodeAddedTrigger node_added_cooldown_trigger firing registered processor for nodes: [127.0.0.1:57124_solr] added at times [806427345863123], now=806428517411150
[junit4] 2> 261744 DEBUG (ScheduledTrigger-1742-thread-3) [ ] o.a.s.c.a.ScheduledTriggers ++++++++ Cooldown inactive - processing event: {
[junit4] 2> "id":"2dd70ff7cc1d3T5f59nw2qmypt7i9jcdpj9xy8z",
[junit4] 2> "source":"node_added_cooldown_trigger",
[junit4] 2> "eventTime":806427345863123,
[junit4] 2> "eventType":"NODEADDED",
[junit4] 2> "properties":{
[junit4] 2> "eventTimes":[806427345863123],
[junit4] 2> "preferredOperation":"movereplica",
[junit4] 2> "nodeNames":["127.0.0.1:57124_solr"],
[junit4] 2> "replicaType":"NRT"}}
[junit4] 2> 261744 DEBUG (ScheduledTrigger-1742-thread-3) [ ] o.a.s.c.a.ScheduledTriggers Pausing all triggers: [.auto_add_replicas, node_added_cooldown_trigger]
[junit4] 2> 261746 DEBUG (ScheduledTrigger-1742-thread-3) [ ] o.a.s.c.a.SystemLogListener Collection .system missing, skip sending event {
[junit4] 2> "id":"2dd70ff7cc1d3T5f59nw2qmypt7i9jcdpj9xy8z",
[junit4] 2> "source":"node_added_cooldown_trigger",
[junit4] 2> "eventTime":806427345863123,
[junit4] 2> "eventType":"NODEADDED",
[junit4] 2> "properties":{
[junit4] 2> "eventTimes":[806427345863123],
[junit4] 2> "preferredOperation":"movereplica",
[junit4] 2> "_enqueue_time_":806428518161719,
[junit4] 2> "nodeNames":["127.0.0.1:57124_solr"],
[junit4] 2> "replicaType":"NRT"}}
[junit4] 2> 261746 DEBUG (ScheduledTrigger-1742-thread-3) [ ] o.a.s.c.a.NodeAddedTrigger Removing new node from tracking: 127.0.0.1:57124_solr
[junit4] 2> 261746 DEBUG (AutoscalingActionExecutor-1743-thread-1) [ ] o.a.s.c.a.ScheduledTriggers -- processing actions for {
[junit4] 2> "id":"2dd70ff7cc1d3T5f59nw2qmypt7i9jcdpj9xy8z",
[junit4] 2> "source":"node_added_cooldown_trigger",
[junit4] 2> "eventTime":806427345863123,
[junit4] 2> "eventType":"NODEADDED",
[junit4] 2> "properties":{
[junit4] 2> "eventTimes":[806427345863123],
[junit4] 2> "preferredOperation":"movereplica",
[junit4] 2> "_enqueue_time_":806428518161719,
[junit4] 2> "nodeNames":["127.0.0.1:57124_solr"],
[junit4] 2> "replicaType":"NRT"}}
[junit4] 2> 261753 DEBUG (AutoscalingActionExecutor-1743-thread-1) [ ] o.a.s.c.a.SystemLogListener Collection .system missing, skip sending event {
[junit4] 2> "id":"2dd70ff7cc1d3T5f59nw2qmypt7i9jcdpj9xy8z",
[junit4] 2> "source":"node_added_cooldown_trigger",
[junit4] 2> "eventTime":806427345863123,
[junit4] 2> "eventType":"NODEADDED",
[junit4] 2> "properties":{
[junit4] 2> "eventTimes":[806427345863123],
[junit4] 2> "preferredOperation":"movereplica",
[junit4] 2> "_enqueue_time_":806428518161719,
[junit4] 2> "nodeNames":["127.0.0.1:57124_solr"],
[junit4] 2> "replicaType":"NRT"}}
[junit4] 2> 261753 DEBUG (AutoscalingActionExecutor-1743-thread-1) [ ] o.a.s.c.a.ScheduledTriggers Resuming trigger: node_added_cooldown_trigger after 5000ms
[junit4] 2> 261753 DEBUG (AutoscalingActionExecutor-1743-thread-1) [ ] o.a.s.c.a.ScheduledTriggers Resuming trigger: .auto_add_replicas after 5000ms
[junit4] 2> 261753 DEBUG (AutoscalingActionExecutor-1743-thread-1) [ ] o.a.s.c.a.ScheduledTriggers -- processing took 6 ms for event id=2dd70ff7cc1d3T5f59nw2qmypt7i9jcdpj9xy8z
[junit4] 2> 263755 INFO (qtp541580290-3044) [n:127.0.0.1:57052_solr ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/metrics params={prefix=CONTAINER.fs.usableSpace,CONTAINER.fs.totalSpace,CONTAINER.cores&wt=javabin&version=2&group=solr.node} status=0 QTime=0
[junit4] 2> 263757 INFO (qtp1998845029-3053) [n:127.0.0.1:57053_solr ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/metrics params={prefix=CONTAINER.fs.usableSpace,CONTAINER.fs.totalSpace,CONTAINER.cores&wt=javabin&version=2&group=solr.node} status=0 QTime=0
[junit4] 2> 263761 INFO (qtp439795907-3109) [n:127.0.0.1:57073_solr ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/metrics params={prefix=CONTAINER.fs.usableSpace,CONTAINER.fs.totalSpace,CONTAINER.cores&wt=javabin&version=2&group=solr.node} status=0 QTime=0
[junit4] 2> 263764 INFO (qtp235384296-3138) [n:127.0.0.1:57124_solr ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/metrics params={prefix=CONTAINER.fs.usableSpace,CONTAINER.fs.totalSpace,CONTAINER.cores&wt=javabin&version=2&group=solr.node} status=0 QTime=0
[junit4] 2> 263764 DEBUG (qtp541580290-3047) [n:127.0.0.1:57052_solr ] o.a.s.c.a.AutoScalingHandler Verified autoscaling configuration
[junit4] 2> 263766 INFO (qtp541580290-3047) [n:127.0.0.1:57052_solr ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/autoscaling params={wt=javabin&version=2} status=0 QTime=16
[junit4] 2> 263767 DEBUG (zkCallback-1736-thread-1) [ ] o.a.s.c.a.OverseerTriggerThread Refreshing /autoscaling.json with znode version 5
[junit4] 2> 263767 DEBUG (OverseerAutoScalingTriggerThread-72110443312644104-127.0.0.1:57052_solr-n_0000000000) [ ] o.a.s.c.a.OverseerTriggerThread Processed trigger updates upto znodeVersion 5
[junit4] 2> 263768 DEBUG (OverseerAutoScalingTriggerThread-72110443312644104-127.0.0.1:57052_solr-n_0000000000) [ ] o.a.s.c.a.ScheduledTriggers Changing value of autoscaling property: triggerCooldownPeriodSeconds from: 5 to: 7
[junit4] 2> 263768 INFO (qtp541580290-3045) [n:127.0.0.1:57052_solr ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/cluster/autoscaling params={wt=javabin&version=2} status=0 QTime=1
[junit4] 2> 263769 WARN (TEST-TriggerCooldownIntegrationTest.testCooldown-seed#[3A6128D520290F62]) [ ] o.e.j.s.h.g.GzipHandler minGzipSize of 0 is inefficient for short content, break even is size 23
[junit4] 2> 263769 INFO (TEST-TriggerCooldownIntegrationTest.testCooldown-seed#[3A6128D520290F62]) [ ] o.a.s.c.s.e.JettySolrRunner Start Jetty (configured port=0, binding port=0)
[junit4] 2> 263769 INFO (TEST-TriggerCooldownIntegrationTest.testCooldown-seed#[3A6128D520290F62]) [ ] o.a.s.c.s.e.JettySolrRunner Trying to start Jetty on port 0 try number 2 ...
[junit4] 2> 263770 INFO (TEST-TriggerCooldownIntegrationTest.testCooldown-seed#[3A6128D520290F62]) [ ] o.e.j.s.Server jetty-9.4.27.v20200227; built: 2020-02-27T18:37:21.340Z; git: a304fd9f351f337e7c0e2a7c28878dd536149c6c; jvm 14+36
[junit4] 2> 263771 DEBUG (OverseerAutoScalingTriggerThread-72110443312644104-127.0.0.1:57052_solr-n_0000000000) [ ] o.a.s.c.a.OverseerTriggerThread -- deactivating old nodeLost / nodeAdded markers
[junit4] 2> 263772 INFO (TEST-TriggerCooldownIntegrationTest.testCooldown-seed#[3A6128D520290F62]) [ ] o.e.j.s.session DefaultSessionIdManager workerName=node0
[junit4] 2> 263772 INFO (TEST-TriggerCooldownIntegrationTest.testCooldown-seed#[3A6128D520290F62]) [ ] o.e.j.s.session No SessionScavenger set, using defaults
[junit4] 2> 263772 INFO (TEST-TriggerCooldownIntegrationTest.testCooldown-seed#[3A6128D520290F62]) [ ] o.e.j.s.session node0 Scavenging every 660000ms
[junit4] 2> 263772 INFO (TEST-TriggerCooldownIntegrationTest.testCooldown-seed#[3A6128D520290F62]) [ ] o.e.j.s.h.ContextHandler Started o.e.j.s.ServletContextHandler@4abe535c{/solr,null,AVAILABLE}
[junit4] 2> 263774 INFO (TEST-TriggerCooldownIntegrationTest.testCooldown-seed#[3A6128D520290F62]) [ ] o.e.j.s.AbstractConnector Started ServerConnector@11d0e915{HTTP/1.1, (http/1.1, h2c)}{127.0.0.1:57210}
[junit4] 2> 263774 INFO (TEST-TriggerCooldownIntegrationTest.testCooldown-seed#[3A6128D520290F62]) [ ] o.e.j.s.Server Started @263867ms
[junit4] 2> 263774 INFO (TEST-TriggerCooldownIntegrationTest.testCooldown-seed#[3A6128D520290F62]) [ ] o.a.s.c.s.e.JettySolrRunner Jetty properties: {hostContext=/solr, hostPort=57210}
[junit4] 2> 263775 ERROR (TEST-TriggerCooldownIntegrationTest.testCooldown-seed#[3A6128D520290F62]) [ ] o.a.s.u.StartupLoggingUtils Missing Java Option solr.log.dir. Logging may be missing or incomplete.
[junit4] 2> 263775 INFO (TEST-TriggerCooldownIntegrationTest.testCooldown-seed#[3A6128D520290F62]) [ ] o.a.s.s.SolrDispatchFilter Using logger factory org.apache.logging.slf4j.Log4jLoggerFactory
[junit4] 2> 263775 INFO (TEST-TriggerCooldownIntegrationTest.testCooldown-seed#[3A6128D520290F62]) [ ] o.a.s.s.SolrDispatchFilter ___ _ Welcome to Apache Solr™ version 8.6.0
[junit4] 2> 263775 INFO (TEST-TriggerCooldownIntegrationTest.testCooldown-seed#[3A6128D520290F62]) [ ] o.a.s.s.SolrDispatchFilter / __| ___| |_ _ Starting in cloud mode on port null
[junit4] 2> 263775 INFO (TEST-TriggerCooldownIntegrationTest.testCooldown-seed#[3A6128D520290F62]) [ ] o.a.s.s.SolrDispatchFilter \__ \/ _ \ | '_| Install dir: /Users/jenkins/workspace/Lucene-Solr-8.x-MacOSX/solr
[junit4] 2> 263775 INFO (TEST-TriggerCooldownIntegrationTest.testCooldown-seed#[3A6128D520290F62]) [ ] o.a.s.s.SolrDispatchFilter |___/\___/_|_| Start time: 2020-05-26T22:19:36.783247Z
[junit4] 2> 263776 INFO (TEST-TriggerCooldownIntegrationTest.testCooldown-seed#[3A6128D520290F62]) [ ] o.a.s.c.c.ConnectionManager Waiting for client to connect to ZooKeeper
[junit4] 2> 263779 DEBUG (OverseerAutoScalingTriggerThread-72110443312644104-127.0.0.1:57052_solr-n_0000000000) [ ] o.a.s.c.a.OverseerTriggerThread Current znodeVersion 5, lastZnodeVersion 5
[junit4] 2> 263780 INFO (zkConnectionManagerCallback-1808-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 263780 INFO (TEST-TriggerCooldownIntegrationTest.testCooldown-seed#[3A6128D520290F62]) [ ] o.a.s.c.c.ConnectionManager Client is connected to ZooKeeper
[junit4] 2> 263781 INFO (TEST-TriggerCooldownIntegrationTest.testCooldown-seed#[3A6128D520290F62]) [ ] o.a.s.s.SolrDispatchFilter solr.xml found in ZooKeeper. Loading...
[junit4] 2> 263936 INFO (TEST-TriggerCooldownIntegrationTest.testCooldown-seed#[3A6128D520290F62]) [ ] o.a.s.h.c.HttpShardHandlerFactory Host whitelist initialized: WhitelistHostChecker [whitelistHosts=null, whitelistHostCheckingEnabled=true]
[junit4] 2> 263938 WARN (TEST-TriggerCooldownIntegrationTest.testCooldown-seed#[3A6128D520290F62]) [ ] o.e.j.u.s.S.config Trusting all certificates configured for Client@305e1dc3[provider=null,keyStore=null,trustStore=null]
[junit4] 2> 263938 WARN (TEST-TriggerCooldownIntegrationTest.testCooldown-seed#[3A6128D520290F62]) [ ] o.e.j.u.s.S.config No Client EndPointIdentificationAlgorithm configured for Client@305e1dc3[provider=null,keyStore=null,trustStore=null]
[junit4] 2> 263942 WARN (TEST-TriggerCooldownIntegrationTest.testCooldown-seed#[3A6128D520290F62]) [ ] o.e.j.u.s.S.config Trusting all certificates configured for Client@7f7a2eed[provider=null,keyStore=null,trustStore=null]
[junit4] 2> 263942 WARN (TEST-TriggerCooldownIntegrationTest.testCooldown-seed#[3A6128D520290F62]) [ ] o.e.j.u.s.S.config No Client EndPointIdentificationAlgorithm configured for Client@7f7a2eed[provider=null,keyStore=null,trustStore=null]
[junit4] 2> 263943 INFO (TEST-TriggerCooldownIntegrationTest.testCooldown-seed#[3A6128D520290F62]) [ ] o.a.s.c.ZkContainer Zookeeper client=127.0.0.1:57046/solr
[junit4] 2> 263944 INFO (TEST-TriggerCooldownIntegrationTest.testCooldown-seed#[3A6128D520290F62]) [ ] o.a.s.c.c.ConnectionManager Waiting for client to connect to ZooKeeper
[junit4] 2> 263950 INFO (zkConnectionManagerCallback-1819-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 263950 INFO (TEST-TriggerCooldownIntegrationTest.testCooldown-seed#[3A6128D520290F62]) [ ] o.a.s.c.c.ConnectionManager Client is connected to ZooKeeper
[junit4] 2> 264054 INFO (TEST-TriggerCooldownIntegrationTest.testCooldown-seed#[3A6128D520290F62]) [n:127.0.0.1:57210_solr ] o.a.s.c.c.ConnectionManager Waiting for client to connect to ZooKeeper
[junit4] 2> 264058 INFO (zkConnectionManagerCallback-1821-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 264058 INFO (TEST-TriggerCooldownIntegrationTest.testCooldown-seed#[3A6128D520290F62]) [n:127.0.0.1:57210_solr ] o.a.s.c.c.ConnectionManager Client is connected to ZooKeeper
[junit4] 2> 264086 INFO (TEST-TriggerCooldownIntegrationTest.testCooldown-seed#[3A6128D520290F62]) [n:127.0.0.1:57210_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (4)
[junit4] 2> 264107 INFO (TEST-TriggerCooldownIntegrationTest.testCooldown-seed#[3A6128D520290F62]) [n:127.0.0.1:57210_solr ] o.a.s.c.ZkController Publish node=127.0.0.1:57210_solr as DOWN
[junit4] 2> 264115 INFO (TEST-TriggerCooldownIntegrationTest.testCooldown-seed#[3A6128D520290F62]) [n:127.0.0.1:57210_solr ] o.a.s.c.TransientSolrCoreCacheDefault Allocating transient cache for 2147483647 transient cores
[junit4] 2> 264115 INFO (TEST-TriggerCooldownIntegrationTest.testCooldown-seed#[3A6128D520290F62]) [n:127.0.0.1:57210_solr ] o.a.s.c.ZkController Register node as live in ZooKeeper:/live_nodes/127.0.0.1:57210_solr
[junit4] 2> 264125 INFO (zkCallback-1759-thread-1) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (4) -> (5)
[junit4] 2> 264126 INFO (zkCallback-1774-thread-1) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (4) -> (5)
[junit4] 2> 264126 INFO (zkCallback-1724-thread-1) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (4) -> (5)
[junit4] 2> 264126 INFO (zkCallback-1797-thread-1) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (4) -> (5)
[junit4] 2> 264126 INFO (zkCallback-1820-thread-1) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (4) -> (5)
[junit4] 2> 264126 INFO (zkCallback-1736-thread-1) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (4) -> (5)
[junit4] 2> 264132 INFO (TEST-TriggerCooldownIntegrationTest.testCooldown-seed#[3A6128D520290F62]) [n:127.0.0.1:57210_solr ] o.a.s.p.PackageLoader /packages.json updated to version -1
[junit4] 2> 264133 WARN (TEST-TriggerCooldownIntegrationTest.testCooldown-seed#[3A6128D520290F62]) [n:127.0.0.1:57210_solr ] 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> 264151 INFO (TEST-TriggerCooldownIntegrationTest.testCooldown-seed#[3A6128D520290F62]) [n:127.0.0.1:57210_solr ] o.a.s.h.a.MetricsHistoryHandler No .system collection, keeping metrics history in memory.
[junit4] 2> 264192 INFO (TEST-TriggerCooldownIntegrationTest.testCooldown-seed#[3A6128D520290F62]) [n:127.0.0.1:57210_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_57210.solr.node' (registry 'solr.node') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@15123b7d
[junit4] 2> 264213 INFO (TEST-TriggerCooldownIntegrationTest.testCooldown-seed#[3A6128D520290F62]) [n:127.0.0.1:57210_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_57210.solr.jvm' (registry 'solr.jvm') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@15123b7d
[junit4] 2> 264213 INFO (TEST-TriggerCooldownIntegrationTest.testCooldown-seed#[3A6128D520290F62]) [n:127.0.0.1:57210_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_57210.solr.jetty' (registry 'solr.jetty') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@15123b7d
[junit4] 2> 264215 INFO (TEST-TriggerCooldownIntegrationTest.testCooldown-seed#[3A6128D520290F62]) [n:127.0.0.1:57210_solr ] o.a.s.c.CorePropertiesLocator Found 0 core definitions underneath /Users/jenkins/workspace/Lucene-Solr-8.x-MacOSX/solr/build/solr-core/test/J1/temp/solr.cloud.autoscaling.TriggerCooldownIntegrationTest_3A6128D520290F62-001/tempDir-001/node5/.
[junit4] 2> 266756 DEBUG (ScheduledTrigger-1742-thread-1) [ ] o.a.s.c.a.NodeAddedTrigger Running NodeAddedTrigger node_added_cooldown_trigger
[junit4] 2> 266756 DEBUG (ScheduledTrigger-1742-thread-1) [ ] o.a.s.c.a.NodeAddedTrigger Found livenodes: 5
[junit4] 2> 266756 DEBUG (ScheduledTrigger-1742-thread-2) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 5 and last live nodes: 4
[junit4] 2> 266756 DEBUG (ScheduledTrigger-1742-thread-1) [ ] o.a.s.c.a.NodeAddedTrigger Tracking new node: 127.0.0.1:57210_solr at time 806433530262482
[junit4] 2> 267765 DEBUG (ScheduledTrigger-1742-thread-1) [ ] o.a.s.c.a.NodeAddedTrigger Running NodeAddedTrigger node_added_cooldown_trigger
[junit4] 2> 267765 DEBUG (ScheduledTrigger-1742-thread-1) [ ] o.a.s.c.a.NodeAddedTrigger Found livenodes: 5
[junit4] 2> 267765 DEBUG (ScheduledTrigger-1742-thread-1) [ ] o.a.s.c.a.NodeAddedTrigger NodeAddedTrigger node_added_cooldown_trigger firing registered processor for nodes: [127.0.0.1:57210_solr] added at times [806433530262482], now=806434539213170
[junit4] 2> 267765 DEBUG (ScheduledTrigger-1742-thread-3) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 5 and last live nodes: 5
[junit4] 2> 267765 DEBUG (ScheduledTrigger-1742-thread-1) [ ] o.a.s.c.a.ScheduledTriggers ++++++++ Cooldown inactive - processing event: {
[junit4] 2> "id":"2dd72701b33d2T5f59nw2qmypt7i9jcdpj9xy90",
[junit4] 2> "source":"node_added_cooldown_trigger",
[junit4] 2> "eventTime":806433530262482,
[junit4] 2> "eventType":"NODEADDED",
[junit4] 2> "properties":{
[junit4] 2> "eventTimes":[806433530262482],
[junit4] 2> "preferredOperation":"movereplica",
[junit4] 2> "nodeNames":["127.0.0.1:57210_solr"],
[junit4] 2> "replicaType":"NRT"}}
[junit4] 2> 267765 DEBUG (ScheduledTrigger-1742-thread-1) [ ] o.a.s.c.a.ScheduledTriggers Pausing all triggers: [.auto_add_replicas, node_added_cooldown_trigger]
[junit4] 2> 267766 DEBUG (ScheduledTrigger-1742-thread-1) [ ] o.a.s.c.a.SystemLogListener Collection .system missing, skip sending event {
[junit4] 2> "id":"2dd72701b33d2T5f59nw2qmypt7i9jcdpj9xy90",
[junit4] 2> "source":"node_added_cooldown_trigger",
[junit4] 2> "eventTime":806433530262482,
[junit4] 2> "eventType":"NODEADDED",
[junit4] 2> "properties":{
[junit4] 2> "eventTimes":[806433530262482],
[junit4] 2> "preferredOperation":"movereplica",
[junit4] 2> "_enqueue_time_":806434539413310,
[junit4] 2> "nodeNames":["127.0.0.1:57210_solr"],
[junit4] 2> "replicaType":"NRT"}}
[junit4] 2> 267766 DEBUG (ScheduledTrigger-1742-thread-1) [ ] o.a.s.c.a.NodeAddedTrigger Removing new node from tracking: 127.0.0.1:57210_solr
[junit4] 2> 267766 DEBUG (AutoscalingActionExecutor-1743-thread-1) [ ] o.a.s.c.a.ScheduledTriggers -- processing actions for {
[junit4] 2> "id":"2dd72701b33d2T5f59nw2qmypt7i9jcdpj9xy90",
[junit4] 2> "source":"node_added_cooldown_trigger",
[junit4] 2> "eventTime":806433530262482,
[junit4] 2> "eventType":"NODEADDED",
[junit4] 2> "properties":{
[junit4] 2> "eventTimes":[806433530262482],
[junit4] 2> "preferredOperation":"movereplica",
[junit4] 2> "_enqueue_time_":806434539413310,
[junit4] 2> "nodeNames":["127.0.0.1:57210_solr"],
[junit4] 2> "replicaType":"NRT"}}
[junit4] 2> 267767 WARN (TEST-TriggerCooldownIntegrationTest.testCooldown-seed#[3A6128D520290F62]) [ ] o.e.j.s.h.g.GzipHandler minGzipSize of 0 is inefficient for short content, break even is size 23
[junit4] 2> 267767 INFO (TEST-TriggerCooldownIntegrationTest.testCooldown-seed#[3A6128D520290F62]) [ ] o.a.s.c.s.e.JettySolrRunner Start Jetty (configured port=0, binding port=0)
[junit4] 2> 267767 INFO (TEST-TriggerCooldownIntegrationTest.testCooldown-seed#[3A6128D520290F62]) [ ] o.a.s.c.s.e.JettySolrRunner Trying to start Jetty on port 0 try number 2 ...
[junit4] 2> 267767 INFO (TEST-TriggerCooldownIntegrationTest.testCooldown-seed#[3A6128D520290F62]) [ ] o.e.j.s.Server jetty-9.4.27.v20200227; built: 2020-02-27T18:37:21.340Z; git: a304fd9f351f337e7c0e2a7c28878dd536149c6c; jvm 14+36
[junit4] 2> 267770 DEBUG (AutoscalingActionExecutor-1743-thread-1) [ ] o.a.s.c.a.SystemLogListener Collection .system missing, skip sending event {
[junit4] 2> "id":"2dd72701b33d2T5f59nw2qmypt7i9jcdpj9xy90",
[junit4] 2> "source":"node_added_cooldown_trigger",
[junit4] 2> "eventTime":806433530262482,
[junit4] 2> "eventType":"NODEADDED",
[junit4] 2> "properties":{
[junit4] 2> "eventTimes":[806433530262482],
[junit4] 2> "preferredOperation":"movereplica",
[junit4] 2> "_enqueue_time_":806434539413310,
[junit4] 2> "nodeNames":["127.0.0.1:57210_solr"],
[junit4] 2> "replicaType":"NRT"}}
[junit4] 2> 267770 DEBUG (AutoscalingActionExecutor-1743-thread-1) [ ] o.a.s.c.a.ScheduledTriggers Resuming trigger: .auto_add_replicas after 7000ms
[junit4] 2> 267770 DEBUG (AutoscalingActionExecutor-1743-thread-1) [ ] o.a.s.c.a.ScheduledTriggers Resuming trigger: node_added_cooldown_trigger after 7000ms
[junit4] 2> 267770 DEBUG (AutoscalingActionExecutor-1743-thread-1) [ ] o.a.s.c.a.ScheduledTriggers -- processing took 3 ms for event id=2dd72701b33d2T5f59nw2qmypt7i9jcdpj9xy90
[junit4] 2> 267770 INFO (TEST-TriggerCooldownIntegrationTest.testCooldown-seed#[3A6128D520290F62]) [ ] o.e.j.s.session DefaultSessionIdManager workerName=node0
[junit4] 2> 267770 INFO (TEST-TriggerCooldownIntegrationTest.testCooldown-seed#[3A6128D520290F62]) [ ] o.e.j.s.session No SessionScavenger set, using defaults
[junit4] 2> 267770 INFO (TEST-TriggerCooldownIntegrationTest.testCooldown-seed#[3A6128D520290F62]) [ ] o.e.j.s.session node0 Scavenging every 660000ms
[junit4]
[...truncated too long message...]
4] 2> 1717992 INFO (jetty-closer-15766-thread-1) [ ] o.a.s.c.ZkController Publish this node as DOWN...
[junit4] 2> 1717992 INFO (jetty-closer-15766-thread-1) [ ] o.a.s.c.ZkController Publish node=127.0.0.1:55639_solr as DOWN
[junit4] 2> 1717996 INFO (jetty-closer-15766-thread-1) [ ] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.node tag=null
[junit4] 2> 1717996 INFO (jetty-closer-15766-thread-1) [ ] o.a.s.m.r.SolrJmxReporter Closing reporter [org.apache.solr.metrics.reporters.SolrJmxReporter@c65e7bb: rootName = solr_55639, domain = solr.node, service url = null, agent id = null] for registry solr.node/com.codahale.metrics.MetricRegistry@4382c64a
[junit4] 2> 1718002 INFO (jetty-closer-15766-thread-1) [ ] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.jvm tag=null
[junit4] 2> 1718002 INFO (jetty-closer-15766-thread-1) [ ] o.a.s.m.r.SolrJmxReporter Closing reporter [org.apache.solr.metrics.reporters.SolrJmxReporter@543647ef: rootName = solr_55639, domain = solr.jvm, service url = null, agent id = null] for registry solr.jvm/com.codahale.metrics.MetricRegistry@183858f2
[junit4] 2> 1718005 INFO (jetty-closer-15766-thread-1) [ ] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.jetty tag=null
[junit4] 2> 1718005 INFO (jetty-closer-15766-thread-1) [ ] o.a.s.m.r.SolrJmxReporter Closing reporter [org.apache.solr.metrics.reporters.SolrJmxReporter@77ed2589: rootName = solr_55639, domain = solr.jetty, service url = null, agent id = null] for registry solr.jetty/com.codahale.metrics.MetricRegistry@466cf964
[junit4] 2> 1718005 INFO (jetty-closer-15766-thread-1) [ ] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.cluster tag=null
[junit4] 2> 1718007 INFO (closeThreadPool-15771-thread-2) [ ] o.a.s.c.Overseer Overseer (id=72110536439889925-127.0.0.1:55639_solr-n_0000000000) closing
[junit4] 2> 1718007 INFO (OverseerStateUpdate-72110536439889925-127.0.0.1:55639_solr-n_0000000000) [n:127.0.0.1:55639_solr ] o.a.s.c.Overseer Overseer Loop exiting : 127.0.0.1:55639_solr
[junit4] 2> 1718009 INFO (OverseerAutoScalingTriggerThread-72110536439889925-127.0.0.1:55639_solr-n_0000000000) [ ] o.a.s.c.a.OverseerTriggerThread OverseerTriggerThread woken up but we are closed, exiting.
[junit4] 2> 1718014 INFO (closeThreadPool-15771-thread-1) [ ] o.a.s.c.Overseer Overseer (id=72110536439889925-127.0.0.1:55639_solr-n_0000000000) closing
[junit4] 2> 1718118 INFO (jetty-closer-15766-thread-1) [ ] o.a.s.c.Overseer Overseer (id=72110536439889925-127.0.0.1:55639_solr-n_0000000000) closing
[junit4] 2> 1718121 INFO (jetty-closer-15766-thread-1) [ ] o.e.j.s.AbstractConnector Stopped ServerConnector@76295f22{HTTP/1.1, (http/1.1, h2c)}{127.0.0.1:0}
[junit4] 2> 1718121 INFO (jetty-closer-15766-thread-1) [ ] o.e.j.s.h.ContextHandler Stopped o.e.j.s.ServletContextHandler@3b8c21b3{/solr,null,UNAVAILABLE}
[junit4] 2> 1718121 INFO (jetty-closer-15766-thread-1) [ ] o.e.j.s.session node0 Stopped scavenging
[junit4] 2> 1718124 INFO (SUITE-SplitByPrefixTest-seed#[3A6128D520290F62]-worker) [ ] o.a.s.c.ZkTestServer Shutting down ZkTestServer.
[junit4] 2> 1718345 WARN (ZkTestServer Run Thread) [ ] o.a.s.c.ZkTestServer Watch limit violations:
[junit4] 2> Maximum concurrent create/delete watches above limit:
[junit4] 2>
[junit4] 2> 4 /solr/collections/c1/terms/shard1_0
[junit4] 2> 4 /solr/collections/c1/terms/shard1_1
[junit4] 2> 3 /solr/collections/c1/state.json
[junit4] 2> 3 /solr/clusterprops.json
[junit4] 2> 3 /solr/aliases.json
[junit4] 2> 3 /solr/collections/c1/terms/shard1
[junit4] 2> 3 /solr/configs/conf/managed-schema
[junit4] 2>
[junit4] 2> Maximum concurrent data watches above limit:
[junit4] 2>
[junit4] 2> 89 /solr/collections/c1/state.json
[junit4] 2> 3 /solr/aliases.json
[junit4] 2> 3 /solr/clusterstate.json
[junit4] 2>
[junit4] 2> Maximum concurrent children watches above limit:
[junit4] 2>
[junit4] 2> 43 /solr/overseer/queue
[junit4] 2> 10 /solr/overseer/collection-queue-work
[junit4] 2> 8 /solr/collections
[junit4] 2> 4 /solr/live_nodes
[junit4] 2>
[junit4] 2> 1718349 INFO (SUITE-SplitByPrefixTest-seed#[3A6128D520290F62]-worker) [ ] o.a.s.c.ZkTestServer waitForServerDown: 127.0.0.1:55631
[junit4] 2> 1718349 INFO (SUITE-SplitByPrefixTest-seed#[3A6128D520290F62]-worker) [ ] o.a.s.c.ZkTestServer parse host and port list: 127.0.0.1:55631
[junit4] 2> 1718349 INFO (SUITE-SplitByPrefixTest-seed#[3A6128D520290F62]-worker) [ ] o.a.s.c.ZkTestServer connecting to 127.0.0.1 55631
[junit4] 2> NOTE: leaving temporary files on disk at: /Users/jenkins/workspace/Lucene-Solr-8.x-MacOSX/solr/build/solr-core/test/J3/temp/solr.cloud.api.collections.SplitByPrefixTest_3A6128D520290F62-001
[junit4] 2> May 26, 2020 10:43:51 PM com.carrotsearch.randomizedtesting.ThreadLeakControl checkThreadLeaks
[junit4] 2> WARNING: Will linger awaiting termination of 1 leaked thread(s).
[junit4] 2> NOTE: test params are: codec=Asserting(Lucene86): {}, docValues:{}, maxPointsInLeafNode=1026, maxMBSortInHeap=5.711844622699146, sim=Asserting(org.apache.lucene.search.similarities.AssertingSimilarity@5c0ad31e), locale=jmc, timezone=Etc/GMT-3
[junit4] 2> NOTE: Mac OS X 10.14.6 x86_64/AdoptOpenJDK 14 (64-bit)/cpus=6,threads=1,free=85764640,total=518979584
[junit4] 2> NOTE: All tests run in this JVM: [DistributedSpellCheckComponentTest, TestQueryTypes, PeerSyncWithLeaderAndIndexFingerprintCachingTest, BadCopyFieldTest, UpdateParamsTest, NodeMutatorTest, RestartWhileUpdatingTest, TestStressLiveNodes, AsyncCallRequestStatusResponseTest, HighlighterTest, TestConfigOverlay, TestBulkSchemaConcurrent, PKIAuthenticationIntegrationTest, StatsReloadRaceTest, BlockJoinFacetRandomTest, AnalyticsQueryTest, TestStreamBody, TestSimUtils, TestSolrConfigHandlerCloud, JavabinLoaderTest, TestOrdValues, AtomicUpdatesTest, TriggerIntegrationTest, CSVRequestHandlerTest, TestSha256AuthenticationProvider, TestFieldCache, BasicZkTest, TestConfigReload, TestSerializedLuceneMatchVersion, WordBreakSolrSpellCheckerTest, AddReplicaTest, LeaderFailoverAfterPartitionTest, TestMiniSolrCloudClusterSSL, TestSystemIdResolver, TestNumericRangeQuery32, HdfsNNFailoverTest, HttpPartitionTest, BigEndianAscendingWordDeserializerTest, TestCloudJSONFacetSKGEquiv, TestSolr4Spatial, TestSolrJ, TestDeleteCollectionOnDownNodes, ConfigSetsAPITest, TestRawResponseWriter, MoreLikeThisComponentTest, DocValuesTest, ShardRoutingCustomTest, TestJsonFacetsWithNestedObjects, TestFieldCacheWithThreads, TestEmbeddedSolrServerConstructors, TestClusterProperties, DocumentBuilderTest, CloudMLTQParserTest, TestDFRSimilarityFactory, JWTAuthPluginIntegrationTest, DistributedFacetPivotWhiteBoxTest, TestSimNodeAddedTrigger, TestDynamicFieldCollectionResource, V2StandaloneTest, HDFSCollectionsAPITest, JSONWriterTest, CoreAdminCreateDiscoverTest, TestReloadDeadlock, MoveReplicaHDFSTest, TestObjectReleaseTracker, SubstringBytesRefFilterTest, AutoScalingHandlerTest, TestIndexingPerformance, TestQueryingOnDownCollection, TestSimpleTrackingShardHandler, TestExpandComponent, DocValuesNotIndexedTest, MergeStrategyTest, TestSSLRandomization, TestLocalFSCloudBackupRestore, SecurityConfHandlerTest, TestAnalyzeInfixSuggestions, CacheHeaderTest, TestJmxIntegration, TestCoreAdminApis, TestHalfAndHalfDocValues, TestSimDistributedQueue, TestSlowCompositeReaderWrapper, TestChildDocTransformerHierarchy, ReindexCollectionTest, AuditLoggerIntegrationTest, UUIDUpdateProcessorFallbackTest, MetricsHistoryIntegrationTest, DeleteInactiveReplicaTest, DeleteStatusTest, DistribDocExpirationUpdateProcessorTest, SystemCollectionCompatTest, TestAuthenticationFramework, TestCloudDeleteByQuery, TestCloudPivotFacet, TestShortCircuitedRequests, TestSolrCloudWithKerberosAlt, TestTolerantUpdateProcessorRandomCloud, TestWithCollection, ConcurrentDeleteAndCreateCollectionTest, CustomCollectionTest, SplitByPrefixTest]
[junit4] Completed [566/910 (2!)] on J3 in 48.45s, 1 test, 1 failure <<< FAILURES!
[...truncated 45975 lines...]
[repro] Jenkins log URL: https://jenkins.thetaphi.de/job/Lucene-Solr-8.x-MacOSX/1049/consoleText
[repro] Revision: 96e3c25d4432a36f4a49afe17542797c2db690d4
[repro] Ant options: "-Dargs=-XX:-UseCompressedOops -XX:+UseSerialGC"
[repro] Repro line: ant test -Dtestcase=TriggerCooldownIntegrationTest -Dtests.method=testCooldown -Dtests.seed=3A6128D520290F62 -Dtests.slow=true -Dtests.locale=mer-KE -Dtests.timezone=Asia/Phnom_Penh -Dtests.asserts=true -Dtests.file.encoding=UTF-8
[repro] Repro line: ant test -Dtestcase=SplitByPrefixTest -Dtests.method=doTest -Dtests.seed=3A6128D520290F62 -Dtests.slow=true -Dtests.locale=jmc -Dtests.timezone=Etc/GMT-3 -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] SplitByPrefixTest
[repro] TriggerCooldownIntegrationTest
[repro] ant compile-test
[...truncated 3486 lines...]
[repro] ant test-nocompile -Dtests.dups=5 -Dtests.maxfailures=10 -Dtests.class="*.SplitByPrefixTest|*.TriggerCooldownIntegrationTest" -Dtests.showOutput=onerror "-Dargs=-XX:-UseCompressedOops -XX:+UseSerialGC" -Dtests.seed=3A6128D520290F62 -Dtests.slow=true -Dtests.locale=jmc -Dtests.timezone=Etc/GMT-3 -Dtests.asserts=true -Dtests.file.encoding=UTF-8
[...truncated 101 lines...]
[repro] Failures w/original seeds:
[repro] 0/5 failed: org.apache.solr.cloud.api.collections.SplitByPrefixTest
[repro] 0/5 failed: org.apache.solr.cloud.autoscaling.TriggerCooldownIntegrationTest
[repro] Exiting with code 0
[...truncated 73 lines...]