Build: https://builds.apache.org/job/Lucene-Solr-Tests-7.x/325/
3 tests failed. FAILED: org.apache.solr.cloud.autoscaling.sim.TestTriggerIntegration.testSearchRate Error Message: The trigger did not fire at all Stack Trace: java.lang.AssertionError: The trigger did not fire at all at __randomizedtesting.SeedInfo.seed([7C8BF33D67D53826:21C3EDB4A8139E69]:0) at org.junit.Assert.fail(Assert.java:93) at org.junit.Assert.assertTrue(Assert.java:43) at org.apache.solr.cloud.autoscaling.sim.TestTriggerIntegration.testSearchRate(TestTriggerIntegration.java:1178) at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method) at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62) at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) at java.lang.reflect.Method.invoke(Method.java:498) at com.carrotsearch.randomizedtesting.RandomizedRunner.invoke(RandomizedRunner.java:1737) at com.carrotsearch.randomizedtesting.RandomizedRunner$8.evaluate(RandomizedRunner.java:934) at com.carrotsearch.randomizedtesting.RandomizedRunner$9.evaluate(RandomizedRunner.java:970) at com.carrotsearch.randomizedtesting.RandomizedRunner$10.evaluate(RandomizedRunner.java:984) at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:57) at org.apache.lucene.util.TestRuleSetupTeardownChained$1.evaluate(TestRuleSetupTeardownChained.java:49) at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:45) at org.apache.lucene.util.TestRuleThreadAndTestName$1.evaluate(TestRuleThreadAndTestName.java:48) at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:64) at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:47) at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36) at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:368) at com.carrotsearch.randomizedtesting.ThreadLeakControl.forkTimeoutingTask(ThreadLeakControl.java:817) at com.carrotsearch.randomizedtesting.ThreadLeakControl$3.evaluate(ThreadLeakControl.java:468) at com.carrotsearch.randomizedtesting.RandomizedRunner.runSingleTest(RandomizedRunner.java:943) at com.carrotsearch.randomizedtesting.RandomizedRunner$5.evaluate(RandomizedRunner.java:829) at com.carrotsearch.randomizedtesting.RandomizedRunner$6.evaluate(RandomizedRunner.java:879) at com.carrotsearch.randomizedtesting.RandomizedRunner$7.evaluate(RandomizedRunner.java:890) at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36) at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:57) at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:45) at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36) at org.apache.lucene.util.TestRuleStoreClassName$1.evaluate(TestRuleStoreClassName.java:41) at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:40) at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:40) at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36) at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36) at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36) at org.apache.lucene.util.TestRuleAssertionsRequired$1.evaluate(TestRuleAssertionsRequired.java:53) at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:47) at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:64) at org.apache.lucene.util.TestRuleIgnoreTestSuites$1.evaluate(TestRuleIgnoreTestSuites.java:54) at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36) at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:368) at java.lang.Thread.run(Thread.java:748) FAILED: org.apache.solr.cloud.autoscaling.sim.TestTriggerIntegration.testNodeAddedTriggerRestoreState Error Message: Two TriggerAction instances should have been created by now Stack Trace: java.lang.AssertionError: Two TriggerAction instances should have been created by now at __randomizedtesting.SeedInfo.seed([7C8BF33D67D53826:F4B67A425D15D98B]:0) at org.junit.Assert.fail(Assert.java:93) at org.apache.solr.cloud.autoscaling.sim.TestTriggerIntegration.testNodeAddedTriggerRestoreState(TestTriggerIntegration.java:361) at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method) at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62) at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) at java.lang.reflect.Method.invoke(Method.java:498) at com.carrotsearch.randomizedtesting.RandomizedRunner.invoke(RandomizedRunner.java:1737) at com.carrotsearch.randomizedtesting.RandomizedRunner$8.evaluate(RandomizedRunner.java:934) at com.carrotsearch.randomizedtesting.RandomizedRunner$9.evaluate(RandomizedRunner.java:970) at com.carrotsearch.randomizedtesting.RandomizedRunner$10.evaluate(RandomizedRunner.java:984) at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:57) at org.apache.lucene.util.TestRuleSetupTeardownChained$1.evaluate(TestRuleSetupTeardownChained.java:49) at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:45) at org.apache.lucene.util.TestRuleThreadAndTestName$1.evaluate(TestRuleThreadAndTestName.java:48) at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:64) at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:47) at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36) at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:368) at com.carrotsearch.randomizedtesting.ThreadLeakControl.forkTimeoutingTask(ThreadLeakControl.java:817) at com.carrotsearch.randomizedtesting.ThreadLeakControl$3.evaluate(ThreadLeakControl.java:468) at com.carrotsearch.randomizedtesting.RandomizedRunner.runSingleTest(RandomizedRunner.java:943) at com.carrotsearch.randomizedtesting.RandomizedRunner$5.evaluate(RandomizedRunner.java:829) at com.carrotsearch.randomizedtesting.RandomizedRunner$6.evaluate(RandomizedRunner.java:879) at com.carrotsearch.randomizedtesting.RandomizedRunner$7.evaluate(RandomizedRunner.java:890) at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36) at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:57) at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:45) at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36) at org.apache.lucene.util.TestRuleStoreClassName$1.evaluate(TestRuleStoreClassName.java:41) at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:40) at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:40) at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36) at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36) at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36) at org.apache.lucene.util.TestRuleAssertionsRequired$1.evaluate(TestRuleAssertionsRequired.java:53) at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:47) at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:64) at org.apache.lucene.util.TestRuleIgnoreTestSuites$1.evaluate(TestRuleIgnoreTestSuites.java:54) at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36) at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:368) at java.lang.Thread.run(Thread.java:748) FAILED: org.apache.solr.cloud.autoscaling.sim.TestTriggerIntegration.testNodeMarkersRegistration Error Message: Path /autoscaling/nodeAdded/127.0.0.1:10009_solr should have been deleted Stack Trace: java.lang.AssertionError: Path /autoscaling/nodeAdded/127.0.0.1:10009_solr should have been deleted at __randomizedtesting.SeedInfo.seed([7C8BF33D67D53826:64317B3169E0F5C9]:0) at org.junit.Assert.fail(Assert.java:93) at org.junit.Assert.assertTrue(Assert.java:43) at org.junit.Assert.assertFalse(Assert.java:68) at org.apache.solr.cloud.autoscaling.sim.TestTriggerIntegration.testNodeMarkersRegistration(TestTriggerIntegration.java:842) 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 11722 lines...] [junit4] Suite: org.apache.solr.cloud.autoscaling.sim.TestTriggerIntegration [junit4] 2> Creating dataDir: /home/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-7.x/solr/build/solr-core/test/J1/temp/solr.cloud.autoscaling.sim.TestTriggerIntegration_7C8BF33D67D53826-001/init-core-data-001 [junit4] 2> 61555 INFO (SUITE-TestTriggerIntegration-seed#[7C8BF33D67D53826]-worker) [ ] o.a.s.SolrTestCaseJ4 Using TrieFields (NUMERIC_POINTS_SYSPROP=false) w/NUMERIC_DOCVALUES_SYSPROP=true [junit4] 2> 61556 INFO (SUITE-TestTriggerIntegration-seed#[7C8BF33D67D53826]-worker) [ ] o.a.s.SolrTestCaseJ4 Randomized ssl (true) and clientAuth (false) via: @org.apache.solr.util.RandomizeSSL(reason=, ssl=NaN, value=NaN, clientAuth=NaN) [junit4] 2> 61589 INFO (SUITE-TestTriggerIntegration-seed#[7C8BF33D67D53826]-worker) [ ] o.a.s.SolrTestCaseJ4 SecureRandom sanity checks: test.solr.allowed.securerandom=null & java.security.egd=file:/dev/./urandom [junit4] 2> 61627 INFO (SUITE-TestTriggerIntegration-seed#[7C8BF33D67D53826]-worker) [ ] o.a.s.c.SolrResourceLoader solr home defaulted to 'solr/' (could not find system property or JNDI) [junit4] 2> 61742 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Adding .autoAddReplicas trigger [junit4] 2> 61743 INFO (TEST-TestTriggerIntegration.testSearchRate-seed#[7C8BF33D67D53826]) [ ] o.a.s.SolrTestCaseJ4 ###Starting testSearchRate [junit4] 2> 61745 INFO (TEST-TestTriggerIntegration.testSearchRate-seed#[7C8BF33D67D53826]) [ ] o.a.s.c.a.s.SimCloudManager === Restarting OverseerTriggerThread and clearing object cache... [junit4] 2> 61745 DEBUG (TEST-TestTriggerIntegration.testSearchRate-seed#[7C8BF33D67D53826]) [ ] o.a.s.c.a.OverseerTriggerThread OverseerTriggerThread has been closed explicitly [junit4] 2> 61745 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Adding .autoAddReplicas trigger [junit4] 2> 61746 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Refreshing /autoscaling.json with znode version 1 [junit4] 2> 61762 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.NodeLostTrigger Initial livenodes: [127.0.0.1:10001_solr, 127.0.0.1:10000_solr] [junit4] 2> 61762 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Current znodeVersion 1, lastZnodeVersion -1 [junit4] 2> 61762 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Processed trigger updates upto znodeVersion 1 [junit4] 2> 61764 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread -- clean old nodeAdded markers [junit4] 2> 61764 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Current znodeVersion 1, lastZnodeVersion 1 [junit4] 2> 61797 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Refreshing /autoscaling.json with znode version 2 [junit4] 2> 61765 DEBUG (ScheduledTrigger-35-thread-1) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 2 [junit4] 2> 61868 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.NodeLostTrigger Initial livenodes: [127.0.0.1:10001_solr, 127.0.0.1:10000_solr] [junit4] 2> 61908 DEBUG (ScheduledTrigger-35-thread-1) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 2 [junit4] 2> 62009 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Processed trigger updates upto znodeVersion 2 [junit4] 2> 62009 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread -- clean old nodeAdded markers [junit4] 2> 62009 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Current znodeVersion 2, lastZnodeVersion 2 [junit4] 2> 62137 DEBUG (ScheduledTrigger-35-thread-2) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 2 [junit4] 2> 62163 DEBUG (ScheduledTrigger-35-thread-1) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 2 [junit4] 2> 62280 DEBUG (ScheduledTrigger-35-thread-1) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 2 [junit4] 2> 62319 DEBUG (ScheduledTrigger-35-thread-1) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 2 [junit4] 2> 62423 DEBUG (ScheduledTrigger-35-thread-1) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 2 [junit4] 2> 62443 DEBUG (ScheduledTrigger-35-thread-1) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 2 [junit4] 2> 62445 DEBUG (simCloudManagerPool-34-thread-4) [ ] o.a.s.c.a.s.SimClusterStateProvider -- elected new leader for collection1 / shard1: {"core_node1":{ [junit4] 2> "node_name":"127.0.0.1:10001_solr", [junit4] 2> "core":"collection1_shard1_replica_n1", [junit4] 2> "leader":"true", [junit4] 2> "state":"active", [junit4] 2> "type":"NRT", [junit4] 2> "INDEX.sizeInBytes":123450000, [junit4] 2> "shard":"shard1", [junit4] 2> "collection":"collection1"}} [junit4] 2> 62479 DEBUG (ScheduledTrigger-35-thread-1) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 2 [junit4] 2> 62507 DEBUG (ScheduledTrigger-35-thread-1) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 2 [junit4] 2> 62544 DEBUG (ScheduledTrigger-35-thread-1) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 2 [junit4] 2> 62551 DEBUG (simCloudManagerPool-34-thread-5) [ ] o.a.s.c.a.AutoScalingHandler Verified autoscaling configuration [junit4] 2> 62580 DEBUG (ScheduledTrigger-35-thread-1) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 2 [junit4] 2> 62600 DEBUG (simCloudManagerPool-34-thread-5) [ ] o.a.s.c.a.OverseerTriggerThread Refreshing /autoscaling.json with znode version 3 [junit4] 2> 62603 DEBUG (simCloudManagerPool-34-thread-5) [ ] o.a.s.c.a.NodeLostTrigger Initial livenodes: [127.0.0.1:10001_solr, 127.0.0.1:10000_solr] [junit4] 2> 62603 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Processed trigger updates upto znodeVersion 3 [junit4] 2> 62603 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread -- clean old nodeAdded markers [junit4] 2> 62603 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Current znodeVersion 3, lastZnodeVersion 3 [junit4] 2> 62618 DEBUG (ScheduledTrigger-35-thread-1) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 2 [junit4] 2> 62655 DEBUG (ScheduledTrigger-35-thread-3) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 2 [junit4] 2> 62658 DEBUG (simCloudManagerPool-34-thread-6) [ ] o.a.s.c.a.AutoScalingHandler Verified autoscaling configuration [junit4] 2> 62689 DEBUG (ScheduledTrigger-35-thread-3) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 2 [junit4] 2> 62759 DEBUG (simCloudManagerPool-34-thread-6) [ ] o.a.s.c.a.OverseerTriggerThread Refreshing /autoscaling.json with znode version 4 [junit4] 2> 62759 DEBUG (simCloudManagerPool-34-thread-6) [ ] o.a.s.c.a.NodeLostTrigger Initial livenodes: [127.0.0.1:10001_solr, 127.0.0.1:10000_solr] [junit4] 2> 62760 DEBUG (ScheduledTrigger-35-thread-4) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 2 [junit4] 2> 62782 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Processed trigger updates upto znodeVersion 4 [junit4] 2> 62783 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread -- clean old nodeAdded markers [junit4] 2> 62783 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Current znodeVersion 4, lastZnodeVersion 4 [junit4] 2> 62802 DEBUG (ScheduledTrigger-35-thread-2) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 2 [junit4] 2> 62832 DEBUG (ScheduledTrigger-35-thread-1) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 2 [junit4] 2> 62853 DEBUG (ScheduledTrigger-35-thread-1) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 2 [junit4] 2> 62888 DEBUG (ScheduledTrigger-35-thread-1) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 2 [junit4] 2> 62924 DEBUG (ScheduledTrigger-35-thread-1) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 2 [junit4] 2> 62927 DEBUG (ScheduledTrigger-35-thread-1) [ ] o.a.s.c.a.ScheduledTriggers ++++++++ Cooldown inactive - processing event: { [junit4] 2> "id":"39ab66a2401fbTcrwbha45ogtcenwkvvquxqvo3", [junit4] 2> "source":"search_rate_trigger", [junit4] 2> "eventTime":1014533185602043, [junit4] 2> "eventType":"SEARCHRATE", [junit4] 2> "properties":{ [junit4] 2> "node":{ [junit4] 2> "127.0.0.1:10001_solr":250.0, [junit4] 2> "127.0.0.1:10000_solr":250.0}, [junit4] 2> "replica":[ [junit4] 2> "{\"core_node1\":{\n \"core\":\"collection1_shard1_replica_n1\",\n \"leader\":\"true\",\n \"INDEX.sizeInBytes\":123450000,\n \"rate\":250.0,\n \"node_name\":\"127.0.0.1:10001_solr\",\n \"state\":\"active\",\n \"type\":\"NRT\",\n \"QUERY./select.requestTimes:1minRate\":250.0,\n \"shard\":\"shard1\",\n \"collection\":\"collection1\"}}", [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:10000_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> 63184 INFO (TEST-TestTriggerIntegration.testSearchRate-seed#[7C8BF33D67D53826]) [ ] o.a.s.SolrTestCaseJ4 ###Ending testSearchRate [junit4] 2> 63184 INFO (TEST-TestTriggerIntegration.testSearchRate-seed#[7C8BF33D67D53826]) [ ] o.a.s.c.a.s.SimSolrCloudTestCase [junit4] 2> [junit4] 2> 63184 INFO (TEST-TestTriggerIntegration.testSearchRate-seed#[7C8BF33D67D53826]) [ ] o.a.s.c.a.s.SimSolrCloudTestCase ############################################# [junit4] 2> 63184 INFO (TEST-TestTriggerIntegration.testSearchRate-seed#[7C8BF33D67D53826]) [ ] o.a.s.c.a.s.SimSolrCloudTestCase ############ FINAL CLUSTER STATS ############ [junit4] 2> 63184 INFO (TEST-TestTriggerIntegration.testSearchRate-seed#[7C8BF33D67D53826]) [ ] o.a.s.c.a.s.SimSolrCloudTestCase ############################################# [junit4] 2> [junit4] 2> 63184 INFO (TEST-TestTriggerIntegration.testSearchRate-seed#[7C8BF33D67D53826]) [ ] o.a.s.c.a.s.SimSolrCloudTestCase ## Live nodes: 2 [junit4] 2> 63185 INFO (TEST-TestTriggerIntegration.testSearchRate-seed#[7C8BF33D67D53826]) [ ] o.a.s.c.a.s.SimSolrCloudTestCase ## Empty nodes: 0 [junit4] 2> 63185 INFO (TEST-TestTriggerIntegration.testSearchRate-seed#[7C8BF33D67D53826]) [ ] o.a.s.c.a.s.SimSolrCloudTestCase ## Dead nodes: 0 [junit4] 2> 63185 INFO (TEST-TestTriggerIntegration.testSearchRate-seed#[7C8BF33D67D53826]) [ ] o.a.s.c.a.s.SimSolrCloudTestCase ## Collections: [collection1] [junit4] 2> 63185 INFO (TEST-TestTriggerIntegration.testSearchRate-seed#[7C8BF33D67D53826]) [ ] o.a.s.c.a.s.SimSolrCloudTestCase ## Max replicas per node: 1 [junit4] 2> 63186 INFO (TEST-TestTriggerIntegration.testSearchRate-seed#[7C8BF33D67D53826]) [ ] o.a.s.c.a.s.SimSolrCloudTestCase ## Min replicas per node: 1 [junit4] 2> 63186 INFO (TEST-TestTriggerIntegration.testSearchRate-seed#[7C8BF33D67D53826]) [ ] o.a.s.c.a.s.SimSolrCloudTestCase ## Total replicas: 2 [junit4] 2> 63186 INFO (TEST-TestTriggerIntegration.testSearchRate-seed#[7C8BF33D67D53826]) [ ] o.a.s.c.a.s.SimSolrCloudTestCase ## * collection1 2 [junit4] 2> 63186 INFO (TEST-TestTriggerIntegration.testSearchRate-seed#[7C8BF33D67D53826]) [ ] o.a.s.c.a.s.SimSolrCloudTestCase ## - active 2 [junit4] 2> 63186 INFO (TEST-TestTriggerIntegration.testSearchRate-seed#[7C8BF33D67D53826]) [ ] o.a.s.c.a.s.SimSolrCloudTestCase ######### Final Solr op counts ########## [junit4] 2> 63187 INFO (TEST-TestTriggerIntegration.testSearchRate-seed#[7C8BF33D67D53826]) [ ] o.a.s.c.a.s.SimSolrCloudTestCase ## - CREATE 1 [junit4] 2> 63187 INFO (TEST-TestTriggerIntegration.testSearchRate-seed#[7C8BF33D67D53826]) [ ] o.a.s.c.a.s.SimSolrCloudTestCase ## - autoscaling 2 [junit4] 2> 63187 INFO (TEST-TestTriggerIntegration.testSearchRate-seed#[7C8BF33D67D53826]) [ ] o.a.s.c.a.s.SimSolrCloudTestCase ## - update 1 [junit4] 2> 63187 INFO (TEST-TestTriggerIntegration.testSearchRate-seed#[7C8BF33D67D53826]) [ ] o.a.s.c.a.s.SimSolrCloudTestCase ######### Autoscaling event counts ########### [junit4] 2> NOTE: reproduce with: ant test -Dtestcase=TestTriggerIntegration -Dtests.method=testSearchRate -Dtests.seed=7C8BF33D67D53826 -Dtests.multiplier=2 -Dtests.slow=true -Dtests.locale=tr-TR -Dtests.timezone=America/Antigua -Dtests.asserts=true -Dtests.file.encoding=UTF-8 [junit4] FAILURE 1.53s J1 | TestTriggerIntegration.testSearchRate <<< [junit4] > Throwable #1: java.lang.AssertionError: The trigger did not fire at all [junit4] > at __randomizedtesting.SeedInfo.seed([7C8BF33D67D53826:21C3EDB4A8139E69]:0) [junit4] > at org.apache.solr.cloud.autoscaling.sim.TestTriggerIntegration.testSearchRate(TestTriggerIntegration.java:1178) [junit4] > at java.lang.Thread.run(Thread.java:748) [junit4] 2> 63227 DEBUG (AutoscalingActionExecutor-36-thread-1) [ ] o.a.s.c.a.ScheduledTriggers -- processing actions for { [junit4] 2> "id":"39ab66a2401fbTcrwbha45ogtcenwkvvquxqvo3", [junit4] 2> "source":"search_rate_trigger", [junit4] 2> "eventTime":1014533185602043, [junit4] 2> "eventType":"SEARCHRATE", [junit4] 2> "properties":{ [junit4] 2> "node":{ [junit4] 2> "127.0.0.1:10001_solr":250.0, [junit4] 2> "127.0.0.1:10000_solr":250.0}, [junit4] 2> "replica":[ [junit4] 2> "{\"core_node1\":{\n \"core\":\"collection1_shard1_replica_n1\",\n \"leader\":\"true\",\n \"INDEX.sizeInBytes\":123450000,\n \"rate\":250.0,\n \"node_name\":\"127.0.0.1:10001_solr\",\n \"state\":\"active\",\n \"type\":\"NRT\",\n \"QUERY./select.requestTimes:1minRate\":250.0,\n \"shard\":\"shard1\",\n \"collection\":\"collection1\"}}", [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:10000_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> "_enqueue_time_":1014539531285393}} [junit4] 2> 63387 DEBUG (AutoscalingActionExecutor-36-thread-1) [ ] o.a.s.c.a.ScheduledTriggers -- processing took 7988 ms for event id=39ab66a2401fbTcrwbha45ogtcenwkvvquxqvo3 [junit4] 2> 63387 INFO (TEST-TestTriggerIntegration.testNodeLostTriggerRestoreState-seed#[7C8BF33D67D53826]) [ ] o.a.s.SolrTestCaseJ4 ###Starting testNodeLostTriggerRestoreState [junit4] 2> 63388 DEBUG (TEST-TestTriggerIntegration.testNodeLostTriggerRestoreState-seed#[7C8BF33D67D53826]) [ ] o.a.s.c.a.OverseerTriggerThread Refreshing /autoscaling.json with znode version 5 [junit4] 2> 63388 INFO (TEST-TestTriggerIntegration.testNodeLostTriggerRestoreState-seed#[7C8BF33D67D53826]) [ ] o.a.s.c.a.s.SimCloudManager === Restarting OverseerTriggerThread and clearing object cache... [junit4] 2> 63388 WARN (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread OverseerTriggerThread woken up but we are closed, exiting. [junit4] 2> 63389 DEBUG (TEST-TestTriggerIntegration.testNodeLostTriggerRestoreState-seed#[7C8BF33D67D53826]) [ ] o.a.s.c.a.OverseerTriggerThread OverseerTriggerThread has been closed explicitly [junit4] 2> 63394 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Adding .autoAddReplicas trigger [junit4] 2> 63395 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Refreshing /autoscaling.json with znode version 6 [junit4] 2> 63395 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.NodeLostTrigger Initial livenodes: [127.0.0.1:10001_solr, 127.0.0.1:10000_solr] [junit4] 2> 63395 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Current znodeVersion 6, lastZnodeVersion -1 [junit4] 2> 63395 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Processed trigger updates upto znodeVersion 6 [junit4] 2> 63395 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread -- clean old nodeAdded markers [junit4] 2> 63395 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Current znodeVersion 6, lastZnodeVersion 6 [junit4] 2> 63395 DEBUG (ScheduledTrigger-38-thread-1) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 2 [junit4] 2> 63416 DEBUG (ScheduledTrigger-38-thread-1) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 2 [junit4] 2> 63510 DEBUG (ScheduledTrigger-38-thread-2) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 2 [junit4] 2> 63530 DEBUG (ScheduledTrigger-38-thread-2) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 3 [junit4] 2> 63553 DEBUG (ScheduledTrigger-38-thread-2) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 3 [junit4] 2> 63572 DEBUG (simCloudManagerPool-37-thread-1) [ ] o.a.s.c.a.AutoScalingHandler Verified autoscaling configuration [junit4] 2> 63585 DEBUG (simCloudManagerPool-37-thread-1) [ ] o.a.s.c.a.OverseerTriggerThread Refreshing /autoscaling.json with znode version 7 [junit4] 2> 63589 DEBUG (ScheduledTrigger-38-thread-2) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 3 [junit4] 2> 63678 DEBUG (simCloudManagerPool-37-thread-1) [ ] o.a.s.c.a.NodeLostTrigger Initial livenodes: [127.0.0.1:10001_solr, 127.0.0.1:10000_solr, 127.0.0.1:10002_solr] [junit4] 2> 63679 DEBUG (simCloudManagerPool-37-thread-1) [ ] o.a.s.c.a.NodeLostTrigger Initial livenodes: [127.0.0.1:10001_solr, 127.0.0.1:10000_solr, 127.0.0.1:10002_solr] [junit4] 2> 63686 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Processed trigger updates upto znodeVersion 7 [junit4] 2> 63686 INFO (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.s.TestTriggerIntegration TestTriggerAction init [junit4] 2> 63686 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread -- clean old nodeAdded markers [junit4] 2> 63686 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Current znodeVersion 7, lastZnodeVersion 7 [junit4] 2> 63698 DEBUG (ScheduledTrigger-38-thread-3) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: node_lost_restore_trigger with currently live nodes: 2 [junit4] 2> 63698 DEBUG (ScheduledTrigger-38-thread-3) [ ] o.a.s.c.a.NodeLostTrigger Tracking lost node: 127.0.0.1:10002_solr [junit4] 2> 63698 DEBUG (ScheduledTrigger-38-thread-3) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 2 [junit4] 2> 63698 DEBUG (ScheduledTrigger-38-thread-3) [ ] o.a.s.c.a.NodeLostTrigger Tracking lost node: 127.0.0.1:10002_solr [junit4] 2> 63723 DEBUG (simCloudManagerPool-37-thread-2) [ ] o.a.s.c.a.AutoScalingHandler Verified autoscaling configuration [junit4] 2> 63723 DEBUG (simCloudManagerPool-37-thread-2) [ ] o.a.s.c.a.OverseerTriggerThread Refreshing /autoscaling.json with znode version 8 [junit4] 2> 63724 DEBUG (simCloudManagerPool-37-thread-2) [ ] o.a.s.c.a.NodeLostTrigger Initial livenodes: [127.0.0.1:10001_solr, 127.0.0.1:10000_solr] [junit4] 2> 63724 DEBUG (simCloudManagerPool-37-thread-2) [ ] o.a.s.c.a.NodeLostTrigger Initial livenodes: [127.0.0.1:10001_solr, 127.0.0.1:10000_solr] [junit4] 2> 63724 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Processed trigger updates upto znodeVersion 8 [junit4] 2> 63751 DEBUG (ScheduledTrigger-38-thread-3) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 2 [junit4] 2> 63759 INFO (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.s.TestTriggerIntegration TestTriggerAction init [junit4] 2> 63759 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread -- clean old nodeAdded markers [junit4] 2> 63759 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Current znodeVersion 8, lastZnodeVersion 8 [junit4] 2> 63759 DEBUG (ScheduledTrigger-38-thread-1) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: node_lost_restore_trigger with currently live nodes: 2 [junit4] 2> 63759 DEBUG (ScheduledTrigger-38-thread-1) [ ] o.a.s.c.a.NodeLostTrigger NodeLostTrigger firing registered processor for lost nodes: [127.0.0.1:10002_solr] [junit4] 2> 63759 DEBUG (ScheduledTrigger-38-thread-1) [ ] o.a.s.c.a.ScheduledTriggers ++++++++ Cooldown inactive - processing event: { [junit4] 2> "id":"39ac0dd7ecc2bTcrwbha45ogtcenwkvvquxqvo6", [junit4] 2> "source":"node_lost_restore_trigger", [junit4] 2> "eventTime":1014578070604843, [junit4] 2> "eventType":"NODELOST", [junit4] 2> "properties":{ [junit4] 2> "eventTimes":[1014578070604843], [junit4] 2> "nodeNames":["127.0.0.1:10002_solr"]}} [junit4] 2> 63780 DEBUG (AutoscalingActionExecutor-39-thread-1) [ ] o.a.s.c.a.ScheduledTriggers -- processing actions for { [junit4] 2> "id":"39ac0dd7ecc2bTcrwbha45ogtcenwkvvquxqvo6", [junit4] 2> "source":"node_lost_restore_trigger", [junit4] 2> "eventTime":1014578070604843, [junit4] 2> "eventType":"NODELOST", [junit4] 2> "properties":{ [junit4] 2> "eventTimes":[1014578070604843], [junit4] 2> "_enqueue_time_":1014581136514493, [junit4] 2> "nodeNames":["127.0.0.1:10002_solr"]}} [junit4] 2> 63780 INFO (TEST-TestTriggerIntegration.testNodeLostTriggerRestoreState-seed#[7C8BF33D67D53826]) [ ] o.a.s.SolrTestCaseJ4 ###Ending testNodeLostTriggerRestoreState [junit4] 2> 63780 INFO (TEST-TestTriggerIntegration.testNodeLostTriggerRestoreState-seed#[7C8BF33D67D53826]) [ ] o.a.s.c.a.s.SimSolrCloudTestCase [junit4] 2> [junit4] 2> 63780 INFO (TEST-TestTriggerIntegration.testNodeLostTriggerRestoreState-seed#[7C8BF33D67D53826]) [ ] o.a.s.c.a.s.SimSolrCloudTestCase ############################################# [junit4] 2> 63780 INFO (TEST-TestTriggerIntegration.testNodeLostTriggerRestoreState-seed#[7C8BF33D67D53826]) [ ] o.a.s.c.a.s.SimSolrCloudTestCase ############ FINAL CLUSTER STATS ############ [junit4] 2> 63780 INFO (TEST-TestTriggerIntegration.testNodeLostTriggerRestoreState-seed#[7C8BF33D67D53826]) [ ] o.a.s.c.a.s.SimSolrCloudTestCase ############################################# [junit4] 2> [junit4] 2> 63780 INFO (TEST-TestTriggerIntegration.testNodeLostTriggerRestoreState-seed#[7C8BF33D67D53826]) [ ] o.a.s.c.a.s.SimSolrCloudTestCase ## Live nodes: 2 [junit4] 2> 63780 INFO (TEST-TestTriggerIntegration.testNodeLostTriggerRestoreState-seed#[7C8BF33D67D53826]) [ ] o.a.s.c.a.s.SimSolrCloudTestCase ## Empty nodes: 2 [junit4] 2> 63780 INFO (TEST-TestTriggerIntegration.testNodeLostTriggerRestoreState-seed#[7C8BF33D67D53826]) [ ] o.a.s.c.a.s.SimSolrCloudTestCase ## Dead nodes: 1 [junit4] 2> 63780 INFO (TEST-TestTriggerIntegration.testNodeLostTriggerRestoreState-seed#[7C8BF33D67D53826]) [ ] o.a.s.c.a.s.SimSolrCloudTestCase ## 127.0.0.1:10002_solr [junit4] 2> 63780 INFO (TEST-TestTriggerIntegration.testNodeLostTriggerRestoreState-seed#[7C8BF33D67D53826]) [ ] o.a.s.c.a.s.SimSolrCloudTestCase ## Collections: [] [junit4] 2> 63780 INFO (TEST-TestTriggerIntegration.testNodeLostTriggerRestoreState-seed#[7C8BF33D67D53826]) [ ] o.a.s.c.a.s.SimSolrCloudTestCase ## Max replicas per node: 0 [junit4] 2> 63780 INFO (TEST-TestTriggerIntegration.testNodeLostTriggerRestoreState-seed#[7C8BF33D67D53826]) [ ] o.a.s.c.a.s.SimSolrCloudTestCase ## Min replicas per node: 0 [junit4] 2> 63780 INFO (TEST-TestTriggerIntegration.testNodeLostTriggerRestoreState-seed#[7C8BF33D67D53826]) [ ] o.a.s.c.a.s.SimSolrCloudTestCase ## Total replicas: 0 [junit4] 2> 63780 INFO (TEST-TestTriggerIntegration.testNodeLostTriggerRestoreState-seed#[7C8BF33D67D53826]) [ ] o.a.s.c.a.s.SimSolrCloudTestCase ######### Final Solr op counts ########## [junit4] 2> 63780 INFO (TEST-TestTriggerIntegration.testNodeLostTriggerRestoreState-seed#[7C8BF33D67D53826]) [ ] o.a.s.c.a.s.SimSolrCloudTestCase ## - autoscaling 2 [junit4] 2> 63780 INFO (TEST-TestTriggerIntegration.testNodeLostTriggerRestoreState-seed#[7C8BF33D67D53826]) [ ] o.a.s.c.a.s.SimSolrCloudTestCase ## - update 1 [junit4] 2> 63780 INFO (TEST-TestTriggerIntegration.testNodeLostTriggerRestoreState-seed#[7C8BF33D67D53826]) [ ] o.a.s.c.a.s.SimSolrCloudTestCase ######### Autoscaling event counts ########### [junit4] 2> 63781 INFO (TEST-TestTriggerIntegration.testNodeLostTriggerRestoreState-seed#[7C8BF33D67D53826]) [ ] o.a.s.c.a.s.SimSolrCloudTestCase ## * Trigger: node_lost_restore_trigger [junit4] 2> 63781 INFO (TEST-TestTriggerIntegration.testNodeLostTriggerRestoreState-seed#[7C8BF33D67D53826]) [ ] o.a.s.c.a.s.SimSolrCloudTestCase ## - STARTED 1 [junit4] 2> 63783 DEBUG (AutoscalingActionExecutor-39-thread-1) [ ] o.a.s.c.a.ScheduledTriggers -- processing took 149 ms for event id=39ac0dd7ecc2bTcrwbha45ogtcenwkvvquxqvo6 [junit4] 2> 63790 INFO (TEST-TestTriggerIntegration.testNodeAddedTriggerRestoreState-seed#[7C8BF33D67D53826]) [ ] o.a.s.SolrTestCaseJ4 ###Starting testNodeAddedTriggerRestoreState [junit4] 2> 63790 DEBUG (TEST-TestTriggerIntegration.testNodeAddedTriggerRestoreState-seed#[7C8BF33D67D53826]) [ ] o.a.s.c.a.OverseerTriggerThread Refreshing /autoscaling.json with znode version 9 [junit4] 2> 63791 DEBUG (TEST-TestTriggerIntegration.testNodeAddedTriggerRestoreState-seed#[7C8BF33D67D53826]) [ ] o.a.s.c.a.s.SimNodeStateProvider - removing dead node values: 127.0.0.1:10002_solr [junit4] 2> 63791 INFO (TEST-TestTriggerIntegration.testNodeAddedTriggerRestoreState-seed#[7C8BF33D67D53826]) [ ] o.a.s.c.a.s.SimCloudManager === Restarting OverseerTriggerThread and clearing object cache... [junit4] 2> 63791 WARN (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread OverseerTriggerThread woken up but we are closed, exiting. [junit4] 2> 63791 DEBUG (TEST-TestTriggerIntegration.testNodeAddedTriggerRestoreState-seed#[7C8BF33D67D53826]) [ ] o.a.s.c.a.OverseerTriggerThread OverseerTriggerThread has been closed explicitly [junit4] 2> 63795 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Adding .autoAddReplicas trigger [junit4] 2> 63796 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Refreshing /autoscaling.json with znode version 10 [junit4] 2> 63796 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.NodeLostTrigger Initial livenodes: [127.0.0.1:10001_solr, 127.0.0.1:10000_solr] [junit4] 2> 63796 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Current znodeVersion 10, lastZnodeVersion -1 [junit4] 2> 63796 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Processed trigger updates upto znodeVersion 10 [junit4] 2> 63815 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread -- clean old nodeAdded markers [junit4] 2> 63816 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Current znodeVersion 10, lastZnodeVersion 10 [junit4] 2> 63816 DEBUG (ScheduledTrigger-41-thread-1) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 2 [junit4] 2> 63848 DEBUG (ScheduledTrigger-41-thread-1) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 2 [junit4] 2> 63868 DEBUG (ScheduledTrigger-41-thread-2) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 2 [junit4] 2> 63896 DEBUG (simCloudManagerPool-40-thread-1) [ ] o.a.s.c.a.AutoScalingHandler Verified autoscaling configuration [junit4] 2> 63897 DEBUG (simCloudManagerPool-40-thread-1) [ ] o.a.s.c.a.OverseerTriggerThread Refreshing /autoscaling.json with znode version 11 [junit4] 2> 63913 DEBUG (ScheduledTrigger-41-thread-1) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 2 [junit4] 2> 63927 DEBUG (simCloudManagerPool-40-thread-1) [ ] o.a.s.c.a.NodeAddedTrigger Initial livenodes: [127.0.0.1:10001_solr, 127.0.0.1:10000_solr] [junit4] 2> 63927 DEBUG (simCloudManagerPool-40-thread-1) [ ] o.a.s.c.a.NodeAddedTrigger NodeAddedTrigger node_added_restore_trigger instantiated with properties: {event=nodeAdded, waitFor=5, actions=[{name=test, class=org.apache.solr.cloud.autoscaling.sim.TestTriggerIntegration$TestTriggerAction}], enabled=true} [junit4] 2> 63927 DEBUG (simCloudManagerPool-40-thread-1) [ ] o.a.s.c.a.NodeLostTrigger Initial livenodes: [127.0.0.1:10001_solr, 127.0.0.1:10000_solr] [junit4] 2> 63927 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Processed trigger updates upto znodeVersion 11 [junit4] 2> 63927 INFO (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.s.TestTriggerIntegration TestTriggerAction init [junit4] 2> 63928 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Current znodeVersion 11, lastZnodeVersion 11 [junit4] 2> 63945 DEBUG (ScheduledTrigger-41-thread-4) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 2 [junit4] 2> 63945 DEBUG (ScheduledTrigger-41-thread-2) [ ] o.a.s.c.a.NodeAddedTrigger Running NodeAddedTrigger node_added_restore_trigger [junit4] 2> 63946 DEBUG (ScheduledTrigger-41-thread-2) [ ] o.a.s.c.a.NodeAddedTrigger Found livenodes: 2 [junit4] 2> 63982 DEBUG (ScheduledTrigger-41-thread-4) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 3 [junit4] 2> 64042 DEBUG (ScheduledTrigger-41-thread-3) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 3 [junit4] 2> 64045 DEBUG (simCloudManagerPool-40-thread-2) [ ] o.a.s.c.a.AutoScalingHandler Verified autoscaling configuration [junit4] 2> 64045 DEBUG (simCloudManagerPool-40-thread-2) [ ] o.a.s.c.a.OverseerTriggerThread Refreshing /autoscaling.json with znode version 12 [junit4] 2> 64046 DEBUG (simCloudManagerPool-40-thread-2) [ ] o.a.s.c.a.NodeAddedTrigger Initial livenodes: [127.0.0.1:10001_solr, 127.0.0.1:10000_solr, 127.0.0.1:10003_solr] [junit4] 2> 64046 DEBUG (simCloudManagerPool-40-thread-2) [ ] o.a.s.c.a.NodeAddedTrigger NodeAddedTrigger node_added_restore_trigger instantiated with properties: {event=nodeAdded, waitFor=0, actions=[{name=test, class=org.apache.solr.cloud.autoscaling.sim.TestTriggerIntegration$TestTriggerAction}], enabled=true} [junit4] 2> 64046 DEBUG (simCloudManagerPool-40-thread-2) [ ] o.a.s.c.a.NodeLostTrigger Initial livenodes: [127.0.0.1:10001_solr, 127.0.0.1:10000_solr, 127.0.0.1:10003_solr] [junit4] 2> 64176 DEBUG (ScheduledTrigger-41-thread-2) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 3 [junit4] 2> 64176 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Processed trigger updates upto znodeVersion 12 [junit4] 2> 64177 INFO (TEST-TestTriggerIntegration.testNodeAddedTriggerRestoreState-seed#[7C8BF33D67D53826]) [ ] o.a.s.SolrTestCaseJ4 ###Ending testNodeAddedTriggerRestoreState [junit4] 2> 64177 INFO (TEST-TestTriggerIntegration.testNodeAddedTriggerRestoreState-seed#[7C8BF33D67D53826]) [ ] o.a.s.c.a.s.SimSolrCloudTestCase [junit4] 2> [junit4] 2> 64177 INFO (TEST-TestTriggerIntegration.testNodeAddedTriggerRestoreState-seed#[7C8BF33D67D53826]) [ ] o.a.s.c.a.s.SimSolrCloudTestCase ############################################# [junit4] 2> 64177 INFO (TEST-TestTriggerIntegration.testNodeAddedTriggerRestoreState-seed#[7C8BF33D67D53826]) [ ] o.a.s.c.a.s.SimSolrCloudTestCase ############ FINAL CLUSTER STATS ############ [junit4] 2> 64177 INFO (TEST-TestTriggerIntegration.testNodeAddedTriggerRestoreState-seed#[7C8BF33D67D53826]) [ ] o.a.s.c.a.s.SimSolrCloudTestCase ############################################# [junit4] 2> [junit4] 2> 64177 INFO (TEST-TestTriggerIntegration.testNodeAddedTriggerRestoreState-seed#[7C8BF33D67D53826]) [ ] o.a.s.c.a.s.SimSolrCloudTestCase ## Live nodes: 3 [junit4] 2> 64177 INFO (TEST-TestTriggerIntegration.testNodeAddedTriggerRestoreState-seed#[7C8BF33D67D53826]) [ ] o.a.s.c.a.s.SimSolrCloudTestCase ## Empty nodes: 3 [junit4] 2> 64177 INFO (TEST-TestTriggerIntegration.testNodeAddedTriggerRestoreState-seed#[7C8BF33D67D53826]) [ ] o.a.s.c.a.s.SimSolrCloudTestCase ## Dead nodes: 0 [junit4] 2> 64177 INFO (TEST-TestTriggerIntegration.testNodeAddedTriggerRestoreState-seed#[7C8BF33D67D53826]) [ ] o.a.s.c.a.s.SimSolrCloudTestCase ## Collections: [] [junit4] 2> 64177 INFO (TEST-TestTriggerIntegration.testNodeAddedTriggerRestoreState-seed#[7C8BF33D67D53826]) [ ] o.a.s.c.a.s.SimSolrCloudTestCase ## Max replicas per node: 0 [junit4] 2> 64177 INFO (TEST-TestTriggerIntegration.testNodeAddedTriggerRestoreState-seed#[7C8BF33D67D53826]) [ ] o.a.s.c.a.s.SimSolrCloudTestCase ## Min replicas per node: 0 [junit4] 2> 64177 INFO (TEST-TestTriggerIntegration.testNodeAddedTriggerRestoreState-seed#[7C8BF33D67D53826]) [ ] o.a.s.c.a.s.SimSolrCloudTestCase ## Total replicas: 0 [junit4] 2> 64177 INFO (TEST-TestTriggerIntegration.testNodeAddedTriggerRestoreState-seed#[7C8BF33D67D53826]) [ ] o.a.s.c.a.s.SimSolrCloudTestCase ######### Final Solr op counts ########## [junit4] 2> 64177 INFO (TEST-TestTriggerIntegration.testNodeAddedTriggerRestoreState-seed#[7C8BF33D67D53826]) [ ] o.a.s.c.a.s.SimSolrCloudTestCase ## - autoscaling 2 [junit4] 2> 64177 INFO (TEST-TestTriggerIntegration.testNodeAddedTriggerRestoreState-seed#[7C8BF33D67D53826]) [ ] o.a.s.c.a.s.SimSolrCloudTestCase ######### Autoscaling event counts ########### [junit4] 2> NOTE: reproduce with: ant test -Dtestcase=TestTriggerIntegration -Dtests.method=testNodeAddedTriggerRestoreState -Dtests.seed=7C8BF33D67D53826 -Dtests.multiplier=2 -Dtests.slow=true -Dtests.locale=tr-TR -Dtests.timezone=America/Antigua -Dtests.asserts=true -Dtests.file.encoding=UTF-8 [junit4] FAILURE 0.40s J1 | TestTriggerIntegration.testNodeAddedTriggerRestoreState <<< [junit4] > Throwable #1: java.lang.AssertionError: Two TriggerAction instances should have been created by now [junit4] > at __randomizedtesting.SeedInfo.seed([7C8BF33D67D53826:F4B67A425D15D98B]:0) [junit4] > at org.apache.solr.cloud.autoscaling.sim.TestTriggerIntegration.testNodeAddedTriggerRestoreState(TestTriggerIntegration.java:361) [junit4] > at java.lang.Thread.run(Thread.java:748) [junit4] 2> 64179 INFO (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.s.TestTriggerIntegration TestTriggerAction init [junit4] 2> 64179 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Current znodeVersion 12, lastZnodeVersion 12 [junit4] 2> 64179 DEBUG (ScheduledTrigger-41-thread-2) [ ] o.a.s.c.a.NodeAddedTrigger Running NodeAddedTrigger node_added_restore_trigger [junit4] 2> 64179 DEBUG (ScheduledTrigger-41-thread-2) [ ] o.a.s.c.a.NodeAddedTrigger Found livenodes: 3 [junit4] 2> 64179 DEBUG (ScheduledTrigger-41-thread-2) [ ] o.a.s.c.a.NodeAddedTrigger Tracking new node: 127.0.0.1:10003_solr at time 1014602102387393 [junit4] 2> 64179 DEBUG (ScheduledTrigger-41-thread-2) [ ] o.a.s.c.a.NodeAddedTrigger NodeAddedTrigger node_added_restore_trigger firing registered processor for nodes: [127.0.0.1:10003_solr] added at times [1014602102387393], now=1014602106906093 [junit4] 2> 64179 DEBUG (ScheduledTrigger-41-thread-2) [ ] o.a.s.c.a.ScheduledTriggers ++++++++ Cooldown inactive - processing event: { [junit4] 2> "id":"39ac675e6b2c1Tcrwbha45ogtcenwkvvquxqvo9", [junit4] 2> "source":"node_added_restore_trigger", [junit4] 2> "eventTime":1014602102387393, [junit4] 2> "eventType":"NODEADDED", [junit4] 2> "properties":{ [junit4] 2> "eventTimes":[1014602102387393], [junit4] 2> "nodeNames":["127.0.0.1:10003_solr"]}} [junit4] 2> 64184 WARN (ScheduledTrigger-41-thread-4) [ ] o.a.s.c.a.NodeAddedTrigger NodeAddedTrigger ran but was already closed [junit4] 2> 64184 ERROR (ScheduledTrigger-41-thread-4) [ ] o.a.s.c.a.NodeAddedTrigger Unexpected exception in NodeAddedTrigger [junit4] 2> java.lang.RuntimeException: Trigger has been closed [junit4] 2> at org.apache.solr.cloud.autoscaling.NodeAddedTrigger.run(NodeAddedTrigger.java:124) [junit4] 2> at org.apache.solr.cloud.autoscaling.ScheduledTriggers$ScheduledTrigger.run(ScheduledTriggers.java:537) [junit4] 2> at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511) [junit4] 2> at java.util.concurrent.FutureTask.runAndReset(FutureTask.java:308) [junit4] 2> at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$301(ScheduledThreadPoolExecutor.java:180) [junit4] 2> at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:294) [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> 64236 DEBUG (AutoscalingActionExecutor-42-thread-1) [ ] o.a.s.c.a.ScheduledTriggers -- processing actions for { [junit4] 2> "id":"39ac675e6b2c1Tcrwbha45ogtcenwkvvquxqvo9", [junit4] 2> "source":"node_added_restore_trigger", [junit4] 2> "eventTime":1014602102387393, [junit4] 2> "eventType":"NODEADDED", [junit4] 2> "properties":{ [junit4] 2> "eventTimes":[1014602102387393], [junit4] 2> "_enqueue_time_":1014602123491493, [junit4] 2> "nodeNames":["127.0.0.1:10003_solr"]}} [junit4] 2> 64249 DEBUG (AutoscalingActionExecutor-42-thread-1) [ ] o.a.s.c.a.ScheduledTriggers -- processing took 658 ms for event id=39ac675e6b2c1Tcrwbha45ogtcenwkvvquxqvo9 [junit4] 2> 64250 DEBUG (ScheduledTrigger-41-thread-3) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 3 [junit4] 2> 64266 DEBUG (ScheduledTrigger-41-thread-1) [ ] o.a.s.c.a.NodeAddedTrigger Running NodeAddedTrigger node_added_restore_trigger [junit4] 2> 64266 DEBUG (ScheduledTrigger-41-thread-1) [ ] o.a.s.c.a.NodeAddedTrigger Found livenodes: 3 [junit4] 2> 64266 INFO (TEST-TestTriggerIntegration.testEventQueue-seed#[7C8BF33D67D53826]) [ ] o.a.s.SolrTestCaseJ4 ###Starting testEventQueue [junit4] 2> 64266 DEBUG (TEST-TestTriggerIntegration.testEventQueue-seed#[7C8BF33D67D53826]) [ ] o.a.s.c.a.OverseerTriggerThread Refreshing /autoscaling.json with znode version 13 [junit4] 2> 64267 INFO (TEST-TestTriggerIntegration.testEventQueue-seed#[7C8BF33D67D53826]) [ ] o.a.s.c.a.s.SimCloudManager === Restarting OverseerTriggerThread and clearing object cache... [junit4] 2> 64267 WARN (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread OverseerTriggerThread woken up but we are closed, exiting. [junit4] 2> 64270 DEBUG (ScheduledTrigger-41-thread-3) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 2 [junit4] 2> 64270 DEBUG (ScheduledTrigger-41-thread-3) [ ] o.a.s.c.a.NodeLostTrigger Tracking lost node: 127.0.0.1:10003_solr [junit4] 2> 64302 DEBUG (ScheduledTrigger-41-thread-3) [ ] o.a.s.c.a.NodeAddedTrigger Running NodeAddedTrigger node_added_restore_trigger [junit4] 2> 64302 DEBUG (ScheduledTrigger-41-thread-3) [ ] o.a.s.c.a.NodeAddedTrigger Found livenodes: 2 [junit4] 2> 64302 DEBUG (ScheduledTrigger-41-thread-3) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 2 [junit4] 2> 64318 DEBUG (TEST-TestTriggerIntegration.testEventQueue-seed#[7C8BF33D67D53826]) [ ] o.a.s.c.a.OverseerTriggerThread OverseerTriggerThread has been closed explicitly [junit4] 2> 64319 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Adding .autoAddReplicas trigger [junit4] 2> 64319 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Refreshing /autoscaling.json with znode version 14 [junit4] 2> 64319 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.NodeLostTrigger Initial livenodes: [127.0.0.1:10001_solr, 127.0.0.1:10000_solr] [junit4] 2> 64319 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Current znodeVersion 14, lastZnodeVersion -1 [junit4] 2> 64319 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Processed trigger updates upto znodeVersion 14 [junit4] 2> 64319 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread -- clean old nodeAdded markers [junit4] 2> 64320 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Current znodeVersion 14, lastZnodeVersion 14 [junit4] 2> 64320 DEBUG (ScheduledTrigger-44-thread-1) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 2 [junit4] 2> 64340 DEBUG (ScheduledTrigger-44-thread-1) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 2 [junit4] 2> 64361 DEBUG (ScheduledTrigger-44-thread-2) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 2 [junit4] 2> 64468 DEBUG (ScheduledTrigger-44-thread-1) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 2 [junit4] 2> 64469 DEBUG (simCloudManagerPool-43-thread-1) [ ] o.a.s.c.a.AutoScalingHandler Verified autoscaling configuration [junit4] 2> 64469 DEBUG (simCloudManagerPool-43-thread-1) [ ] o.a.s.c.a.OverseerTriggerThread Refreshing /autoscaling.json with znode version 15 [junit4] 2> 64469 DEBUG (simCloudManagerPool-43-thread-1) [ ] o.a.s.c.a.NodeLostTrigger Initial livenodes: [127.0.0.1:10001_solr, 127.0.0.1:10000_solr] [junit4] 2> 64469 INFO (simCloudManagerPool-43-thread-1) [ ] o.a.s.c.a.s.TestTriggerIntegration TestEventQueueAction instantiated [junit4] 2> 64469 DEBUG (simCloudManagerPool-43-thread-1) [ ] o.a.s.c.a.NodeAddedTrigger Initial livenodes: [127.0.0.1:10001_solr, 127.0.0.1:10000_solr] [junit4] 2> 64469 DEBUG (simCloudManagerPool-43-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> 64469 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Processed trigger updates upto znodeVersion 15 [junit4] 2> 64470 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.s.TestTriggerIntegration TestTriggerAction init [junit4] 2> 64470 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Current znodeVersion 15, lastZnodeVersion 15 [junit4] 2> 64470 DEBUG (ScheduledTrigger-44-thread-2) [ ] o.a.s.c.a.NodeAddedTrigger Running NodeAddedTrigger node_added_trigger1 [junit4] 2> 64470 DEBUG (ScheduledTrigger-44-thread-2) [ ] o.a.s.c.a.NodeAddedTrigger Found livenodes: 3 [junit4] 2> 64470 DEBUG (ScheduledTrigger-44-thread-2) [ ] o.a.s.c.a.NodeAddedTrigger Tracking new node: 127.0.0.1:10004_solr at time 1014616655063993 [junit4] 2> 64488 DEBUG (ScheduledTrigger-44-thread-2) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 3 [junit4] 2> 64490 DEBUG (ScheduledTrigger-44-thread-2) [ ] o.a.s.c.a.NodeAddedTrigger Running NodeAddedTrigger node_added_trigger1 [junit4] 2> 64490 DEBUG (ScheduledTrigger-44-thread-2) [ ] o.a.s.c.a.NodeAddedTrigger Found livenodes: 3 [junit4] 2> 64490 DEBUG (ScheduledTrigger-44-thread-2) [ ] o.a.s.c.a.NodeAddedTrigger NodeAddedTrigger node_added_trigger1 firing registered processor for nodes: [127.0.0.1:10004_solr] added at times [1014616655063993], now=1014617670094993 [junit4] 2> 64490 DEBUG (ScheduledTrigger-44-thread-2) [ ] o.a.s.c.a.ScheduledTriggers ++++++++ Cooldown inactive - processing event: { [junit4] 2> "id":"39ac9d94eebb9Tcrwbha45ogtcenwkvvquxqvoc", [junit4] 2> "source":"node_added_trigger1", [junit4] 2> "eventTime":1014616655063993, [junit4] 2> "eventType":"NODEADDED", [junit4] 2> "properties":{ [junit4] 2> "eventTimes":[1014616655063993], [junit4] 2> "nodeNames":["127.0.0.1:10004_solr"]}} [junit4] 2> 64501 DEBUG (AutoscalingActionExecutor-45-thread-1) [ ] o.a.s.c.a.ScheduledTriggers -- processing actions for { [junit4] 2> "id":"39ac9d94eebb9Tcrwbha45ogtcenwkvvquxqvoc", [junit4] 2> "source":"node_added_trigger1", [junit4] 2> "eventTime":1014616655063993, [junit4] 2> "eventType":"NODEADDED", [junit4] 2> "properties":{ [junit4] 2> "eventTimes":[1014616655063993], [junit4] 2> "_enqueue_time_":1014617679087143, [junit4] 2> "nodeNames":["127.0.0.1:10004_solr"]}} [junit4] 2> 64502 INFO (AutoscalingActionExecutor-45-thread-1) [ ] o.a.s.c.a.s.TestTriggerIntegration -- event: { [junit4] 2> "id":"39ac9d94eebb9Tcrwbha45ogtcenwkvvquxqvoc", [junit4] 2> "source":"node_added_trigger1", [junit4] 2> "eventTime":1014616655063993, [junit4] 2> "eventType":"NODEADDED", [junit4] 2> "properties":{ [junit4] 2> "eventTimes":[1014616655063993], [junit4] 2> "_enqueue_time_":1014617679087143, [junit4] 2> "nodeNames":["127.0.0.1:10004_solr"]}} [junit4] 2> 64504 INFO (TEST-TestTriggerIntegration.testEventQueue-seed#[7C8BF33D67D53826]) [ ] o.a.s.c.a.s.SimCloudManager === Restarting OverseerTriggerThread and clearing object cache... [junit4] 2> 64505 WARN (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread OverseerTriggerThread woken up but we are closed, exiting. [junit4] 2> 64505 DEBUG (TEST-TestTriggerIntegration.testEventQueue-seed#[7C8BF33D67D53826]) [ ] o.a.s.c.a.OverseerTriggerThread OverseerTriggerThread has been closed explicitly [junit4] 2> 64507 WARN (AutoscalingActionExecutor-45-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> 64507 DEBUG (AutoscalingActionExecutor-45-thread-1) [ ] o.a.s.c.a.ScheduledTriggers -- processing took 290 ms for event id=39ac9d94eebb9Tcrwbha45ogtcenwkvvquxqvoc [junit4] 2> 64520 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Refreshing /autoscaling.json with znode version 15 [junit4] 2> 64521 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.NodeLostTrigger Initial livenodes: [127.0.0.1:10004_solr, 127.0.0.1:10000_solr] [junit4] 2> 64521 INFO (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.s.TestTriggerIntegration TestEventQueueAction instantiated [junit4] 2> 64521 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.NodeAddedTrigger Initial livenodes: [127.0.0.1:10004_solr, 127.0.0.1:10000_solr] [junit4] 2> 64521 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> 64521 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Current znodeVersion 15, lastZnodeVersion -1 [junit4] 2> 64521 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Processed trigger updates upto znodeVersion 15 [junit4] 2> 64541 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.NodeLostTrigger Adding lost node from marker path: 127.0.0.1:10001_solr [junit4] 2> 64557 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.s.TestTriggerIntegration TestTriggerAction init [junit4] 2> 64573 DEBUG (ScheduledTrigger-47-thread-1) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 2 [junit4] 2> 64573 DEBUG (ScheduledTrigger-47-thread-1) [ ] o.a.s.c.a.NodeLostTrigger Tracking lost node: 127.0.0.1:10001_solr [junit4] 2> 64593 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Current znodeVersion 15, lastZnodeVersion 15 [junit4] 2> 64594 DEBUG (ScheduledTrigger-47-thread-2) [ ] o.a.s.c.a.ScheduledTriggers ++++++++ Cooldown inactive - processing event: { [junit4] 2> "id":"39ac9d94eebb9Tcrwbha45ogtcenwkvvquxqvoc", [junit4] 2> "source":"node_added_trigger1", [junit4] 2> "eventTime":1014616655063993, [junit4] 2> "eventType":"NODEADDED", [junit4] 2> "properties":{ [junit4] 2> "eventTimes":[1014616655063993], [junit4] 2> "_dequeue_time_":1014622843541493, [junit4] 2> "_enqueue_time_":1014617679087143, [junit4] 2> "nodeNames":["127.0.0.1:10004_solr"], [junit4] 2> "replaying":true}} [junit4] 2> 64663 DEBUG (ScheduledTrigger-47-thread-2) [ ] o.a.s.c.a.NodeAddedTrigger Running NodeAddedTrigger node_added_trigger1 [junit4] 2> 64664 DEBUG (ScheduledTrigger-47-thread-2) [ ] o.a.s.c.a.NodeAddedTrigger Found livenodes: 2 [junit4] 2> 64665 DEBUG (AutoscalingActionExecutor-48-thread-1) [ ] o.a.s.c.a.ScheduledTriggers -- processing actions for { [junit4] 2> "id":"39ac9d94eebb9Tcrwbha45ogtcenwkvvquxqvoc", [junit4] 2> "source":"node_added_trigger1", [junit4] 2> "eventTime":1014616655063993, [junit4] 2> "eventType":"NODEADDED", [junit4] 2> "properties":{ [junit4] 2> "eventTimes":[1014616655063993], [junit4] 2> "_dequeue_time_":1014622843541493, [junit4] 2> "_enqueue_time_":1014617679087143, [junit4] 2> "nodeNames":["127.0.0.1:10004_solr"], [junit4] 2> "replaying":true}} [junit4] 2> 64665 INFO (AutoscalingActionExecutor-48-thread-1) [ ] o.a.s.c.a.s.TestTriggerIntegration -- event: { [junit4] 2> "id":"39ac9d94eebb9Tcrwbha45ogtcenwkvvquxqvoc", [junit4] 2> "source":"node_added_trigger1", [junit4] 2> "eventTime":1014616655063993, [junit4] 2> "eventType":"NODEADDED", [junit4] 2> "properties":{ [junit4] 2> "eventTimes":[1014616655063993], [junit4] 2> "_dequeue_time_":1014622843541493, [junit4] 2> "_enqueue_time_":1014617679087143, [junit4] 2> "nodeNames":["127.0.0.1:10004_solr"], [junit4] 2> "replaying":true}} [junit4] 2> 64679 INFO (TEST-TestTriggerIntegration.testEventQueue-seed#[7C8BF33D67D53826]) [ ] o.a.s.SolrTestCaseJ4 ###Ending testEventQueue [junit4] 2> 64679 INFO (TEST-TestTriggerIntegration.testEventQueue-seed#[7C8BF33D67D53826]) [ ] o.a.s.c.a.s.SimSolrCloudTestCase [junit4] 2> [junit4] 2> 64679 INFO (TEST-TestTriggerIntegration.testEventQueue-seed#[7C8BF33D67D53826]) [ ] o.a.s.c.a.s.SimSolrCloudTestCase ############################################# [junit4] 2> 64679 INFO (TEST-TestTriggerIntegration.testEventQueue-seed#[7C8BF33D67D53826]) [ ] o.a.s.c.a.s.SimSolrCloudTestCase ############ FINAL CLUSTER STATS ############ [junit4] 2> 64679 INFO (TEST-TestTriggerIntegration.testEventQueue-seed#[7C8BF33D67D53826]) [ ] o.a.s.c.a.s.SimSolrCloudTestCase ############################################# [junit4] 2> [junit4] 2> 64679 INFO (TEST-TestTriggerIntegration.testEventQueue-seed#[7C8BF33D67D53826]) [ ] o.a.s.c.a.s.SimSolrCloudTestCase ## Live nodes: 2 [junit4] 2> 64679 INFO (TEST-TestTriggerIntegration.testEventQueue-seed#[7C8BF33D67D53826]) [ ] o.a.s.c.a.s.SimSolrCloudTestCase ## Empty nodes: 2 [junit4] 2> 64679 INFO (TEST-TestTriggerIntegration.testEventQueue-seed#[7C8BF33D67D53826]) [ ] o.a.s.c.a.s.SimSolrCloudTestCase ## Dead nodes: 1 [junit4] 2> 64679 INFO (TEST-TestTriggerIntegration.testEventQueue-seed#[7C8BF33D67D53826]) [ ] o.a.s.c.a.s.SimSolrCloudTestCase ## 127.0.0.1:10001_solr [junit4] 2> 64679 INFO (TEST-TestTriggerIntegration.testEventQueue-seed#[7C8BF33D67D53826]) [ ] o.a.s.c.a.s.SimSolrCloudTestCase ## Collections: [] [junit4] 2> 64679 INFO (TEST-TestTriggerIntegration.testEventQueue-seed#[7C8BF33D67D53826]) [ ] o.a.s.c.a.s.SimSolrCloudTestCase ## Max replicas per node: 0 [junit4] 2> 64679 INFO (TEST-TestTriggerIntegration.testEventQueue-seed#[7C8BF33D67D53826]) [ ] o.a.s.c.a.s.SimSolrCloudTestCase ## Min replicas per node: 0 [junit4] 2> 64679 INFO (TEST-TestTriggerIntegration.testEventQueue-seed#[7C8BF33D67D53826]) [ ] o.a.s.c.a.s.SimSolrCloudTestCase ## Total replicas: 0 [junit4] 2> 64679 INFO (TEST-TestTriggerIntegration.testEventQueue-seed#[7C8BF33D67D53826]) [ ] o.a.s.c.a.s.SimSolrCloudTestCase ######### Final Solr op counts ########## [junit4] 2> 64679 INFO (TEST-TestTriggerIntegration.testEventQueue-seed#[7C8BF33D67D53826]) [ ] o.a.s.c.a.s.SimSolrCloudTestCase ## - autoscaling 1 [junit4] 2> 64679 INFO (TEST-TestTriggerIntegration.testEventQueue-seed#[7C8BF33D67D53826]) [ ] o.a.s.c.a.s.SimSolrCloudTestCase ## - update 2 [junit4] 2> 64679 INFO (TEST-TestTriggerIntegration.testEventQueue-seed#[7C8BF33D67D53826]) [ ] o.a.s.c.a.s.SimSolrCloudTestCase ######### Autoscaling event counts ########### [junit4] 2> 64679 INFO (TEST-TestTriggerIntegration.testEventQueue-seed#[7C8BF33D67D53826]) [ ] o.a.s.c.a.s.SimSolrCloudTestCase ## * Trigger: node_added_trigger1 [junit4] 2> 64679 INFO (TEST-TestTriggerIntegration.testEventQueue-seed#[7C8BF33D67D53826]) [ ] o.a.s.c.a.s.SimSolrCloudTestCase ## - STARTED 2 [junit4] 2> 64736 DEBUG (AutoscalingActionExecutor-48-thread-1) [ ] o.a.s.c.a.ScheduledTriggers -- processing took 3556 ms for event id=39ac9d94eebb9Tcrwbha45ogtcenwkvvquxqvoc [junit4] 2> 64739 DEBUG (ScheduledTrigger-47-thread-2) [ ] o.a.s.c.a.NodeAddedTrigger Running NodeAddedTrigger node_added_trigger1 [junit4] 2> 64739 DEBUG (ScheduledTrigger-47-thread-2) [ ] o.a.s.c.a.NodeAddedTrigger Found livenodes: 2 [junit4] 2> 64776 DEBUG (ScheduledTrigger-47-thread-2) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 2 [junit4] 2> 64776 DEBUG (ScheduledTrigger-47-thread-3) [ ] o.a.s.c.a.NodeAddedTrigger Running NodeAddedTrigger node_added_trigger1 [junit4] 2> 64776 DEBUG (ScheduledTrigger-47-thread-3) [ ] o.a.s.c.a.NodeAddedTrigger Found livenodes: 2 [junit4] 2> 64777 INFO (TEST-TestTriggerIntegration.testTriggerThrottling-seed#[7C8BF33D67D53826]) [ ] o.a.s.SolrTestCaseJ4 ###Starting testTriggerThrottling [junit4] 2> 64777 DEBUG (TEST-TestTriggerIntegration.testTriggerThrottling-seed#[7C8BF33D67D53826]) [ ] o.a.s.c.a.OverseerTriggerThread Refreshing /autoscaling.json with znode version 16 [junit4] 2> 64777 DEBUG (TEST-TestTriggerIntegration.testTriggerThrottling-seed#[7C8BF33D67D53826]) [ ] o.a.s.c.a.s.SimNodeStateProvider - removing dead node values: 127.0.0.1:10001_solr [junit4] 2> 64777 INFO (TEST-TestTriggerIntegration.testTriggerThrottling-seed#[7C8BF33D67D53826]) [ ] o.a.s.c.a.s.SimCloudManager === Restarting OverseerTriggerThread and clearing object cache... [junit4] 2> 64777 WARN (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread OverseerTriggerThread woken up but we are closed, exiting. [junit4] 2> 64777 DEBUG (TEST-TestTriggerIntegration.testTriggerThrottling-seed#[7C8BF33D67D53826]) [ ] o.a.s.c.a.OverseerTriggerThread OverseerTriggerThread has been closed explicitly [junit4] 2> 64779 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Adding .autoAddReplicas trigger [junit4] 2> 64779 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Refreshing /autoscaling.json with znode version 17 [junit4] 2> 64779 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.NodeLostTrigger Initial livenodes: [127.0.0.1:10004_solr, 127.0.0.1:10000_solr] [junit4] 2> 64779 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Current znodeVersion 17, lastZnodeVersion -1 [junit4] 2> 64780 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Processed trigger updates upto znodeVersion 17 [junit4] 2> 64847 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread -- clean old nodeAdded markers [junit4] 2> 64847 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Current znodeVersion 17, lastZnodeVersion 17 [junit4] 2> 64848 DEBUG (ScheduledTrigger-50-thread-1) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 2 [junit4] 2> 64914 DEBUG (ScheduledTrigger-50-thread-1) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 2 [junit4] 2> 64914 DEBUG (simCloudManagerPool-49-thread-1) [ ] o.a.s.c.a.AutoScalingHandler Verified autoscaling configuration [junit4] 2> 64915 DEBUG (simCloudManagerPool-49-thread-1) [ ] o.a.s.c.a.OverseerTriggerThread Refreshing /autoscaling.json with znode version 18 [junit4] 2> 64934 DEBUG (simCloudManagerPool-49-thread-1) [ ] o.a.s.c.a.NodeLostTrigger Initial livenodes: [127.0.0.1:10004_solr, 127.0.0.1:10000_solr] [junit4] 2> 64935 DEBUG (simCloudManagerPool-49-thread-1) [ ] o.a.s.c.a.NodeAddedTrigger Initial livenodes: [127.0.0.1:10004_solr, 127.0.0.1:10000_solr] [junit4] 2> 64935 DEBUG (ScheduledTrigger-50-thread-3) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 2 [junit4] 2> 64956 DEBUG (ScheduledTrigger-50-thread-1) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 2 [junit4] 2> 64970 DEBUG (simCloudManagerPool-49-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> 64978 DEBUG (ScheduledTrigger-50-thread-4) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 2 [junit4] 2> 64986 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Processed trigger updates upto znodeVersion 18 [junit4] 2> 64987 INFO (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.s.TestTriggerIntegration TestTriggerAction init [junit4] 2> 64987 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Current znodeVersion 18, lastZnodeVersion 18 [junit4] 2> 64987 DEBUG (ScheduledTrigger-50-thread-2) [ ] o.a.s.c.a.NodeAddedTrigger Running NodeAddedTrigger node_added_trigger1 [junit4] 2> 64987 DEBUG (ScheduledTrigger-50-thread-2) [ ] o.a.s.c.a.NodeAddedTrigger Found livenodes: 2 [junit4] 2> 65003 DEBUG (simCloudManagerPool-49-thread-2) [ ] o.a.s.c.a.AutoScalingHandler Verified autoscaling configuration [junit4] 2> 65004 DEBUG (simCloudManagerPool-49-thread-2) [ ] o.a.s.c.a.OverseerTriggerThread Refreshing /autoscaling.json with znode version 19 [junit4] 2> 65004 DEBUG (simCloudManagerPool-49-thread-2) [ ] o.a.s.c.a.NodeAddedTrigger Initial livenodes: [127.0.0.1:10004_solr, 127.0.0.1:10000_solr] [junit4] 2> 65004 DEBUG (simCloudManagerPool-49-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> 65004 DEBUG (simCloudManagerPool-49-thread-2) [ ] o.a.s.c.a.NodeLostTrigger Initial livenodes: [127.0.0.1:10004_solr, 127.0.0.1:10000_solr] [junit4] 2> 65004 DEBUG (simCloudManagerPool-49-thread-2) [ ] o.a.s.c.a.NodeAddedTrigger Initial livenodes: [127.0.0.1:10004_solr, 127.0.0.1:10000_solr] [junit4] 2> 65004 DEBUG (simCloudManagerPool-49-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> 65004 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Processed trigger updates upto znodeVersion 19 [junit4] 2> 65004 INFO (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.s.TestTriggerIntegration TestTriggerAction init [junit4] 2> 65004 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Current znodeVersion 19, lastZnodeVersion 19 [junit4] 2> 65007 DEBUG (ScheduledTrigger-50-thread-2) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 3 [junit4] 2> 65007 DEBUG (ScheduledTrigger-50-thread-2) [ ] o.a.s.c.a.NodeAddedTrigger Running NodeAddedTrigger node_added_trigger2 [junit4] 2> 65007 DEBUG (ScheduledTrigger-50-thread-2) [ ] o.a.s.c.a.NodeAddedTrigger Found livenodes: 3 [junit4] 2> 65007 DEBUG (ScheduledTrigger-50-thread-2) [ ] o.a.s.c.a.NodeAddedTrigger Tracking new node: 127.0.0.1:10005_solr at time 1014643514211393 [junit4] 2> 65007 DEBUG (ScheduledTrigger-50-thread-2) [ ] o.a.s.c.a.NodeAddedTrigger NodeAddedTrigger node_added_trigger2 firing registered processor for nodes: [127.0.0.1:10005_solr] added at times [1014643514211393], now=1014643515889093 [junit4] 2> 65007 DEBUG (ScheduledTrigger-50-thread-2) [ ] o.a.s.c.a.ScheduledTriggers ++++++++ Cooldown inactive - processing event: { [junit4] 2> "id":"39ad01a3cfc41Tcrwbha45ogtcenwkvvquxqvog", [junit4] 2> "source":"node_added_trigger2", [junit4] 2> "eventTime":1014643514211393, [junit4] 2> "eventType":"NODEADDED", [junit4] 2> "properties":{ [junit4] 2> "eventTimes":[1014643514211393], [junit4] 2> "nodeNames":["127.0.0.1:10005_solr"]}} [junit4] 2> 65008 DEBUG (AutoscalingActionExecutor-51-thread-1) [ ] o.a.s.c.a.ScheduledTriggers -- processing actions for { [junit4] 2> "id":"39ad01a3cfc41Tcrwbha45ogtcenwkvvquxqvog", [junit4] 2> "source":"node_added_trigger2", [junit4] 2> "eventTime":1014643514211393, [junit4] 2> "eventType":"NODEADDED", [junit4] 2> "properties":{ [junit4] 2> "eventTimes":[1014643514211393], [junit4] 2> "_enqueue_time_":1014643524030893, [junit4] 2> "nodeNames":["127.0.0.1:10005_solr"]}} [junit4] 2> 65008 INFO (AutoscalingActionExecutor-51-thread-1) [ ] o.a.s.c.a.s.TestTriggerIntegration action executed from node_added_trigger2 [junit4] 2> 65009 DEBUG (AutoscalingActionExecutor-51-thread-1) [ ] o.a.s.c.a.ScheduledTriggers -- processing took 26 ms for event id=39ad01a3cfc41Tcrwbha45ogtcenwkvvquxqvog [junit4] 2> 65027 DEBUG (ScheduledTrigger-50-thread-2) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 3 [junit4] 2> 65028 DEBUG (ScheduledTrigger-50-thread-2) [ ] o.a.s.c.a.NodeAddedTrigger Running NodeAddedTrigger node_added_trigger2 [junit4] 2> 65028 DEBUG (ScheduledTrigger-50-thread-2) [ ] o.a.s.c.a.NodeAddedTrigger Found livenodes: 3 [junit4] 2> 65028 DEBUG (ScheduledTrigger-50-thread-2) [ ] o.a.s.c.a.NodeAddedTrigger Running NodeAddedTrigger node_added_trigger1 [junit4] 2> 65028 DEBUG (ScheduledTrigger-50-thread-2) [ ] o.a.s.c.a.NodeAddedTrigger Found livenodes: 3 [junit4] 2> 65028 DEBUG (ScheduledTrigger-50-thread-2) [ ] o.a.s.c.a.NodeAddedTrigger Tracking new node: 127.0.0.1:10005_solr at time 1014644581448393 [junit4] 2> 65028 DEBUG (ScheduledTrigger-50-thread-2) [ ] o.a.s.c.a.NodeAddedTrigger NodeAddedTrigger node_added_trigger1 firing registered processor for nodes: [127.0.0.1:10005_solr] added at times [1014644581448393], now=1014644583108993 [junit4] 2> 65029 DEBUG (ScheduledTrigger-50-thread-2) [ ] o.a.s.c.a.ScheduledTriggers -------- Cooldown period - rejecting event: { [junit4] 2> "id":"39ad059d9bac9Tcrwbha45ogtcenwkvvquxqvoj", [junit4] 2> "source":"node_added_trigger1", [junit4] 2> "eventTime":1014644581448393, [junit4] 2> "eventType":"NODEADDED", [junit4] 2> "properties":{ [junit4] 2> "eventTimes":[1014644581448393], [junit4] 2> "nodeNames":["127.0.0.1:10005_solr"]}} [junit4] 2> 65063 DEBUG (ScheduledTrigger-50-thread-1) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 3 [junit4] 2> 65064 DEBUG (ScheduledTrigger-50-thread-1) [ ] o.a.s.c.a.NodeAddedTrigger Running NodeAddedTrigger node_added_trigger2 [junit4] 2> 65064 DEBUG (ScheduledTrigger-50-thread-1) [ ] o.a.s.c.a.NodeAddedTrigger Found livenodes: 3 [junit4] 2> 65064 DEBUG (ScheduledTrigger-50-thread-4) [ ] o.a.s.c.a.NodeAddedTrigger Running NodeAddedTrigger node_added_trigger1 [junit4] 2> 65064 DEBUG (ScheduledTrigger-50-thread-4) [ ] o.a.s.c.a.NodeAddedTrigger Found livenodes: 3 [junit4] 2> 65064 DEBUG (ScheduledTrigger-50-thread-4) [ ] o.a.s.c.a.NodeAddedTrigger NodeAddedTrigger node_added_trigger1 firing registered processor for nodes: [127.0.0.1:10005_solr] added at times [1014644581448393], now=1014646343356793 [junit4] 2> 65064 DEBUG (ScheduledTrigger-50-thread-4) [ ] o.a.s.c.a.ScheduledTriggers -------- Cooldown period - rejecting event: { [junit4] 2> "id":"39ad059d9bac9Tcrwbha45ogtcenwkvvquxqvol", [junit4] 2> "source":"node_added_trigger1", [junit4] 2> "eventTime":1014644581448393, [junit4] 2> "eventType":"NODEADDED", [junit4] 2> "properties":{ [junit4] 2> "eventTimes":[1014644581448393], [junit4] 2> "nodeNames":["127.0.0.1:10005_solr"]}} [junit4] 2> 65096 DEBUG (ScheduledTrigger-50-thread-2) [ ] o.a.s.c.a.NodeAddedTrigger Running NodeAddedTrigger node_added_trigger2 [junit4] 2> 65096 DEBUG (ScheduledTrigger-50-thread-2) [ ] o.a.s.c.a.NodeAddedTrigger Found livenodes: 3 [junit4] 2> 65096 DEBUG (ScheduledTrigger-50-thread-2) [ ] o.a.s.c.a.NodeAddedTrigger Running NodeAddedTrigger node_added_trigger1 [junit4] 2> 65096 DEBUG (ScheduledTrigger-50-thread-2) [ ] o.a.s.c.a.NodeAddedTrigger Found livenodes: 3 [junit4] 2> 65096 DEBUG (ScheduledTrigger-50-thread-2) [ ] o.a.s.c.a.NodeAddedTrigger NodeAddedTrigger node_added_trigger1 firing registered processor for nodes: [127.0.0.1:10005_solr] added at times [1014644581448393], now=1014647953661543 [junit4] 2> 65096 DEBUG (ScheduledTrigger-50-thread-2) [ ] o.a.s.c.a.ScheduledTriggers -------- Cooldown period - rejecting event: { [junit4] 2> "id":"39ad059d9bac9Tcrwbha45ogtcenwkvvquxqvon", [junit4] 2> "source":"node_added_trigger1", [junit4] 2> "eventTime":1014644581448393, [junit4] 2> "eventType":"NODEADDED", [junit4] 2> "properties":{ [junit4] 2> "eventTimes":[1014644581448393], [junit4] 2> "nodeNames":["127.0.0.1:10005_solr"]}} [junit4] 2> 65116 DEBUG (ScheduledTrigger-50-thread-1) [ ] o.a.s.c.a.NodeAddedTrigger Running NodeAddedTrigger node_added_trigger2 [junit4] 2> 65116 DEBUG (ScheduledTrigger-50-thread-1) [ ] o.a.s.c.a.NodeAddedTrigger Found livenodes: 3 [junit4] 2> 65116 DEBUG (ScheduledTrigger-50-thread-3) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 3 [junit4] 2> 65118 DEBUG (ScheduledTrigger-50-thread-1) [ ] o.a.s.c.a.NodeAddedTrigger Running NodeAddedTrigger node_added_trigger1 [junit4] 2> 65118 DEBUG (ScheduledTrigger-50-thread-1) [ ] o.a.s.c.a.NodeAddedTrigger Found livenodes: 3 [junit4] 2> 65118 DEBUG (ScheduledTrigger-50-thread-1) [ ] o.a.s.c.a.NodeAddedTrigger NodeAddedTrigger node_added_trigger1 firing registered processor for nodes: [127.0.0.1:10005_solr] added at times [1014644581448393], now=1014649062224893 [junit4] 2> 65118 DEBUG (ScheduledTrigger-50-thread-1) [ ] o.a.s.c.a.ScheduledTriggers ++++++++ Cooldown inactive - processing event: { [junit4] 2> "id":"39ad059d9bac9Tcrwbha45ogtcenwkvvquxqvop", [junit4] 2> "source":"node_added_trigger1", [junit4] 2> "eventTime":1014644581448393, [junit4] 2> "eventType":"NODEADDED", [junit4] 2> "properties":{ [junit4] 2> "eventTimes":[1014644581448393], [junit4] 2> "nodeNames":["127.0.0.1:10005_solr"]}} [junit4] 2> 65136 DEBUG (AutoscalingActionExecutor-51-thread-1) [ ] o.a.s.c.a.ScheduledTriggers -- processing actions for { [junit4] 2> "id":"39ad059d9bac9Tcrwbha45ogtcenwkvvquxqvop", [junit4] 2> "source":"node_added_trigger1", [junit4] 2> "eventTime":1014644581448393, [junit4] 2> "eventType":"NODEADDED", [junit4] 2> "properties":{ [junit4] 2> "eventTimes":[1014644581448393], [junit4] 2> "_enqueue_time_":1014649071932993, [junit4] 2> "nodeNames":["127.0.0.1:10005_solr"]}} [junit4] 2> 65136 INFO (AutoscalingActionExecutor-51-thread-1) [ ] o.a.s.c.a.s.TestTriggerIntegration last action at 1014643579754493 time = 1014649954040343 [junit4] 2> 65136 INFO (AutoscalingActionExecutor-51-thread-1) [ ] o.a.s.c.a.s.TestTriggerIntegration action executed from node_added_trigger1 [junit4] 2> 65154 DEBUG (simCloudManagerPool-49-thread-9) [ ] o.a.s.c.a.AutoScalingHandler Verified autoscaling configuration [junit4] 2> 65155 DEBUG (simCloudManagerPool-49-thread-9) [ ] o.a.s.c.a.OverseerTriggerThread Refreshing /autoscaling.json with znode version 20 [junit4] 2> 65155 DEBUG (simCloudManagerPool-49-thread-9) [ ] o.a.s.c.a.NodeAddedTrigger Initial livenodes: [127.0.0.1:10004_solr, 127.0.0.1:10005_solr, 127.0.0.1:10000_solr] [junit4] 2> 65155 DEBUG (simCloudManagerPool-49-thread-9) [ ] 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> 65155 DEBUG (simCloudManagerPool-49-thread-9) [ ] o.a.s.c.a.NodeLostTrigger Initial livenodes: [127.0.0.1:10004_solr, 127.0.0.1:10005_solr, 127.0.0.1:10000_solr] [junit4] 2> 65155 DEBUG (simCloudManagerPool-49-thread-9) [ ] o.a.s.c.a.NodeAddedTrigger Initial livenodes: [127.0.0.1:10004_solr, 127.0.0.1:10005_solr, 127.0.0.1:10000_solr] [junit4] 2> 65155 DEBUG (simCloudManagerPool-49-thread-9) [ ] 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> 65155 DEBUG (simCloudManagerPool-49-thread-9) [ ] o.a.s.c.a.NodeLostTrigger Initial livenodes: [127.0.0.1:10004_solr, 127.0.0.1:10005_solr, 127.0.0.1:10000_solr] [junit4] 2> 65155 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Processed trigger updates upto znodeVersion 20 [junit4] 2> 65169 DEBUG (AutoscalingActionExecutor-51-thread-1) [ ] o.a.s.c.a.ScheduledTriggers -- processing took 1650 ms for event id=39ad059d9bac9Tcr [...truncated too long message...] che... [junit4] 2> 68568 WARN (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread OverseerTriggerThread woken up but we are closed, exiting. [junit4] 2> 68568 DEBUG (TEST-TestTriggerIntegration.testEventFromRestoredState-seed#[7C8BF33D67D53826]) [ ] o.a.s.c.a.OverseerTriggerThread OverseerTriggerThread has been closed explicitly [junit4] 2> 68616 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Refreshing /autoscaling.json with znode version 45 [junit4] 2> 68616 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.NodeLostTrigger Initial livenodes: [127.0.0.1:10006_solr, 127.0.0.1:10010_solr, 127.0.0.1:10014_solr, 127.0.0.1:10015_solr] [junit4] 2> 68617 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.NodeAddedTrigger Initial livenodes: [127.0.0.1:10006_solr, 127.0.0.1:10010_solr, 127.0.0.1:10014_solr, 127.0.0.1:10015_solr] [junit4] 2> 68617 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.NodeAddedTrigger NodeAddedTrigger node_added_trigger instantiated with properties: {event=nodeAdded, waitFor=10, actions=[{name=test, class=org.apache.solr.cloud.autoscaling.sim.TestTriggerIntegration$TestTriggerAction}], enabled=true} [junit4] 2> 68617 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Current znodeVersion 45, lastZnodeVersion -1 [junit4] 2> 68617 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Processed trigger updates upto znodeVersion 45 [junit4] 2> 68636 INFO (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.s.TestTriggerIntegration TestTriggerAction init [junit4] 2> 68636 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.NodeAddedTrigger Adding node from marker path: 127.0.0.1:10015_solr [junit4] 2> 68645 DEBUG (ScheduledTrigger-74-thread-1) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 4 [junit4] 2> 68652 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Current znodeVersion 45, lastZnodeVersion 45 [junit4] 2> 68661 DEBUG (ScheduledTrigger-74-thread-2) [ ] o.a.s.c.a.NodeAddedTrigger Running NodeAddedTrigger node_added_trigger [junit4] 2> 68661 DEBUG (ScheduledTrigger-74-thread-2) [ ] o.a.s.c.a.NodeAddedTrigger Found livenodes: 4 [junit4] 2> 68661 DEBUG (ScheduledTrigger-74-thread-2) [ ] o.a.s.c.a.NodeAddedTrigger NodeAddedTrigger node_added_trigger firing registered processor for nodes: [127.0.0.1:10015_solr] added at times [1014812227653293], now=1014826203733893 [junit4] 2> 68661 DEBUG (ScheduledTrigger-74-thread-2) [ ] o.a.s.c.a.ScheduledTriggers ++++++++ Cooldown inactive - processing event: { [junit4] 2> "id":"39af76257ceadTcrwbha45ogtcenwkvvquxqvpu", [junit4] 2> "source":"node_added_trigger", [junit4] 2> "eventTime":1014812227653293, [junit4] 2> "eventType":"NODEADDED", [junit4] 2> "properties":{ [junit4] 2> "eventTimes":[1014812227653293], [junit4] 2> "nodeNames":["127.0.0.1:10015_solr"]}} [junit4] 2> 68681 DEBUG (AutoscalingActionExecutor-75-thread-1) [ ] o.a.s.c.a.ScheduledTriggers -- processing actions for { [junit4] 2> "id":"39af76257ceadTcrwbha45ogtcenwkvvquxqvpu", [junit4] 2> "source":"node_added_trigger", [junit4] 2> "eventTime":1014812227653293, [junit4] 2> "eventType":"NODEADDED", [junit4] 2> "properties":{ [junit4] 2> "eventTimes":[1014812227653293], [junit4] 2> "_enqueue_time_":1014826212141743, [junit4] 2> "nodeNames":["127.0.0.1:10015_solr"]}} [junit4] 2> 68682 DEBUG (AutoscalingActionExecutor-75-thread-1) [ ] o.a.s.c.a.ScheduledTriggers -- processing took 29 ms for event id=39af76257ceadTcrwbha45ogtcenwkvvquxqvpu [junit4] 2> 68693 INFO (TEST-TestTriggerIntegration.testEventFromRestoredState-seed#[7C8BF33D67D53826]) [ ] o.a.s.SolrTestCaseJ4 ###Ending testEventFromRestoredState [junit4] 2> 68693 INFO (TEST-TestTriggerIntegration.testEventFromRestoredState-seed#[7C8BF33D67D53826]) [ ] o.a.s.c.a.s.SimSolrCloudTestCase [junit4] 2> [junit4] 2> 68693 INFO (TEST-TestTriggerIntegration.testEventFromRestoredState-seed#[7C8BF33D67D53826]) [ ] o.a.s.c.a.s.SimSolrCloudTestCase ############################################# [junit4] 2> 68693 INFO (TEST-TestTriggerIntegration.testEventFromRestoredState-seed#[7C8BF33D67D53826]) [ ] o.a.s.c.a.s.SimSolrCloudTestCase ############ FINAL CLUSTER STATS ############ [junit4] 2> 68693 INFO (TEST-TestTriggerIntegration.testEventFromRestoredState-seed#[7C8BF33D67D53826]) [ ] o.a.s.c.a.s.SimSolrCloudTestCase ############################################# [junit4] 2> [junit4] 2> 68693 INFO (TEST-TestTriggerIntegration.testEventFromRestoredState-seed#[7C8BF33D67D53826]) [ ] o.a.s.c.a.s.SimSolrCloudTestCase ## Live nodes: 4 [junit4] 2> 68693 INFO (TEST-TestTriggerIntegration.testEventFromRestoredState-seed#[7C8BF33D67D53826]) [ ] o.a.s.c.a.s.SimSolrCloudTestCase ## Empty nodes: 4 [junit4] 2> 68693 INFO (TEST-TestTriggerIntegration.testEventFromRestoredState-seed#[7C8BF33D67D53826]) [ ] o.a.s.c.a.s.SimSolrCloudTestCase ## Dead nodes: 0 [junit4] 2> 68693 INFO (TEST-TestTriggerIntegration.testEventFromRestoredState-seed#[7C8BF33D67D53826]) [ ] o.a.s.c.a.s.SimSolrCloudTestCase ## Collections: [] [junit4] 2> 68693 INFO (TEST-TestTriggerIntegration.testEventFromRestoredState-seed#[7C8BF33D67D53826]) [ ] o.a.s.c.a.s.SimSolrCloudTestCase ## Max replicas per node: 0 [junit4] 2> 68693 INFO (TEST-TestTriggerIntegration.testEventFromRestoredState-seed#[7C8BF33D67D53826]) [ ] o.a.s.c.a.s.SimSolrCloudTestCase ## Min replicas per node: 0 [junit4] 2> 68693 INFO (TEST-TestTriggerIntegration.testEventFromRestoredState-seed#[7C8BF33D67D53826]) [ ] o.a.s.c.a.s.SimSolrCloudTestCase ## Total replicas: 0 [junit4] 2> 68693 INFO (TEST-TestTriggerIntegration.testEventFromRestoredState-seed#[7C8BF33D67D53826]) [ ] o.a.s.c.a.s.SimSolrCloudTestCase ######### Final Solr op counts ########## [junit4] 2> 68693 INFO (TEST-TestTriggerIntegration.testEventFromRestoredState-seed#[7C8BF33D67D53826]) [ ] o.a.s.c.a.s.SimSolrCloudTestCase ## - autoscaling 1 [junit4] 2> 68693 INFO (TEST-TestTriggerIntegration.testEventFromRestoredState-seed#[7C8BF33D67D53826]) [ ] o.a.s.c.a.s.SimSolrCloudTestCase ## - update 4 [junit4] 2> 68693 INFO (TEST-TestTriggerIntegration.testEventFromRestoredState-seed#[7C8BF33D67D53826]) [ ] o.a.s.c.a.s.SimSolrCloudTestCase ######### Autoscaling event counts ########### [junit4] 2> 68693 INFO (TEST-TestTriggerIntegration.testEventFromRestoredState-seed#[7C8BF33D67D53826]) [ ] o.a.s.c.a.s.SimSolrCloudTestCase ## * Trigger: node_added_trigger [junit4] 2> 68694 INFO (TEST-TestTriggerIntegration.testEventFromRestoredState-seed#[7C8BF33D67D53826]) [ ] o.a.s.c.a.s.SimSolrCloudTestCase ## - STARTED 2 [junit4] 2> 68694 INFO (TEST-TestTriggerIntegration.testEventFromRestoredState-seed#[7C8BF33D67D53826]) [ ] o.a.s.c.a.s.SimSolrCloudTestCase ## - SUCCEEDED 2 [junit4] 2> 68714 DEBUG (ScheduledTrigger-74-thread-3) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 4 [junit4] 2> 68714 DEBUG (SUITE-TestTriggerIntegration-seed#[7C8BF33D67D53826]-worker) [ ] o.a.s.c.a.OverseerTriggerThread OverseerTriggerThread has been closed explicitly [junit4] 2> 68714 WARN (ScheduledTrigger-74-thread-3) [ ] o.a.s.c.a.NodeAddedTrigger NodeAddedTrigger ran but was already closed [junit4] 2> 68714 ERROR (ScheduledTrigger-74-thread-3) [ ] o.a.s.c.a.NodeAddedTrigger Unexpected exception in NodeAddedTrigger [junit4] 2> java.lang.RuntimeException: Trigger has been closed [junit4] 2> at org.apache.solr.cloud.autoscaling.NodeAddedTrigger.run(NodeAddedTrigger.java:124) [junit4] 2> at org.apache.solr.cloud.autoscaling.ScheduledTriggers$ScheduledTrigger.run(ScheduledTriggers.java:537) [junit4] 2> at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511) [junit4] 2> at java.util.concurrent.FutureTask.runAndReset(FutureTask.java:308) [junit4] 2> at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$301(ScheduledThreadPoolExecutor.java:180) [junit4] 2> at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:294) [junit4] 2> at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149) [junit4] 2> at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624) [junit4] 2> at java.lang.Thread.run(Thread.java:748) [junit4] 2> NOTE: leaving temporary files on disk at: /home/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-7.x/solr/build/solr-core/test/J1/temp/solr.cloud.autoscaling.sim.TestTriggerIntegration_7C8BF33D67D53826-001 [junit4] 2> 68746 WARN (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread OverseerTriggerThread woken up but we are closed, exiting. [junit4] 2> NOTE: test params are: codec=Lucene70, sim=RandomSimilarity(queryNorm=false): {}, locale=tr-TR, timezone=America/Antigua [junit4] 2> NOTE: Linux 4.4.0-104-generic amd64/Oracle Corporation 1.8.0_152 (64-bit)/cpus=4,threads=1,free=252479448,total=324009984 [junit4] 2> NOTE: All tests run in this JVM: [TestSha256AuthenticationProvider, BasicZkTest, TestFastLRUCache, HighlighterMaxOffsetTest, CachingDirectoryFactoryTest, TestTriggerIntegration] [junit4] Completed [8/767 (1!)] on J1 in 7.40s, 11 tests, 3 failures <<< FAILURES! [...truncated 50720 lines...]
--------------------------------------------------------------------- To unsubscribe, e-mail: dev-unsubscr...@lucene.apache.org For additional commands, e-mail: dev-h...@lucene.apache.org