You are viewing a plain text version of this content. The canonical link for it is here.
Posted to dev@lucene.apache.org by Policeman Jenkins Server <je...@thetaphi.de> on 2018/01/06 14:36:54 UTC
[JENKINS] Lucene-Solr-7.x-Solaris (64bit/jdk1.8.0) - Build # 377 -
Still Unstable!
Build: https://jenkins.thetaphi.de/job/Lucene-Solr-7.x-Solaris/377/
Java: 64bit/jdk1.8.0 -XX:-UseCompressedOops -XX:+UseConcMarkSweepGC
1 tests failed.
FAILED: org.apache.solr.cloud.autoscaling.sim.TestTriggerIntegration.testCooldown
Error Message:
Stack Trace:
java.lang.NullPointerException
at __randomizedtesting.SeedInfo.seed([A494A0B444D55030:952ACD503A7F25C2]:0)
at org.apache.solr.cloud.autoscaling.sim.TestTriggerIntegration.testCooldown(TestTriggerIntegration.java:1084)
at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
at java.lang.reflect.Method.invoke(Method.java:498)
at com.carrotsearch.randomizedtesting.RandomizedRunner.invoke(RandomizedRunner.java:1737)
at com.carrotsearch.randomizedtesting.RandomizedRunner$8.evaluate(RandomizedRunner.java:934)
at com.carrotsearch.randomizedtesting.RandomizedRunner$9.evaluate(RandomizedRunner.java:970)
at com.carrotsearch.randomizedtesting.RandomizedRunner$10.evaluate(RandomizedRunner.java:984)
at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:57)
at org.apache.lucene.util.TestRuleSetupTeardownChained$1.evaluate(TestRuleSetupTeardownChained.java:49)
at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:45)
at org.apache.lucene.util.TestRuleThreadAndTestName$1.evaluate(TestRuleThreadAndTestName.java:48)
at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:64)
at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:47)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:368)
at com.carrotsearch.randomizedtesting.ThreadLeakControl.forkTimeoutingTask(ThreadLeakControl.java:817)
at com.carrotsearch.randomizedtesting.ThreadLeakControl$3.evaluate(ThreadLeakControl.java:468)
at com.carrotsearch.randomizedtesting.RandomizedRunner.runSingleTest(RandomizedRunner.java:943)
at com.carrotsearch.randomizedtesting.RandomizedRunner$5.evaluate(RandomizedRunner.java:829)
at com.carrotsearch.randomizedtesting.RandomizedRunner$6.evaluate(RandomizedRunner.java:879)
at com.carrotsearch.randomizedtesting.RandomizedRunner$7.evaluate(RandomizedRunner.java:890)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:57)
at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:45)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at org.apache.lucene.util.TestRuleStoreClassName$1.evaluate(TestRuleStoreClassName.java:41)
at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:40)
at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:40)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at org.apache.lucene.util.TestRuleAssertionsRequired$1.evaluate(TestRuleAssertionsRequired.java:53)
at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:47)
at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:64)
at org.apache.lucene.util.TestRuleIgnoreTestSuites$1.evaluate(TestRuleIgnoreTestSuites.java:54)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:368)
at java.lang.Thread.run(Thread.java:748)
Build Log:
[...truncated 12207 lines...]
[junit4] Suite: org.apache.solr.cloud.autoscaling.sim.TestTriggerIntegration
[junit4] 2> Creating dataDir: /export/home/jenkins/workspace/Lucene-Solr-7.x-Solaris/solr/build/solr-core/test/J0/temp/solr.cloud.autoscaling.sim.TestTriggerIntegration_A494A0B444D55030-001/init-core-data-001
[junit4] 2> 1296227 WARN (SUITE-TestTriggerIntegration-seed#[A494A0B444D55030]-worker) [ ] o.a.s.SolrTestCaseJ4 startTrackingSearchers: numOpens=32 numCloses=32
[junit4] 2> 1296227 INFO (SUITE-TestTriggerIntegration-seed#[A494A0B444D55030]-worker) [ ] o.a.s.SolrTestCaseJ4 Using PointFields (NUMERIC_POINTS_SYSPROP=true) w/NUMERIC_DOCVALUES_SYSPROP=false
[junit4] 2> 1296229 INFO (SUITE-TestTriggerIntegration-seed#[A494A0B444D55030]-worker) [ ] o.a.s.SolrTestCaseJ4 Randomized ssl (false) and clientAuth (false) via: @org.apache.solr.util.RandomizeSSL(reason=, value=NaN, ssl=NaN, clientAuth=NaN)
[junit4] 2> 1296229 INFO (SUITE-TestTriggerIntegration-seed#[A494A0B444D55030]-worker) [ ] o.a.s.SolrTestCaseJ4 SecureRandom sanity checks: test.solr.allowed.securerandom=null & java.security.egd=file:/dev/./urandom
[junit4] 2> 1296230 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Adding .autoAddReplicas trigger
[junit4] 2> 1296231 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Refreshing /autoscaling.json with znode version 0
[junit4] 2> 1296231 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.NodeLostTrigger Initial livenodes: [127.0.0.1:10006_solr, 127.0.0.1:10005_solr]
[junit4] 2> 1296231 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Current znodeVersion 0, lastZnodeVersion -1
[junit4] 2> 1296231 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Processed trigger updates upto znodeVersion 0
[junit4] 2> 1296231 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread -- clean old nodeAdded markers
[junit4] 2> 1296231 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Current znodeVersion 0, lastZnodeVersion 0
[junit4] 2> 1296231 DEBUG (ScheduledTrigger-2144-thread-1) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 2
[junit4] 2> 1296234 INFO (TEST-TestTriggerIntegration.testNodeLostTrigger-seed#[A494A0B444D55030]) [ ] o.a.s.SolrTestCaseJ4 ###Starting testNodeLostTrigger
[junit4] 2> 1296234 DEBUG (TEST-TestTriggerIntegration.testNodeLostTrigger-seed#[A494A0B444D55030]) [ ] o.a.s.c.a.OverseerTriggerThread Refreshing /autoscaling.json with znode version 1
[junit4] 2> 1296234 INFO (TEST-TestTriggerIntegration.testNodeLostTrigger-seed#[A494A0B444D55030]) [ ] o.a.s.c.a.s.SimCloudManager === Restarting OverseerTriggerThread and clearing object cache...
[junit4] 2> 1296234 WARN (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread OverseerTriggerThread woken up but we are closed, exiting.
[junit4] 2> 1296235 DEBUG (TEST-TestTriggerIntegration.testNodeLostTrigger-seed#[A494A0B444D55030]) [ ] o.a.s.c.a.OverseerTriggerThread OverseerTriggerThread has been closed explicitly
[junit4] 2> 1296236 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Adding .autoAddReplicas trigger
[junit4] 2> 1296236 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Refreshing /autoscaling.json with znode version 2
[junit4] 2> 1296236 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.NodeLostTrigger Initial livenodes: [127.0.0.1:10006_solr, 127.0.0.1:10005_solr]
[junit4] 2> 1296236 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Current znodeVersion 2, lastZnodeVersion -1
[junit4] 2> 1296236 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Processed trigger updates upto znodeVersion 2
[junit4] 2> 1296236 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread -- clean old nodeAdded markers
[junit4] 2> 1296236 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Current znodeVersion 2, lastZnodeVersion 2
[junit4] 2> 1296236 DEBUG (ScheduledTrigger-2147-thread-1) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 2
[junit4] 2> 1296265 DEBUG (ScheduledTrigger-2147-thread-1) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 2
[junit4] 2> 1296302 DEBUG (ScheduledTrigger-2147-thread-1) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 2
[junit4] 2> 1296325 DEBUG (ScheduledTrigger-2147-thread-1) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 2
[junit4] 2> 1296339 DEBUG (simCloudManagerPool-2146-thread-1) [ ] o.a.s.c.a.AutoScalingHandler Verified autoscaling configuration
[junit4] 2> 1296339 DEBUG (simCloudManagerPool-2146-thread-1) [ ] o.a.s.c.a.OverseerTriggerThread Refreshing /autoscaling.json with znode version 3
[junit4] 2> 1296340 DEBUG (simCloudManagerPool-2146-thread-1) [ ] o.a.s.c.a.NodeLostTrigger Initial livenodes: [127.0.0.1:10006_solr, 127.0.0.1:10005_solr]
[junit4] 2> 1296340 DEBUG (simCloudManagerPool-2146-thread-1) [ ] o.a.s.c.a.NodeLostTrigger Initial livenodes: [127.0.0.1:10006_solr, 127.0.0.1:10005_solr]
[junit4] 2> 1296340 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Processed trigger updates upto znodeVersion 3
[junit4] 2> 1296340 INFO (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.s.TestTriggerIntegration TestTriggerAction init
[junit4] 2> 1296340 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread -- clean old nodeAdded markers
[junit4] 2> 1296341 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Current znodeVersion 3, lastZnodeVersion 3
[junit4] 2> 1296341 DEBUG (ScheduledTrigger-2147-thread-4) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: node_lost_trigger with currently live nodes: 2
[junit4] 2> 1296350 DEBUG (ScheduledTrigger-2147-thread-4) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 1
[junit4] 2> 1296350 DEBUG (ScheduledTrigger-2147-thread-4) [ ] o.a.s.c.a.NodeLostTrigger Tracking lost node: 127.0.0.1:10006_solr
[junit4] 2> 1296361 DEBUG (ScheduledTrigger-2147-thread-1) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: node_lost_trigger with currently live nodes: 1
[junit4] 2> 1296361 DEBUG (ScheduledTrigger-2147-thread-1) [ ] o.a.s.c.a.NodeLostTrigger Tracking lost node: 127.0.0.1:10006_solr
[junit4] 2> 1296372 DEBUG (ScheduledTrigger-2147-thread-1) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 1
[junit4] 2> 1296383 DEBUG (ScheduledTrigger-2147-thread-1) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: node_lost_trigger with currently live nodes: 1
[junit4] 2> 1296383 DEBUG (ScheduledTrigger-2147-thread-1) [ ] o.a.s.c.a.NodeLostTrigger NodeLostTrigger firing registered processor for lost nodes: [127.0.0.1:10006_solr]
[junit4] 2> 1296383 DEBUG (ScheduledTrigger-2147-thread-1) [ ] o.a.s.c.a.ScheduledTriggers ++++++++ Cooldown inactive - processing event: {
[junit4] 2> "id":"aaae4689ea4bdT9cexyk69jg0ohfkc8shjh1tvq",
[junit4] 2> "source":"node_lost_trigger",
[junit4] 2> "eventTime":3002647751599293,
[junit4] 2> "eventType":"NODELOST",
[junit4] 2> "properties":{
[junit4] 2> "eventTimes":[3002647751599293],
[junit4] 2> "nodeNames":["127.0.0.1:10006_solr"]}}
[junit4] 2> 1296394 DEBUG (AutoscalingActionExecutor-2148-thread-1) [ ] o.a.s.c.a.ScheduledTriggers -- processing actions for {
[junit4] 2> "id":"aaae4689ea4bdT9cexyk69jg0ohfkc8shjh1tvq",
[junit4] 2> "source":"node_lost_trigger",
[junit4] 2> "eventTime":3002647751599293,
[junit4] 2> "eventType":"NODELOST",
[junit4] 2> "properties":{
[junit4] 2> "eventTimes":[3002647751599293],
[junit4] 2> "_enqueue_time_":3002648827921343,
[junit4] 2> "nodeNames":["127.0.0.1:10006_solr"]}}
[junit4] 2> 1296403 DEBUG (simCloudManagerPool-2146-thread-3) [ ] o.a.s.c.a.AutoScalingHandler Verified autoscaling configuration
[junit4] 2> 1296403 DEBUG (simCloudManagerPool-2146-thread-3) [ ] o.a.s.c.a.OverseerTriggerThread Refreshing /autoscaling.json with znode version 4
[junit4] 2> 1296403 DEBUG (simCloudManagerPool-2146-thread-3) [ ] o.a.s.c.a.NodeLostTrigger Initial livenodes: [127.0.0.1:10005_solr]
[junit4] 2> 1296404 DEBUG (simCloudManagerPool-2146-thread-3) [ ] o.a.s.c.a.NodeLostTrigger Initial livenodes: [127.0.0.1:10005_solr]
[junit4] 2> 1296404 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Processed trigger updates upto znodeVersion 4
[junit4] 2> 1296404 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread -- clean old nodeAdded markers
[junit4] 2> 1296404 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Current znodeVersion 4, lastZnodeVersion 4
[junit4] 2> 1296414 DEBUG (AutoscalingActionExecutor-2148-thread-1) [ ] o.a.s.c.a.ScheduledTriggers -- processing took 991 ms for event id=aaae4689ea4bdT9cexyk69jg0ohfkc8shjh1tvq
[junit4] 2> 1296414 DEBUG (ScheduledTrigger-2147-thread-4) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 1
[junit4] 2> 1296414 DEBUG (ScheduledTrigger-2147-thread-4) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: node_lost_trigger with currently live nodes: 1
[junit4] 2> 1296440 DEBUG (ScheduledTrigger-2147-thread-4) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 1
[junit4] 2> 1296447 INFO (TEST-TestTriggerIntegration.testNodeLostTrigger-seed#[A494A0B444D55030]) [ ] o.a.s.SolrTestCaseJ4 ###Ending testNodeLostTrigger
[junit4] 2> 1296447 INFO (TEST-TestTriggerIntegration.testNodeLostTrigger-seed#[A494A0B444D55030]) [ ] o.a.s.c.a.s.SimSolrCloudTestCase
[junit4] 2>
[junit4] 2> 1296447 INFO (TEST-TestTriggerIntegration.testNodeLostTrigger-seed#[A494A0B444D55030]) [ ] o.a.s.c.a.s.SimSolrCloudTestCase #############################################
[junit4] 2> 1296447 INFO (TEST-TestTriggerIntegration.testNodeLostTrigger-seed#[A494A0B444D55030]) [ ] o.a.s.c.a.s.SimSolrCloudTestCase ############ FINAL CLUSTER STATS ############
[junit4] 2> 1296447 INFO (TEST-TestTriggerIntegration.testNodeLostTrigger-seed#[A494A0B444D55030]) [ ] o.a.s.c.a.s.SimSolrCloudTestCase #############################################
[junit4] 2>
[junit4] 2> 1296447 INFO (TEST-TestTriggerIntegration.testNodeLostTrigger-seed#[A494A0B444D55030]) [ ] o.a.s.c.a.s.SimSolrCloudTestCase ## Live nodes: 1
[junit4] 2> 1296447 INFO (TEST-TestTriggerIntegration.testNodeLostTrigger-seed#[A494A0B444D55030]) [ ] o.a.s.c.a.s.SimSolrCloudTestCase ## Empty nodes: 1
[junit4] 2> 1296447 INFO (TEST-TestTriggerIntegration.testNodeLostTrigger-seed#[A494A0B444D55030]) [ ] o.a.s.c.a.s.SimSolrCloudTestCase ## Dead nodes: 1
[junit4] 2> 1296447 INFO (TEST-TestTriggerIntegration.testNodeLostTrigger-seed#[A494A0B444D55030]) [ ] o.a.s.c.a.s.SimSolrCloudTestCase ## 127.0.0.1:10006_solr
[junit4] 2> 1296447 INFO (TEST-TestTriggerIntegration.testNodeLostTrigger-seed#[A494A0B444D55030]) [ ] o.a.s.c.a.s.SimSolrCloudTestCase ## Collections: []
[junit4] 2> 1296447 INFO (TEST-TestTriggerIntegration.testNodeLostTrigger-seed#[A494A0B444D55030]) [ ] o.a.s.c.a.s.SimSolrCloudTestCase ## Max replicas per node: 0
[junit4] 2> 1296447 INFO (TEST-TestTriggerIntegration.testNodeLostTrigger-seed#[A494A0B444D55030]) [ ] o.a.s.c.a.s.SimSolrCloudTestCase ## Min replicas per node: 0
[junit4] 2> 1296447 INFO (TEST-TestTriggerIntegration.testNodeLostTrigger-seed#[A494A0B444D55030]) [ ] o.a.s.c.a.s.SimSolrCloudTestCase ## Total replicas: 0
[junit4] 2> 1296447 INFO (TEST-TestTriggerIntegration.testNodeLostTrigger-seed#[A494A0B444D55030]) [ ] o.a.s.c.a.s.SimSolrCloudTestCase ######### Final Solr op counts ##########
[junit4] 2> 1296447 INFO (TEST-TestTriggerIntegration.testNodeLostTrigger-seed#[A494A0B444D55030]) [ ] o.a.s.c.a.s.SimSolrCloudTestCase ## - autoscaling 2
[junit4] 2> 1296447 INFO (TEST-TestTriggerIntegration.testNodeLostTrigger-seed#[A494A0B444D55030]) [ ] o.a.s.c.a.s.SimSolrCloudTestCase ## - update 2
[junit4] 2> 1296447 INFO (TEST-TestTriggerIntegration.testNodeLostTrigger-seed#[A494A0B444D55030]) [ ] o.a.s.c.a.s.SimSolrCloudTestCase ######### Autoscaling event counts ###########
[junit4] 2> 1296448 INFO (TEST-TestTriggerIntegration.testNodeLostTrigger-seed#[A494A0B444D55030]) [ ] o.a.s.c.a.s.SimSolrCloudTestCase ## * Trigger: node_lost_trigger
[junit4] 2> 1296448 INFO (TEST-TestTriggerIntegration.testNodeLostTrigger-seed#[A494A0B444D55030]) [ ] o.a.s.c.a.s.SimSolrCloudTestCase ## - STARTED 1
[junit4] 2> 1296448 INFO (TEST-TestTriggerIntegration.testNodeLostTrigger-seed#[A494A0B444D55030]) [ ] o.a.s.c.a.s.SimSolrCloudTestCase ## - SUCCEEDED 1
[junit4] 2> 1296452 INFO (TEST-TestTriggerIntegration.testEventQueue-seed#[A494A0B444D55030]) [ ] o.a.s.SolrTestCaseJ4 ###Starting testEventQueue
[junit4] 2> 1296452 DEBUG (TEST-TestTriggerIntegration.testEventQueue-seed#[A494A0B444D55030]) [ ] o.a.s.c.a.OverseerTriggerThread Refreshing /autoscaling.json with znode version 5
[junit4] 2> 1296452 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Processed trigger updates upto znodeVersion 5
[junit4] 2> 1296453 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread -- clean old nodeLost markers
[junit4] 2> 1296453 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread -- clean old nodeAdded markers
[junit4] 2> 1296453 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Current znodeVersion 5, lastZnodeVersion 5
[junit4] 2> 1296453 DEBUG (TEST-TestTriggerIntegration.testEventQueue-seed#[A494A0B444D55030]) [ ] o.a.s.c.a.s.SimNodeStateProvider - removing dead node values: 127.0.0.1:10006_solr
[junit4] 2> 1296453 INFO (TEST-TestTriggerIntegration.testEventQueue-seed#[A494A0B444D55030]) [ ] o.a.s.c.a.s.SimCloudManager === Restarting OverseerTriggerThread and clearing object cache...
[junit4] 2> 1296440 DEBUG (ScheduledTrigger-2147-thread-1) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: node_lost_trigger with currently live nodes: 1
[junit4] 2> 1296453 WARN (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread OverseerTriggerThread woken up but we are closed, exiting.
[junit4] 2> 1296453 DEBUG (TEST-TestTriggerIntegration.testEventQueue-seed#[A494A0B444D55030]) [ ] o.a.s.c.a.OverseerTriggerThread OverseerTriggerThread has been closed explicitly
[junit4] 2> 1296454 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Adding .autoAddReplicas trigger
[junit4] 2> 1296454 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Refreshing /autoscaling.json with znode version 6
[junit4] 2> 1296454 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.NodeLostTrigger Initial livenodes: [127.0.0.1:10005_solr, 127.0.0.1:10007_solr]
[junit4] 2> 1296454 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Current znodeVersion 6, lastZnodeVersion -1
[junit4] 2> 1296454 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Processed trigger updates upto znodeVersion 6
[junit4] 2> 1296455 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread -- clean old nodeAdded markers
[junit4] 2> 1296455 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Current znodeVersion 6, lastZnodeVersion 6
[junit4] 2> 1296456 DEBUG (ScheduledTrigger-2150-thread-1) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 2
[junit4] 2> 1296477 DEBUG (ScheduledTrigger-2150-thread-1) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 2
[junit4] 2> 1296501 DEBUG (ScheduledTrigger-2150-thread-1) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 2
[junit4] 2> 1296521 DEBUG (ScheduledTrigger-2150-thread-1) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 2
[junit4] 2> 1296542 DEBUG (ScheduledTrigger-2150-thread-1) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 2
[junit4] 2> 1296559 DEBUG (simCloudManagerPool-2149-thread-1) [ ] o.a.s.c.a.AutoScalingHandler Verified autoscaling configuration
[junit4] 2> 1296559 DEBUG (simCloudManagerPool-2149-thread-1) [ ] o.a.s.c.a.OverseerTriggerThread Refreshing /autoscaling.json with znode version 7
[junit4] 2> 1296559 DEBUG (simCloudManagerPool-2149-thread-1) [ ] o.a.s.c.a.NodeLostTrigger Initial livenodes: [127.0.0.1:10005_solr, 127.0.0.1:10007_solr]
[junit4] 2> 1296560 INFO (simCloudManagerPool-2149-thread-1) [ ] o.a.s.c.a.s.TestTriggerIntegration TestEventQueueAction instantiated
[junit4] 2> 1296560 DEBUG (simCloudManagerPool-2149-thread-1) [ ] o.a.s.c.a.NodeAddedTrigger Initial livenodes: [127.0.0.1:10005_solr, 127.0.0.1:10007_solr]
[junit4] 2> 1296560 DEBUG (simCloudManagerPool-2149-thread-1) [ ] o.a.s.c.a.NodeAddedTrigger NodeAddedTrigger node_added_trigger1 instantiated with properties: {event=nodeAdded, waitFor=1, actions=[{name=test, class=org.apache.solr.cloud.autoscaling.sim.TestTriggerIntegration$TestEventQueueAction}], enabled=true}
[junit4] 2> 1296560 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Processed trigger updates upto znodeVersion 7
[junit4] 2> 1296560 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.s.TestTriggerIntegration TestTriggerAction init
[junit4] 2> 1296560 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Current znodeVersion 7, lastZnodeVersion 7
[junit4] 2> 1296560 DEBUG (ScheduledTrigger-2150-thread-4) [ ] o.a.s.c.a.NodeAddedTrigger Running NodeAddedTrigger node_added_trigger1
[junit4] 2> 1296560 DEBUG (ScheduledTrigger-2150-thread-4) [ ] o.a.s.c.a.NodeAddedTrigger Found livenodes: 3
[junit4] 2> 1296560 DEBUG (ScheduledTrigger-2150-thread-4) [ ] o.a.s.c.a.NodeAddedTrigger Tracking new node: 127.0.0.1:10008_solr at time 3002657704495093
[junit4] 2> 1296566 DEBUG (ScheduledTrigger-2150-thread-2) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 3
[junit4] 2> 1296581 DEBUG (ScheduledTrigger-2150-thread-1) [ ] o.a.s.c.a.NodeAddedTrigger Running NodeAddedTrigger node_added_trigger1
[junit4] 2> 1296581 DEBUG (ScheduledTrigger-2150-thread-1) [ ] o.a.s.c.a.NodeAddedTrigger Found livenodes: 3
[junit4] 2> 1296581 DEBUG (ScheduledTrigger-2150-thread-1) [ ] o.a.s.c.a.NodeAddedTrigger NodeAddedTrigger node_added_trigger1 firing registered processor for nodes: [127.0.0.1:10008_solr] added at times [3002657704495093], now=3002658749355443
[junit4] 2> 1296581 DEBUG (ScheduledTrigger-2150-thread-1) [ ] o.a.s.c.a.ScheduledTriggers ++++++++ Cooldown inactive - processing event: {
[junit4] 2> "id":"aaae6b9dbc7f5T9cexyk69jg0ohfkc8shjh1tvt",
[junit4] 2> "source":"node_added_trigger1",
[junit4] 2> "eventTime":3002657704495093,
[junit4] 2> "eventType":"NODEADDED",
[junit4] 2> "properties":{
[junit4] 2> "eventTimes":[3002657704495093],
[junit4] 2> "nodeNames":["127.0.0.1:10008_solr"]}}
[junit4] 2> 1296582 DEBUG (AutoscalingActionExecutor-2151-thread-1) [ ] o.a.s.c.a.ScheduledTriggers -- processing actions for {
[junit4] 2> "id":"aaae6b9dbc7f5T9cexyk69jg0ohfkc8shjh1tvt",
[junit4] 2> "source":"node_added_trigger1",
[junit4] 2> "eventTime":3002657704495093,
[junit4] 2> "eventType":"NODEADDED",
[junit4] 2> "properties":{
[junit4] 2> "eventTimes":[3002657704495093],
[junit4] 2> "_enqueue_time_":3002658756249143,
[junit4] 2> "nodeNames":["127.0.0.1:10008_solr"]}}
[junit4] 2> 1296582 INFO (AutoscalingActionExecutor-2151-thread-1) [ ] o.a.s.c.a.s.TestTriggerIntegration -- event: {
[junit4] 2> "id":"aaae6b9dbc7f5T9cexyk69jg0ohfkc8shjh1tvt",
[junit4] 2> "source":"node_added_trigger1",
[junit4] 2> "eventTime":3002657704495093,
[junit4] 2> "eventType":"NODEADDED",
[junit4] 2> "properties":{
[junit4] 2> "eventTimes":[3002657704495093],
[junit4] 2> "_enqueue_time_":3002658756249143,
[junit4] 2> "nodeNames":["127.0.0.1:10008_solr"]}}
[junit4] 2> 1296583 INFO (TEST-TestTriggerIntegration.testEventQueue-seed#[A494A0B444D55030]) [ ] o.a.s.c.a.s.SimCloudManager === Restarting OverseerTriggerThread and clearing object cache...
[junit4] 2> 1296583 DEBUG (TEST-TestTriggerIntegration.testEventQueue-seed#[A494A0B444D55030]) [ ] o.a.s.c.a.OverseerTriggerThread OverseerTriggerThread has been closed explicitly
[junit4] 2> 1296583 WARN (AutoscalingActionExecutor-2151-thread-1) [ ] o.a.s.c.a.ScheduledTriggers Exception executing actions
[junit4] 2> org.apache.lucene.store.AlreadyClosedException: ScheduledTrigger node_added_trigger1 has been closed.
[junit4] 2> at org.apache.solr.cloud.autoscaling.ScheduledTriggers$ScheduledTrigger.dequeue(ScheduledTriggers.java:494)
[junit4] 2> at org.apache.solr.cloud.autoscaling.ScheduledTriggers.lambda$null$3(ScheduledTriggers.java:306)
[junit4] 2> at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511)
[junit4] 2> at java.util.concurrent.FutureTask.run(FutureTask.java:266)
[junit4] 2> at org.apache.solr.common.util.ExecutorUtil$MDCAwareThreadPoolExecutor.lambda$execute$0(ExecutorUtil.java:188)
[junit4] 2> at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)
[junit4] 2> at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
[junit4] 2> at java.lang.Thread.run(Thread.java:748)
[junit4] 2> 1296583 DEBUG (AutoscalingActionExecutor-2151-thread-1) [ ] o.a.s.c.a.ScheduledTriggers -- processing took 55 ms for event id=aaae6b9dbc7f5T9cexyk69jg0ohfkc8shjh1tvt
[junit4] 2> 1296583 WARN (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread OverseerTriggerThread woken up but we are closed, exiting.
[junit4] 2> 1296584 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Refreshing /autoscaling.json with znode version 7
[junit4] 2> 1296584 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.NodeLostTrigger Initial livenodes: [127.0.0.1:10005_solr, 127.0.0.1:10008_solr]
[junit4] 2> 1296584 INFO (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.s.TestTriggerIntegration TestEventQueueAction instantiated
[junit4] 2> 1296584 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.NodeAddedTrigger Initial livenodes: [127.0.0.1:10005_solr, 127.0.0.1:10008_solr]
[junit4] 2> 1296584 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.NodeAddedTrigger NodeAddedTrigger node_added_trigger1 instantiated with properties: {event=nodeAdded, waitFor=1, actions=[{name=test, class=org.apache.solr.cloud.autoscaling.sim.TestTriggerIntegration$TestEventQueueAction}], enabled=true}
[junit4] 2> 1296584 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Current znodeVersion 7, lastZnodeVersion -1
[junit4] 2> 1296584 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Processed trigger updates upto znodeVersion 7
[junit4] 2> 1296585 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.NodeLostTrigger Adding lost node from marker path: 127.0.0.1:10007_solr
[junit4] 2> 1296585 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.s.TestTriggerIntegration TestTriggerAction init
[junit4] 2> 1296585 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Current znodeVersion 7, lastZnodeVersion 7
[junit4] 2> 1296585 DEBUG (ScheduledTrigger-2153-thread-1) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 2
[junit4] 2> 1296585 DEBUG (ScheduledTrigger-2153-thread-1) [ ] o.a.s.c.a.NodeLostTrigger Tracking lost node: 127.0.0.1:10007_solr
[junit4] 2> 1296585 DEBUG (ScheduledTrigger-2153-thread-2) [ ] o.a.s.c.a.ScheduledTriggers ++++++++ Cooldown inactive - processing event: {
[junit4] 2> "id":"aaae6b9dbc7f5T9cexyk69jg0ohfkc8shjh1tvt",
[junit4] 2> "source":"node_added_trigger1",
[junit4] 2> "eventTime":3002657704495093,
[junit4] 2> "eventType":"NODEADDED",
[junit4] 2> "properties":{
[junit4] 2> "eventTimes":[3002657704495093],
[junit4] 2> "_dequeue_time_":3002658935684643,
[junit4] 2> "_enqueue_time_":3002658756249143,
[junit4] 2> "nodeNames":["127.0.0.1:10008_solr"],
[junit4] 2> "replaying":true}}
[junit4] 2> 1296586 DEBUG (ScheduledTrigger-2153-thread-2) [ ] o.a.s.c.a.NodeAddedTrigger Running NodeAddedTrigger node_added_trigger1
[junit4] 2> 1296586 DEBUG (ScheduledTrigger-2153-thread-2) [ ] o.a.s.c.a.NodeAddedTrigger Found livenodes: 2
[junit4] 2> 1296587 DEBUG (AutoscalingActionExecutor-2154-thread-1) [ ] o.a.s.c.a.ScheduledTriggers -- processing actions for {
[junit4] 2> "id":"aaae6b9dbc7f5T9cexyk69jg0ohfkc8shjh1tvt",
[junit4] 2> "source":"node_added_trigger1",
[junit4] 2> "eventTime":3002657704495093,
[junit4] 2> "eventType":"NODEADDED",
[junit4] 2> "properties":{
[junit4] 2> "eventTimes":[3002657704495093],
[junit4] 2> "_dequeue_time_":3002658935684643,
[junit4] 2> "_enqueue_time_":3002658756249143,
[junit4] 2> "nodeNames":["127.0.0.1:10008_solr"],
[junit4] 2> "replaying":true}}
[junit4] 2> 1296587 INFO (AutoscalingActionExecutor-2154-thread-1) [ ] o.a.s.c.a.s.TestTriggerIntegration -- event: {
[junit4] 2> "id":"aaae6b9dbc7f5T9cexyk69jg0ohfkc8shjh1tvt",
[junit4] 2> "source":"node_added_trigger1",
[junit4] 2> "eventTime":3002657704495093,
[junit4] 2> "eventType":"NODEADDED",
[junit4] 2> "properties":{
[junit4] 2> "eventTimes":[3002657704495093],
[junit4] 2> "_dequeue_time_":3002658935684643,
[junit4] 2> "_enqueue_time_":3002658756249143,
[junit4] 2> "nodeNames":["127.0.0.1:10008_solr"],
[junit4] 2> "replaying":true}}
[junit4] 2> 1296594 DEBUG (AutoscalingActionExecutor-2154-thread-1) [ ] o.a.s.c.a.ScheduledTriggers -- processing took 346 ms for event id=aaae6b9dbc7f5T9cexyk69jg0ohfkc8shjh1tvt
[junit4] 2> 1296607 DEBUG (ScheduledTrigger-2153-thread-1) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 2
[junit4] 2> 1296608 DEBUG (ScheduledTrigger-2153-thread-3) [ ] o.a.s.c.a.NodeAddedTrigger Running NodeAddedTrigger node_added_trigger1
[junit4] 2> 1296608 DEBUG (ScheduledTrigger-2153-thread-3) [ ] o.a.s.c.a.NodeAddedTrigger Found livenodes: 2
[junit4] 2> 1296637 DEBUG (ScheduledTrigger-2153-thread-1) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 2
[junit4] 2> 1296642 DEBUG (ScheduledTrigger-2153-thread-1) [ ] o.a.s.c.a.NodeAddedTrigger Running NodeAddedTrigger node_added_trigger1
[junit4] 2> 1296642 DEBUG (ScheduledTrigger-2153-thread-1) [ ] o.a.s.c.a.NodeAddedTrigger Found livenodes: 2
[junit4] 2> 1296663 DEBUG (ScheduledTrigger-2153-thread-3) [ ] o.a.s.c.a.NodeAddedTrigger Running NodeAddedTrigger node_added_trigger1
[junit4] 2> 1296664 DEBUG (ScheduledTrigger-2153-thread-3) [ ] o.a.s.c.a.NodeAddedTrigger Found livenodes: 2
[junit4] 2> 1296664 DEBUG (ScheduledTrigger-2153-thread-4) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 2
[junit4] 2> 1296684 INFO (TEST-TestTriggerIntegration.testEventQueue-seed#[A494A0B444D55030]) [ ] o.a.s.SolrTestCaseJ4 ###Ending testEventQueue
[junit4] 2> 1296684 INFO (TEST-TestTriggerIntegration.testEventQueue-seed#[A494A0B444D55030]) [ ] o.a.s.c.a.s.SimSolrCloudTestCase
[junit4] 2>
[junit4] 2> 1296684 INFO (TEST-TestTriggerIntegration.testEventQueue-seed#[A494A0B444D55030]) [ ] o.a.s.c.a.s.SimSolrCloudTestCase #############################################
[junit4] 2> 1296684 INFO (TEST-TestTriggerIntegration.testEventQueue-seed#[A494A0B444D55030]) [ ] o.a.s.c.a.s.SimSolrCloudTestCase ############ FINAL CLUSTER STATS ############
[junit4] 2> 1296684 INFO (TEST-TestTriggerIntegration.testEventQueue-seed#[A494A0B444D55030]) [ ] o.a.s.c.a.s.SimSolrCloudTestCase #############################################
[junit4] 2>
[junit4] 2> 1296684 INFO (TEST-TestTriggerIntegration.testEventQueue-seed#[A494A0B444D55030]) [ ] o.a.s.c.a.s.SimSolrCloudTestCase ## Live nodes: 2
[junit4] 2> 1296684 INFO (TEST-TestTriggerIntegration.testEventQueue-seed#[A494A0B444D55030]) [ ] o.a.s.c.a.s.SimSolrCloudTestCase ## Empty nodes: 2
[junit4] 2> 1296684 DEBUG (ScheduledTrigger-2153-thread-3) [ ] o.a.s.c.a.NodeAddedTrigger Running NodeAddedTrigger node_added_trigger1
[junit4] 2> 1296684 DEBUG (ScheduledTrigger-2153-thread-3) [ ] o.a.s.c.a.NodeAddedTrigger Found livenodes: 2
[junit4] 2> 1296684 INFO (TEST-TestTriggerIntegration.testEventQueue-seed#[A494A0B444D55030]) [ ] o.a.s.c.a.s.SimSolrCloudTestCase ## Dead nodes: 1
[junit4] 2> 1296684 INFO (TEST-TestTriggerIntegration.testEventQueue-seed#[A494A0B444D55030]) [ ] o.a.s.c.a.s.SimSolrCloudTestCase ## 127.0.0.1:10007_solr
[junit4] 2> 1296684 DEBUG (ScheduledTrigger-2153-thread-3) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 2
[junit4] 2> 1296684 INFO (TEST-TestTriggerIntegration.testEventQueue-seed#[A494A0B444D55030]) [ ] o.a.s.c.a.s.SimSolrCloudTestCase ## Collections: []
[junit4] 2> 1296684 INFO (TEST-TestTriggerIntegration.testEventQueue-seed#[A494A0B444D55030]) [ ] o.a.s.c.a.s.SimSolrCloudTestCase ## Max replicas per node: 0
[junit4] 2> 1296684 INFO (TEST-TestTriggerIntegration.testEventQueue-seed#[A494A0B444D55030]) [ ] o.a.s.c.a.s.SimSolrCloudTestCase ## Min replicas per node: 0
[junit4] 2> 1296684 INFO (TEST-TestTriggerIntegration.testEventQueue-seed#[A494A0B444D55030]) [ ] o.a.s.c.a.s.SimSolrCloudTestCase ## Total replicas: 0
[junit4] 2> 1296684 INFO (TEST-TestTriggerIntegration.testEventQueue-seed#[A494A0B444D55030]) [ ] o.a.s.c.a.s.SimSolrCloudTestCase ######### Final Solr op counts ##########
[junit4] 2> 1296684 INFO (TEST-TestTriggerIntegration.testEventQueue-seed#[A494A0B444D55030]) [ ] o.a.s.c.a.s.SimSolrCloudTestCase ## - autoscaling 1
[junit4] 2> 1296684 INFO (TEST-TestTriggerIntegration.testEventQueue-seed#[A494A0B444D55030]) [ ] o.a.s.c.a.s.SimSolrCloudTestCase ## - update 3
[junit4] 2> 1296684 INFO (TEST-TestTriggerIntegration.testEventQueue-seed#[A494A0B444D55030]) [ ] o.a.s.c.a.s.SimSolrCloudTestCase ######### Autoscaling event counts ###########
[junit4] 2> 1296684 INFO (TEST-TestTriggerIntegration.testEventQueue-seed#[A494A0B444D55030]) [ ] o.a.s.c.a.s.SimSolrCloudTestCase ## * Trigger: node_added_trigger1
[junit4] 2> 1296684 INFO (TEST-TestTriggerIntegration.testEventQueue-seed#[A494A0B444D55030]) [ ] o.a.s.c.a.s.SimSolrCloudTestCase ## - STARTED 2
[junit4] 2> 1296684 INFO (TEST-TestTriggerIntegration.testEventQueue-seed#[A494A0B444D55030]) [ ] o.a.s.c.a.s.SimSolrCloudTestCase ## - SUCCEEDED 1
[junit4] 2> 1296705 DEBUG (ScheduledTrigger-2153-thread-3) [ ] o.a.s.c.a.NodeAddedTrigger Running NodeAddedTrigger node_added_trigger1
[junit4] 2> 1296705 DEBUG (ScheduledTrigger-2153-thread-4) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 2
[junit4] 2> 1296705 DEBUG (ScheduledTrigger-2153-thread-3) [ ] o.a.s.c.a.NodeAddedTrigger Found livenodes: 2
[junit4] 2> 1296708 INFO (TEST-TestTriggerIntegration.testCooldown-seed#[A494A0B444D55030]) [ ] o.a.s.SolrTestCaseJ4 ###Starting testCooldown
[junit4] 2> 1296708 DEBUG (TEST-TestTriggerIntegration.testCooldown-seed#[A494A0B444D55030]) [ ] o.a.s.c.a.OverseerTriggerThread Refreshing /autoscaling.json with znode version 8
[junit4] 2> 1296708 DEBUG (TEST-TestTriggerIntegration.testCooldown-seed#[A494A0B444D55030]) [ ] o.a.s.c.a.s.SimNodeStateProvider - removing dead node values: 127.0.0.1:10007_solr
[junit4] 2> 1296708 INFO (TEST-TestTriggerIntegration.testCooldown-seed#[A494A0B444D55030]) [ ] o.a.s.c.a.s.SimCloudManager === Restarting OverseerTriggerThread and clearing object cache...
[junit4] 2> 1296709 DEBUG (TEST-TestTriggerIntegration.testCooldown-seed#[A494A0B444D55030]) [ ] o.a.s.c.a.OverseerTriggerThread OverseerTriggerThread has been closed explicitly
[junit4] 2> 1296710 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Adding .autoAddReplicas trigger
[junit4] 2> 1296710 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Refreshing /autoscaling.json with znode version 9
[junit4] 2> 1296710 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.NodeLostTrigger Initial livenodes: [127.0.0.1:10005_solr, 127.0.0.1:10008_solr]
[junit4] 2> 1296710 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Current znodeVersion 9, lastZnodeVersion -1
[junit4] 2> 1296710 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Processed trigger updates upto znodeVersion 9
[junit4] 2> 1296711 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread -- clean old nodeAdded markers
[junit4] 2> 1296711 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Current znodeVersion 9, lastZnodeVersion 9
[junit4] 2> 1296711 DEBUG (ScheduledTrigger-2156-thread-1) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 2
[junit4] 2> 1296717 WARN (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread OverseerTriggerThread woken up but we are closed, exiting.
[junit4] 2> 1296731 DEBUG (ScheduledTrigger-2156-thread-1) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 2
[junit4] 2> 1296751 DEBUG (ScheduledTrigger-2156-thread-1) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 2
[junit4] 2> 1296773 DEBUG (ScheduledTrigger-2156-thread-1) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 2
[junit4] 2> 1296825 DEBUG (ScheduledTrigger-2156-thread-1) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 2
[junit4] 2> 1296826 DEBUG (simCloudManagerPool-2155-thread-1) [ ] o.a.s.c.a.AutoScalingHandler Verified autoscaling configuration
[junit4] 2> 1296826 DEBUG (simCloudManagerPool-2155-thread-1) [ ] o.a.s.c.a.OverseerTriggerThread Refreshing /autoscaling.json with znode version 10
[junit4] 2> 1296827 DEBUG (simCloudManagerPool-2155-thread-1) [ ] o.a.s.c.a.NodeAddedTrigger Initial livenodes: [127.0.0.1:10005_solr, 127.0.0.1:10008_solr]
[junit4] 2> 1296827 DEBUG (simCloudManagerPool-2155-thread-1) [ ] 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.sim.TestTriggerIntegration$TestTriggerAction}], enabled=true}
[junit4] 2> 1296827 DEBUG (simCloudManagerPool-2155-thread-1) [ ] o.a.s.c.a.NodeLostTrigger Initial livenodes: [127.0.0.1:10005_solr, 127.0.0.1:10008_solr]
[junit4] 2> 1296827 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Processed trigger updates upto znodeVersion 10
[junit4] 2> 1296827 INFO (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.s.TestTriggerIntegration TestTriggerAction init
[junit4] 2> 1296827 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Current znodeVersion 10, lastZnodeVersion 10
[junit4] 2> 1296827 DEBUG (ScheduledTrigger-2156-thread-4) [ ] o.a.s.c.a.NodeAddedTrigger Running NodeAddedTrigger node_added_cooldown_trigger
[junit4] 2> 1296827 DEBUG (ScheduledTrigger-2156-thread-4) [ ] o.a.s.c.a.NodeAddedTrigger Found livenodes: 2
[junit4] 2> 1296833 DEBUG (simCloudManagerPool-2155-thread-2) [ ] o.a.s.c.a.AutoScalingHandler Verified autoscaling configuration
[junit4] 2> 1296841 DEBUG (simCloudManagerPool-2155-thread-2) [ ] o.a.s.c.a.OverseerTriggerThread Refreshing /autoscaling.json with znode version 11
[junit4] 2> 1296841 DEBUG (simCloudManagerPool-2155-thread-2) [ ] o.a.s.c.a.NodeAddedTrigger Initial livenodes: [127.0.0.1:10005_solr, 127.0.0.1:10008_solr]
[junit4] 2> 1296841 DEBUG (simCloudManagerPool-2155-thread-2) [ ] 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.sim.TestTriggerIntegration$TestTriggerAction}], enabled=true}
[junit4] 2> 1296841 DEBUG (simCloudManagerPool-2155-thread-2) [ ] o.a.s.c.a.NodeLostTrigger Initial livenodes: [127.0.0.1:10005_solr, 127.0.0.1:10008_solr]
[junit4] 2> 1296841 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Processed trigger updates upto znodeVersion 11
[junit4] 2> 1296841 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Current znodeVersion 11, lastZnodeVersion 11
[junit4] 2> 1296846 DEBUG (ScheduledTrigger-2156-thread-2) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 3
[junit4] 2> 1296848 DEBUG (ScheduledTrigger-2156-thread-1) [ ] o.a.s.c.a.NodeAddedTrigger Running NodeAddedTrigger node_added_cooldown_trigger
[junit4] 2> 1296848 DEBUG (ScheduledTrigger-2156-thread-1) [ ] o.a.s.c.a.NodeAddedTrigger Found livenodes: 3
[junit4] 2> 1296848 DEBUG (ScheduledTrigger-2156-thread-1) [ ] o.a.s.c.a.NodeAddedTrigger Tracking new node: 127.0.0.1:10009_solr at time 3002672093959943
[junit4] 2> 1296893 DEBUG (ScheduledTrigger-2156-thread-3) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 3
[junit4] 2> 1296893 DEBUG (ScheduledTrigger-2156-thread-4) [ ] o.a.s.c.a.NodeAddedTrigger Running NodeAddedTrigger node_added_cooldown_trigger
[junit4] 2> 1296893 DEBUG (ScheduledTrigger-2156-thread-4) [ ] o.a.s.c.a.NodeAddedTrigger Found livenodes: 3
[junit4] 2> 1296893 DEBUG (ScheduledTrigger-2156-thread-4) [ ] o.a.s.c.a.NodeAddedTrigger NodeAddedTrigger node_added_cooldown_trigger firing registered processor for nodes: [127.0.0.1:10009_solr] added at times [3002672093959943], now=3002674356077593
[junit4] 2> 1296894 DEBUG (ScheduledTrigger-2156-thread-4) [ ] o.a.s.c.a.ScheduledTriggers ++++++++ Cooldown inactive - processing event: {
[junit4] 2> "id":"aaaea13899707T9cexyk69jg0ohfkc8shjh1tvx",
[junit4] 2> "source":"node_added_cooldown_trigger",
[junit4] 2> "eventTime":3002672093959943,
[junit4] 2> "eventType":"NODEADDED",
[junit4] 2> "properties":{
[junit4] 2> "eventTimes":[3002672093959943],
[junit4] 2> "nodeNames":["127.0.0.1:10009_solr"]}}
[junit4] 2> 1296894 DEBUG (AutoscalingActionExecutor-2157-thread-1) [ ] o.a.s.c.a.ScheduledTriggers -- processing actions for {
[junit4] 2> "id":"aaaea13899707T9cexyk69jg0ohfkc8shjh1tvx",
[junit4] 2> "source":"node_added_cooldown_trigger",
[junit4] 2> "eventTime":3002672093959943,
[junit4] 2> "eventType":"NODEADDED",
[junit4] 2> "properties":{
[junit4] 2> "eventTimes":[3002672093959943],
[junit4] 2> "_enqueue_time_":3002674367186143,
[junit4] 2> "nodeNames":["127.0.0.1:10009_solr"]}}
[junit4] 2> 1296930 INFO (TEST-TestTriggerIntegration.testCooldown-seed#[A494A0B444D55030]) [ ] o.a.s.SolrTestCaseJ4 ###Ending testCooldown
[junit4] 2> 1296930 INFO (TEST-TestTriggerIntegration.testCooldown-seed#[A494A0B444D55030]) [ ] o.a.s.c.a.s.SimSolrCloudTestCase
[junit4] 2>
[junit4] 2> 1296930 INFO (TEST-TestTriggerIntegration.testCooldown-seed#[A494A0B444D55030]) [ ] o.a.s.c.a.s.SimSolrCloudTestCase #############################################
[junit4] 2> 1296930 INFO (TEST-TestTriggerIntegration.testCooldown-seed#[A494A0B444D55030]) [ ] o.a.s.c.a.s.SimSolrCloudTestCase ############ FINAL CLUSTER STATS ############
[junit4] 2> 1296930 INFO (TEST-TestTriggerIntegration.testCooldown-seed#[A494A0B444D55030]) [ ] o.a.s.c.a.s.SimSolrCloudTestCase #############################################
[junit4] 2>
[junit4] 2> 1296930 INFO (TEST-TestTriggerIntegration.testCooldown-seed#[A494A0B444D55030]) [ ] o.a.s.c.a.s.SimSolrCloudTestCase ## Live nodes: 3
[junit4] 2> 1296930 INFO (TEST-TestTriggerIntegration.testCooldown-seed#[A494A0B444D55030]) [ ] o.a.s.c.a.s.SimSolrCloudTestCase ## Empty nodes: 3
[junit4] 2> 1296930 INFO (TEST-TestTriggerIntegration.testCooldown-seed#[A494A0B444D55030]) [ ] o.a.s.c.a.s.SimSolrCloudTestCase ## Dead nodes: 0
[junit4] 2> 1296930 INFO (TEST-TestTriggerIntegration.testCooldown-seed#[A494A0B444D55030]) [ ] o.a.s.c.a.s.SimSolrCloudTestCase ## Collections: []
[junit4] 2> 1296930 INFO (TEST-TestTriggerIntegration.testCooldown-seed#[A494A0B444D55030]) [ ] o.a.s.c.a.s.SimSolrCloudTestCase ## Max replicas per node: 0
[junit4] 2> 1296930 INFO (TEST-TestTriggerIntegration.testCooldown-seed#[A494A0B444D55030]) [ ] o.a.s.c.a.s.SimSolrCloudTestCase ## Min replicas per node: 0
[junit4] 2> 1296930 INFO (TEST-TestTriggerIntegration.testCooldown-seed#[A494A0B444D55030]) [ ] o.a.s.c.a.s.SimSolrCloudTestCase ## Total replicas: 0
[junit4] 2> 1296930 INFO (TEST-TestTriggerIntegration.testCooldown-seed#[A494A0B444D55030]) [ ] o.a.s.c.a.s.SimSolrCloudTestCase ######### Final Solr op counts ##########
[junit4] 2> 1296930 INFO (TEST-TestTriggerIntegration.testCooldown-seed#[A494A0B444D55030]) [ ] o.a.s.c.a.s.SimSolrCloudTestCase ## - autoscaling 2
[junit4] 2> 1296930 INFO (TEST-TestTriggerIntegration.testCooldown-seed#[A494A0B444D55030]) [ ] o.a.s.c.a.s.SimSolrCloudTestCase ## - update 1
[junit4] 2> 1296930 INFO (TEST-TestTriggerIntegration.testCooldown-seed#[A494A0B444D55030]) [ ] o.a.s.c.a.s.SimSolrCloudTestCase ######### Autoscaling event counts ###########
[junit4] 2> 1296930 INFO (TEST-TestTriggerIntegration.testCooldown-seed#[A494A0B444D55030]) [ ] o.a.s.c.a.s.SimSolrCloudTestCase ## * Trigger: node_added_cooldown_trigger
[junit4] 2> 1296930 INFO (TEST-TestTriggerIntegration.testCooldown-seed#[A494A0B444D55030]) [ ] o.a.s.c.a.s.SimSolrCloudTestCase ## - STARTED 1
[junit4] 2> 1296932 DEBUG (AutoscalingActionExecutor-2157-thread-1) [ ] o.a.s.c.a.ScheduledTriggers -- processing took 1874 ms for event id=aaaea13899707T9cexyk69jg0ohfkc8shjh1tvx
[junit4] 2> NOTE: reproduce with: ant test -Dtestcase=TestTriggerIntegration -Dtests.method=testCooldown -Dtests.seed=A494A0B444D55030 -Dtests.slow=true -Dtests.locale=ar-YE -Dtests.timezone=America/Bahia -Dtests.asserts=true -Dtests.file.encoding=UTF-8
[junit4] ERROR 0.25s J0 | TestTriggerIntegration.testCooldown <<<
[junit4] > Throwable #1: java.lang.NullPointerException
[junit4] > at __randomizedtesting.SeedInfo.seed([A494A0B444D55030:952ACD503A7F25C2]:0)
[junit4] > at org.apache.solr.cloud.autoscaling.sim.TestTriggerIntegration.testCooldown(TestTriggerIntegration.java:1084)
[junit4] > at java.lang.Thread.run(Thread.java:748)
[junit4] 2> 1296947 INFO (TEST-TestTriggerIntegration.testTriggerThrottling-seed#[A494A0B444D55030]) [ ] o.a.s.SolrTestCaseJ4 ###Starting testTriggerThrottling
[junit4] 2> 1296947 DEBUG (TEST-TestTriggerIntegration.testTriggerThrottling-seed#[A494A0B444D55030]) [ ] o.a.s.c.a.OverseerTriggerThread Refreshing /autoscaling.json with znode version 12
[junit4] 2> 1296948 INFO (TEST-TestTriggerIntegration.testTriggerThrottling-seed#[A494A0B444D55030]) [ ] o.a.s.c.a.s.SimCloudManager === Restarting OverseerTriggerThread and clearing object cache...
[junit4] 2> 1296948 DEBUG (TEST-TestTriggerIntegration.testTriggerThrottling-seed#[A494A0B444D55030]) [ ] o.a.s.c.a.OverseerTriggerThread OverseerTriggerThread has been closed explicitly
[junit4] 2> 1296949 WARN (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread OverseerTriggerThread woken up but we are closed, exiting.
[junit4] 2> 1296949 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Adding .autoAddReplicas trigger
[junit4] 2> 1296949 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Refreshing /autoscaling.json with znode version 13
[junit4] 2> 1296949 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.NodeLostTrigger Initial livenodes: [127.0.0.1:10005_solr, 127.0.0.1:10009_solr]
[junit4] 2> 1296949 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Current znodeVersion 13, lastZnodeVersion -1
[junit4] 2> 1296949 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Processed trigger updates upto znodeVersion 13
[junit4] 2> 1296949 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread -- clean old nodeAdded markers
[junit4] 2> 1296949 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Current znodeVersion 13, lastZnodeVersion 13
[junit4] 2> 1296949 DEBUG (ScheduledTrigger-2159-thread-1) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 2
[junit4] 2> 1296970 DEBUG (ScheduledTrigger-2159-thread-1) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 2
[junit4] 2> 1296991 DEBUG (ScheduledTrigger-2159-thread-2) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 2
[junit4] 2> 1297011 DEBUG (ScheduledTrigger-2159-thread-2) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 2
[junit4] 2> 1297034 DEBUG (ScheduledTrigger-2159-thread-2) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 2
[junit4] 2> 1297054 DEBUG (simCloudManagerPool-2158-thread-1) [ ] o.a.s.c.a.AutoScalingHandler Verified autoscaling configuration
[junit4] 2> 1297054 DEBUG (simCloudManagerPool-2158-thread-1) [ ] o.a.s.c.a.OverseerTriggerThread Refreshing /autoscaling.json with znode version 14
[junit4] 2> 1297054 DEBUG (ScheduledTrigger-2159-thread-2) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 2
[junit4] 2> 1297055 DEBUG (simCloudManagerPool-2158-thread-1) [ ] o.a.s.c.a.NodeLostTrigger Initial livenodes: [127.0.0.1:10005_solr, 127.0.0.1:10009_solr]
[junit4] 2> 1297055 DEBUG (simCloudManagerPool-2158-thread-1) [ ] o.a.s.c.a.NodeAddedTrigger Initial livenodes: [127.0.0.1:10005_solr, 127.0.0.1:10009_solr]
[junit4] 2> 1297055 DEBUG (simCloudManagerPool-2158-thread-1) [ ] 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.TestTriggerIntegration$ThrottlingTesterAction}], enabled=true}
[junit4] 2> 1297055 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Processed trigger updates upto znodeVersion 14
[junit4] 2> 1297055 INFO (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.s.TestTriggerIntegration TestTriggerAction init
[junit4] 2> 1297055 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Current znodeVersion 14, lastZnodeVersion 14
[junit4] 2> 1297055 DEBUG (ScheduledTrigger-2159-thread-3) [ ] o.a.s.c.a.NodeAddedTrigger Running NodeAddedTrigger node_added_trigger1
[junit4] 2> 1297055 DEBUG (ScheduledTrigger-2159-thread-3) [ ] o.a.s.c.a.NodeAddedTrigger Found livenodes: 2
[junit4] 2> 1297056 DEBUG (simCloudManagerPool-2158-thread-2) [ ] o.a.s.c.a.AutoScalingHandler Verified autoscaling configuration
[junit4] 2> 1297056 DEBUG (simCloudManagerPool-2158-thread-2) [ ] o.a.s.c.a.OverseerTriggerThread Refreshing /autoscaling.json with znode version 15
[junit4] 2> 1297056 DEBUG (simCloudManagerPool-2158-thread-2) [ ] o.a.s.c.a.NodeAddedTrigger Initial livenodes: [127.0.0.1:10005_solr, 127.0.0.1:10009_solr]
[junit4] 2> 1297056 DEBUG (simCloudManagerPool-2158-thread-2) [ ] 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.TestTriggerIntegration$ThrottlingTesterAction}], enabled=true}
[junit4] 2> 1297056 DEBUG (simCloudManagerPool-2158-thread-2) [ ] o.a.s.c.a.NodeLostTrigger Initial livenodes: [127.0.0.1:10005_solr, 127.0.0.1:10009_solr]
[junit4] 2> 1297056 DEBUG (simCloudManagerPool-2158-thread-2) [ ] o.a.s.c.a.NodeAddedTrigger Initial livenodes: [127.0.0.1:10005_solr, 127.0.0.1:10009_solr]
[junit4] 2> 1297056 DEBUG (simCloudManagerPool-2158-thread-2) [ ] 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.TestTriggerIntegration$ThrottlingTesterAction}], enabled=true}
[junit4] 2> 1297061 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Processed trigger updates upto znodeVersion 15
[junit4] 2> 1297061 INFO (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.s.TestTriggerIntegration TestTriggerAction init
[junit4] 2> 1297062 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Current znodeVersion 15, lastZnodeVersion 15
[junit4] 2> 1297062 DEBUG (ScheduledTrigger-2159-thread-2) [ ] o.a.s.c.a.NodeAddedTrigger Running NodeAddedTrigger node_added_trigger2
[junit4] 2> 1297062 DEBUG (ScheduledTrigger-2159-thread-2) [ ] o.a.s.c.a.NodeAddedTrigger Found livenodes: 2
[junit4] 2> 1297075 DEBUG (ScheduledTrigger-2159-thread-3) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 3
[junit4] 2> 1297075 DEBUG (ScheduledTrigger-2159-thread-3) [ ] o.a.s.c.a.NodeAddedTrigger Running NodeAddedTrigger node_added_trigger1
[junit4] 2> 1297075 DEBUG (ScheduledTrigger-2159-thread-3) [ ] o.a.s.c.a.NodeAddedTrigger Found livenodes: 3
[junit4] 2> 1297075 DEBUG (ScheduledTrigger-2159-thread-3) [ ] o.a.s.c.a.NodeAddedTrigger Tracking new node: 127.0.0.1:10010_solr at time 3002683462120193
[junit4] 2> 1297075 DEBUG (ScheduledTrigger-2159-thread-3) [ ] o.a.s.c.a.NodeAddedTrigger NodeAddedTrigger node_added_trigger1 firing registered processor for nodes: [127.0.0.1:10010_solr] added at times [3002683462120193], now=3002683463929043
[junit4] 2> 1297076 DEBUG (ScheduledTrigger-2159-thread-3) [ ] o.a.s.c.a.ScheduledTriggers ++++++++ Cooldown inactive - processing event: {
[junit4] 2> "id":"aaaecb921f301T9cexyk69jg0ohfkc8shjh1tw0",
[junit4] 2> "source":"node_added_trigger1",
[junit4] 2> "eventTime":3002683462120193,
[junit4] 2> "eventType":"NODEADDED",
[junit4] 2> "properties":{
[junit4] 2> "eventTimes":[3002683462120193],
[junit4] 2> "nodeNames":["127.0.0.1:10010_solr"]}}
[junit4] 2> 1297078 DEBUG (AutoscalingActionExecutor-2160-thread-1) [ ] o.a.s.c.a.ScheduledTriggers -- processing actions for {
[junit4] 2> "id":"aaaecb921f301T9cexyk69jg0ohfkc8shjh1tw0",
[junit4] 2> "source":"node_added_trigger1",
[junit4] 2> "eventTime":3002683462120193,
[junit4] 2> "eventType":"NODEADDED",
[junit4] 2> "properties":{
[junit4] 2> "eventTimes":[3002683462120193],
[junit4] 2> "_enqueue_time_":3002683469805243,
[junit4] 2> "nodeNames":["127.0.0.1:10010_solr"]}}
[junit4] 2> 1297079 INFO (AutoscalingActionExecutor-2160-thread-1) [ ] o.a.s.c.a.s.TestTriggerIntegration action executed from node_added_trigger1
[junit4] 2> 1297080 DEBUG (AutoscalingActionExecutor-2160-thread-1) [ ] o.a.s.c.a.ScheduledTriggers -- processing took 105 ms for event id=aaaecb921f301T9cexyk69jg0ohfkc8shjh1tw0
[junit4] 2> 1297083 DEBUG (ScheduledTrigger-2159-thread-2) [ ] o.a.s.c.a.NodeAddedTrigger Running NodeAddedTrigger node_added_trigger2
[junit4] 2> 1297083 DEBUG (ScheduledTrigger-2159-thread-2) [ ] o.a.s.c.a.NodeAddedTrigger Found livenodes: 3
[junit4] 2> 1297083 DEBUG (ScheduledTrigger-2159-thread-2) [ ] o.a.s.c.a.NodeAddedTrigger Tracking new node: 127.0.0.1:10010_solr at time 3002683859922093
[junit4] 2> 1297083 DEBUG (ScheduledTrigger-2159-thread-2) [ ] o.a.s.c.a.NodeAddedTrigger NodeAddedTrigger node_added_trigger2 firing registered processor for nodes: [127.0.0.1:10010_solr] added at times [3002683859922093], now=3002683863215243
[junit4] 2> 1297084 DEBUG (ScheduledTrigger-2159-thread-2) [ ] o.a.s.c.a.ScheduledTriggers -------- Cooldown period - rejecting event: {
[junit4] 2> "id":"aaaecd0d7ecadT9cexyk69jg0ohfkc8shjh1tw3",
[junit4] 2> "source":"node_added_trigger2",
[junit4] 2> "eventTime":3002683859922093,
[junit4] 2> "eventType":"NODEADDED",
[junit4] 2> "properties":{
[junit4] 2> "eventTimes":[3002683859922093],
[junit4] 2> "nodeNames":["127.0.0.1:10010_solr"]}}
[junit4] 2> 1297096 DEBUG (ScheduledTrigger-2159-thread-4) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 3
[junit4] 2> 1297099 DEBUG (ScheduledTrigger-2159-thread-4) [ ] o.a.s.c.a.NodeAddedTrigger Running NodeAddedTrigger node_added_trigger1
[junit4] 2> 1297099 DEBUG (ScheduledTrigger-2159-thread-4) [ ] o.a.s.c.a.NodeAddedTrigger Found livenodes: 3
[junit4] 2> 1297110 DEBUG (ScheduledTrigger-2159-thread-4) [ ] o.a.s.c.a.NodeAddedTrigger Running NodeAddedTrigger node_added_trigger2
[junit4] 2> 1297110 DEBUG (ScheduledTrigger-2159-thread-4) [ ] o.a.s.c.a.NodeAddedTrigger Found livenodes: 3
[junit4] 2> 1297110 DEBUG (ScheduledTrigger-2159-thread-4) [ ] o.a.s.c.a.NodeAddedTrigger NodeAddedTrigger node_added_trigger2 firing registered processor for nodes: [127.0.0.1:10010_solr] added at times [3002683859922093], now=3002685195938593
[junit4] 2> 1297110 DEBUG (ScheduledTrigger-2159-thread-4) [ ] o.a.s.c.a.ScheduledTriggers -------- Cooldown period - rejecting event: {
[junit4] 2> "id":"aaaecd0d7ecadT9cexyk69jg0ohfkc8shjh1tw5",
[junit4] 2> "source":"node_added_trigger2",
[junit4] 2> "eventTime":3002683859922093,
[junit4] 2> "eventType":"NODEADDED",
[junit4] 2> "properties":{
[junit4] 2> "eventTimes":[3002683859922093],
[junit4] 2> "nodeNames":["127.0.0.1:10010_solr"]}}
[junit4] 2> 1297123 DEBUG (ScheduledTrigger-2159-thread-2) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 3
[junit4] 2> 1297123 DEBUG (ScheduledTrigger-2159-thread-2) [ ] o.a.s.c.a.NodeAddedTrigger Running NodeAddedTrigger node_added_trigger1
[junit4] 2> 1297123 DEBUG (ScheduledTrigger-2159-thread-2) [ ] o.a.s.c.a.NodeAddedTrigger Found livenodes: 3
[junit4] 2> 1297133 DEBUG (ScheduledTrigger-2159-thread-2) [ ] o.a.s.c.a.NodeAddedTrigger Running NodeAddedTrigger node_added_trigger2
[junit4] 2> 1297133 DEBUG (ScheduledTrigger-2159-thread-2) [ ] o.a.s.c.a.NodeAddedTrigger Found livenodes: 3
[junit4] 2> 1297133 DEBUG (ScheduledTrigger-2159-thread-2) [ ] o.a.s.c.a.NodeAddedTrigger NodeAddedTrigger node_added_trigger2 firing registered processor for nodes: [127.0.0.1:10010_solr] added at times [3002683859922093], now=3002686358596293
[junit4] 2> 1297133 DEBUG (ScheduledTrigger-2159-thread-2) [ ] o.a.s.c.a.ScheduledTriggers -------- Cooldown period - rejecting event: {
[junit4] 2> "id":"aaaecd0d7ecadT9cexyk69jg0ohfkc8shjh1tw7",
[junit4] 2> "source":"node_added_trigger2",
[junit4] 2> "eventTime":3002683859922093,
[junit4] 2> "eventType":"NODEADDED",
[junit4] 2> "properties":{
[junit4] 2> "eventTimes":[3002683859922093],
[junit4] 2> "nodeNames":["127.0.0.1:10010_solr"]}}
[junit4] 2> 1297143 DEBUG (ScheduledTrigger-2159-thread-4) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 3
[junit4] 2> 1297143 DEBUG (ScheduledTrigger-2159-thread-4) [ ] o.a.s.c.a.NodeAddedTrigger Running NodeAddedTrigger node_added_trigger1
[junit4] 2> 1297144 DEBUG (ScheduledTrigger-2159-thread-4) [ ] o.a.s.c.a.NodeAddedTrigger Found livenodes: 3
[junit4] 2> 1297159 DEBUG (ScheduledTrigger-2159-thread-4) [ ] o.a.s.c.a.NodeAddedTrigger Running NodeAddedTrigger node_added_trigger2
[junit4] 2> 1297159 DEBUG (ScheduledTrigger-2159-thread-4) [ ] o.a.s.c.a.NodeAddedTrigger Found livenodes: 3
[junit4] 2> 1297159 DEBUG (ScheduledTrigger-2159-thread-4) [ ] o.a.s.c.a.NodeAddedTrigger NodeAddedTrigger node_added_trigger2 firing registered processor for nodes: [127.0.0.1:10010_solr] added at times [3002683859922093], now=3002687626107643
[junit4] 2> 1297159 DEBUG (ScheduledTrigger-2159-thread-4) [ ] o.a.s.c.a.ScheduledTriggers -------- Cooldown period - rejecting event: {
[junit4] 2> "id":"aaaecd0d7ecadT9cexyk69jg0ohfkc8shjh1tw9",
[junit4] 2> "source":"node_added_trigger2",
[junit4] 2> "eventTime":3002683859922093,
[junit4] 2> "eventType":"NODEADDED",
[junit4] 2> "properties":{
[junit4] 2> "eventTimes":[3002683859922093],
[junit4] 2> "nodeNames":["127.0.0.1:10010_solr"]}}
[junit4] 2> 1297170 DEBUG (ScheduledTrigger-2159-thread-4) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 3
[junit4] 2> 1297170 DEBUG (ScheduledTrigger-2159-thread-4) [ ] o.a.s.c.a.NodeAddedTrigger Running NodeAddedTrigger node_added_trigger1
[junit4] 2> 1297170 DEBUG (ScheduledTrigger-2159-thread-4) [ ] o.a.s.c.a.NodeAddedTrigger Found livenodes: 3
[junit4] 2> 1297183 DEBUG (ScheduledTrigger-2159-thread-1) [ ] o.a.s.c.a.NodeAddedTrigger Running NodeAddedTrigger node_added_trigger2
[junit4] 2> 1297183 DEBUG (ScheduledTrigger-2159-thread-1) [ ] o.a.s.c.a.NodeAddedTrigger Found livenodes: 3
[junit4] 2> 1297183 DEBUG (ScheduledTrigger-2159-thread-1) [ ] o.a.s.c.a.NodeAddedTrigger NodeAddedTrigger node_added_trigger2 firing registered processor for nodes: [127.0.0.1:10010_solr] added at times [3002683859922093], now=3002688859453943
[junit4] 2> 1297183 DEBUG (ScheduledTrigger-2159-thread-1) [ ] o.a.s.c.a.ScheduledTriggers ++++++++ Cooldown inactive - processing event: {
[junit4] 2> "id":"aaaecd0d7ecadT9cexyk69jg0ohfkc8shjh1twb",
[junit4] 2> "source":"node_added_trigger2",
[junit4] 2> "eventTime":3002683859922093,
[junit4] 2> "eventType":"NODEADDED",
[junit4] 2> "properties":{
[junit4] 2> "eventTimes":[3002683859922093],
[junit4] 2> "nodeNames":["127.0.0.1:10010_solr"]}}
[junit4] 2> 1297185 DEBUG (AutoscalingActionExecutor-2160-thread-1) [ ] o.a.s.c.a.ScheduledTriggers -- processing actions for {
[junit4] 2> "id":"aaaecd0d7ecadT9cexyk69jg0ohfkc8shjh1twb",
[junit4] 2> "source":"node_added_trigger2",
[junit4] 2> "eventTime":3002683859922093,
[junit4] 2> "eventType":"NODEADDED",
[junit4] 2> "properties":{
[junit4] 2> "eventTimes":[3002683859922093],
[junit4] 2> "_enqueue_time_":3002688866692293,
[junit4] 2> "nodeNames":["127.0.0.1:10010_solr"]}}
[junit4] 2> 1297185 INFO (AutoscalingActionExecutor-2160-thread-1) [ ] o.a.s.c.a.s.TestTriggerIntegration last action at 3002683619055093 time = 3002688942761043
[junit4] 2> 1297185 INFO (AutoscalingActionExecutor-2160-thread-1) [ ] o.a.s.c.a.s.TestTriggerIntegration action executed from node_added_trigger2
[junit4] 2> 1297191 DEBUG (AutoscalingActionExecutor-2160-thread-1) [ ] o.a.s.c.a.ScheduledTriggers -- processing took 282 ms for event id=aaaecd0d7ecadT9cexyk69jg0ohfkc8shjh1twb
[junit4] 2> 1297191 DEBUG (simCloudManagerPool-2158-thread-11) [ ] o.a.s.c.a.AutoScalingHandler Verified autoscaling configuration
[junit4] 2> 1297191 DEBUG (simCloudManagerPool-2158-thread-11) [ ] o.a.s.c.a.OverseerTriggerThread Refreshing /autoscaling.json with znode version 16
[junit4] 2> 1297191 DEBUG (simCloudManagerPool-2158-thread-11) [ ] o.a.s.c.a.NodeAddedTrigger Initial livenodes: [127.0.0.1:10010_solr, 127.0.0.1:10005_solr, 127.0.0.1:10009_solr]
[junit4] 2> 1297191 DEBUG (simCloudManagerPool-2158-thread-11) [ ] 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.TestTriggerIntegration$ThrottlingTesterAction}], enabled=true}
[junit4] 2> 1297191 DEBUG (simCloudManagerPool-2158-thread-11) [ ] o.a.s.c.a.NodeLostTrigger Initial livenodes: [127.0.0.1:10010_solr, 127.0.0.1:10005_solr, 127.0.0.1:10009_solr]
[junit4] 2> 1297191 DEBUG (simCloudManagerPool-2158-thread-11) [ ] o.a.s.c.a.NodeAddedTrigger Initial livenodes: [127.0.0.1:10010_solr, 127.0.0.1:10005_solr, 127.0.0.1:10009_solr]
[junit4] 2> 1297191 DEBUG (simCloudManagerPool-2158-thread-11) [ ] 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.TestTriggerIntegration$ThrottlingTesterAction}], enabled=true}
[junit4] 2> 1297191 DEBUG (simCloudManagerPool-2158-thread-11) [ ] o.a.s.c.a.NodeLostTrigger Initial livenodes: [127.0.0.1:10010_solr, 127.0.0.1:10005_solr, 127.0.0.1:10009_solr]
[junit4] 2> 1297192 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Processed trigger updates upto znodeVersion 16
[junit4] 2> 1297192 INFO (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.s.TestTriggerIntegration TestTriggerAction init
[junit4] 2> 1297192 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Current znodeVersion 16, lastZnodeVersion 16
[junit4] 2> 1297193 DEBUG (ScheduledTrigger-2159-thread-1) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: node_lost_trigger1 with currently live nodes: 3
[junit4] 2> 1297194 DEBUG (simCloudManagerPool-2158-thread-12) [ ] o.a.s.c.a.AutoScalingHandler Verified autoscaling configuration
[junit4] 2> 1297194 DEBUG (simCloudManagerPool-2158-thread-12) [ ] o.a.s.c.a.OverseerTriggerThread Refreshing /autoscaling.json with znode version 17
[junit4] 2> 1297194 DEBUG (simCloudManagerPool-2158-thread-12) [ ] o.a.s.c.a.NodeAddedTrigger Initial livenodes: [127.0.0.1:10010_solr, 127.0.0.1:10005_solr, 127.0.0.1:10009_solr]
[junit4] 2> 1297194 DEBUG (simCloudManagerPool-2158-thread-12) [ ] 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.TestTriggerIntegration$ThrottlingTesterAction}], enabled=true}
[junit4] 2> 1297194 DEBUG (simCloudManagerPool-2158-thread-12) [ ] o.a.s.c.a.NodeLostTrigger Initial livenodes: [127.0.0.1:10010_solr, 127.0.0.1:10005_solr, 127.0.0.1:10009_solr]
[junit4] 2> 1297194 DEBUG (simCloudManagerPool-2158-thread-12) [ ] o.a.s.c.a.NodeAddedTrigger Initial livenodes: [127.0.0.1:10010_solr, 127.0.0.1:10005_solr, 127.0.0.1:10009_solr]
[junit4] 2> 1297199 DEBUG (simCloudManagerPool-2158-thread-12) [ ] 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.TestTriggerIntegration$ThrottlingTesterAction}], enabled=true}
[junit4] 2> 1297199 DEBUG (simCloudManagerPool-2158-thread-12) [ ] o.a.s.c.a.NodeLostTrigger Initial livenodes: [127.0.0.1:10010_solr, 127.0.0.1:10005_solr, 127.0.0.1:10009_solr]
[junit4] 2> 1297199 DEBUG (simCloudManagerPool-2158-thread-12) [ ] o.a.s.c.a.NodeLostTrigger Initial livenodes: [127.0.0.1:10010_solr, 127.0.0.1:10005_solr, 127.0.0.1:10009_solr]
[junit4] 2> 1297200 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Processed trigger updates upto znodeVersion 17
[junit4] 2> 1297200 INFO (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.s.TestTriggerIntegration TestTriggerAction init
[junit4] 2> 1297200 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Current znodeVersion 17, lastZnodeVersion 17
[junit4] 2> 1297201 DEBUG (ScheduledTrigger-2159-thread-3) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: node_lost_trigger2 with currently live nodes: 2
[junit4] 2> 1297201 DEBUG (ScheduledTrigger-2159-thread-3) [ ] o.a.s.c.a.NodeLostTrigger Tracking lost node: 127.0.0.1:10010_solr
[junit4] 2> 1297201 DEBUG (ScheduledTrigger-2159-thread-3) [ ] o.a.s.c.a.NodeLostTrigger NodeLostTrigger firing registered processor for lost nodes: [127.0.0.1:10010_solr]
[junit4] 2> 1297202 DEBUG (ScheduledTrigger-2159-thread-3) [ ] o.a.s.c.a.ScheduledTriggers ++++++++ Cooldown inactive - processing event: {
[junit4] 2> "id":"aaaee30b679dbT9cexyk69jg0ohfkc8shjh1twe",
[junit4] 2> "source":"node_lost_trigger2",
[junit4] 2> "eventTime":3002689763310043,
[junit4] 2> "eventType":"NODELOST",
[junit4] 2> "properties":{
[junit4] 2> "eventTimes":[3002689763310043],
[junit4] 2> "nodeNames":["127.0.0.1:10010_solr"]}}
[junit4] 2> 1297203 DEBUG (AutoscalingActionExecutor-2160-thread-1) [ ] o.a.s.c.a.ScheduledTriggers -- processing actions for {
[junit4] 2> "id":"aaaee30b679dbT9cexyk69jg0ohfkc8shjh1twe",
[junit4] 2> "source":"node_lost_trigger2",
[junit4] 2> "eventTime":3002689763310043,
[junit4] 2> "eventType":"NODELOST",
[junit4] 2> "properties":{
[junit4] 2> "eventTimes":[3002689763310043],
[junit4] 2> "_enqueue_time_":3002689770006293,
[junit4] 2> "nodeNames":["127.0.0.1:10010_solr"]}}
[junit4] 2> 1297203 INFO (AutoscalingActionExecutor-2160-thread-1) [ ] o.a.s.c.a.s.TestTriggerIntegration action executed from node_lost_trigger2
[junit4] 2> 1297204 DEBUG (AutoscalingActionExecutor-2160-thread-1) [ ] o.a.s.c.a.ScheduledTriggers -- processing took 61 ms for event id=aaaee30b679dbT9cexyk69jg0ohfkc8shjh1twe
[junit4] 2> 1297210 DEBUG (ScheduledTrigger-2159-thread-3) [ ] o.a.s.c.a.NodeAddedTrigger Running NodeAddedTrigger node_added_trigger2
[junit4] 2> 1297210 DEBUG (ScheduledTrigger-2159-thread-3) [ ] o.a.s.c.a.NodeAddedTrigger Found livenodes: 2
[junit4] 2> 1297210 DEBUG (ScheduledTrigger-2159-thread-3) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 2
[junit4] 2> 1297211 DEBUG (ScheduledTrigger-2159-thread-3) [ ] o.a.s.c.a.NodeLostTrigger Tracking lost node: 127.0.0.1:10010_solr
[junit4] 2> 1297211 DEBUG (ScheduledTrigger-2159-thread-3) [ ] o.a.s.c.a.NodeAddedTrigger Running NodeAddedTrigger node_added_trigger1
[junit4] 2> 1297211 DEBUG (ScheduledTrigger-2159-thread-3) [ ] o.a.s.c.a.NodeAddedTrigger Found livenodes: 2
[junit4] 2> 1297284 DEBUG (ScheduledTrigger-2159-thread-3) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: node_lost_trigger1 with currently live nodes: 2
[junit4] 2> 1297284 DEBUG (ScheduledTrigger-2159-thread-3) [ ] o.a.s.c.a.NodeLostTrigger Tracking lost node: 127.0.0.1:10010_solr
[junit4] 2> 1297284 DEBUG (ScheduledTrigger-2159-thread-3) [ ] o.a.s.c.a.NodeLostTrigger NodeLostTrigger firing registered processor for lost nodes: [127.0.0.1:10010_solr]
[junit4] 2> 1297285 DEBUG (ScheduledTrigger-2159-thread-3) [ ] o.a.s.c.a.ScheduledTriggers -------- Cooldown period - rejecting event: {
[junit4] 2> "id":"aaaef2812e183T9cexyk69jg0ohfkc8shjh1twh",
[junit4] 2> "source":"node_lost_trigger1",
[junit4] 2> "eventTime":3002693913338243,
[junit4] 2> "eventType":"NODELOST",
[junit4] 2> "properties":{
[junit4] 2> "eventTimes":[3002693913338243],
[junit4] 2> "nodeNames":["127.0.0.1:10010_solr"]}}
[junit4] 2> 1297285 DEBUG (ScheduledTrigger-2159-thread-3) [ ] o.a.s.c.a.NodeLostTrigger NodeLostTrigger processor for lost nodes: [127.0.0.1:10010_solr] is not ready, will try later
[junit4] 2> 1297285 DEBUG (ScheduledTrigger-2159-thread-3) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: node_lost_trigger2 with currently live nodes: 2
[junit4] 2> 1297286 DEBUG (ScheduledTrigger-2159-thread-3) [ ] o.a.s.c.a.NodeAddedTrigger Running NodeAddedTrigger node_added_trigger2
[junit4] 2> 1297286 DEBUG (ScheduledTrigger-2159-thread-3) [ ] o.a.s.c.a.NodeAddedTrigger Found livenodes: 2
[junit4] 2> 1297286 DEBUG (ScheduledTrigger-2159-thread-3) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 2
[junit4] 2> 1297286 DEBUG (ScheduledTrigger-2159-thread-3) [ ] o.a.s.c.a.NodeAddedTrigger Running NodeAddedTrigger node_added_trigger1
[junit4] 2> 1297286 DEBUG (ScheduledTrigger-2159-thread-3) [ ] o.a.s.c.a.NodeAddedTrigger Found livenodes: 2
[junit4] 2> 1297309 DEBUG (ScheduledTrigger-2159-thread-2) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: node_lost_trigger1 with currently live nodes: 2
[junit4] 2> 1297309 DEBUG (ScheduledTrigger-2159-thread-2) [ ] o.a.s.c.a.NodeLostTrigger NodeLostTrigger firing registered processor for lost nodes: [127.0.0.1:10010_solr]
[junit4] 2> 1297309 DEBUG (ScheduledTrigger-2159-thread-2) [ ] o.a.s.c.a.ScheduledTriggers ++++++++ Cooldown inactive - processing event: {
[junit4] 2> "id":"aaaef2812e183T9cexyk69jg0ohfkc8shjh1twj",
[junit4] 2> "source":"node_lost_trigger1",
[junit4] 2> "eventTime":3002693913338243,
[junit4] 2> "eventType":"NODELOST",
[junit4] 2> "properties":{
[junit4] 2> "eventTimes":[3002693913338243],
[junit4] 2> "nodeNames":["127.0.0.1:10010_solr"]}}
[junit4] 2> 1297310 DEBUG (AutoscalingActionExecutor-2160-thread-1) [ ] o.a.s.c.a.ScheduledTriggers -- processing actions for {
[junit4] 2> "id":"aaaef2812e183T9cexyk69jg0ohfkc8shjh1twj",
[junit4] 2> "source":"node_lost_trigger1",
[junit4] 2> "eventTime":3002693913338243,
[junit4] 2> "eventType":"NODELOST",
[junit4] 2> "properties":{
[junit4] 2> "eventTimes":[3002693913338243],
[junit4] 2> "_enqueue_time_":3002695143747443,
[junit4] 2> "nodeNames":["127.0.0.1:10010_solr"]}}
[junit4] 2> 1297310 INFO (AutoscalingActionExecutor-2160-thread-1) [ ] o.a.s.c.a.s.TestTriggerIntegration last action at 3002689832865643 time = 3002695213637943
[junit4] 2> 1297310 INFO (AutoscalingActionExecutor-2160-thread-1) [ ] o.a.s.c.a.s.TestTriggerIntegration action executed from node_lost_trigger1
[junit4] 2> 1297311 DEBUG (AutoscalingActionExecutor-2160-thread-1) [ ] o.a.s.c.a.ScheduledTriggers -- processing took 51 ms for event id=aaaef2812e183T9cexyk69jg0ohfkc8shjh1twj
[junit4] 2> 1297312 INFO (TEST-TestTriggerIntegration.testTriggerThrottling-seed#[A494A0B444D55030]) [ ] o.a.s.SolrTestCaseJ4 ###Ending testTriggerThrottling
[junit4] 2> 1297312 INFO (TEST-TestTriggerIntegration.testTriggerThrottling-seed#[A494A0B444D55030]) [ ] o.a.s.c.a.s.SimSolrCloudTestCase
[junit4] 2>
[junit4] 2> 1297312 INFO (TEST-TestTriggerIntegration.testTriggerThrottling-seed#[A494A0B444D55030]) [ ] o.a.s.c.a.s.SimSolrCloudTestCase #############################################
[junit4] 2> 1297312 INFO (TEST-TestTriggerIntegration.testTriggerThrottling-seed#[A494A0B444D55030]) [ ] o.a.s.c.a.s.SimSolrCloudTestCase ############ FINAL CLUSTER STATS ############
[junit4] 2> 1297312 INFO (TEST-TestTriggerIntegration.testTriggerThrottling-seed#[A494A0B444D55030]) [ ] o.a.s.c.a.s.SimSolrCloudTestCase #############################################
[junit4] 2>
[junit4] 2> 1297312 INFO (TEST-TestTriggerIntegration.testTriggerThrottling-seed#[A494A0B444D55030]) [ ] o.a.s.c.a.s.SimSolrCloudTestCase ## Live nodes: 2
[junit4] 2> 1297312 INFO (TEST-TestTriggerIntegration.testTriggerThrottling-seed#[A494A0B444D55030]) [ ] o.a.s.c.a.s.SimSolrCloudTestCase ## Empty nodes: 2
[junit4] 2> 1297312 INFO (TEST-TestTriggerIntegration.testTriggerThrottling-seed#[A494A0B444D55030]) [ ] o.a.s.c.a.s.SimSolrCloudTestCase ## Dead nodes: 1
[junit4] 2> 1297312 INFO (TEST-TestTriggerIntegration.testTriggerThrottling-seed#[A494A0B444D55030]) [ ] o.a.s.c.a.s.SimSolrCloudTestCase ## 127.0.0.1:10010_solr
[junit4] 2> 1297312 INFO (TEST-TestTriggerIntegration.testTriggerThrottling-seed#[A494A0B444D55030]) [ ] o.a.s.c.a.s.SimSolrCloudTestCase ## Collections: []
[junit4] 2> 1297312 INFO (TEST-TestTriggerIntegration.testTriggerThrottling-seed#[A494A0B444D55030]) [ ] o.a.s.c.a.s.SimSolrCloudTestCase ## Max replicas per node: 0
[junit4] 2> 1297312 INFO (TEST-TestTriggerIntegration.testTriggerThrottling-seed#[A494A0B444D55030]) [ ] o.a.s.c.a.s.SimSolrCloudTestCase ## Min replicas per node: 0
[junit4] 2> 1297312 INFO (TEST-TestTriggerIntegration.testTriggerThrottling-seed#[A494A0B444D55030]) [ ] o.a.s.c.a.s.SimSolrCloudTestCase ## Total replicas: 0
[junit4] 2> 1297312 INFO (TEST-TestTriggerIntegration.testTriggerThrottling-seed#[A494A0B444D55030]) [ ] o.a.s.c.a.s.SimSolrCloudTestCase ######### Final Solr op counts ##########
[junit4] 2> 1297312 INFO (TEST-TestTriggerIntegration.testTriggerThrottling-seed#[A494A0B444D55030]) [ ] o.a.s.c.a.s.SimSolrCloudTestCase ## - autoscaling 4
[junit4] 2> 1297312 INFO (TEST-TestTriggerIntegration.testTriggerThrottling-seed#[A494A0B444D55030]) [ ] o.a.s.c.a.s.SimSolrCloudTestCase ## - update 13
[junit4] 2> 1297312 INFO (TEST-TestTriggerIntegration.testTriggerThrottling-seed#[A494A0B444D55030]) [ ] o.a.s.c.a.s.SimSolrCloudTestCase ######### Autoscaling event counts ###########
[junit4] 2> 1297312 INFO (TEST-TestTriggerIntegration.testTriggerThrottling-seed#[A494A0B444D55030]) [ ] o.a.s.c.a.s.SimSolrCloudTestCase ## * Trigger: node_added_trigger1
[junit4] 2> 1297312 INFO (TEST-TestTriggerIntegration.testTriggerThrottling-seed#[A494A0B444D55030]) [ ] o.a.s.c.a.s.SimSolrCloudTestCase ## - STARTED 1
[junit4] 2> 1297312 INFO (TEST-TestTriggerIntegration.testTriggerThrottling-seed#[A494A0B444D55030]) [ ] o.a.s.c.a.s.SimSolrCloudTestCase ## - SUCCEEDED 1
[junit4] 2> 1297312 INFO (TEST-TestTriggerIntegration.testTriggerThrottling-seed#[A494A0B444D55030]) [ ] o.a.s.c.a.s.SimSolrCloudTestCase ## * Trigger: node_added_trigger2
[junit4] 2> 1297312 INFO (TEST-TestTriggerIntegration.testTriggerThrottling-seed#[A494A0B444D55030]) [ ] o.a.s.c.a.s.SimSolrCloudTestCase ## - IGNORED 4
[junit4] 2> 1297312 INFO (TEST-TestTriggerIntegration.testTriggerThrottling-seed#[A494A0B444D55030]) [ ] o.a.s.c.a.s.SimSolrCloudTestCase ## - STARTED 1
[junit4] 2> 1297312 INFO (TEST-TestTriggerIntegration.testTriggerThrottling-seed#[A494A0B444D55030]) [ ] o.a.s.c.a.s.SimSolrCloudTestCase ## - SUCCEEDED 1
[junit4] 2> 1297312 INFO (TEST-TestTriggerIntegration.testTriggerThrottling-seed#[A494A0B444D55030]) [ ] o.a.s.c.a.s.SimSolrCloudTestCase ## * Trigger: node_lost_trigger1
[junit4] 2> 1297312 INFO (TEST-TestTriggerIntegration.testTriggerThrottling-seed#[A494A0B444D55030]) [ ] o.a.s.c.a.s.SimSolrCloudTestCase ## - IGNORED 1
[junit4] 2> 1297312 INFO (TEST-TestTriggerIntegration.testTriggerThrottling-seed#[A494A0B444D55030]) [ ] o.a.s.c.a.s.SimSolrCloudTestCase ## - STARTED 1
[junit4] 2> 1297312 INFO (TEST-TestTriggerIntegration.testTriggerThrottling-seed#[A494A0B444D55030]) [ ] o.a.s.c.a.s.SimSolrCloudTestCase ## - SUCCEEDED 1
[junit4] 2> 1297312 INFO (TEST-TestTriggerIntegration.testTriggerThrottling-seed#[A494A0B444D55030]) [ ] o.a.s.c.a.s.SimSolrCloudTestCase ## * Trigger: node_lost_trigger2
[junit4] 2> 1297312 INFO (TEST-TestTriggerIntegration.testTriggerThrottling-seed#[A494A0B444D55030]) [ ] o.a.s.c.a.s.SimSolrCloudTestCase ## - STARTED 1
[junit4] 2> 1297312 INFO (TEST-TestTriggerIntegration.testTriggerThrottling-seed#[A494A0B444D55030]) [ ] o.a.s.c.a.s.SimSolrCloudTestCase ## - SUCCEEDED 1
[junit4] 2> 1297330 INFO (TEST-TestTriggerIntegration.testNodeAddedTrigger-seed#[A494A0B444D55030]) [ ] o.a.s.SolrTestCaseJ4 ###Starting testNodeAddedTrigger
[junit4] 2> 1297330 DEBUG (TEST-TestTriggerIntegration.testNodeAddedTrigger-seed#[A494A0B444D55030]) [ ] o.a.s.c.a.OverseerTriggerThread Refreshing /autoscaling.json with znode version 18
[junit4] 2> 1297330 DEBUG (TEST-TestTriggerIntegration.testNodeAddedTrigger-seed#[A494A0B444D55030]) [ ] o.a.s.c.a.s.SimNodeStateProvider - removing dead node values: 127.0.0.1:10010_solr
[junit4] 2> 1297330 INFO (TEST-TestTriggerIntegration.testNodeAddedTrigger-seed#[A494A0B444D55030]) [ ] o.a.s.c.a.s.SimCloudManager === Restarting OverseerTriggerThread and clearing object cache...
[junit4] 2> 1297330 WARN (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread OverseerTriggerThread woken up but we are closed, exiting.
[junit4] 2> 1297335 DEBUG (TEST-TestTriggerIntegration.testNodeAddedTrigger-seed#[A494A0B444D55030]) [ ] o.a.s.c.a.OverseerTriggerThread OverseerTriggerThread has been closed explicitly
[junit4] 2> 1297337 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Adding .autoAddReplicas trigger
[junit4] 2> 1297337 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Refreshing /autoscaling.json with znode version 19
[junit4] 2> 1297337 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.NodeLostTrigger Initial livenodes: [127.0.0.1:10005_solr, 127.0.0.1:10009_solr]
[junit4] 2> 1297337 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Current znodeVersion 19, lastZnodeVersion -1
[junit4] 2> 1297337 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Processed trigger updates upto znodeVersion 19
[junit4] 2> 1297338 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread -- clean old nodeAdded markers
[junit4] 2> 1297338 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Current znodeVersion 19, lastZnodeVersion 19
[junit4] 2> 1297338 DEBUG (ScheduledTrigger-2162-thread-1) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 2
[junit4] 2> 1297361 DEBUG (ScheduledTrigger-2162-thread-1) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 2
[junit4] 2> 1297381 DEBUG (ScheduledTrigger-2162-thread-1) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 2
[junit4] 2> 1297401 DEBUG (ScheduledTrigger-2162-thread-1) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 2
[junit4] 2> 1297422 DEBUG (ScheduledTrigger-2162-thread-1) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 2
[junit4] 2> 1297442 DEBUG (simCloudManagerPool-2161-thread-1) [ ] o.a.s.c.a.AutoScalingHandler Verified autoscaling configuration
[junit4] 2> 1297442 DEBUG (simCloudManagerPool-2161-thread-1) [ ] o.a.s.c.a.OverseerTriggerThread Refreshing /autoscaling.json with znode version 20
[junit4] 2> 1297443 DEBUG (ScheduledTrigger-2162-thread-1) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 2
[junit4] 2> 1297443 DEBUG (simCloudManagerPool-2161-thread-1) [ ] o.a.s.c.a.NodeLostTrigger Initial livenodes: [127.0.0.1:10005_solr, 127.0.0.1:10009_solr]
[junit4] 2> 1297443 DEBUG (simCloudManagerPool-2161-thread-1) [ ] o.a.s.c.a.NodeAddedTrigger Initial livenodes: [127.0.0.1:10005_solr, 127.0.0.1:10009_solr]
[junit4] 2> 1297443 DEBUG (simCloudManagerPool-2161-thread-1) [ ] 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.TestTriggerIntegration$TestTriggerAction}], enabled=true}
[junit4] 2> 1297445 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Processed trigger updates upto znodeVersion 20
[junit4] 2> 1297445 INFO (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.s.TestTriggerIntegration TestTriggerAction init
[junit4] 2> 1297445 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Current znodeVersion 20, lastZnodeVersion 20
[junit4] 2> 1297445 DEBUG (ScheduledTrigger-2162-thread-3) [ ] o.a.s.c.a.NodeAddedTrigger Running NodeAddedTrigger node_added_trigger
[junit4] 2> 1297445 DEBUG (ScheduledTrigger-2162-thread-3) [ ] o.a.s.c.a.NodeAddedTrigger Found livenodes: 2
[junit4] 2> 1297464 DEBUG (ScheduledTrigger-2162-thread-3) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 3
[junit4] 2> 1297466 DEBUG (ScheduledTrigger-2162-thread-3) [ ] o.a.s.c.a.NodeAddedTrigger Running NodeAddedTrigger node_added_trigger
[junit4] 2> 1297466 DEBUG (ScheduledTrigger-2162-thread-3) [ ] o.a.s.c.a.NodeAddedTrigger Found livenodes: 3
[junit4] 2> 1297466 DEBUG (ScheduledTrigger-2162-thread-3) [ ] o.a.s.c.a.NodeAddedTrigger Tracking new node: 127.0.0.1:10011_solr at time 3002702982980193
[junit4] 2> 1297484 DEBUG (ScheduledTrigg
[...truncated too long message...]
[junit4] 2> "properties":{
[junit4] 2> "node":{
[junit4] 2> "127.0.0.1:10018_solr":250.0,
[junit4] 2> "127.0.0.1:10019_solr":250.0},
[junit4] 2> "replica":[
[junit4] 2> "{\"core_node2\":{\n \"core\":\"collection1_shard1_replica_n2\",\n \"INDEX.sizeInBytes\":123450000,\n \"rate\":250.0,\n \"node_name\":\"127.0.0.1:10018_solr\",\n \"state\":\"active\",\n \"type\":\"NRT\",\n \"QUERY./select.requestTimes:1minRate\":250.0,\n \"shard\":\"shard1\",\n \"collection\":\"collection1\"}}",
[junit4] 2> "{\"core_node1\":{\n \"core\":\"collection1_shard1_replica_n1\",\n \"INDEX.sizeInBytes\":123450000,\n \"rate\":250.0,\n \"node_name\":\"127.0.0.1:10019_solr\",\n \"state\":\"active\",\n \"type\":\"NRT\",\n \"QUERY./select.requestTimes:1minRate\":250.0,\n \"shard\":\"shard1\",\n \"collection\":\"collection1\"}}"],
[junit4] 2> "collection":{"collection1":500.0},
[junit4] 2> "shard":{"collection1":{"shard1":500.0}}}}
[junit4] 2> 1299533 DEBUG (ScheduledTrigger-2189-thread-3) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 2
[junit4] 2> 1299534 DEBUG (ScheduledTrigger-2189-thread-3) [ ] o.a.s.c.a.ScheduledTriggers -------- Cooldown period - rejecting event: {
[junit4] 2> "id":"aab088034e41fT9cexyk69jg0ohfkc8shjh1txi",
[junit4] 2> "source":"search_rate_trigger",
[junit4] 2> "eventTime":3002802766144543,
[junit4] 2> "eventType":"SEARCHRATE",
[junit4] 2> "properties":{
[junit4] 2> "node":{
[junit4] 2> "127.0.0.1:10018_solr":250.0,
[junit4] 2> "127.0.0.1:10019_solr":250.0},
[junit4] 2> "replica":[
[junit4] 2> "{\"core_node2\":{\n \"core\":\"collection1_shard1_replica_n2\",\n \"INDEX.sizeInBytes\":123450000,\n \"rate\":250.0,\n \"node_name\":\"127.0.0.1:10018_solr\",\n \"state\":\"active\",\n \"type\":\"NRT\",\n \"QUERY./select.requestTimes:1minRate\":250.0,\n \"shard\":\"shard1\",\n \"collection\":\"collection1\"}}",
[junit4] 2> "{\"core_node1\":{\n \"core\":\"collection1_shard1_replica_n1\",\n \"INDEX.sizeInBytes\":123450000,\n \"rate\":250.0,\n \"node_name\":\"127.0.0.1:10019_solr\",\n \"state\":\"active\",\n \"type\":\"NRT\",\n \"QUERY./select.requestTimes:1minRate\":250.0,\n \"shard\":\"shard1\",\n \"collection\":\"collection1\"}}"],
[junit4] 2> "collection":{"collection1":500.0},
[junit4] 2> "shard":{"collection1":{"shard1":500.0}}}}
[junit4] 2> 1299537 INFO (TEST-TestTriggerIntegration.testSearchRate-seed#[A494A0B444D55030]) [ ] o.a.s.SolrTestCaseJ4 ###Ending testSearchRate
[junit4] 2> 1299537 INFO (TEST-TestTriggerIntegration.testSearchRate-seed#[A494A0B444D55030]) [ ] o.a.s.c.a.s.SimSolrCloudTestCase
[junit4] 2>
[junit4] 2> 1299537 INFO (TEST-TestTriggerIntegration.testSearchRate-seed#[A494A0B444D55030]) [ ] o.a.s.c.a.s.SimSolrCloudTestCase #############################################
[junit4] 2> 1299537 INFO (TEST-TestTriggerIntegration.testSearchRate-seed#[A494A0B444D55030]) [ ] o.a.s.c.a.s.SimSolrCloudTestCase ############ FINAL CLUSTER STATS ############
[junit4] 2> 1299537 INFO (TEST-TestTriggerIntegration.testSearchRate-seed#[A494A0B444D55030]) [ ] o.a.s.c.a.s.SimSolrCloudTestCase #############################################
[junit4] 2>
[junit4] 2> 1299537 INFO (TEST-TestTriggerIntegration.testSearchRate-seed#[A494A0B444D55030]) [ ] o.a.s.c.a.s.SimSolrCloudTestCase ## Live nodes: 2
[junit4] 2> 1299537 INFO (TEST-TestTriggerIntegration.testSearchRate-seed#[A494A0B444D55030]) [ ] o.a.s.c.a.s.SimSolrCloudTestCase ## Empty nodes: 0
[junit4] 2> 1299537 INFO (TEST-TestTriggerIntegration.testSearchRate-seed#[A494A0B444D55030]) [ ] o.a.s.c.a.s.SimSolrCloudTestCase ## Dead nodes: 0
[junit4] 2> 1299537 INFO (TEST-TestTriggerIntegration.testSearchRate-seed#[A494A0B444D55030]) [ ] o.a.s.c.a.s.SimSolrCloudTestCase ## Collections: [collection1]
[junit4] 2> 1299537 INFO (TEST-TestTriggerIntegration.testSearchRate-seed#[A494A0B444D55030]) [ ] o.a.s.c.a.s.SimSolrCloudTestCase ## Max replicas per node: 1
[junit4] 2> 1299537 INFO (TEST-TestTriggerIntegration.testSearchRate-seed#[A494A0B444D55030]) [ ] o.a.s.c.a.s.SimSolrCloudTestCase ## Min replicas per node: 1
[junit4] 2> 1299537 INFO (TEST-TestTriggerIntegration.testSearchRate-seed#[A494A0B444D55030]) [ ] o.a.s.c.a.s.SimSolrCloudTestCase ## Total replicas: 2
[junit4] 2> 1299537 INFO (TEST-TestTriggerIntegration.testSearchRate-seed#[A494A0B444D55030]) [ ] o.a.s.c.a.s.SimSolrCloudTestCase ## * collection1 2
[junit4] 2> 1299537 INFO (TEST-TestTriggerIntegration.testSearchRate-seed#[A494A0B444D55030]) [ ] o.a.s.c.a.s.SimSolrCloudTestCase ## - active 2
[junit4] 2> 1299537 INFO (TEST-TestTriggerIntegration.testSearchRate-seed#[A494A0B444D55030]) [ ] o.a.s.c.a.s.SimSolrCloudTestCase ######### Final Solr op counts ##########
[junit4] 2> 1299537 INFO (TEST-TestTriggerIntegration.testSearchRate-seed#[A494A0B444D55030]) [ ] o.a.s.c.a.s.SimSolrCloudTestCase ## - CREATE 1
[junit4] 2> 1299537 INFO (TEST-TestTriggerIntegration.testSearchRate-seed#[A494A0B444D55030]) [ ] o.a.s.c.a.s.SimSolrCloudTestCase ## - autoscaling 2
[junit4] 2> 1299537 INFO (TEST-TestTriggerIntegration.testSearchRate-seed#[A494A0B444D55030]) [ ] o.a.s.c.a.s.SimSolrCloudTestCase ## - update 4
[junit4] 2> 1299537 INFO (TEST-TestTriggerIntegration.testSearchRate-seed#[A494A0B444D55030]) [ ] o.a.s.c.a.s.SimSolrCloudTestCase ######### Autoscaling event counts ###########
[junit4] 2> 1299537 INFO (TEST-TestTriggerIntegration.testSearchRate-seed#[A494A0B444D55030]) [ ] o.a.s.c.a.s.SimSolrCloudTestCase ## * Trigger: search_rate_trigger
[junit4] 2> 1299537 INFO (TEST-TestTriggerIntegration.testSearchRate-seed#[A494A0B444D55030]) [ ] o.a.s.c.a.s.SimSolrCloudTestCase ## - IGNORED 2
[junit4] 2> 1299537 INFO (TEST-TestTriggerIntegration.testSearchRate-seed#[A494A0B444D55030]) [ ] o.a.s.c.a.s.SimSolrCloudTestCase ## - STARTED 1
[junit4] 2> 1299537 INFO (TEST-TestTriggerIntegration.testSearchRate-seed#[A494A0B444D55030]) [ ] o.a.s.c.a.s.SimSolrCloudTestCase ## - SUCCEEDED 1
[junit4] 2> 1299538 WARN (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread OverseerTriggerThread woken up but we are closed, exiting.
[junit4] 2> 1299539 DEBUG (SUITE-TestTriggerIntegration-seed#[A494A0B444D55030]-worker) [ ] o.a.s.c.a.OverseerTriggerThread OverseerTriggerThread has been closed explicitly
[junit4] 2> NOTE: leaving temporary files on disk at: /export/home/jenkins/workspace/Lucene-Solr-7.x-Solaris/solr/build/solr-core/test/J0/temp/solr.cloud.autoscaling.sim.TestTriggerIntegration_A494A0B444D55030-001
[junit4] 2> NOTE: test params are: codec=Asserting(Lucene70): {}, docValues:{}, maxPointsInLeafNode=1165, maxMBSortInHeap=6.558980622339023, sim=RandomSimilarity(queryNorm=true): {}, locale=ar-YE, timezone=America/Bahia
[junit4] 2> NOTE: SunOS 5.11 amd64/Oracle Corporation 1.8.0_152 (64-bit)/cpus=3,threads=1,free=105337192,total=386097152
[junit4] 2> NOTE: All tests run in this JVM: [FieldAnalysisRequestHandlerTest, TestDownShardTolerantSearch, TestMaxTokenLenTokenizer, SuggesterWFSTTest, SolrXmlInZkTest, TestOmitPositions, BasicAuthIntegrationTest, DeleteShardTest, SolrMetricsIntegrationTest, TestGraphTermsQParserPlugin, CursorMarkTest, TestFiltering, SolrTestCaseJ4Test, HighlighterConfigTest, XsltUpdateRequestHandlerTest, TestCloudJSONFacetJoinDomain, TestFuzzyAnalyzedSuggestions, TestDistributedStatsComponentCardinality, TestReRankQParserPlugin, VMParamsZkACLAndCredentialsProvidersTest, DistanceUnitsTest, TestCustomDocTransformer, MinimalSchemaTest, PeerSyncReplicationTest, TestSolrCloudWithDelegationTokens, BJQParserTest, TestCloudSearcherWarming, TestSubQueryTransformerCrossCore, TestReloadDeadlock, UUIDFieldTest, LeaderElectionTest, TestSimpleQParserPlugin, CdcrBidirectionalTest, SmileWriterTest, TestComplexPhraseQParserPlugin, UnloadDistributedZkTest, DirectSolrConnectionTest, BadCopyFieldTest, TestJoin, ShowFileRequestHandlerTest, DisMaxRequestHandlerTest, DistributedQueryElevationComponentTest, TestInitParams, TestReplicaProperties, TestRawResponseWriter, MetricsHandlerTest, TimeZoneUtilsTest, SolrCLIZkUtilsTest, TestEmbeddedSolrServerSchemaAPI, TestIBSimilarityFactory, StatsComponentTest, ConvertedLegacyTest, CSVRequestHandlerTest, TestFieldCache, SpellCheckComponentTest, DistributedFacetPivotSmallTest, OverseerTest, ScriptEngineTest, SpellCheckCollatorWithCollapseTest, ConfigSetsAPITest, URLClassifyProcessorTest, TestXIncludeConfig, TestSizeLimitedDistributedMap, HttpTriggerListenerTest, TestJsonFacets, BinaryUpdateRequestHandlerTest, TestJmxIntegration, SliceStateTest, TestLegacyFieldCache, CoreMergeIndexesAdminHandlerTest, ZkControllerTest, ClusterStateTest, TestTrackingShardHandlerFactory, DistributedDebugComponentTest, RegexBytesRefFilterTest, ExecutePlanActionTest, CreateCollectionCleanupTest, TestPolicyCloud, PreAnalyzedFieldManagedSchemaCloudTest, TestReqParamsAPI, TestSchemaVersionResource, RollingRestartTest, OverriddenZkACLAndCredentialsProvidersTest, TestQuerySenderNoQuery, DateMathParserTest, TestFieldCacheVsDocValues, TestWriterPerf, DefaultValueUpdateProcessorTest, SparseHLLTest, IndexBasedSpellCheckerTest, TestTolerantSearch, HdfsCollectionsAPIDistributedZkTest, StressHdfsTest, EnumFieldTest, TestStreamBody, ChaosMonkeyNothingIsSafeTest, TestRangeQuery, ExplicitHLLTest, TestTriggerIntegration]
[junit4] Completed [174/765 (1!)] on J0 in 3.34s, 11 tests, 1 error <<< FAILURES!
[...truncated 50127 lines...]