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/06/19 00:22:38 UTC
[JENKINS-Experimental-GC] Lucene-Solr-master-Windows
(64bit/jdk-14.0.1) - Build # 8993 - Unstable!
Build: https://jenkins.thetaphi.de/job/Lucene-Solr-master-Windows/8993/
Java: 64bit/jdk-14.0.1 -XX:+UseCompressedOops -XX:+UnlockExperimentalVMOptions -XX:+UseShenandoahGC
2 tests failed.
FAILED: org.apache.solr.cloud.PeerSyncReplicationTest.test
Error Message:
expected:<0> but was:<1>
Stack Trace:
java.lang.AssertionError: expected:<0> but was:<1>
at __randomizedtesting.SeedInfo.seed([51F1CBB5FD0B5B7C:D9A5F46F53F73684]: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.PeerSyncReplicationTest.test(PeerSyncReplicationTest.java:202)
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:1754)
at com.carrotsearch.randomizedtesting.RandomizedRunner$8.evaluate(RandomizedRunner.java:942)
at com.carrotsearch.randomizedtesting.RandomizedRunner$9.evaluate(RandomizedRunner.java:978)
at com.carrotsearch.randomizedtesting.RandomizedRunner$10.evaluate(RandomizedRunner.java:992)
at org.apache.solr.BaseDistributedSearchTestCase$ShardsRepeatRule$ShardsFixedStatement.callStatement(BaseDistributedSearchTestCase.java:1090)
at org.apache.solr.BaseDistributedSearchTestCase$ShardsRepeatRule$ShardsStatement.evaluate(BaseDistributedSearchTestCase.java:1061)
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:370)
at com.carrotsearch.randomizedtesting.ThreadLeakControl.forkTimeoutingTask(ThreadLeakControl.java:819)
at com.carrotsearch.randomizedtesting.ThreadLeakControl$3.evaluate(ThreadLeakControl.java:470)
at com.carrotsearch.randomizedtesting.RandomizedRunner.runSingleTest(RandomizedRunner.java:951)
at com.carrotsearch.randomizedtesting.RandomizedRunner$5.evaluate(RandomizedRunner.java:836)
at com.carrotsearch.randomizedtesting.RandomizedRunner$6.evaluate(RandomizedRunner.java:887)
at com.carrotsearch.randomizedtesting.RandomizedRunner$7.evaluate(RandomizedRunner.java:898)
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:370)
at com.carrotsearch.randomizedtesting.ThreadLeakControl.lambda$forkTimeoutingTask$0(ThreadLeakControl.java:826)
at java.base/java.lang.Thread.run(Thread.java:832)
FAILED: org.apache.solr.cloud.autoscaling.sim.TestSimTriggerIntegration.testNodeMarkersRegistration
Error Message:
Stack Trace:
java.lang.AssertionError
at __randomizedtesting.SeedInfo.seed([51F1CBB5FD0B5B7C:494B43B9F33E9693]:0)
at org.junit.Assert.fail(Assert.java:86)
at org.junit.Assert.assertTrue(Assert.java:41)
at org.junit.Assert.assertTrue(Assert.java:52)
at org.apache.solr.cloud.autoscaling.sim.TestSimTriggerIntegration.testNodeMarkersRegistration(TestSimTriggerIntegration.java:1053)
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:1754)
at com.carrotsearch.randomizedtesting.RandomizedRunner$8.evaluate(RandomizedRunner.java:942)
at com.carrotsearch.randomizedtesting.RandomizedRunner$9.evaluate(RandomizedRunner.java:978)
at com.carrotsearch.randomizedtesting.RandomizedRunner$10.evaluate(RandomizedRunner.java:992)
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:370)
at com.carrotsearch.randomizedtesting.ThreadLeakControl.forkTimeoutingTask(ThreadLeakControl.java:819)
at com.carrotsearch.randomizedtesting.ThreadLeakControl$3.evaluate(ThreadLeakControl.java:470)
at com.carrotsearch.randomizedtesting.RandomizedRunner.runSingleTest(RandomizedRunner.java:951)
at com.carrotsearch.randomizedtesting.RandomizedRunner$5.evaluate(RandomizedRunner.java:836)
at com.carrotsearch.randomizedtesting.RandomizedRunner$6.evaluate(RandomizedRunner.java:887)
at com.carrotsearch.randomizedtesting.RandomizedRunner$7.evaluate(RandomizedRunner.java:898)
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:370)
at com.carrotsearch.randomizedtesting.ThreadLeakControl.lambda$forkTimeoutingTask$0(ThreadLeakControl.java:826)
at java.base/java.lang.Thread.run(Thread.java:832)
Build Log:
[...truncated 12954 lines...]
[junit4] Suite: org.apache.solr.cloud.autoscaling.sim.TestSimTriggerIntegration
[junit4] 2> 555587 INFO (SUITE-TestSimTriggerIntegration-seed#[51F1CBB5FD0B5B7C]-worker) [ ] o.a.s.SolrTestCase Setting 'solr.default.confdir' system property to test-framework derived value of 'C:\Users\jenkins\workspace\Lucene-Solr-master-Windows\solr\server\solr\configsets\_default\conf'
[junit4] 2> 555587 INFO (SUITE-TestSimTriggerIntegration-seed#[51F1CBB5FD0B5B7C]-worker) [ ] o.a.s.SolrTestCaseJ4 Created dataDir: C:\Users\jenkins\workspace\Lucene-Solr-master-Windows\solr\build\solr-core\test\J0\temp\solr.cloud.autoscaling.sim.TestSimTriggerIntegration_51F1CBB5FD0B5B7C-001\data-dir-27-001
[junit4] 2> 555587 INFO (SUITE-TestSimTriggerIntegration-seed#[51F1CBB5FD0B5B7C]-worker) [ ] o.a.s.SolrTestCaseJ4 Using PointFields (NUMERIC_POINTS_SYSPROP=true) w/NUMERIC_DOCVALUES_SYSPROP=false
[junit4] 2> 555600 INFO (SUITE-TestSimTriggerIntegration-seed#[51F1CBB5FD0B5B7C]-worker) [ ] o.a.s.SolrTestCaseJ4 Randomized ssl (false) and clientAuth (false) via: @org.apache.solr.util.RandomizeSSL(reason="", value=0.0/0.0, ssl=0.0/0.0, clientAuth=0.0/0.0)
[junit4] 2> 555600 INFO (SUITE-TestSimTriggerIntegration-seed#[51F1CBB5FD0B5B7C]-worker) [ ] o.a.s.SolrTestCaseJ4 SecureRandom sanity checks: test.solr.allowed.securerandom=null & java.security.egd=file:/dev/./urandom
[junit4] 2> 555617 INFO (TEST-TestSimTriggerIntegration.testListeners-seed#[51F1CBB5FD0B5B7C]) [ ] o.a.s.SolrTestCaseJ4 ###Starting testListeners
[junit4] 2> 555624 INFO (TEST-TestSimTriggerIntegration.testListeners-seed#[51F1CBB5FD0B5B7C]) [ ] o.a.s.c.SolrPaths solr home defaulted to 'solr/' (could not find system property or JNDI)
[junit4] 2> 555736 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Adding .auto_add_replicas and .scheduled_maintenance triggers
[junit4] 2> 555736 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Refreshing /autoscaling.json with znode version 1
[junit4] 2> 555736 DEBUG (TEST-TestSimTriggerIntegration.testListeners-seed#[51F1CBB5FD0B5B7C]) [ ] o.a.s.c.a.s.SimClusterStateProvider --- new Overseer leader: 127.0.0.1:10000_solr
[junit4] 2> 555740 INFO (TEST-TestSimTriggerIntegration.testListeners-seed#[51F1CBB5FD0B5B7C]) [ ] o.a.s.h.a.MetricsHistoryHandler No .system collection, keeping metrics history in memory.
[junit4] 2> 555744 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Current znodeVersion 1, lastZnodeVersion 0
[junit4] 2> 555744 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Processed trigger updates upto znodeVersion 1
[junit4] 2> 555744 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.NodeLostTrigger NodeLostTrigger .auto_add_replicas - Initial livenodes: [127.0.0.1:10001_solr, 127.0.0.1:10000_solr]
[junit4] 2> 555744 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread -- deactivating old nodeLost / nodeAdded markers
[junit4] 2> 555744 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Current znodeVersion 1, lastZnodeVersion 1
[junit4] 2> 555748 DEBUG (ScheduledTrigger-6030-thread-2) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 2 and last live nodes: 2
[junit4] 2> 555753 DEBUG (simCloudManagerPool-6029-thread-2) [ ] o.a.s.c.a.AutoScalingHandler Verified autoscaling configuration
[junit4] 2> 555753 DEBUG (simCloudManagerPool-6029-thread-2) [ ] o.a.s.c.a.OverseerTriggerThread Refreshing /autoscaling.json with znode version 2
[junit4] 2> 555753 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Processed trigger updates upto znodeVersion 2
[junit4] 2> 555756 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread -- deactivating old nodeLost / nodeAdded markers
[junit4] 2> 555756 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Current znodeVersion 2, lastZnodeVersion 2
[junit4] 2> 555775 DEBUG (simCloudManagerPool-6029-thread-3) [ ] o.a.s.c.a.AutoScalingHandler Verified autoscaling configuration
[junit4] 2> 555780 DEBUG (simCloudManagerPool-6029-thread-3) [ ] o.a.s.c.a.OverseerTriggerThread Refreshing /autoscaling.json with znode version 3
[junit4] 2> 555780 DEBUG (ScheduledTrigger-6030-thread-2) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 2 and last live nodes: 2
[junit4] 2> 555780 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Processed trigger updates upto znodeVersion 3
[junit4] 2> 555780 INFO (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.s.TestSimTriggerIntegration TestTriggerAction init
[junit4] 2> 555780 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.NodeAddedTrigger NodeAddedTrigger node_added_trigger - Initial livenodes: [127.0.0.1:10001_solr, 127.0.0.1:10000_solr]
[junit4] 2> 555780 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.NodeAddedTrigger NodeAddedTrigger node_added_trigger instantiated with properties: {event=nodeAdded, waitFor=3, actions=[{name=test, class=org.apache.solr.cloud.autoscaling.sim.TestSimTriggerIntegration$TestTriggerAction}, {name=test1, class=org.apache.solr.cloud.autoscaling.sim.TestSimTriggerIntegration$TestDummyAction}], enabled=true}
[junit4] 2> 555780 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread -- deactivating old nodeLost / nodeAdded markers
[junit4] 2> 555780 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Current znodeVersion 3, lastZnodeVersion 3
[junit4] 2> 555780 DEBUG (ScheduledTrigger-6030-thread-3) [ ] o.a.s.c.a.NodeAddedTrigger Running NodeAddedTrigger node_added_trigger
[junit4] 2> 555780 DEBUG (ScheduledTrigger-6030-thread-3) [ ] o.a.s.c.a.NodeAddedTrigger Found livenodes: 2
[junit4] 2> 555784 DEBUG (simCloudManagerPool-6029-thread-4) [ ] o.a.s.c.a.AutoScalingHandler Verified autoscaling configuration
[junit4] 2> 555784 DEBUG (simCloudManagerPool-6029-thread-4) [ ] o.a.s.c.a.OverseerTriggerThread Refreshing /autoscaling.json with znode version 4
[junit4] 2> 555788 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Processed trigger updates upto znodeVersion 4
[junit4] 2> 555788 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread -- deactivating old nodeLost / nodeAdded markers
[junit4] 2> 555788 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Current znodeVersion 4, lastZnodeVersion 4
[junit4] 2> 555796 DEBUG (simCloudManagerPool-6029-thread-5) [ ] o.a.s.c.a.AutoScalingHandler Verified autoscaling configuration
[junit4] 2> 555796 DEBUG (simCloudManagerPool-6029-thread-5) [ ] o.a.s.c.a.OverseerTriggerThread Refreshing /autoscaling.json with znode version 5
[junit4] 2> 555800 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Processed trigger updates upto znodeVersion 5
[junit4] 2> 555800 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread -- deactivating old nodeLost / nodeAdded markers
[junit4] 2> 555800 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Current znodeVersion 5, lastZnodeVersion 5
[junit4] 2> 555800 DEBUG (TEST-TestSimTriggerIntegration.testListeners-seed#[51F1CBB5FD0B5B7C]) [ ] o.a.s.c.a.s.SimClusterStateProvider -- creating marker: /autoscaling/nodeAdded/127.0.0.1:10002_solr
[junit4] 2> 555816 DEBUG (ScheduledTrigger-6030-thread-1) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 3 and last live nodes: 2
[junit4] 2> 555816 DEBUG (ScheduledTrigger-6030-thread-1) [ ] o.a.s.c.a.NodeAddedTrigger Running NodeAddedTrigger node_added_trigger
[junit4] 2> 555816 DEBUG (ScheduledTrigger-6030-thread-1) [ ] o.a.s.c.a.NodeAddedTrigger Found livenodes: 3
[junit4] 2> 555816 DEBUG (ScheduledTrigger-6030-thread-1) [ ] o.a.s.c.a.NodeAddedTrigger Tracking new node: 127.0.0.1:10002_solr at time 64058965372300
[junit4] 2> 555852 DEBUG (ScheduledTrigger-6030-thread-2) [ ] o.a.s.c.a.NodeAddedTrigger Running NodeAddedTrigger node_added_trigger
[junit4] 2> 555852 DEBUG (ScheduledTrigger-6030-thread-2) [ ] o.a.s.c.a.NodeAddedTrigger Found livenodes: 3
[junit4] 2> 555852 DEBUG (ScheduledTrigger-6030-thread-3) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 3 and last live nodes: 3
[junit4] 2> 555884 DEBUG (ScheduledTrigger-6030-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> 555884 DEBUG (ScheduledTrigger-6030-thread-2) [ ] o.a.s.c.a.NodeAddedTrigger Running NodeAddedTrigger node_added_trigger
[junit4] 2> 555884 DEBUG (ScheduledTrigger-6030-thread-2) [ ] o.a.s.c.a.NodeAddedTrigger Found livenodes: 3
[junit4] 2> 555884 DEBUG (ScheduledTrigger-6030-thread-2) [ ] o.a.s.c.a.NodeAddedTrigger NodeAddedTrigger node_added_trigger firing registered processor for nodes: [127.0.0.1:10002_solr] added at times [64058965372300], now=64062374942300
[junit4] 2> 555884 DEBUG (ScheduledTrigger-6030-thread-2) [ ] o.a.s.c.a.ScheduledTriggers ++++++++ Cooldown inactive - processing event: {
[junit4] 2> "id":"3a42e3e02d8cTcdtvldgmeaydxda05hi56i3dj",
[junit4] 2> "source":"node_added_trigger",
[junit4] 2> "eventTime":64058965372300,
[junit4] 2> "eventType":"NODEADDED",
[junit4] 2> "properties":{
[junit4] 2> "eventTimes":[64058965372300],
[junit4] 2> "preferredOperation":"movereplica",
[junit4] 2> "nodeNames":["127.0.0.1:10002_solr"],
[junit4] 2> "replicaType":"NRT"}}
[junit4] 2> 555884 DEBUG (ScheduledTrigger-6030-thread-2) [ ] o.a.s.c.a.ScheduledTriggers Pausing all triggers: [.auto_add_replicas, node_added_trigger]
[junit4] 2> 555888 DEBUG (ScheduledTrigger-6030-thread-2) [ ] o.a.s.c.a.SystemLogListener Collection .system missing, skip sending event {
[junit4] 2> "id":"3a42e3e02d8cTcdtvldgmeaydxda05hi56i3dj",
[junit4] 2> "source":"node_added_trigger",
[junit4] 2> "eventTime":64058965372300,
[junit4] 2> "eventType":"NODEADDED",
[junit4] 2> "properties":{
[junit4] 2> "eventTimes":[64058965372300],
[junit4] 2> "preferredOperation":"movereplica",
[junit4] 2> "_enqueue_time_":64062483627300,
[junit4] 2> "nodeNames":["127.0.0.1:10002_solr"],
[junit4] 2> "replicaType":"NRT"}}
[junit4] 2> 555900 DEBUG (ScheduledTrigger-6030-thread-2) [ ] o.a.s.c.a.NodeAddedTrigger Removing new node from tracking: 127.0.0.1:10002_solr
[junit4] 2> 555905 DEBUG (AutoscalingActionExecutor-6031-thread-1) [ ] o.a.s.c.a.ScheduledTriggers -- processing actions for {
[junit4] 2> "id":"3a42e3e02d8cTcdtvldgmeaydxda05hi56i3dj",
[junit4] 2> "source":"node_added_trigger",
[junit4] 2> "eventTime":64058965372300,
[junit4] 2> "eventType":"NODEADDED",
[junit4] 2> "properties":{
[junit4] 2> "eventTimes":[64058965372300],
[junit4] 2> "preferredOperation":"movereplica",
[junit4] 2> "_enqueue_time_":64062483627300,
[junit4] 2> "nodeNames":["127.0.0.1:10002_solr"],
[junit4] 2> "replicaType":"NRT"}}
[junit4] 2> 555924 DEBUG (AutoscalingActionExecutor-6031-thread-1) [ ] o.a.s.c.a.SystemLogListener Collection .system missing, skip sending event {
[junit4] 2> "id":"3a42e3e02d8cTcdtvldgmeaydxda05hi56i3dj",
[junit4] 2> "source":"node_added_trigger",
[junit4] 2> "eventTime":64058965372300,
[junit4] 2> "eventType":"NODEADDED",
[junit4] 2> "properties":{
[junit4] 2> "eventTimes":[64058965372300],
[junit4] 2> "preferredOperation":"movereplica",
[junit4] 2> "_enqueue_time_":64062483627300,
[junit4] 2> "nodeNames":["127.0.0.1:10002_solr"],
[junit4] 2> "replicaType":"NRT"}}
[junit4] 2> 555924 DEBUG (AutoscalingActionExecutor-6031-thread-1) [ ] o.a.s.c.a.ScheduledTriggers Resuming trigger: .auto_add_replicas after 100ms
[junit4] 2> 555924 DEBUG (AutoscalingActionExecutor-6031-thread-1) [ ] o.a.s.c.a.ScheduledTriggers Resuming trigger: node_added_trigger after 100ms
[junit4] 2> 555924 DEBUG (AutoscalingActionExecutor-6031-thread-1) [ ] o.a.s.c.a.ScheduledTriggers -- processing took 951 ms for event id=3a42e3e02d8cTcdtvldgmeaydxda05hi56i3dj
[junit4] 2> 555935 DEBUG (TEST-TestSimTriggerIntegration.testListeners-seed#[51F1CBB5FD0B5B7C]) [ ] o.a.s.c.a.s.SimClusterStateProvider -- creating marker: /autoscaling/nodeAdded/127.0.0.1:10003_solr
[junit4] 2> 556037 DEBUG (ScheduledTrigger-6030-thread-1) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 4 and last live nodes: 3
[junit4] 2> 556037 DEBUG (ScheduledTrigger-6030-thread-1) [ ] o.a.s.c.a.NodeAddedTrigger Running NodeAddedTrigger node_added_trigger
[junit4] 2> 556037 DEBUG (ScheduledTrigger-6030-thread-1) [ ] o.a.s.c.a.NodeAddedTrigger Found livenodes: 4
[junit4] 2> 556037 DEBUG (ScheduledTrigger-6030-thread-1) [ ] o.a.s.c.a.NodeAddedTrigger Tracking new node: 127.0.0.1:10003_solr at time 64069971477300
[junit4] 2> 556064 DEBUG (ScheduledTrigger-6030-thread-1) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 4 and last live nodes: 4
[junit4] 2> 556064 DEBUG (ScheduledTrigger-6030-thread-4) [ ] o.a.s.c.a.NodeAddedTrigger Running NodeAddedTrigger node_added_trigger
[junit4] 2> 556064 DEBUG (ScheduledTrigger-6030-thread-4) [ ] o.a.s.c.a.NodeAddedTrigger Found livenodes: 4
[junit4] 2> 556096 DEBUG (ScheduledTrigger-6030-thread-1) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 4 and last live nodes: 4
[junit4] 2> 556096 DEBUG (ScheduledTrigger-6030-thread-1) [ ] o.a.s.c.a.NodeAddedTrigger Running NodeAddedTrigger node_added_trigger
[junit4] 2> 556096 DEBUG (ScheduledTrigger-6030-thread-1) [ ] o.a.s.c.a.NodeAddedTrigger Found livenodes: 4
[junit4] 2> 556132 DEBUG (ScheduledTrigger-6030-thread-1) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 4 and last live nodes: 4
[junit4] 2> 556132 DEBUG (ScheduledTrigger-6030-thread-1) [ ] o.a.s.c.a.NodeAddedTrigger Running NodeAddedTrigger node_added_trigger
[junit4] 2> 556132 DEBUG (ScheduledTrigger-6030-thread-1) [ ] o.a.s.c.a.NodeAddedTrigger Found livenodes: 4
[junit4] 2> 556132 DEBUG (ScheduledTrigger-6030-thread-1) [ ] o.a.s.c.a.NodeAddedTrigger NodeAddedTrigger node_added_trigger firing registered processor for nodes: [127.0.0.1:10003_solr] added at times [64069971477300], now=64074985597300
[junit4] 2> 556132 DEBUG (ScheduledTrigger-6030-thread-1) [ ] o.a.s.c.a.ScheduledTriggers ++++++++ Cooldown inactive - processing event: {
[junit4] 2> "id":"3a4573e40334Tcdtvldgmeaydxda05hi56i3dk",
[junit4] 2> "source":"node_added_trigger",
[junit4] 2> "eventTime":64069971477300,
[junit4] 2> "eventType":"NODEADDED",
[junit4] 2> "properties":{
[junit4] 2> "eventTimes":[64069971477300],
[junit4] 2> "preferredOperation":"movereplica",
[junit4] 2> "nodeNames":["127.0.0.1:10003_solr"],
[junit4] 2> "replicaType":"NRT"}}
[junit4] 2> 556132 DEBUG (ScheduledTrigger-6030-thread-1) [ ] o.a.s.c.a.ScheduledTriggers Pausing all triggers: [.auto_add_replicas, node_added_trigger]
[junit4] 2> 556132 DEBUG (ScheduledTrigger-6030-thread-1) [ ] o.a.s.c.a.SystemLogListener Collection .system missing, skip sending event {
[junit4] 2> "id":"3a4573e40334Tcdtvldgmeaydxda05hi56i3dk",
[junit4] 2> "source":"node_added_trigger",
[junit4] 2> "eventTime":64069971477300,
[junit4] 2> "eventType":"NODEADDED",
[junit4] 2> "properties":{
[junit4] 2> "eventTimes":[64069971477300],
[junit4] 2> "preferredOperation":"movereplica",
[junit4] 2> "_enqueue_time_":64075003872300,
[junit4] 2> "nodeNames":["127.0.0.1:10003_solr"],
[junit4] 2> "replicaType":"NRT"}}
[junit4] 2> 556132 DEBUG (AutoscalingActionExecutor-6031-thread-1) [ ] o.a.s.c.a.ScheduledTriggers -- processing actions for {
[junit4] 2> "id":"3a4573e40334Tcdtvldgmeaydxda05hi56i3dk",
[junit4] 2> "source":"node_added_trigger",
[junit4] 2> "eventTime":64069971477300,
[junit4] 2> "eventType":"NODEADDED",
[junit4] 2> "properties":{
[junit4] 2> "eventTimes":[64069971477300],
[junit4] 2> "preferredOperation":"movereplica",
[junit4] 2> "_enqueue_time_":64075003872300,
[junit4] 2> "nodeNames":["127.0.0.1:10003_solr"],
[junit4] 2> "replicaType":"NRT"}}
[junit4] 2> 556132 DEBUG (ScheduledTrigger-6030-thread-1) [ ] o.a.s.c.a.NodeAddedTrigger Removing new node from tracking: 127.0.0.1:10003_solr
[junit4] 2> 556132 DEBUG (AutoscalingActionExecutor-6031-thread-1) [ ] o.a.s.c.a.SystemLogListener Collection .system missing, skip sending event {
[junit4] 2> "id":"3a4573e40334Tcdtvldgmeaydxda05hi56i3dk",
[junit4] 2> "source":"node_added_trigger",
[junit4] 2> "eventTime":64069971477300,
[junit4] 2> "eventType":"NODEADDED",
[junit4] 2> "properties":{
[junit4] 2> "eventTimes":[64069971477300],
[junit4] 2> "preferredOperation":"movereplica",
[junit4] 2> "_enqueue_time_":64075003872300,
[junit4] 2> "nodeNames":["127.0.0.1:10003_solr"],
[junit4] 2> "replicaType":"NRT"}}
[junit4] 2> 556132 WARN (AutoscalingActionExecutor-6031-thread-1) [ ] o.a.s.c.a.ScheduledTriggers Exception executing actions
[junit4] 2> => org.apache.solr.cloud.autoscaling.TriggerActionException: Error processing action for trigger event: {
[junit4] 2> "id":"3a4573e40334Tcdtvldgmeaydxda05hi56i3dk",
[junit4] 2> "source":"node_added_trigger",
[junit4] 2> "eventTime":64069971477300,
[junit4] 2> "eventType":"NODEADDED",
[junit4] 2> "properties":{
[junit4] 2> "eventTimes":[64069971477300],
[junit4] 2> "preferredOperation":"movereplica",
[junit4] 2> "_enqueue_time_":64075003872300,
[junit4] 2> "nodeNames":["127.0.0.1:10003_solr"],
[junit4] 2> "replicaType":"NRT"}}
[junit4] 2> at org.apache.solr.cloud.autoscaling.ScheduledTriggers.lambda$add$3(ScheduledTriggers.java:331)
[junit4] 2> org.apache.solr.cloud.autoscaling.TriggerActionException: Error processing action for trigger event: {
[junit4] 2> "id":"3a4573e40334Tcdtvldgmeaydxda05hi56i3dk",
[junit4] 2> "source":"node_added_trigger",
[junit4] 2> "eventTime":64069971477300,
[junit4] 2> "eventType":"NODEADDED",
[junit4] 2> "properties":{
[junit4] 2> "eventTimes":[64069971477300],
[junit4] 2> "preferredOperation":"movereplica",
[junit4] 2> "_enqueue_time_":64075003872300,
[junit4] 2> "nodeNames":["127.0.0.1:10003_solr"],
[junit4] 2> "replicaType":"NRT"}}
[junit4] 2> at org.apache.solr.cloud.autoscaling.ScheduledTriggers.lambda$add$3(ScheduledTriggers.java:331) ~[java/:?]
[junit4] 2> at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:515) ~[?:?]
[junit4] 2> at java.util.concurrent.FutureTask.run(FutureTask.java:264) ~[?:?]
[junit4] 2> at org.apache.solr.common.util.ExecutorUtil$MDCAwareThreadPoolExecutor.lambda$execute$0(ExecutorUtil.java:212) ~[java/:?]
[junit4] 2> at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1130) ~[?:?]
[junit4] 2> at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:630) ~[?:?]
[junit4] 2> at java.lang.Thread.run(Thread.java:832) [?:?]
[junit4] 2> Caused by: java.lang.RuntimeException: failure
[junit4] 2> at org.apache.solr.cloud.autoscaling.sim.TestSimTriggerIntegration$TestDummyAction.process(TestSimTriggerIntegration.java:1116) ~[test/:?]
[junit4] 2> at org.apache.solr.cloud.autoscaling.ScheduledTriggers.lambda$add$3(ScheduledTriggers.java:328) ~[java/:?]
[junit4] 2> ... 6 more
[junit4] 2> 556132 DEBUG (AutoscalingActionExecutor-6031-thread-1) [ ] o.a.s.c.a.ScheduledTriggers Resuming trigger: node_added_trigger after 100ms
[junit4] 2> 556132 DEBUG (AutoscalingActionExecutor-6031-thread-1) [ ] o.a.s.c.a.ScheduledTriggers Resuming trigger: .auto_add_replicas after 100ms
[junit4] 2> 556132 DEBUG (AutoscalingActionExecutor-6031-thread-1) [ ] o.a.s.c.a.ScheduledTriggers -- processing took 42 ms for event id=3a4573e40334Tcdtvldgmeaydxda05hi56i3dk
[junit4] 2> 556171 DEBUG (TEST-TestSimTriggerIntegration.testListeners-seed#[51F1CBB5FD0B5B7C]) [ ] o.a.s.c.a.ScheduledTriggers Shutting down scheduled thread pool executor now
[junit4] 2> 556171 DEBUG (TEST-TestSimTriggerIntegration.testListeners-seed#[51F1CBB5FD0B5B7C]) [ ] o.a.s.c.a.ScheduledTriggers Shutting down action executor now
[junit4] 2> 556171 DEBUG (TEST-TestSimTriggerIntegration.testListeners-seed#[51F1CBB5FD0B5B7C]) [ ] o.a.s.c.a.ScheduledTriggers Awaiting termination for action executor
[junit4] 2> 556171 INFO (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread OverseerTriggerThread woken up but we are closed, exiting.
[junit4] 2> 556171 DEBUG (TEST-TestSimTriggerIntegration.testListeners-seed#[51F1CBB5FD0B5B7C]) [ ] o.a.s.c.a.ScheduledTriggers Awaiting termination for scheduled thread pool executor
[junit4] 2> 556193 DEBUG (TEST-TestSimTriggerIntegration.testListeners-seed#[51F1CBB5FD0B5B7C]) [ ] o.a.s.c.a.ScheduledTriggers ScheduledTriggers closed completely
[junit4] 2> 556193 DEBUG (TEST-TestSimTriggerIntegration.testListeners-seed#[51F1CBB5FD0B5B7C]) [ ] o.a.s.c.a.OverseerTriggerThread OverseerTriggerThread has been closed explicitly
[junit4] 2> 556193 INFO (TEST-TestSimTriggerIntegration.testListeners-seed#[51F1CBB5FD0B5B7C]) [ ] o.a.s.SolrTestCaseJ4 ###Ending testListeners
[junit4] 2> 556202 INFO (TEST-TestSimTriggerIntegration.testTriggerThrottling-seed#[51F1CBB5FD0B5B7C]) [ ] o.a.s.SolrTestCaseJ4 ###Starting testTriggerThrottling
[junit4] 2> 556268 DEBUG (TEST-TestSimTriggerIntegration.testTriggerThrottling-seed#[51F1CBB5FD0B5B7C]) [ ] o.a.s.c.a.s.SimClusterStateProvider --- new Overseer leader: 127.0.0.1:10004_solr
[junit4] 2> 556268 INFO (TEST-TestSimTriggerIntegration.testTriggerThrottling-seed#[51F1CBB5FD0B5B7C]) [ ] o.a.s.h.a.MetricsHistoryHandler No .system collection, keeping metrics history in memory.
[junit4] 2> 556268 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Adding .auto_add_replicas and .scheduled_maintenance triggers
[junit4] 2> 556268 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Refreshing /autoscaling.json with znode version 1
[junit4] 2> 556268 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Current znodeVersion 1, lastZnodeVersion 0
[junit4] 2> 556268 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Processed trigger updates upto znodeVersion 1
[junit4] 2> 556272 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.NodeLostTrigger NodeLostTrigger .auto_add_replicas - Initial livenodes: [127.0.0.1:10004_solr, 127.0.0.1:10005_solr]
[junit4] 2> 556272 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread -- deactivating old nodeLost / nodeAdded markers
[junit4] 2> 556272 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Current znodeVersion 1, lastZnodeVersion 1
[junit4] 2> 556273 DEBUG (ScheduledTrigger-6036-thread-2) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 2 and last live nodes: 2
[junit4] 2> 556274 DEBUG (simCloudManagerPool-6035-thread-2) [ ] o.a.s.c.a.AutoScalingHandler Verified autoscaling configuration
[junit4] 2> 556274 DEBUG (simCloudManagerPool-6035-thread-2) [ ] o.a.s.c.a.OverseerTriggerThread Refreshing /autoscaling.json with znode version 2
[junit4] 2> 556274 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Processed trigger updates upto znodeVersion 2
[junit4] 2> 556274 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread -- deactivating old nodeLost / nodeAdded markers
[junit4] 2> 556274 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Current znodeVersion 2, lastZnodeVersion 2
[junit4] 2> 556284 DEBUG (simCloudManagerPool-6035-thread-3) [ ] o.a.s.c.a.AutoScalingHandler Verified autoscaling configuration
[junit4] 2> 556284 DEBUG (simCloudManagerPool-6035-thread-3) [ ] o.a.s.c.a.OverseerTriggerThread Refreshing /autoscaling.json with znode version 3
[junit4] 2> 556284 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Processed trigger updates upto znodeVersion 3
[junit4] 2> 556288 INFO (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.s.TestSimTriggerIntegration TestTriggerAction init
[junit4] 2> 556288 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.NodeAddedTrigger NodeAddedTrigger node_added_trigger1 - Initial livenodes: [127.0.0.1:10004_solr, 127.0.0.1:10005_solr]
[junit4] 2> 556288 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.NodeAddedTrigger NodeAddedTrigger node_added_trigger1 instantiated with properties: {event=nodeAdded, waitFor=0, actions=[{name=test, class=org.apache.solr.cloud.autoscaling.sim.TestSimTriggerIntegration$ThrottlingTesterAction}], enabled=true}
[junit4] 2> 556288 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread -- deactivating old nodeLost / nodeAdded markers
[junit4] 2> 556288 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Current znodeVersion 3, lastZnodeVersion 3
[junit4] 2> 556288 DEBUG (ScheduledTrigger-6036-thread-1) [ ] o.a.s.c.a.NodeAddedTrigger Running NodeAddedTrigger node_added_trigger1
[junit4] 2> 556288 DEBUG (ScheduledTrigger-6036-thread-1) [ ] o.a.s.c.a.NodeAddedTrigger Found livenodes: 2
[junit4] 2> 556289 DEBUG (simCloudManagerPool-6035-thread-4) [ ] o.a.s.c.a.AutoScalingHandler Verified autoscaling configuration
[junit4] 2> 556289 DEBUG (simCloudManagerPool-6035-thread-4) [ ] o.a.s.c.a.OverseerTriggerThread Refreshing /autoscaling.json with znode version 4
[junit4] 2> 556289 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Processed trigger updates upto znodeVersion 4
[junit4] 2> 556289 INFO (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.s.TestSimTriggerIntegration TestTriggerAction init
[junit4] 2> 556289 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.NodeAddedTrigger NodeAddedTrigger node_added_trigger2 - Initial livenodes: [127.0.0.1:10004_solr, 127.0.0.1:10005_solr]
[junit4] 2> 556289 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.NodeAddedTrigger NodeAddedTrigger node_added_trigger2 instantiated with properties: {event=nodeAdded, waitFor=0, actions=[{name=test, class=org.apache.solr.cloud.autoscaling.sim.TestSimTriggerIntegration$ThrottlingTesterAction}], enabled=true}
[junit4] 2> 556289 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread -- deactivating old nodeLost / nodeAdded markers
[junit4] 2> 556289 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Current znodeVersion 4, lastZnodeVersion 4
[junit4] 2> 556289 DEBUG (ScheduledTrigger-6036-thread-3) [ ] o.a.s.c.a.NodeAddedTrigger Running NodeAddedTrigger node_added_trigger2
[junit4] 2> 556289 DEBUG (ScheduledTrigger-6036-thread-3) [ ] o.a.s.c.a.NodeAddedTrigger Found livenodes: 2
[junit4] 2> 556289 DEBUG (TEST-TestSimTriggerIntegration.testTriggerThrottling-seed#[51F1CBB5FD0B5B7C]) [ ] o.a.s.c.a.s.SimClusterStateProvider -- creating marker: /autoscaling/nodeAdded/127.0.0.1:10006_solr
[junit4] 2> 556300 DEBUG (ScheduledTrigger-6036-thread-3) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 3 and last live nodes: 2
[junit4] 2> 556315 DEBUG (ScheduledTrigger-6036-thread-3) [ ] o.a.s.c.a.NodeAddedTrigger Running NodeAddedTrigger node_added_trigger1
[junit4] 2> 556315 DEBUG (ScheduledTrigger-6036-thread-3) [ ] o.a.s.c.a.NodeAddedTrigger Found livenodes: 3
[junit4] 2> 556315 DEBUG (ScheduledTrigger-6036-thread-1) [ ] o.a.s.c.a.NodeAddedTrigger Running NodeAddedTrigger node_added_trigger2
[junit4] 2> 556315 DEBUG (ScheduledTrigger-6036-thread-1) [ ] o.a.s.c.a.NodeAddedTrigger Found livenodes: 3
[junit4] 2> 556315 DEBUG (ScheduledTrigger-6036-thread-3) [ ] o.a.s.c.a.NodeAddedTrigger Tracking new node: 127.0.0.1:10006_solr at time 64083901547300
[junit4] 2> 556315 DEBUG (ScheduledTrigger-6036-thread-1) [ ] o.a.s.c.a.NodeAddedTrigger Tracking new node: 127.0.0.1:10006_solr at time 64083901547300
[junit4] 2> 556315 DEBUG (ScheduledTrigger-6036-thread-1) [ ] o.a.s.c.a.NodeAddedTrigger NodeAddedTrigger node_added_trigger2 firing registered processor for nodes: [127.0.0.1:10006_solr] added at times [64083901547300], now=64083903592300
[junit4] 2> 556315 DEBUG (ScheduledTrigger-6036-thread-3) [ ] o.a.s.c.a.NodeAddedTrigger NodeAddedTrigger node_added_trigger1 firing registered processor for nodes: [127.0.0.1:10006_solr] added at times [64083901547300], now=64083903582300
[junit4] 2> 556315 DEBUG (ScheduledTrigger-6036-thread-3) [ ] o.a.s.c.a.ScheduledTriggers ++++++++ Cooldown inactive - processing event: {
[junit4] 2> "id":"3a48b2300324Tcdtvldgmeaydxda05hi56i3dn",
[junit4] 2> "source":"node_added_trigger1",
[junit4] 2> "eventTime":64083901547300,
[junit4] 2> "eventType":"NODEADDED",
[junit4] 2> "properties":{
[junit4] 2> "eventTimes":[64083901547300],
[junit4] 2> "preferredOperation":"movereplica",
[junit4] 2> "nodeNames":["127.0.0.1:10006_solr"],
[junit4] 2> "replicaType":"NRT"}}
[junit4] 2> 556315 DEBUG (ScheduledTrigger-6036-thread-1) [ ] o.a.s.c.a.ScheduledTriggers ++++++++ Cooldown inactive - processing event: {
[junit4] 2> "id":"3a48b2300324Tcdtvldgmeaydxda05hi56i3dm",
[junit4] 2> "source":"node_added_trigger2",
[junit4] 2> "eventTime":64083901547300,
[junit4] 2> "eventType":"NODEADDED",
[junit4] 2> "properties":{
[junit4] 2> "eventTimes":[64083901547300],
[junit4] 2> "preferredOperation":"movereplica",
[junit4] 2> "nodeNames":["127.0.0.1:10006_solr"],
[junit4] 2> "replicaType":"NRT"}}
[junit4] 2> 556315 DEBUG (ScheduledTrigger-6036-thread-1) [ ] o.a.s.c.a.ScheduledTriggers Ignoring event 3a48b2300324Tcdtvldgmeaydxda05hi56i3dm, already processing other actions.
[junit4] 2> 556315 DEBUG (ScheduledTrigger-6036-thread-1) [ ] o.a.s.c.a.SystemLogListener Collection .system missing, skip sending event {
[junit4] 2> "id":"3a48b2300324Tcdtvldgmeaydxda05hi56i3dm",
[junit4] 2> "source":"node_added_trigger2",
[junit4] 2> "eventTime":64083901547300,
[junit4] 2> "eventType":"NODEADDED",
[junit4] 2> "properties":{
[junit4] 2> "eventTimes":[64083901547300],
[junit4] 2> "preferredOperation":"movereplica",
[junit4] 2> "nodeNames":["127.0.0.1:10006_solr"],
[junit4] 2> "replicaType":"NRT"}}
[junit4] 2> 556315 DEBUG (ScheduledTrigger-6036-thread-1) [ ] o.a.s.c.a.NodeAddedTrigger Processor returned false for [127.0.0.1:10006_solr]!
[junit4] 2> 556316 DEBUG (ScheduledTrigger-6036-thread-3) [ ] o.a.s.c.a.ScheduledTriggers Pausing all triggers: [.auto_add_replicas, node_added_trigger2, node_added_trigger1]
[junit4] 2> 556316 DEBUG (ScheduledTrigger-6036-thread-3) [ ] o.a.s.c.a.SystemLogListener Collection .system missing, skip sending event {
[junit4] 2> "id":"3a48b2300324Tcdtvldgmeaydxda05hi56i3dn",
[junit4] 2> "source":"node_added_trigger1",
[junit4] 2> "eventTime":64083901547300,
[junit4] 2> "eventType":"NODEADDED",
[junit4] 2> "properties":{
[junit4] 2> "eventTimes":[64083901547300],
[junit4] 2> "preferredOperation":"movereplica",
[junit4] 2> "_enqueue_time_":64083940532300,
[junit4] 2> "nodeNames":["127.0.0.1:10006_solr"],
[junit4] 2> "replicaType":"NRT"}}
[junit4] 2> 556316 DEBUG (ScheduledTrigger-6036-thread-3) [ ] o.a.s.c.a.NodeAddedTrigger Removing new node from tracking: 127.0.0.1:10006_solr
[junit4] 2> 556316 DEBUG (AutoscalingActionExecutor-6037-thread-1) [ ] o.a.s.c.a.ScheduledTriggers -- processing actions for {
[junit4] 2> "id":"3a48b2300324Tcdtvldgmeaydxda05hi56i3dn",
[junit4] 2> "source":"node_added_trigger1",
[junit4] 2> "eventTime":64083901547300,
[junit4] 2> "eventType":"NODEADDED",
[junit4] 2> "properties":{
[junit4] 2> "eventTimes":[64083901547300],
[junit4] 2> "preferredOperation":"movereplica",
[junit4] 2> "_enqueue_time_":64083940532300,
[junit4] 2> "nodeNames":["127.0.0.1:10006_solr"],
[junit4] 2> "replicaType":"NRT"}}
[junit4] 2> 556316 INFO (AutoscalingActionExecutor-6037-thread-1) [ ] o.a.s.c.a.s.TestSimTriggerIntegration action executed from node_added_trigger1
[junit4] 2> 556318 DEBUG (AutoscalingActionExecutor-6037-thread-1) [ ] o.a.s.c.a.SystemLogListener Collection .system missing, skip sending event {
[junit4] 2> "id":"3a48b2300324Tcdtvldgmeaydxda05hi56i3dn",
[junit4] 2> "source":"node_added_trigger1",
[junit4] 2> "eventTime":64083901547300,
[junit4] 2> "eventType":"NODEADDED",
[junit4] 2> "properties":{
[junit4] 2> "eventTimes":[64083901547300],
[junit4] 2> "preferredOperation":"movereplica",
[junit4] 2> "_enqueue_time_":64083940532300,
[junit4] 2> "nodeNames":["127.0.0.1:10006_solr"],
[junit4] 2> "replicaType":"NRT"}}
[junit4] 2> 556318 DEBUG (AutoscalingActionExecutor-6037-thread-1) [ ] o.a.s.c.a.ScheduledTriggers Resuming trigger: node_added_trigger1 after 100ms
[junit4] 2> 556318 DEBUG (AutoscalingActionExecutor-6037-thread-1) [ ] o.a.s.c.a.ScheduledTriggers Resuming trigger: .auto_add_replicas after 100ms
[junit4] 2> 556318 DEBUG (AutoscalingActionExecutor-6037-thread-1) [ ] o.a.s.c.a.ScheduledTriggers Resuming trigger: node_added_trigger2 after 100ms
[junit4] 2> 556318 DEBUG (AutoscalingActionExecutor-6037-thread-1) [ ] o.a.s.c.a.ScheduledTriggers -- processing took 34 ms for event id=3a48b2300324Tcdtvldgmeaydxda05hi56i3dn
[junit4] 2> 556443 DEBUG (ScheduledTrigger-6036-thread-2) [ ] o.a.s.c.a.NodeAddedTrigger Running NodeAddedTrigger node_added_trigger1
[junit4] 2> 556443 DEBUG (ScheduledTrigger-6036-thread-2) [ ] o.a.s.c.a.NodeAddedTrigger Found livenodes: 3
[junit4] 2> 556443 DEBUG (ScheduledTrigger-6036-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> 556443 DEBUG (ScheduledTrigger-6036-thread-3) [ ] o.a.s.c.a.NodeAddedTrigger Running NodeAddedTrigger node_added_trigger2
[junit4] 2> 556443 DEBUG (ScheduledTrigger-6036-thread-3) [ ] o.a.s.c.a.NodeAddedTrigger Found livenodes: 3
[junit4] 2> 556443 DEBUG (ScheduledTrigger-6036-thread-3) [ ] o.a.s.c.a.NodeAddedTrigger NodeAddedTrigger node_added_trigger2 firing registered processor for nodes: [127.0.0.1:10006_solr] added at times [64083901547300], now=64090275987300
[junit4] 2> 556443 DEBUG (ScheduledTrigger-6036-thread-3) [ ] o.a.s.c.a.ScheduledTriggers ++++++++ Cooldown inactive - processing event: {
[junit4] 2> "id":"3a48b2300324Tcdtvldgmeaydxda05hi56i3do",
[junit4] 2> "source":"node_added_trigger2",
[junit4] 2> "eventTime":64083901547300,
[junit4] 2> "eventType":"NODEADDED",
[junit4] 2> "properties":{
[junit4] 2> "eventTimes":[64083901547300],
[junit4] 2> "preferredOperation":"movereplica",
[junit4] 2> "nodeNames":["127.0.0.1:10006_solr"],
[junit4] 2> "replicaType":"NRT"}}
[junit4] 2> 556443 DEBUG (ScheduledTrigger-6036-thread-3) [ ] o.a.s.c.a.ScheduledTriggers Pausing all triggers: [.auto_add_replicas, node_added_trigger2, node_added_trigger1]
[junit4] 2> 556443 DEBUG (ScheduledTrigger-6036-thread-3) [ ] o.a.s.c.a.SystemLogListener Collection .system missing, skip sending event {
[junit4] 2> "id":"3a48b2300324Tcdtvldgmeaydxda05hi56i3do",
[junit4] 2> "source":"node_added_trigger2",
[junit4] 2> "eventTime":64083901547300,
[junit4] 2> "eventType":"NODEADDED",
[junit4] 2> "properties":{
[junit4] 2> "eventTimes":[64083901547300],
[junit4] 2> "preferredOperation":"movereplica",
[junit4] 2> "_enqueue_time_":64090294087300,
[junit4] 2> "nodeNames":["127.0.0.1:10006_solr"],
[junit4] 2> "replicaType":"NRT"}}
[junit4] 2> 556443 DEBUG (ScheduledTrigger-6036-thread-3) [ ] o.a.s.c.a.NodeAddedTrigger Removing new node from tracking: 127.0.0.1:10006_solr
[junit4] 2> 556443 DEBUG (AutoscalingActionExecutor-6037-thread-1) [ ] o.a.s.c.a.ScheduledTriggers -- processing actions for {
[junit4] 2> "id":"3a48b2300324Tcdtvldgmeaydxda05hi56i3do",
[junit4] 2> "source":"node_added_trigger2",
[junit4] 2> "eventTime":64083901547300,
[junit4] 2> "eventType":"NODEADDED",
[junit4] 2> "properties":{
[junit4] 2> "eventTimes":[64083901547300],
[junit4] 2> "preferredOperation":"movereplica",
[junit4] 2> "_enqueue_time_":64090294087300,
[junit4] 2> "nodeNames":["127.0.0.1:10006_solr"],
[junit4] 2> "replicaType":"NRT"}}
[junit4] 2> 556443 INFO (AutoscalingActionExecutor-6037-thread-1) [ ] o.a.s.c.a.s.TestSimTriggerIntegration last action at 64083992027300 time = 64090323897300
[junit4] 2> 556443 INFO (AutoscalingActionExecutor-6037-thread-1) [ ] o.a.s.c.a.s.TestSimTriggerIntegration action executed from node_added_trigger2
[junit4] 2> 556443 DEBUG (AutoscalingActionExecutor-6037-thread-1) [ ] o.a.s.c.a.SystemLogListener Collection .system missing, skip sending event {
[junit4] 2> "id":"3a48b2300324Tcdtvldgmeaydxda05hi56i3do",
[junit4] 2> "source":"node_added_trigger2",
[junit4] 2> "eventTime":64083901547300,
[junit4] 2> "eventType":"NODEADDED",
[junit4] 2> "properties":{
[junit4] 2> "eventTimes":[64083901547300],
[junit4] 2> "preferredOperation":"movereplica",
[junit4] 2> "_enqueue_time_":64090294087300,
[junit4] 2> "nodeNames":["127.0.0.1:10006_solr"],
[junit4] 2> "replicaType":"NRT"}}
[junit4] 2> 556444 DEBUG (AutoscalingActionExecutor-6037-thread-1) [ ] o.a.s.c.a.ScheduledTriggers Resuming trigger: .auto_add_replicas after 100ms
[junit4] 2> 556444 DEBUG (AutoscalingActionExecutor-6037-thread-1) [ ] o.a.s.c.a.ScheduledTriggers Resuming trigger: node_added_trigger1 after 100ms
[junit4] 2> 556444 DEBUG (AutoscalingActionExecutor-6037-thread-1) [ ] o.a.s.c.a.ScheduledTriggers Resuming trigger: node_added_trigger2 after 100ms
[junit4] 2> 556444 DEBUG (AutoscalingActionExecutor-6037-thread-1) [ ] o.a.s.c.a.ScheduledTriggers -- processing took 24 ms for event id=3a48b2300324Tcdtvldgmeaydxda05hi56i3do
[junit4] 2> 556446 DEBUG (simCloudManagerPool-6035-thread-5) [ ] o.a.s.c.a.AutoScalingHandler Verified autoscaling configuration
[junit4] 2> 556446 DEBUG (simCloudManagerPool-6035-thread-5) [ ] o.a.s.c.a.OverseerTriggerThread Refreshing /autoscaling.json with znode version 5
[junit4] 2> 556447 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Processed trigger updates upto znodeVersion 5
[junit4] 2> 556448 INFO (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.s.TestSimTriggerIntegration TestTriggerAction init
[junit4] 2> 556448 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.NodeLostTrigger NodeLostTrigger node_lost_trigger1 - Initial livenodes: [127.0.0.1:10004_solr, 127.0.0.1:10006_solr, 127.0.0.1:10005_solr]
[junit4] 2> 556448 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread -- deactivating old nodeLost / nodeAdded markers
[junit4] 2> 556448 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Current znodeVersion 5, lastZnodeVersion 5
[junit4] 2> 556448 DEBUG (ScheduledTrigger-6036-thread-4) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: node_lost_trigger1 with currently live nodes: 3 and last live nodes: 3
[junit4] 2> 556455 DEBUG (simCloudManagerPool-6035-thread-6) [ ] o.a.s.c.a.AutoScalingHandler Verified autoscaling configuration
[junit4] 2> 556457 DEBUG (simCloudManagerPool-6035-thread-6) [ ] o.a.s.c.a.OverseerTriggerThread Refreshing /autoscaling.json with znode version 6
[junit4] 2> 556457 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Processed trigger updates upto znodeVersion 6
[junit4] 2> 556460 INFO (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.s.TestSimTriggerIntegration TestTriggerAction init
[junit4] 2> 556461 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.NodeLostTrigger NodeLostTrigger node_lost_trigger2 - Initial livenodes: [127.0.0.1:10004_solr, 127.0.0.1:10006_solr, 127.0.0.1:10005_solr]
[junit4] 2> 556461 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread -- deactivating old nodeLost / nodeAdded markers
[junit4] 2> 556461 DEBUG (ScheduledTrigger-6036-thread-1) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: node_lost_trigger2 with currently live nodes: 3 and last live nodes: 3
[junit4] 2> 556461 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Current znodeVersion 6, lastZnodeVersion 6
[junit4] 2> 556462 DEBUG (TEST-TestSimTriggerIntegration.testTriggerThrottling-seed#[51F1CBB5FD0B5B7C]) [ ] o.a.s.c.a.s.SimClusterStateProvider -- created marker: /autoscaling/nodeLost/127.0.0.1:10006_solr
[junit4] 2> 556463 DEBUG (TEST-TestSimTriggerIntegration.testTriggerThrottling-seed#[51F1CBB5FD0B5B7C]) [ ] o.a.s.c.a.ScheduledTriggers Shutting down scheduled thread pool executor now
[junit4] 2> 556463 DEBUG (TEST-TestSimTriggerIntegration.testTriggerThrottling-seed#[51F1CBB5FD0B5B7C]) [ ] o.a.s.c.a.ScheduledTriggers Shutting down action executor now
[junit4] 2> 556463 DEBUG (TEST-TestSimTriggerIntegration.testTriggerThrottling-seed#[51F1CBB5FD0B5B7C]) [ ] o.a.s.c.a.ScheduledTriggers Awaiting termination for action executor
[junit4] 2> 556463 DEBUG (TEST-TestSimTriggerIntegration.testTriggerThrottling-seed#[51F1CBB5FD0B5B7C]) [ ] o.a.s.c.a.ScheduledTriggers Awaiting termination for scheduled thread pool executor
[junit4] 2> 556464 INFO (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread OverseerTriggerThread woken up but we are closed, exiting.
[junit4] 2> 556464 DEBUG (TEST-TestSimTriggerIntegration.testTriggerThrottling-seed#[51F1CBB5FD0B5B7C]) [ ] o.a.s.c.a.ScheduledTriggers ScheduledTriggers closed completely
[junit4] 2> 556464 DEBUG (TEST-TestSimTriggerIntegration.testTriggerThrottling-seed#[51F1CBB5FD0B5B7C]) [ ] o.a.s.c.a.OverseerTriggerThread OverseerTriggerThread has been closed explicitly
[junit4] 2> 556465 INFO (TEST-TestSimTriggerIntegration.testTriggerThrottling-seed#[51F1CBB5FD0B5B7C]) [ ] o.a.s.SolrTestCaseJ4 ###Ending testTriggerThrottling
[junit4] 2> 556468 INFO (TEST-TestSimTriggerIntegration.testSearchRate-seed#[51F1CBB5FD0B5B7C]) [ ] o.a.s.SolrTestCaseJ4 ###Starting testSearchRate
[junit4] 2> 556513 DEBUG (TEST-TestSimTriggerIntegration.testSearchRate-seed#[51F1CBB5FD0B5B7C]) [ ] o.a.s.c.a.s.SimClusterStateProvider --- new Overseer leader: 127.0.0.1:10007_solr
[junit4] 2> 556520 INFO (TEST-TestSimTriggerIntegration.testSearchRate-seed#[51F1CBB5FD0B5B7C]) [ ] o.a.s.h.a.MetricsHistoryHandler No .system collection, keeping metrics history in memory.
[junit4] 2> 556524 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Adding .auto_add_replicas and .scheduled_maintenance triggers
[junit4] 2> 556525 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Refreshing /autoscaling.json with znode version 1
[junit4] 2> 556525 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Current znodeVersion 1, lastZnodeVersion 0
[junit4] 2> 556525 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Processed trigger updates upto znodeVersion 1
[junit4] 2> 556527 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.NodeLostTrigger NodeLostTrigger .auto_add_replicas - Initial livenodes: [127.0.0.1:10008_solr, 127.0.0.1:10007_solr]
[junit4] 2> 556527 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread -- deactivating old nodeLost / nodeAdded markers
[junit4] 2> 556527 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Current znodeVersion 1, lastZnodeVersion 1
[junit4] 2> 556533 DEBUG (ScheduledTrigger-6042-thread-2) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 2 and last live nodes: 2
[junit4] 2> 556541 DEBUG (simCloudManagerPool-6041-thread-2) [ ] o.a.s.c.a.AutoScalingHandler Verified autoscaling configuration
[junit4] 2> 556542 DEBUG (simCloudManagerPool-6041-thread-2) [ ] o.a.s.c.a.OverseerTriggerThread Refreshing /autoscaling.json with znode version 2
[junit4] 2> 556553 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Processed trigger updates upto znodeVersion 2
[junit4] 2> 556555 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread -- deactivating old nodeLost / nodeAdded markers
[junit4] 2> 556555 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Current znodeVersion 2, lastZnodeVersion 2
[junit4] 2> 556555 DEBUG (ScheduledTrigger-6042-thread-2) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 2 and last live nodes: 2
[junit4] 2> 556565 DEBUG (simCloudManagerPool-6041-thread-3) [ ] o.a.s.c.a.s.SimClusterStateProvider -- simCreateCollection collection1
[junit4] 2> 556590 DEBUG (ScheduledTrigger-6042-thread-2) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 2 and last live nodes: 2
[junit4] 2> 556599 DEBUG (simCloudManagerPool-6041-thread-3) [ ] o.a.s.c.a.s.SimClusterStateProvider -- finished createCollection collection1
[junit4] 2> 556602 INFO (TEST-TestSimTriggerIntegration.testSearchRate-seed#[51F1CBB5FD0B5B7C]) [ ] o.a.s.c.CloudUtil -- shards without leaders: [shard1]
[junit4] 2> 556612 INFO (TEST-TestSimTriggerIntegration.testSearchRate-seed#[51F1CBB5FD0B5B7C]) [ ] o.a.s.c.CloudUtil -- shards without leaders: [shard1]
[junit4] 2> 556613 DEBUG (ScheduledTrigger-6042-thread-3) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 2 and last live nodes: 2
[junit4] 2> 556634 DEBUG (simCloudManagerPool-6041-thread-4) [ ] o.a.s.c.a.s.SimClusterStateProvider Running leader election (collection1 / shard1)
[junit4] 2> 556634 DEBUG (simCloudManagerPool-6041-thread-4) [ ] o.a.s.c.a.s.SimClusterStateProvider -- elected new leader for collection1 / shard1 (currentVersion=3): {"core_node1":{
[junit4] 2> "core":"collection1_shard1_replica_n1",
[junit4] 2> "shard":"shard1",
[junit4] 2> "collection":"collection1",
[junit4] 2> "node_name":"127.0.0.1:10007_solr",
[junit4] 2> "type":"NRT",
[junit4] 2> "leader":"true",
[junit4] 2> "SEARCHER.searcher.maxDoc":0,
[junit4] 2> "SEARCHER.searcher.deletedDocs":0,
[junit4] 2> "INDEX.sizeInBytes":10240,
[junit4] 2> "state":"active",
[junit4] 2> "INDEX.sizeInGB":9.5367431640625E-6,
[junit4] 2> "SEARCHER.searcher.numDocs":0}}
[junit4] 2> 556647 DEBUG (ScheduledTrigger-6042-thread-3) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 2 and last live nodes: 2
[junit4] 2> 556678 DEBUG (ScheduledTrigger-6042-thread-3) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 2 and last live nodes: 2
[junit4] 2> 556681 DEBUG (simCloudManagerPool-6041-thread-6) [ ] o.a.s.c.a.AutoScalingHandler Verified autoscaling configuration
[junit4] 2> 556681 DEBUG (simCloudManagerPool-6041-thread-6) [ ] o.a.s.c.a.OverseerTriggerThread Refreshing /autoscaling.json with znode version 3
[junit4] 2> 556683 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Processed trigger updates upto znodeVersion 3
[junit4] 2> 556684 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread -- deactivating old nodeLost / nodeAdded markers
[junit4] 2> 556684 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Current znodeVersion 3, lastZnodeVersion 3
[junit4] 2> 556688 DEBUG (ScheduledTrigger-6042-thread-4) [ ] o.a.s.c.a.SearchRateTrigger ### rates for node 127.0.0.1:10008_solr
[junit4] 2> 556688 DEBUG (ScheduledTrigger-6042-thread-4) [ ] o.a.s.c.a.SearchRateTrigger ### rates for node 127.0.0.1:10007_solr
[junit4] 2> 556696 DEBUG (simCloudManagerPool-6041-thread-7) [ ] o.a.s.c.a.AutoScalingHandler Verified autoscaling configuration
[junit4] 2> 556696 DEBUG (simCloudManagerPool-6041-thread-7) [ ] o.a.s.c.a.OverseerTriggerThread Refreshing /autoscaling.json with znode version 4
[junit4] 2> 556704 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Processed trigger updates upto znodeVersion 4
[junit4] 2> 556704 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread -- deactivating old nodeLost / nodeAdded markers
[junit4] 2> 556704 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Current znodeVersion 4, lastZnodeVersion 4
[junit4] 2> 556797 DEBUG (ScheduledTrigger-6042-thread-2) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 2 and last live nodes: 2
[junit4] 2> 556802 DEBUG (ScheduledTrigger-6042-thread-1) [ ] o.a.s.c.a.SearchRateTrigger ### rates for node 127.0.0.1:10008_solr
[junit4] 2> 556802 DEBUG (ScheduledTrigger-6042-thread-1) [ ] o.a.s.c.a.SearchRateTrigger ### metrics:solr.core.collection1.shard1.replica_n2:QUERY./select.requestTimes:1minRate 250
[junit4] 2> 556802 DEBUG (ScheduledTrigger-6042-thread-1) [ ] o.a.s.c.a.SearchRateTrigger ### rates for node 127.0.0.1:10007_solr
[junit4] 2> 556802 DEBUG (ScheduledTrigger-6042-thread-1) [ ] o.a.s.c.a.SearchRateTrigger ### metrics:solr.core.collection1.shard1.replica_n1:QUERY./select.requestTimes:1minRate 250
[junit4] 2> 556802 DEBUG (ScheduledTrigger-6042-thread-1) [ ] o.a.s.c.a.SearchRateTrigger ## Collection: collection1
[junit4] 2> 556802 DEBUG (ScheduledTrigger-6042-thread-1) [ ] o.a.s.c.a.SearchRateTrigger ## - shard1
[junit4] 2> 556802 DEBUG (ScheduledTrigger-6042-thread-1) [ ] o.a.s.c.a.SearchRateTrigger ## collection1_shard1_replica_n2 250.0
[junit4] 2> 556802 DEBUG (ScheduledTrigger-6042-thread-1) [ ] o.a.s.c.a.SearchRateTrigger ## collection1_shard1_replica_n1 250.0
[junit4] 2> 556824 DEBUG (ScheduledTrigger-6042-thread-1) [ ] o.a.s.c.a.SearchRateTrigger -- collection1.shard1: totalShardRate=500.0, shardRate=250.0
[junit4] 2> 556826 DEBUG (ScheduledTrigger-6042-thread-1) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 2 and last live nodes: 2
[junit4] 2> 556847 DEBUG (ScheduledTrigger-6042-thread-3) [ ] o.a.s.c.a.SearchRateTrigger ### rates for node 127.0.0.1:10008_solr
[junit4] 2> 556852 DEBUG (ScheduledTrigger-6042-thread-3) [ ] o.a.s.c.a.SearchRateTrigger ### metrics:solr.core.collection1.shard1.replica_n2:QUERY./select.requestTimes:1minRate 250
[junit4] 2> 556852 DEBUG (ScheduledTrigger-6042-thread-3) [ ] o.a.s.c.a.SearchRateTrigger ### rates for node 127.0.0.1:10007_solr
[junit4] 2> 556852 DEBUG (ScheduledTrigger-6042-thread-3) [ ] o.a.s.c.a.SearchRateTrigger ### metrics:solr.core.collection1.shard1.replica_n1:QUERY./select.requestTimes:1minRate 250
[junit4] 2> 556852 DEBUG (ScheduledTrigger-6042-thread-4) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 2 and last live nodes: 2
[junit4] 2> 556852 DEBUG (ScheduledTrigger-6042-thread-3) [ ] o.a.s.c.a.SearchRateTrigger ## Collection: collection1
[junit4] 2> 556852 DEBUG (ScheduledTrigger-6042-thread-3) [ ] o.a.s.c.a.SearchRateTrigger ## - shard1
[junit4] 2> 556852 DEBUG (ScheduledTrigger-6042-thread-3) [ ] o.a.s.c.a.SearchRateTrigger ## collection1_shard1_replica_n2 250.0
[junit4] 2> 556852 DEBUG (ScheduledTrigger-6042-thread-3) [ ] o.a.s.c.a.SearchRateTrigger ## collection1_shard1_replica_n1 250.0
[junit4] 2> 556852 DEBUG (ScheduledTrigger-6042-thread-3) [ ] o.a.s.c.a.SearchRateTrigger -- collection1.shard1: totalShardRate=500.0, shardRate=250.0
[junit4] 2> 556872 DEBUG (ScheduledTrigger-6042-thread-3) [ ] o.a.s.c.a.ScheduledTriggers ++++++++ Cooldown inactive - processing event: {
[junit4] 2> "id":"3a4e6961b9acTcdtvldgmeaydxda05hi56i3dq",
[junit4] 2> "source":"search_rate_trigger",
[junit4] 2> "eventTime":64108449872300,
[junit4] 2> "eventType":"SEARCHRATE",
[junit4] 2> "properties":{
[junit4] 2> "hotReplicas":[
[junit4] 2> {"core_node2":{
[junit4] 2> "core":"collection1_shard1_replica_n2",
[junit4] 2> "shard":"shard1",
[junit4] 2> "collection":"collection1",
[junit4] 2> "node_name":"127.0.0.1:10008_solr",
[junit4] 2> "type":"NRT",
[junit4] 2> "SEARCHER.searcher.maxDoc":0,
[junit4] 2> "SEARCHER.searcher.deletedDocs":0,
[junit4] 2> "INDEX.sizeInBytes":10240,
[junit4] 2> "rate":250.0,
[junit4] 2> "state":"active",
[junit4] 2> "QUERY./select.requestTimes:1minRate":250,
[junit4] 2> "INDEX.sizeInGB":9.5367431640625E-6,
[junit4] 2> "SEARCHER.searcher.numDocs":0}},
[junit4] 2> {"core_node1":{
[junit4] 2> "core":"collection1_shard1_replica_n1",
[junit4] 2> "shard":"shard1",
[junit4] 2> "collection":"collection1",
[junit4] 2> "node_name":"127.0.0.1:10007_solr",
[junit4] 2> "type":"NRT",
[junit4] 2> "leader":"true",
[junit4] 2> "SEARCHER.searcher.maxDoc":0,
[junit4] 2> "SEARCHER.searcher.deletedDocs":0,
[junit4] 2> "INDEX.sizeInBytes":10240,
[junit4] 2> "rate":250.0,
[junit4] 2> "state":"active",
[junit4] 2> "QUERY./select.requestTimes:1minRate":250,
[junit4] 2> "INDEX.sizeInGB":9.5367431640625E-6,
[junit4] 2> "SEARCHER.searcher.numDocs":0}}],
[junit4] 2> "coldNodes":{},
[junit4] 2> "coldShards":{},
[junit4] 2> "coldReplicas":[],
[junit4] 2> "violationType":["hotShards"],
[junit4] 2> "coldCollections":{},
[junit4] 2> "hotShards":{"collection1":{"shard1":250.0}},
[junit4] 2> "hotCollections":{"collection1":500.0},
[junit4] 2> "hotNodes":{
[junit4] 2> "127.0.0.1:10008_solr":250.0,
[junit4] 2> "127.0.0.1:10007_solr":250.0},
[junit4] 2> "requestedOps":[
[junit4] 2> {
[junit4] 2> "action":"ADDREPLICA",
[junit4] 2> "hints":{"COLL_SHARD":[{
[junit4] 2> "first":"collection1",
[junit4] 2> "second":"shard1"}]}},
[junit4] 2> {
[junit4] 2> "action":"ADDREPLICA",
[junit4] 2> "hints":{"COLL_SHARD":[{
[junit4] 2> "first":"collection1",
[junit4] 2> "second":"shard1"}]}},
[junit4] 2> {
[junit4] 2> "action":"ADDREPLICA",
[junit4] 2> "hints":{"COLL_SHARD":[{
[junit4] 2> "first":"collection1",
[junit4] 2> "second":"shard1"}]}}]}}
[junit4] 2> 556878 DEBUG (ScheduledTrigger-6042-thread-3) [ ] o.a.s.c.a.ScheduledTriggers Pausing all triggers: [.auto_add_replicas, search_rate_trigger]
[junit4] 2> 556879 DEBUG (ScheduledTrigger-6042-thread-3) [ ] o.a.s.c.a.SystemLogListener Collection .system missing, skip sending event {
[junit4] 2> "id":"3a4e6961b9acTcdtvldgmeaydxda05hi56i3dq",
[junit4] 2> "source":"search_rate_trigger",
[junit4] 2> "eventTime":64108449872300,
[junit4] 2> "eventType":"SEARCHRATE",
[junit4] 2> "properties":{
[junit4] 2> "hotReplicas":[
[junit4] 2> {"core_node2":{
[junit4] 2> "core":"collection1_shard1_replica_n2",
[junit4] 2> "shard":"shard1",
[junit4] 2> "collection":"collection1",
[junit4] 2> "node_name":"127.0.0.1:10008_solr",
[junit4] 2> "type":"NRT",
[junit4] 2> "SEARCHER.searcher.maxDoc":0,
[junit4] 2> "SEARCHER.searcher.deletedDocs":0,
[junit4] 2> "INDEX.sizeInBytes":10240,
[junit4] 2> "rate":250.0,
[junit4] 2> "state":"active",
[junit4] 2> "QUERY./select.requestTimes:1minRate":250,
[junit4] 2> "INDEX.sizeInGB":9.5367431640625E-6,
[junit4] 2> "SEARCHER.searcher.numDocs":0}},
[junit4] 2> {"core_node1":{
[junit4] 2> "core":"collection1_shard1_replica_n1",
[junit4] 2> "shard":"shard1",
[junit4] 2> "collection":"collection1",
[junit4] 2> "node_name":"127.0.0.1:10007_solr",
[junit4] 2> "type":"NRT",
[junit4] 2> "leader":"true",
[junit4] 2> "SEARCHER.searcher.maxDoc":0,
[junit4] 2> "SEARCHER.searcher.deletedDocs":0,
[junit4] 2> "INDEX.sizeInBytes":10240,
[junit4] 2> "rate":250.0,
[junit4] 2> "state":"active",
[junit4] 2> "QUERY./select.requestTimes:1minRate":250,
[junit4] 2> "INDEX.sizeInGB":9.5367431640625E-6,
[junit4] 2> "SEARCHER.searcher.numDocs":0}}],
[junit4] 2> "coldNodes":{},
[junit4] 2> "coldShards":{},
[junit4] 2> "coldReplicas":[],
[junit4] 2> "violationType":["hotShards"],
[junit4] 2> "coldCollections":{},
[junit4] 2> "hotShards":{"collection1":{"shard1":250.0}},
[junit4] 2> "hotCollections":{"collection1":500.0},
[junit4] 2> "hotNodes":{
[junit4] 2> "127.0.0.1:10008_solr":250.0,
[junit4] 2> "127.0.0.1:10007_solr":250.0},
[junit4] 2> "_enqueue_time_":64112037012300,
[junit4] 2> "requestedOps":[
[junit4] 2> {
[junit4] 2> "action":"ADDREPLICA",
[junit4] 2> "hints":{"COLL_SHARD":[{
[junit4] 2> "first":"collection1",
[junit4] 2> "second":"shard1"}]}},
[junit4] 2> {
[junit4] 2> "action":"ADDREPLICA",
[junit4] 2> "hints":{"COLL_SHARD":[{
[junit4] 2> "first":"collection1",
[junit4] 2> "second":"shard1"}]}},
[junit4] 2> {
[junit4] 2> "action":"ADDREPLICA",
[junit4] 2> "hints":{"COLL_SHARD":[{
[junit4] 2> "first":"collection1",
[junit4] 2> "second":"shard1"}]}}]}}
[junit4] 2> 556990 DEBUG (AutoscalingActionExecutor-6043-thread-1) [ ] o.a.s.c.a.ScheduledTriggers -- processing actions for {
[junit4] 2> "id":"3a4e6961b9acTcdtvldgmeaydxda05hi56i3dq",
[junit4] 2> "source":"search_rate_trigger",
[junit4] 2> "eventTime":64108449872300,
[junit4] 2> "eventType":"SEARCHRATE",
[junit4] 2> "properties":{
[junit4] 2> "hotReplicas":[
[junit4] 2> {"core_node2":{
[junit4] 2> "core":"collection1_shard1_replica_n2",
[junit4] 2> "shard":"shard1",
[junit4] 2> "collection":"collection1",
[junit4] 2> "node_name":"127.0.0.1:10008_solr",
[junit4] 2> "type":"NRT",
[junit4] 2> "SEARCHER.searcher.maxDoc":0,
[junit4] 2> "SEARCHER.searcher.deletedDocs":0,
[junit4] 2> "INDEX.sizeInBytes":10240,
[junit4] 2> "rate":250.0,
[junit4] 2> "state":"active",
[junit4] 2> "QUERY./select.requestTimes:1minRate":250,
[junit4] 2> "INDEX.sizeInGB":9.5367431640625E-6,
[junit4] 2> "SEARCHER.searcher.numDocs":0}},
[junit4] 2> {"core_node1":{
[junit4] 2> "core":"collection1_shard1_replica_n1",
[junit4] 2> "shard":"shard1",
[junit4] 2> "collection":"collection1",
[junit4] 2> "node_name":"127.0.0.1:10007_solr",
[junit4] 2> "type":"NRT",
[junit4] 2> "leader":"true",
[junit4] 2> "SEARCHER.searcher.maxDoc":0,
[junit4] 2> "SEARCHER.searcher.deletedDocs":0,
[junit4] 2> "INDEX.sizeInBytes":10240,
[junit4] 2> "rate":250.0,
[junit4] 2> "state":"active",
[junit4] 2> "QUERY./select.requestTimes:1minRate":250,
[junit4] 2> "INDEX.sizeInGB":9.5367431640625E-6,
[junit4] 2> "SEARCHER.searcher.numDocs":0}}],
[junit4] 2> "coldNodes":{},
[junit4] 2> "coldShards":{},
[junit4] 2> "coldReplicas":[],
[junit4] 2> "violationType":["hotShards"],
[junit4] 2> "coldCollections":{},
[junit4] 2> "hotShards":{"collection1":{"shard1":250.0}},
[junit4] 2> "hotCollections":{"collection1":500.0},
[junit4] 2> "hotNodes":{
[junit4] 2> "127.0.0.1:10008_solr":250.0,
[junit4] 2> "127.0.0.1:10007_solr":250.0},
[junit4] 2> "_enqueue_time_":64112037012300,
[junit4] 2> "requestedOps":[
[junit4] 2> {
[junit4] 2> "action":"ADDREPLICA",
[junit4] 2> "hints":{"COLL_SHARD":[{
[junit4] 2> "first":"collection1",
[junit4] 2> "second":"shard1"}]}},
[junit4] 2> {
[junit4] 2> "action":"ADDREPLICA",
[junit4] 2> "hints":{"COLL_SHARD":[{
[junit4] 2> "first":"collection1",
[junit4] 2> "second":"shard1"}]}},
[junit4] 2> {
[junit4] 2> "action":"ADDREPLICA",
[junit4] 2> "hints":{"COLL_SHARD":[{
[junit4] 2> "first":"collection1",
[junit4] 2> "second":"shard1"}]}}]}}
[junit4] 2> 556992 DEBUG (AutoscalingActionExecutor-6043-thread-1) [ ] o.a.s.c.a.ComputePlanAction -- processing event: {
[junit4] 2> "id":"3a4e6961b9acTcdtvldgmeaydxda05hi56i3dq",
[junit4] 2> "source":"search_rate_trigger",
[junit4] 2> "eventTime":64108449872300,
[junit4] 2> "eventType":"SEARCHRATE",
[junit4] 2> "properties":{
[junit4] 2> "hotReplicas":[
[junit4] 2> {"core_node2":{
[junit4] 2> "core":"collection1_shard1_replica_n2",
[junit4] 2> "shard":"shard1",
[junit4] 2> "collection":"collection1",
[junit4] 2> "node_name":"127.0.0.1:10008_solr",
[junit4] 2> "type":"NRT",
[junit4] 2> "SEARCHER.searcher.maxDoc":0,
[junit4] 2> "SEARCHER.searcher.deletedDocs":0,
[junit4] 2> "INDEX.sizeInBytes":10240,
[junit4] 2> "rate":250.0,
[junit4] 2> "state":"active",
[junit4] 2> "QUERY./select.requestTimes:1minRate":250,
[junit4] 2> "INDEX.sizeInGB":9.5367431640625E-6,
[junit4] 2> "SEARCHER.searcher.numDocs":0}},
[junit4] 2> {"core_node1":{
[junit4] 2> "core":"collection1_shard1_replica_n1",
[junit4] 2> "shard":"shard1",
[junit4] 2> "collection":"collection1",
[junit4] 2> "node_name":"127.0.0.1:10007_solr",
[junit4] 2> "type":"NRT",
[junit4] 2> "leader":"true",
[junit4] 2> "SEARCHER.searcher.maxDoc":0,
[junit4] 2> "SEARCHER.searcher.deletedDocs":0,
[junit4] 2> "INDEX.sizeInBytes":10240,
[junit4] 2> "rate":250.0,
[junit4] 2> "state":"active",
[junit4] 2> "QUERY./select.requestTimes:1minRate":250,
[junit4] 2> "INDEX.sizeInGB":9.5367431640625E-6,
[junit4] 2> "SEARCHER.searcher.numDocs":0}}],
[junit4] 2> "coldNodes":{},
[junit4] 2> "coldShards":{},
[junit4] 2> "coldReplicas":[],
[junit4] 2> "violationType":["hotShards"],
[junit4] 2> "coldCollections":{},
[junit4] 2> "hotShards":{"collection1":{"shard1":250.0}},
[junit4] 2> "hotCollections":{"collection1":500.0},
[junit4] 2> "hotNodes":{
[junit4] 2> "127.0.0.1:10008_solr":250.0,
[junit4] 2> "127.0.0.1:10007_solr":250.0},
[junit4] 2> "_enqueue_time_":64112037012300,
[junit4] 2> "requestedOps":[
[junit4] 2> {
[junit4] 2> "action":"ADDREPLICA",
[junit4] 2> "hints":{"COLL_SHARD":[{
[junit4] 2> "first":"collection1",
[junit4] 2> "second":"shard1"}]}},
[junit4] 2> {
[junit4] 2> "action":"ADDREPLICA",
[junit4] 2> "hints":{"COLL_SHARD":[{
[junit4] 2> "first":"collection1",
[junit4] 2> "second":"shard1"}]}},
[junit4] 2> {
[junit4] 2> "action":"ADDREPLICA",
[junit4] 2> "hints":{"COLL_SHARD":[{
[junit4] 2> "first":"collection1",
[junit4] 2> "second":"shard1"}]}}]}} with context properties: {AFTER_ACTION=[start], BEFORE_ACTION=[start, compute]}
[junit4] 2> 556999 DEBUG (AutoscalingActionExecutor-6043-thread-1) [ ] o.a.s.c.a.ComputePlanAction Computed Plan: action=ADDREPLICA&collection=collection1&shard=shard1&node=127.0.0.1:10007_solr&type=NRT
[junit4] 2> 557019 DEBUG (AutoscalingActionExecutor-6043-thread-1) [ ] o.a.s.c.a.ComputePlanAction Computed Plan: action=ADDREPLICA&collection=collection1&shard=shard1&node=127.0.0.1:10008_solr&type=NRT
[junit4] 2> 557019 DEBUG (AutoscalingActionExecutor-6043-thread-1) [ ] o.a.s.c.a.ComputePlanAction Computed Plan: action=ADDREPLICA&collection=collection1&shard=shard1&node=127.0.0.1:10008_solr&type=NRT
[junit4] 2> 557019 DEBUG (AutoscalingActionExecutor-6043-thread-1) [ ] o.a.s.c.a.ExecutePlanAction -- processing event: {
[junit4] 2> "id":"3a4e6961b9acTcdtvldgmeaydxda05hi56i3dq",
[junit4] 2> "source":"search_rate_trigger",
[junit4] 2> "eventTime":64108449872300,
[junit4] 2> "eventType":"SEARCHRATE",
[junit4] 2> "properties":{
[junit4] 2> "hotReplicas":[
[junit4] 2> {"core_node2":{
[junit4] 2> "core":"collection1_shard1_replica_n2",
[junit4] 2> "shard":"shard1",
[junit4] 2> "collection":"collection1",
[junit4] 2> "node_name":"127.0.0.1:10008_solr",
[junit4] 2> "type":"NRT",
[junit4] 2> "SEARCHER.searcher.maxDoc":0,
[junit4] 2> "SEARCHER.searcher.deletedDocs":0,
[junit4] 2> "INDEX.sizeInBytes":10240,
[junit4] 2> "rate":250.0,
[junit4] 2> "state":"active",
[junit4] 2> "QUERY./select.requestTimes:1minRate":250,
[junit4] 2> "INDEX.sizeInGB":9.5367431640625E-6,
[junit4] 2> "SEARCHER.searcher.numDocs":0}},
[junit4] 2> {"core_node1":{
[junit4] 2> "core":"collection1_shard1_replica_n1",
[junit4] 2> "shard":"shard1",
[junit4] 2> "collection":"collection1",
[junit4] 2> "node_name":"127.0.0.1:10007_solr",
[junit4] 2> "type":"NRT",
[junit4] 2> "leader":"true",
[junit4] 2> "SEARCHER.searcher.maxDoc":0,
[junit4] 2> "SEARCHER.searcher.deletedDocs":0,
[junit4] 2> "INDEX.sizeInBytes":10240,
[junit4] 2> "rate":250.0,
[junit4] 2> "state":"active",
[junit4] 2> "QUERY./select.requestTimes:1minRate":250,
[junit4] 2> "INDEX.sizeInGB":9.5367431640625E-6,
[junit4] 2> "SEARCHER.searcher.numDocs":0}}],
[junit4] 2> "__start__":3,
[junit4] 2> "coldNodes":{},
[junit4] 2> "coldShards":{},
[junit4] 2> "coldReplicas":[],
[junit4] 2> "violationType":["hotShards"],
[junit4] 2> "coldCollections":{},
[junit4] 2> "hotShards":{"collection1":{"shard1":250.0}},
[junit4] 2> "hotCollections":{"collection1":500.0},
[junit4] 2> "hotNodes":{
[junit4] 2> "127.0.0.1:10008_solr":250.0,
[junit4] 2> "127.0.0.1:10007_solr":250.0},
[junit4] 2> "_enqueue_time_":64112037012300,
[junit4] 2> "requestedOps":[
[junit4] 2> {
[junit4] 2> "action":"ADDREPLICA",
[junit4] 2> "hints":{"COLL_SHARD":[{
[junit4] 2> "first":"collection1",
[junit4] 2> "second":"shard1"}]}},
[junit4] 2> {
[junit4] 2> "action":"ADDREPLICA",
[junit4] 2> "hints":{"COLL_SHARD":[{
[junit4] 2> "first":"collection1",
[junit4] 2> "second":"shard1"}]}},
[junit4] 2> {
[junit4] 2> "action":"ADDREPLICA",
[junit4] 2> "hints":{"COLL_SHARD":[{
[junit4] 2> "first":"collection1",
[junit4] 2> "second":"shard1"}]}}]}} with context properties: {operations=[{
[junit4] 2> "class":"org.apache.solr.client.solrj.request.CollectionAdminRequest$AddReplica",
[junit4] 2> "method":"GET",
[junit4] 2> "params.action":"ADDREPLICA",
[junit4] 2> "params.collection":"collection1",
[junit4] 2> "params.shard":"shard1",
[junit4] 2> "params.node":"127.0.0.1:10007_solr",
[junit4] 2> "params.type":"NRT"}, {
[junit4] 2> "class":"org.apache.solr.client.solrj.request.CollectionAdminRequest$AddReplica",
[junit4] 2> "method":"GET",
[junit4] 2> "params.action":"ADDREPLICA",
[junit4] 2> "params.collection":"collection1",
[junit4] 2> "params.shard":"shard1",
[junit4] 2> "params.node":"127.0.0.1:10008_solr",
[junit4] 2> "params.type":"NRT"}, {
[junit4] 2> "class":"org.apache.solr.client.solrj.request.CollectionAdminRequest$AddReplica",
[junit4] 2> "method":"GET",
[junit4] 2> "params.action":"ADDREPLICA",
[junit4] 2> "params.collection":"collection1",
[junit4] 2> "params.shard":"shard1",
[junit4] 2> "params.node":"127.0.0.1:10008_solr",
[junit4] 2> "params.type":"NRT"}], AFTER_ACTION=[start, compute], BEFORE_ACTION=[start, compute, execute]}
[junit4] 2> 557021 DEBUG (AutoscalingActionExecutor-6043-thread-1) [ ] o.a.s.c.a.ExecutePlanAction Executing operation: action=ADDREPLICA&collection=collection1&shard=shard1&node=127.0.0.1:10007_solr&type=NRT
[junit4] 2> 557025 INFO (simCloudManagerPool-6041-thread-8) [ ] o.a.s.c.a.c.AddReplicaCmd Node Identified 127.0.0.1:10007_solr for creating new replica of shard shard1 for collection collection1
[junit4] 2> 557025 INFO (simCloudManagerPool-6041-thread-8) [ ] o.a.s.c.a.c.AddReplicaCmd Returning CreateReplica command.
[junit4] 2> 557087 DEBUG (AutoscalingActionExecutor-6043-thread-1) [ ] o.a.s.c.a.ExecutePlanAction Executing operation: action=ADDREPLICA&collection=collection1&shard=shard1&node=127.0.0.1:10008_solr&type=NRT
[junit4] 2> 557131 INFO (simCloudManagerPool-6041-thread-11) [ ] o.a.s.c.a.c.AddReplicaCmd Node Identified 127.0.0.1:10008_solr for creating new replica of shard shard1 for collection collection1
[junit4] 2> 557131 INFO (simCloudManagerPool-6041-thread-11) [ ] o.a.s.c.a.c.AddReplicaCmd Returning CreateReplica command.
[junit4] 2> 557164 DEBUG (AutoscalingActionExecutor-6043-thread-1) [ ] o.a.s.c.a.ExecutePlanAction Executing operation: action=ADDREPLICA&collection=collection1&shard=shard1&node=127.0.0.1:10008_solr&type=NRT
[junit4] 2> 557180 INFO (simCloudManagerPool-6041-thread-14) [ ] o.a.s.c.a.c.AddReplicaCmd Node Identified 127.0.0.1:10008_solr for creating new replica of shard shard1 for collection collection1
[junit4] 2> 557180 INFO (simCloudManagerPool-6041-thread-14) [ ] o.a.s.c.a.c.AddReplicaCmd Returning CreateReplica command.
[junit4] 2> 557260 DEBUG (AutoscalingActionExecutor-6043-thread-1) [ ] o.a.s.c.a.SystemLogListener Collection .system missing, skip sending event {
[junit4] 2> "id":"3a4e6961b9acTcdtvldgmeaydxda05hi56i3dq",
[junit4] 2> "source":"search_rate_trigger",
[junit4] 2> "eventTime":64108449872300,
[junit4] 2> "eventType":"SEARCHRATE",
[junit4] 2> "properties":{
[junit4] 2> "hotReplicas":[
[junit4] 2> {"core_node2":{
[junit4] 2> "core":"collection1_shard1_replica_n2",
[junit4] 2> "shard":"shard1",
[junit4] 2> "collection":"collection1",
[junit4] 2> "node_name":"127.0.0.1:10008_solr",
[junit4] 2> "type":"NRT",
[junit4] 2> "SEARCHER.searcher.maxDoc":0,
[junit4] 2> "SEARCHER.searcher.deletedDocs":0,
[junit4] 2> "INDEX.sizeInBytes":10240,
[junit4] 2> "rate":250.0,
[junit4] 2> "state":"active",
[junit4] 2> "QUERY./select.requestTimes:1minRate":250,
[junit4] 2> "INDEX.sizeInGB":9.5367431640625E-6,
[junit4] 2> "SEARCHER.searcher.numDocs":0}},
[junit4] 2> {"core_node1":{
[junit4] 2> "core":"collection1_shard1_replica_n1",
[junit4] 2> "shard":"shard1",
[junit4] 2> "collection":"collection1",
[junit4] 2> "node_name":"127.0.0.1:10007_solr",
[junit4] 2> "type":"NRT",
[junit4] 2> "leader":"true",
[junit4] 2> "SEARCHER.searcher.maxDoc":0,
[junit4] 2> "SEARCHER.searcher.deletedDocs":0,
[junit4] 2> "INDEX.sizeInBytes":10240,
[junit4] 2> "rate":250.0,
[junit4] 2> "state":"active",
[junit4] 2> "QUERY./select.requestTimes:1minRate":250,
[junit4] 2> "INDEX.sizeInGB":9.5367431640625E-6,
[junit4] 2> "SEARCHER.searcher.numDocs":0}}],
[junit4] 2> "__start__":3,
[junit4] 2> "coldNodes":{},
[junit4] 2> "coldShards":{},
[junit4] 2> "coldReplicas":[],
[junit4] 2> "violationType":["hotShards"],
[junit4] 2> "coldCollections":{},
[junit4] 2> "hotShards":{"collection1":{"shard1":250.0}},
[junit4] 2> "hotCollections":{"collection1":500.0},
[junit4] 2> "hotNodes":{
[junit4] 2> "127.0.0.1:10008_solr":250.0,
[junit4] 2> "127.0.0.1:10007_solr":250.0},
[junit4] 2> "_enqueue_time_":64112037012300,
[junit4] 2> "requestedOps":[
[junit4] 2> {
[junit4] 2> "action":"ADDREPLICA",
[junit4] 2> "hints":{"COLL_SHARD":[{
[junit4] 2> "first":"collection1",
[junit4] 2> "second":"shard1"}]}},
[junit4] 2> {
[junit4] 2> "action":"ADDREPLICA",
[junit4] 2> "hints":{"COLL_SHARD":[{
[junit4] 2> "first":"collection1",
[junit4] 2> "second":"shard1"}]}},
[junit4] 2> {
[junit4] 2> "action":"ADDREPLICA",
[junit4] 2> "hints":{"COLL_SHARD":[{
[junit4] 2> "first":"collection1",
[junit4] 2> "second":"shard1"}]}}]}}
[junit4] 2> 557264 DEBUG (AutoscalingActionExecutor-6043-thread-1) [ ] o.a.s.c.a.ScheduledTriggers Resuming trigger: search_rate_trigger after 100ms
[junit4] 2> 557264 DEBUG (AutoscalingActionExecutor-6043-thread-1) [ ] o.a.s.c.a.ScheduledTriggers Resuming trigger: .auto_add_replicas after 100ms
[junit4] 2> 557264 DEBUG (AutoscalingActionExecutor-6043-thread-1) [ ] o.a.s.c.a.ScheduledTriggers -- processing took 13665 ms for event id=3a4e6961b9acTcdtvldgmeaydxda05hi56i3dq
[junit4] 2> 557280 DEBUG (TEST-TestSimTriggerIntegration.testSearchRate-seed#[51F1CB
[...truncated too long message...]
/solr/autoscaling/events/.auto_add_replicas (0)
[junit4] 1> /solr/autoscaling.json (0)
[junit4] 1> DATA:
[junit4] 1> {
[junit4] 1> "cluster-preferences":[
[junit4] 1> {
[junit4] 1> "minimize":"cores",
[junit4] 1> "precision":1},
[junit4] 1> {"maximize":"freedisk"}],
[junit4] 1> "cluster-policy":[
[junit4] 1> {
[junit4] 1> "replica":"<2",
[junit4] 1> "shard":"#EACH",
[junit4] 1> "node":"#ANY",
[junit4] 1> "strict":"false"},
[junit4] 1> {
[junit4] 1> "replica":"#EQUAL",
[junit4] 1> "node":"#ANY",
[junit4] 1> "strict":"false"},
[junit4] 1> {
[junit4] 1> "cores":"#EQUAL",
[junit4] 1> "node":"#ANY",
[junit4] 1> "strict":"false"}],
[junit4] 1> "triggers":{
[junit4] 1> ".auto_add_replicas":{
[junit4] 1> "name":".auto_add_replicas",
[junit4] 1> "event":"nodeLost",
[junit4] 1> "waitFor":120,
[junit4] 1> "enabled":true,
[junit4] 1> "actions":[
[junit4] 1> {
[junit4] 1> "name":"auto_add_replicas_plan",
[junit4] 1> "class":"solr.AutoAddReplicasPlanAction"},
[junit4] 1> {
[junit4] 1> "name":"execute_plan",
[junit4] 1> "class":"solr.ExecutePlanAction"}]},
[junit4] 1> ".scheduled_maintenance":{
[junit4] 1> "name":".scheduled_maintenance",
[junit4] 1> "event":"scheduled",
[junit4] 1> "startTime":"NOW",
[junit4] 1> "every":"+1DAY",
[junit4] 1> "enabled":true,
[junit4] 1> "actions":[
[junit4] 1> {
[junit4] 1> "name":"inactive_shard_plan",
[junit4] 1> "class":"solr.InactiveShardPlanAction"},
[junit4] 1> {
[junit4] 1> "name":"inactive_markers_plan",
[junit4] 1> "class":"solr.InactiveMarkersPlanAction"},
[junit4] 1> {
[junit4] 1> "name":"execute_plan",
[junit4] 1> "class":"solr.ExecutePlanAction"}]}},
[junit4] 1> "listeners":{
[junit4] 1> ".auto_add_replicas.system":{
[junit4] 1> "beforeAction":[],
[junit4] 1> "afterAction":[],
[junit4] 1> "stage":[
[junit4] 1> "STARTED",
[junit4] 1> "ABORTED",
[junit4] 1> "SUCCEEDED",
[junit4] 1> "FAILED",
[junit4] 1> "BEFORE_ACTION",
[junit4] 1> "AFTER_ACTION",
[junit4] 1> "IGNORED"],
[junit4] 1> "trigger":".auto_add_replicas",
[junit4] 1> "class":"org.apache.solr.cloud.autoscaling.SystemLogListener"},
[junit4] 1> ".scheduled_maintenance.system":{
[junit4] 1> "beforeAction":[],
[junit4] 1> "afterAction":[],
[junit4] 1> "stage":[
[junit4] 1> "STARTED",
[junit4] 1> "ABORTED",
[junit4] 1> "SUCCEEDED",
[junit4] 1> "FAILED",
[junit4] 1> "BEFORE_ACTION",
[junit4] 1> "AFTER_ACTION",
[junit4] 1> "IGNORED"],
[junit4] 1> "trigger":".scheduled_maintenance",
[junit4] 1> "class":"org.apache.solr.cloud.autoscaling.SystemLogListener"}},
[junit4] 1> "properties":{}}
[junit4] 1>
[junit4] 2> 762997 INFO (TEST-PeerSyncReplicationTest.test-seed#[51F1CBB5FD0B5B7C]) [ ] o.a.s.c.ZkTestServer Shutting down ZkTestServer.
[junit4] 2> 763225 INFO (TEST-PeerSyncReplicationTest.test-seed#[51F1CBB5FD0B5B7C]) [ ] o.a.s.c.ZkTestServer waitForServerDown: 127.0.0.1:51091
[junit4] 2> 763225 INFO (TEST-PeerSyncReplicationTest.test-seed#[51F1CBB5FD0B5B7C]) [ ] o.a.s.c.ZkTestServer parse host and port list: 127.0.0.1:51091
[junit4] 2> 763225 INFO (TEST-PeerSyncReplicationTest.test-seed#[51F1CBB5FD0B5B7C]) [ ] o.a.s.c.ZkTestServer connecting to 127.0.0.1 51091
[junit4] 2> NOTE: reproduce with: ant test -Dtestcase=PeerSyncReplicationTest -Dtests.method=test -Dtests.seed=51F1CBB5FD0B5B7C -Dtests.slow=true -Dtests.locale=sr-Latn -Dtests.timezone=America/Merida -Dtests.asserts=true -Dtests.file.encoding=ISO-8859-1
[junit4] FAILURE 98.0s J3 | PeerSyncReplicationTest.test <<<
[junit4] > Throwable #1: java.lang.AssertionError: expected:<0> but was:<1>
[junit4] > at __randomizedtesting.SeedInfo.seed([51F1CBB5FD0B5B7C:D9A5F46F53F73684]:0)
[junit4] > at org.apache.solr.cloud.PeerSyncReplicationTest.test(PeerSyncReplicationTest.java:202)
[junit4] > at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
[junit4] > at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
[junit4] > at java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
[junit4] > at java.base/java.lang.reflect.Method.invoke(Method.java:564)
[junit4] > at org.apache.solr.BaseDistributedSearchTestCase$ShardsRepeatRule$ShardsFixedStatement.callStatement(BaseDistributedSearchTestCase.java:1090)
[junit4] > at org.apache.solr.BaseDistributedSearchTestCase$ShardsRepeatRule$ShardsStatement.evaluate(BaseDistributedSearchTestCase.java:1061)
[junit4] > at java.base/java.lang.Thread.run(Thread.java:832)
[junit4] 2> NOTE: leaving temporary files on disk at: C:\Users\jenkins\workspace\Lucene-Solr-master-Windows\solr\build\solr-core\test\J3\temp\solr.cloud.PeerSyncReplicationTest_51F1CBB5FD0B5B7C-001
[junit4] 2> NOTE: test params are: codec=Asserting(Lucene86), sim=Asserting(org.apache.lucene.search.similarities.AssertingSimilarity@4e2d0fbe), locale=sr-Latn, timezone=America/Merida
[junit4] 2> NOTE: Windows 10 10.0 amd64/AdoptOpenJDK 14.0.1 (64-bit)/cpus=6,threads=1,free=148681080,total=536870912
[junit4] 2> NOTE: All tests run in this JVM: [TestSchemaResource, DistributedFacetPivotLongTailTest, TestCollectionAPI, ConnectionManagerTest, QueryEqualityTest, TestJavabinTupleStreamParser, SolrJmxReporterTest, SolrIndexMetricsTest, TestUseDocValuesAsStored, CollectionTooManyReplicasTest, ShowFileRequestHandlerTest, TestHdfsBackupRestoreCore, CursorPagingTest, HdfsDirectoryTest, TestDocSet, NumericFieldsTest, IgnoreCommitOptimizeUpdateProcessorFactoryTest, CollectionPropsTest, GraphQueryTest, ForceLeaderTest, NodeLostTriggerIntegrationTest, XCJFQueryTest, TestXmlQParserPlugin, OverriddenZkACLAndCredentialsProvidersTest, AnalysisErrorHandlingTest, TestPartialUpdateDeduplication, TestSimExtremeIndexing, BaseCdcrDistributedZkTest, TestJsonFacetsStatsParsing, SplitShardTest, TestInitQParser, SolrLogPostToolTest, TestStressThreadBackup, TestGroupingSearch, XsltUpdateRequestHandlerTest, CurrencyRangeFacetCloudTest, SharedFSAutoReplicaFailoverTest, DebugComponentTest, TestWaitForStateWithJettyShutdowns, TestManagedStopFilterFactory, TestRestoreCore, TestAnalyzedSuggestions, TestRangeQuery, TestCloudManagedSchema, OutputWriterTest, TestCustomStream, ResourceLoaderTest, TestPseudoReturnFields, SolrMetricManagerTest, TestLeaderElectionZkExpiry, TestImplicitCoreProperties, QueryElevationComponentTest, TestLegacyNumericUtils, SearchHandlerTest, TestSolrFieldCacheBean, TestApiFramework, IndexSizeEstimatorTest, HdfsBasicDistributedZkTest, VersionInfoTest, HdfsDirectoryFactoryTest, ZkDynamicConfigTest, ReplaceNodeNoTargetTest, ZkShardTermsTest, TestInPlaceUpdateWithRouteField, ChaosMonkeyNothingIsSafeTest, HttpPartitionWithTlogReplicasTest, TestCloudPseudoReturnFields, TestLMDirichletSimilarityFactory, TestSegmentSorting, TestDistributedTracing, CleanupOldIndexTest, SpellCheckCollatorWithCollapseTest, TestShardHandlerFactory, TestHighFrequencyDictionaryFactory, TestCursorMarkWithoutUniqueKey, TestConfigSetsAPI, DefaultValueUpdateProcessorTest, TestMinMaxOnMultiValuedField, HdfsRecoveryZkTest, TestSurroundQueryParser, TestMultiWordSynonyms, PeerSyncReplicationTest]
[junit4] Completed [300/910 (2!)] on J3 in 98.06s, 1 test, 1 failure <<< FAILURES!
[...truncated 47026 lines...]
[repro] Jenkins log URL: https://jenkins.thetaphi.de/job/Lucene-Solr-master-Windows/8993/consoleText
[repro] Revision: 972c84022ec9c2b867848cb11f6d4c6bc466e8f2
[repro] Ant options: "-Dargs=-XX:+UseCompressedOops -XX:+UnlockExperimentalVMOptions -XX:+UseShenandoahGC"
[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] PeerSyncReplicationTest
[repro] TestSimTriggerIntegration
[repro] ant compile-test
[...truncated 2471 lines...]
[repro] ant test-nocompile -Dtests.dups=5 -Dtests.maxfailures=10 -Dtests.class="*.PeerSyncReplicationTest|*.TestSimTriggerIntegration" -Dtests.showOutput=onerror "-Dargs=-XX:+UseCompressedOops -XX:+UnlockExperimentalVMOptions -XX:+UseShenandoahGC" -Dtests.seed=51F1CBB5FD0B5B7C -Dtests.slow=true -Dtests.locale=sr-Latn -Dtests.timezone=America/Merida -Dtests.asserts=true -Dtests.file.encoding=ISO-8859-1
[...truncated 162 lines...]
[repro] Failures w/original seeds:
[repro] 0/5 failed: org.apache.solr.cloud.PeerSyncReplicationTest
[repro] 0/5 failed: org.apache.solr.cloud.autoscaling.sim.TestSimTriggerIntegration
[repro] Exiting with code 0
[...truncated 78 lines...]