You are viewing a plain text version of this content. The canonical link for it is here.
Posted to builds@lucene.apache.org by Apache Jenkins Server <je...@builds.apache.org> on 2019/11/11 03:24:19 UTC
[JENKINS] Lucene-Solr-Tests-8.3 - Build # 91 - Unstable
Build: https://builds.apache.org/job/Lucene-Solr-Tests-8.3/91/
1 tests failed.
FAILED: org.apache.solr.cloud.autoscaling.sim.TestSimTriggerIntegration.testNodeLostTriggerRestoreState
Error Message:
OverseerTriggerThread never caught up to the latest znodeVersion
Stack Trace:
java.util.concurrent.TimeoutException: OverseerTriggerThread never caught up to the latest znodeVersion
at __randomizedtesting.SeedInfo.seed([6025CDAA20F4310C:4BDA18F1BA8C24DC]:0)
at org.apache.solr.util.TimeOut.waitFor(TimeOut.java:66)
at org.apache.solr.cloud.autoscaling.sim.SimSolrCloudTestCase.assertAutoscalingUpdateComplete(SimSolrCloudTestCase.java:98)
at org.apache.solr.cloud.autoscaling.sim.TestSimTriggerIntegration.testNodeLostTriggerRestoreState(TestSimTriggerIntegration.java:300)
at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
at java.lang.reflect.Method.invoke(Method.java:498)
at com.carrotsearch.randomizedtesting.RandomizedRunner.invoke(RandomizedRunner.java:1750)
at com.carrotsearch.randomizedtesting.RandomizedRunner$8.evaluate(RandomizedRunner.java:938)
at com.carrotsearch.randomizedtesting.RandomizedRunner$9.evaluate(RandomizedRunner.java:974)
at com.carrotsearch.randomizedtesting.RandomizedRunner$10.evaluate(RandomizedRunner.java:988)
at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:57)
at org.apache.lucene.util.TestRuleSetupTeardownChained$1.evaluate(TestRuleSetupTeardownChained.java:49)
at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:45)
at org.apache.lucene.util.TestRuleThreadAndTestName$1.evaluate(TestRuleThreadAndTestName.java:48)
at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:64)
at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:47)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:368)
at com.carrotsearch.randomizedtesting.ThreadLeakControl.forkTimeoutingTask(ThreadLeakControl.java:817)
at com.carrotsearch.randomizedtesting.ThreadLeakControl$3.evaluate(ThreadLeakControl.java:468)
at com.carrotsearch.randomizedtesting.RandomizedRunner.runSingleTest(RandomizedRunner.java:947)
at com.carrotsearch.randomizedtesting.RandomizedRunner$5.evaluate(RandomizedRunner.java:832)
at com.carrotsearch.randomizedtesting.RandomizedRunner$6.evaluate(RandomizedRunner.java:883)
at com.carrotsearch.randomizedtesting.RandomizedRunner$7.evaluate(RandomizedRunner.java:894)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:57)
at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:45)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at org.apache.lucene.util.TestRuleStoreClassName$1.evaluate(TestRuleStoreClassName.java:41)
at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:40)
at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:40)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at org.apache.lucene.util.TestRuleAssertionsRequired$1.evaluate(TestRuleAssertionsRequired.java:53)
at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:47)
at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:64)
at org.apache.lucene.util.TestRuleIgnoreTestSuites$1.evaluate(TestRuleIgnoreTestSuites.java:54)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:368)
at java.lang.Thread.run(Thread.java:748)
Build Log:
[...truncated 15213 lines...]
[junit4] Suite: org.apache.solr.cloud.autoscaling.sim.TestSimTriggerIntegration
[junit4] 2> 1904483 INFO (SUITE-TestSimTriggerIntegration-seed#[6025CDAA20F4310C]-worker) [ ] o.a.s.SolrTestCaseJ4 Created dataDir: /home/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-8.3/solr/build/solr-core/test/J1/temp/solr.cloud.autoscaling.sim.TestSimTriggerIntegration_6025CDAA20F4310C-001/data-dir-177-001
[junit4] 2> 1904483 INFO (SUITE-TestSimTriggerIntegration-seed#[6025CDAA20F4310C]-worker) [ ] o.a.s.SolrTestCaseJ4 Using TrieFields (NUMERIC_POINTS_SYSPROP=false) w/NUMERIC_DOCVALUES_SYSPROP=true
[junit4] 2> 1904484 INFO (SUITE-TestSimTriggerIntegration-seed#[6025CDAA20F4310C]-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> 1904484 INFO (SUITE-TestSimTriggerIntegration-seed#[6025CDAA20F4310C]-worker) [ ] o.a.s.SolrTestCaseJ4 SecureRandom sanity checks: test.solr.allowed.securerandom=null & java.security.egd=file:/dev/./urandom
[junit4] 2> 1904487 INFO (TEST-TestSimTriggerIntegration.testNodeMarkersRegistration-seed#[6025CDAA20F4310C]) [ ] o.a.s.SolrTestCaseJ4 ###Starting testNodeMarkersRegistration
[junit4] 2> 1904514 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Adding .auto_add_replicas and .scheduled_maintenance triggers
[junit4] 2> 1904514 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Refreshing /autoscaling.json with znode version 1
[junit4] 2> 1904514 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Current znodeVersion 1, lastZnodeVersion 0
[junit4] 2> 1904514 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Processed trigger updates upto znodeVersion 1
[junit4] 2> 1904514 DEBUG (TEST-TestSimTriggerIntegration.testNodeMarkersRegistration-seed#[6025CDAA20F4310C]) [ ] o.a.s.c.a.s.SimClusterStateProvider --- new Overseer leader: 127.0.0.1:10000_solr
[junit4] 2> 1904515 DEBUG (TEST-TestSimTriggerIntegration.testNodeMarkersRegistration-seed#[6025CDAA20F4310C]) [ ] o.a.s.c.a.s.SimClusterStateProvider ** creating new collection states, currentVersion=0
[junit4] 2> 1904516 DEBUG (TEST-TestSimTriggerIntegration.testNodeMarkersRegistration-seed#[6025CDAA20F4310C]) [ ] o.a.s.c.a.s.SimClusterStateProvider ** saved cluster state version 0
[junit4] 2> 1904516 INFO (TEST-TestSimTriggerIntegration.testNodeMarkersRegistration-seed#[6025CDAA20F4310C]) [ ] o.a.s.h.a.MetricsHistoryHandler No .system collection, keeping metrics history in memory.
[junit4] 2> 1904517 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.NodeLostTrigger NodeLostTrigger .auto_add_replicas - Initial livenodes: [127.0.0.1:10001_solr, 127.0.0.1:10000_solr]
[junit4] 2> 1904517 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread -- deactivating old nodeLost / nodeAdded markers
[junit4] 2> 1904517 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Current znodeVersion 1, lastZnodeVersion 1
[junit4] 2> 1904518 DEBUG (ScheduledTrigger-10110-thread-2) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 2 and last live nodes: 2
[junit4] 2> 1904519 DEBUG (simCloudManagerPool-10109-thread-2) [ ] o.a.s.c.a.AutoScalingHandler Verified autoscaling configuration
[junit4] 2> 1904519 DEBUG (simCloudManagerPool-10109-thread-2) [ ] o.a.s.c.a.OverseerTriggerThread Refreshing /autoscaling.json with znode version 2
[junit4] 2> 1904520 INFO (TEST-TestSimTriggerIntegration.testNodeMarkersRegistration-seed#[6025CDAA20F4310C]) [ ] o.a.s.c.a.s.TestSimTriggerIntegration ====== KILL OVERSEER 1
[junit4] 2> 1904520 INFO (TEST-TestSimTriggerIntegration.testNodeMarkersRegistration-seed#[6025CDAA20F4310C]) [ ] o.a.s.c.a.s.SimCloudManager === Restarting OverseerTriggerThread and clearing object cache...
[junit4] 2> 1904523 DEBUG (TEST-TestSimTriggerIntegration.testNodeMarkersRegistration-seed#[6025CDAA20F4310C]) [ ] o.a.s.c.a.ScheduledTriggers Shutting down scheduled thread pool executor now
[junit4] 2> 1904523 INFO (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread OverseerTriggerThread woken up but we are closed, exiting.
[junit4] 2> 1904523 DEBUG (TEST-TestSimTriggerIntegration.testNodeMarkersRegistration-seed#[6025CDAA20F4310C]) [ ] o.a.s.c.a.ScheduledTriggers Shutting down action executor now
[junit4] 2> 1904523 DEBUG (TEST-TestSimTriggerIntegration.testNodeMarkersRegistration-seed#[6025CDAA20F4310C]) [ ] o.a.s.c.a.ScheduledTriggers Awaiting termination for action executor
[junit4] 2> 1904523 DEBUG (TEST-TestSimTriggerIntegration.testNodeMarkersRegistration-seed#[6025CDAA20F4310C]) [ ] o.a.s.c.a.ScheduledTriggers Awaiting termination for scheduled thread pool executor
[junit4] 2> 1904524 DEBUG (TEST-TestSimTriggerIntegration.testNodeMarkersRegistration-seed#[6025CDAA20F4310C]) [ ] o.a.s.c.a.ScheduledTriggers ScheduledTriggers closed completely
[junit4] 2> 1904524 DEBUG (TEST-TestSimTriggerIntegration.testNodeMarkersRegistration-seed#[6025CDAA20F4310C]) [ ] o.a.s.c.a.OverseerTriggerThread OverseerTriggerThread has been closed explicitly
[junit4] 2> 1904524 INFO (TEST-TestSimTriggerIntegration.testNodeMarkersRegistration-seed#[6025CDAA20F4310C]) [ ] o.a.s.c.a.s.SimCloudManager = killing node 127.0.0.1:10000_solr
[junit4] 2> 1904524 DEBUG (TEST-TestSimTriggerIntegration.testNodeMarkersRegistration-seed#[6025CDAA20F4310C]) [ ] o.a.s.c.a.s.SimClusterStateProvider -- created marker: /autoscaling/nodeLost/127.0.0.1:10000_solr
[junit4] 2> 1904524 DEBUG (TEST-TestSimTriggerIntegration.testNodeMarkersRegistration-seed#[6025CDAA20F4310C]) [ ] o.a.s.c.a.s.SimClusterStateProvider --- new Overseer leader: 127.0.0.1:10001_solr
[junit4] 2> 1904524 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Refreshing /autoscaling.json with znode version 2
[junit4] 2> 1904525 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Current znodeVersion 2, lastZnodeVersion 0
[junit4] 2> 1904525 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Processed trigger updates upto znodeVersion 2
[junit4] 2> 1904525 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.NodeLostTrigger NodeLostTrigger .auto_add_replicas - Initial livenodes: [127.0.0.1:10001_solr, 127.0.0.1:10002_solr]
[junit4] 2> 1904525 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.NodeLostTrigger Adding lost node from marker path: 127.0.0.1:10000_solr
[junit4] 2> 1904525 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread -- deactivating old nodeLost / nodeAdded markers
[junit4] 2> 1904525 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Current znodeVersion 2, lastZnodeVersion 2
[junit4] 2> 1904525 DEBUG (ScheduledTrigger-10115-thread-1) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 2 and last live nodes: 2
[junit4] 2> 1904525 DEBUG (ScheduledTrigger-10115-thread-1) [ ] o.a.s.c.a.NodeLostTrigger Tracking lost node: 127.0.0.1:10000_solr
[junit4] 2> 1904545 DEBUG (ScheduledTrigger-10115-thread-1) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 2 and last live nodes: 2
[junit4] 2> 1904566 DEBUG (ScheduledTrigger-10115-thread-2) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 2 and last live nodes: 2
[junit4] 2> 1904586 DEBUG (ScheduledTrigger-10115-thread-1) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 2 and last live nodes: 2
[junit4] 2> 1904606 DEBUG (ScheduledTrigger-10115-thread-1) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 2 and last live nodes: 2
[junit4] 2> 1904626 DEBUG (ScheduledTrigger-10115-thread-1) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 2 and last live nodes: 2
[junit4] 2> 1904630 INFO (TEST-TestSimTriggerIntegration.testNodeMarkersRegistration-seed#[6025CDAA20F4310C]) [ ] o.a.s.c.a.s.TestSimTriggerIntegration ====== ADD TRIGGERS
[junit4] 2> 1904632 DEBUG (simCloudManagerPool-10114-thread-1) [ ] o.a.s.c.a.AutoScalingHandler Verified autoscaling configuration
[junit4] 2> 1904632 DEBUG (simCloudManagerPool-10114-thread-1) [ ] o.a.s.c.a.OverseerTriggerThread Refreshing /autoscaling.json with znode version 3
[junit4] 2> 1904633 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Processed trigger updates upto znodeVersion 3
[junit4] 2> 1904633 INFO (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.s.TestSimTriggerIntegration TestEventMarkerAction init
[junit4] 2> 1904633 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.NodeAddedTrigger NodeAddedTrigger node_added_triggerMR - Initial livenodes: [127.0.0.1:10001_solr, 127.0.0.1:10002_solr]
[junit4] 2> 1904633 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.NodeAddedTrigger NodeAddedTrigger node_added_triggerMR instantiated with properties: {event=nodeAdded, waitFor=1, actions=[{name=test, class=org.apache.solr.cloud.autoscaling.sim.TestSimTriggerIntegration$TestEventMarkerAction}], enabled=true}
[junit4] 2> 1904633 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread -- deactivating old nodeLost / nodeAdded markers
[junit4] 2> 1904633 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Current znodeVersion 3, lastZnodeVersion 3
[junit4] 2> 1904633 DEBUG (ScheduledTrigger-10115-thread-3) [ ] o.a.s.c.a.NodeAddedTrigger Running NodeAddedTrigger node_added_triggerMR
[junit4] 2> 1904634 DEBUG (ScheduledTrigger-10115-thread-3) [ ] o.a.s.c.a.NodeAddedTrigger Found livenodes: 2
[junit4] 2> 1904634 DEBUG (simCloudManagerPool-10114-thread-2) [ ] o.a.s.c.a.AutoScalingHandler Verified autoscaling configuration
[junit4] 2> 1904634 DEBUG (simCloudManagerPool-10114-thread-2) [ ] o.a.s.c.a.OverseerTriggerThread Refreshing /autoscaling.json with znode version 4
[junit4] 2> 1904634 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Processed trigger updates upto znodeVersion 4
[junit4] 2> 1904635 INFO (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.s.TestSimTriggerIntegration TestEventMarkerAction init
[junit4] 2> 1904635 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.NodeLostTrigger NodeLostTrigger node_lost_triggerMR - Initial livenodes: [127.0.0.1:10001_solr, 127.0.0.1:10002_solr]
[junit4] 2> 1904635 DEBUG (ScheduledTrigger-10115-thread-1) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: node_lost_triggerMR with currently live nodes: 2 and last live nodes: 2
[junit4] 2> 1904635 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread -- deactivating old nodeLost / nodeAdded markers
[junit4] 2> 1904635 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Current znodeVersion 4, lastZnodeVersion 4
[junit4] 2> 1904635 DEBUG (simCloudManagerPool-10114-thread-3) [ ] o.a.s.c.a.AutoScalingHandler Verified autoscaling configuration
[junit4] 2> 1904635 DEBUG (simCloudManagerPool-10114-thread-3) [ ] o.a.s.c.a.OverseerTriggerThread Refreshing /autoscaling.json with znode version 5
[junit4] 2> 1904636 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Processed trigger updates upto znodeVersion 5
[junit4] 2> 1904636 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread -- deactivating old nodeLost / nodeAdded markers
[junit4] 2> 1904636 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Current znodeVersion 5, lastZnodeVersion 5
[junit4] 2> 1904636 INFO (TEST-TestSimTriggerIntegration.testNodeMarkersRegistration-seed#[6025CDAA20F4310C]) [ ] o.a.s.c.a.s.TestSimTriggerIntegration ====== ADD NODE 1
[junit4] 2> 1904636 DEBUG (TEST-TestSimTriggerIntegration.testNodeMarkersRegistration-seed#[6025CDAA20F4310C]) [ ] o.a.s.c.a.s.SimClusterStateProvider -- creating marker: /autoscaling/nodeAdded/127.0.0.1:10003_solr
[junit4] 2> 1904647 DEBUG (ScheduledTrigger-10115-thread-4) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 3 and last live nodes: 2
[junit4] 2> 1904655 DEBUG (ScheduledTrigger-10115-thread-2) [ ] o.a.s.c.a.NodeAddedTrigger Running NodeAddedTrigger node_added_triggerMR
[junit4] 2> 1904655 DEBUG (ScheduledTrigger-10115-thread-2) [ ] o.a.s.c.a.NodeAddedTrigger Found livenodes: 3
[junit4] 2> 1904655 DEBUG (ScheduledTrigger-10115-thread-3) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: node_lost_triggerMR with currently live nodes: 3 and last live nodes: 2
[junit4] 2> 1904655 DEBUG (ScheduledTrigger-10115-thread-2) [ ] o.a.s.c.a.NodeAddedTrigger Tracking new node: 127.0.0.1:10003_solr at time 9862553869016760
[junit4] 2> 1904667 DEBUG (ScheduledTrigger-10115-thread-1) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 3 and last live nodes: 3
[junit4] 2> 1904675 DEBUG (ScheduledTrigger-10115-thread-4) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: node_lost_triggerMR with currently live nodes: 3 and last live nodes: 3
[junit4] 2> 1904675 DEBUG (ScheduledTrigger-10115-thread-3) [ ] o.a.s.c.a.NodeAddedTrigger Running NodeAddedTrigger node_added_triggerMR
[junit4] 2> 1904675 DEBUG (ScheduledTrigger-10115-thread-3) [ ] o.a.s.c.a.NodeAddedTrigger Found livenodes: 3
[junit4] 2> 1904675 DEBUG (ScheduledTrigger-10115-thread-3) [ ] o.a.s.c.a.NodeAddedTrigger NodeAddedTrigger node_added_triggerMR firing registered processor for nodes: [127.0.0.1:10003_solr] added at times [9862553869016760], now=9862554876186860
[junit4] 2> 1904676 DEBUG (ScheduledTrigger-10115-thread-3) [ ] o.a.s.c.a.ScheduledTriggers ++++++++ Cooldown inactive - processing event: {
[junit4] 2> "id":"2309f0c3f0deb8Taeijcq2todj4jxogzau7scz2d",
[junit4] 2> "source":"node_added_triggerMR",
[junit4] 2> "eventTime":9862553869016760,
[junit4] 2> "eventType":"NODEADDED",
[junit4] 2> "properties":{
[junit4] 2> "eventTimes":[9862553869016760],
[junit4] 2> "preferredOperation":"movereplica",
[junit4] 2> "nodeNames":["127.0.0.1:10003_solr"],
[junit4] 2> "replicaType":"NRT"}}
[junit4] 2> 1904676 DEBUG (ScheduledTrigger-10115-thread-3) [ ] o.a.s.c.a.ScheduledTriggers Pausing all triggers: [node_lost_triggerMR, node_added_triggerMR, .auto_add_replicas]
[junit4] 2> 1904676 DEBUG (ScheduledTrigger-10115-thread-3) [ ] o.a.s.c.a.SystemLogListener Collection .system missing, skip sending event {
[junit4] 2> "id":"2309f0c3f0deb8Taeijcq2todj4jxogzau7scz2d",
[junit4] 2> "source":"node_added_triggerMR",
[junit4] 2> "eventTime":9862553869016760,
[junit4] 2> "eventType":"NODEADDED",
[junit4] 2> "properties":{
[junit4] 2> "eventTimes":[9862553869016760],
[junit4] 2> "preferredOperation":"movereplica",
[junit4] 2> "_enqueue_time_":9862554897274110,
[junit4] 2> "nodeNames":["127.0.0.1:10003_solr"],
[junit4] 2> "replicaType":"NRT"}}
[junit4] 2> 1904676 DEBUG (ScheduledTrigger-10115-thread-3) [ ] o.a.s.c.a.s.TestSimTriggerIntegration --- listener fired for event: {
[junit4] 2> "id":"2309f0c3f0deb8Taeijcq2todj4jxogzau7scz2d",
[junit4] 2> "source":"node_added_triggerMR",
[junit4] 2> "eventTime":9862553869016760,
[junit4] 2> "eventType":"NODEADDED",
[junit4] 2> "properties":{
[junit4] 2> "eventTimes":[9862553869016760],
[junit4] 2> "preferredOperation":"movereplica",
[junit4] 2> "_enqueue_time_":9862554897274110,
[junit4] 2> "nodeNames":["127.0.0.1:10003_solr"],
[junit4] 2> "replicaType":"NRT"}}, stage: STARTED
[junit4] 2> 1904676 DEBUG (ScheduledTrigger-10115-thread-3) [ ] o.a.s.c.a.s.TestSimTriggerIntegration --- listener wait complete for event: {
[junit4] 2> "id":"2309f0c3f0deb8Taeijcq2todj4jxogzau7scz2d",
[junit4] 2> "source":"node_added_triggerMR",
[junit4] 2> "eventTime":9862553869016760,
[junit4] 2> "eventType":"NODEADDED",
[junit4] 2> "properties":{
[junit4] 2> "eventTimes":[9862553869016760],
[junit4] 2> "preferredOperation":"movereplica",
[junit4] 2> "_enqueue_time_":9862554897274110,
[junit4] 2> "nodeNames":["127.0.0.1:10003_solr"],
[junit4] 2> "replicaType":"NRT"}}, stage: STARTED
[junit4] 2> 1904676 DEBUG (ScheduledTrigger-10115-thread-3) [ ] o.a.s.c.a.NodeAddedTrigger Removing new node from tracking: 127.0.0.1:10003_solr
[junit4] 2> 1904676 DEBUG (AutoscalingActionExecutor-10116-thread-1) [ ] o.a.s.c.a.ScheduledTriggers -- processing actions for {
[junit4] 2> "id":"2309f0c3f0deb8Taeijcq2todj4jxogzau7scz2d",
[junit4] 2> "source":"node_added_triggerMR",
[junit4] 2> "eventTime":9862553869016760,
[junit4] 2> "eventType":"NODEADDED",
[junit4] 2> "properties":{
[junit4] 2> "eventTimes":[9862553869016760],
[junit4] 2> "preferredOperation":"movereplica",
[junit4] 2> "_enqueue_time_":9862554897274110,
[junit4] 2> "nodeNames":["127.0.0.1:10003_solr"],
[junit4] 2> "replicaType":"NRT"}}
[junit4] 2> 1904677 DEBUG (TEST-TestSimTriggerIntegration.testNodeMarkersRegistration-seed#[6025CDAA20F4310C]) [ ] o.a.s.c.a.s.SimClusterStateProvider -- created marker: /autoscaling/nodeLost/127.0.0.1:10003_solr
[junit4] 2> 1904677 DEBUG (TEST-TestSimTriggerIntegration.testNodeMarkersRegistration-seed#[6025CDAA20F4310C]) [ ] o.a.s.c.a.s.SimNodeStateProvider --removing value for 127.0.0.1:10003_solr
[junit4] 2> 1904677 DEBUG (AutoscalingActionExecutor-10116-thread-1) [ ] o.a.s.c.a.SystemLogListener Collection .system missing, skip sending event {
[junit4] 2> "id":"2309f0c3f0deb8Taeijcq2todj4jxogzau7scz2d",
[junit4] 2> "source":"node_added_triggerMR",
[junit4] 2> "eventTime":9862553869016760,
[junit4] 2> "eventType":"NODEADDED",
[junit4] 2> "properties":{
[junit4] 2> "eventTimes":[9862553869016760],
[junit4] 2> "preferredOperation":"movereplica",
[junit4] 2> "_enqueue_time_":9862554897274110,
[junit4] 2> "nodeNames":["127.0.0.1:10003_solr"],
[junit4] 2> "replicaType":"NRT"}}
[junit4] 2> 1904677 DEBUG (AutoscalingActionExecutor-10116-thread-1) [ ] o.a.s.c.a.ScheduledTriggers Resuming trigger: node_added_triggerMR after 100ms
[junit4] 2> 1904677 DEBUG (AutoscalingActionExecutor-10116-thread-1) [ ] o.a.s.c.a.ScheduledTriggers Resuming trigger: .auto_add_replicas after 100ms
[junit4] 2> 1904677 DEBUG (AutoscalingActionExecutor-10116-thread-1) [ ] o.a.s.c.a.ScheduledTriggers Resuming trigger: node_lost_triggerMR after 100ms
[junit4] 2> 1904677 DEBUG (AutoscalingActionExecutor-10116-thread-1) [ ] o.a.s.c.a.ScheduledTriggers -- processing took 18 ms for event id=2309f0c3f0deb8Taeijcq2todj4jxogzau7scz2d
[junit4] 2> 1904777 DEBUG (ScheduledTrigger-10115-thread-1) [ ] o.a.s.c.a.NodeAddedTrigger Running NodeAddedTrigger node_added_triggerMR
[junit4] 2> 1904777 DEBUG (ScheduledTrigger-10115-thread-1) [ ] o.a.s.c.a.NodeAddedTrigger Found livenodes: 2
[junit4] 2> 1904777 DEBUG (ScheduledTrigger-10115-thread-4) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 2 and last live nodes: 3
[junit4] 2> 1904777 DEBUG (ScheduledTrigger-10115-thread-4) [ ] o.a.s.c.a.NodeLostTrigger Tracking lost node: 127.0.0.1:10003_solr
[junit4] 2> 1904777 DEBUG (ScheduledTrigger-10115-thread-3) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: node_lost_triggerMR with currently live nodes: 2 and last live nodes: 3
[junit4] 2> 1904777 DEBUG (ScheduledTrigger-10115-thread-3) [ ] o.a.s.c.a.NodeLostTrigger Tracking lost node: 127.0.0.1:10003_solr
[junit4] 2> 1904797 DEBUG (ScheduledTrigger-10115-thread-1) [ ] o.a.s.c.a.NodeAddedTrigger Running NodeAddedTrigger node_added_triggerMR
[junit4] 2> 1904797 DEBUG (ScheduledTrigger-10115-thread-1) [ ] o.a.s.c.a.NodeAddedTrigger Found livenodes: 2
[junit4] 2> 1904797 DEBUG (ScheduledTrigger-10115-thread-2) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: node_lost_triggerMR with currently live nodes: 2 and last live nodes: 2
[junit4] 2> 1904797 DEBUG (ScheduledTrigger-10115-thread-3) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 2 and last live nodes: 2
[junit4] 2> 1904797 DEBUG (ScheduledTrigger-10115-thread-2) [ ] o.a.s.c.a.NodeLostTrigger NodeLostTrigger firing registered processor for lost nodes: [127.0.0.1:10003_solr]
[junit4] 2> 1904797 DEBUG (ScheduledTrigger-10115-thread-2) [ ] o.a.s.c.a.ScheduledTriggers ++++++++ Cooldown inactive - processing event: {
[junit4] 2> "id":"2309f22e6f3d88Taeijcq2todj4jxogzau7scz2e",
[junit4] 2> "source":"node_lost_triggerMR",
[junit4] 2> "eventTime":9862559950650760,
[junit4] 2> "eventType":"NODELOST",
[junit4] 2> "properties":{
[junit4] 2> "eventTimes":[9862559950650760],
[junit4] 2> "preferredOperation":"movereplica",
[junit4] 2> "nodeNames":["127.0.0.1:10003_solr"]}}
[junit4] 2> 1904797 DEBUG (ScheduledTrigger-10115-thread-2) [ ] o.a.s.c.a.ScheduledTriggers Pausing all triggers: [node_lost_triggerMR, node_added_triggerMR, .auto_add_replicas]
[junit4] 2> 1904797 DEBUG (ScheduledTrigger-10115-thread-2) [ ] o.a.s.c.a.SystemLogListener Collection .system missing, skip sending event {
[junit4] 2> "id":"2309f22e6f3d88Taeijcq2todj4jxogzau7scz2e",
[junit4] 2> "source":"node_lost_triggerMR",
[junit4] 2> "eventTime":9862559950650760,
[junit4] 2> "eventType":"NODELOST",
[junit4] 2> "properties":{
[junit4] 2> "eventTimes":[9862559950650760],
[junit4] 2> "preferredOperation":"movereplica",
[junit4] 2> "_enqueue_time_":9862560965630210,
[junit4] 2> "nodeNames":["127.0.0.1:10003_solr"]}}
[junit4] 2> 1904797 DEBUG (AutoscalingActionExecutor-10116-thread-1) [ ] o.a.s.c.a.ScheduledTriggers -- processing actions for {
[junit4] 2> "id":"2309f22e6f3d88Taeijcq2todj4jxogzau7scz2e",
[junit4] 2> "source":"node_lost_triggerMR",
[junit4] 2> "eventTime":9862559950650760,
[junit4] 2> "eventType":"NODELOST",
[junit4] 2> "properties":{
[junit4] 2> "eventTimes":[9862559950650760],
[junit4] 2> "preferredOperation":"movereplica",
[junit4] 2> "_enqueue_time_":9862560965630210,
[junit4] 2> "nodeNames":["127.0.0.1:10003_solr"]}}
[junit4] 2> 1904798 INFO (TEST-TestSimTriggerIntegration.testNodeMarkersRegistration-seed#[6025CDAA20F4310C]) [ ] o.a.s.c.a.s.TestSimTriggerIntegration ====== KILL OVERSEER 2
[junit4] 2> 1904798 DEBUG (TEST-TestSimTriggerIntegration.testNodeMarkersRegistration-seed#[6025CDAA20F4310C]) [ ] o.a.s.c.a.s.SimClusterStateProvider -- created marker: /autoscaling/nodeLost/127.0.0.1:10001_solr
[junit4] 2> 1904798 DEBUG (TEST-TestSimTriggerIntegration.testNodeMarkersRegistration-seed#[6025CDAA20F4310C]) [ ] o.a.s.c.a.s.SimClusterStateProvider --- new Overseer leader: 127.0.0.1:10002_solr
[junit4] 2> 1904798 DEBUG (TEST-TestSimTriggerIntegration.testNodeMarkersRegistration-seed#[6025CDAA20F4310C]) [ ] o.a.s.c.a.s.SimNodeStateProvider --removing value for 127.0.0.1:10001_solr
[junit4] 2> 1904798 DEBUG (AutoscalingActionExecutor-10116-thread-1) [ ] o.a.s.c.a.SystemLogListener Collection .system missing, skip sending event {
[junit4] 2> "id":"2309f22e6f3d88Taeijcq2todj4jxogzau7scz2e",
[junit4] 2> "source":"node_lost_triggerMR",
[junit4] 2> "eventTime":9862559950650760,
[junit4] 2> "eventType":"NODELOST",
[junit4] 2> "properties":{
[junit4] 2> "eventTimes":[9862559950650760],
[junit4] 2> "preferredOperation":"movereplica",
[junit4] 2> "_enqueue_time_":9862560965630210,
[junit4] 2> "nodeNames":["127.0.0.1:10003_solr"]}}
[junit4] 2> 1904798 DEBUG (AutoscalingActionExecutor-10116-thread-1) [ ] o.a.s.c.a.ScheduledTriggers Resuming trigger: node_lost_triggerMR after 100ms
[junit4] 2> 1904798 DEBUG (AutoscalingActionExecutor-10116-thread-1) [ ] o.a.s.c.a.ScheduledTriggers Resuming trigger: .auto_add_replicas after 100ms
[junit4] 2> 1904798 DEBUG (AutoscalingActionExecutor-10116-thread-1) [ ] o.a.s.c.a.ScheduledTriggers Resuming trigger: node_added_triggerMR after 100ms
[junit4] 2> 1904798 DEBUG (AutoscalingActionExecutor-10116-thread-1) [ ] o.a.s.c.a.ScheduledTriggers -- processing took 17 ms for event id=2309f22e6f3d88Taeijcq2todj4jxogzau7scz2e
[junit4] 2> 1904898 DEBUG (ScheduledTrigger-10115-thread-1) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: node_lost_triggerMR with currently live nodes: 1 and last live nodes: 2
[junit4] 2> 1904898 DEBUG (ScheduledTrigger-10115-thread-1) [ ] o.a.s.c.a.NodeLostTrigger Tracking lost node: 127.0.0.1:10001_solr
[junit4] 2> 1904898 DEBUG (ScheduledTrigger-10115-thread-4) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 1 and last live nodes: 2
[junit4] 2> 1904898 DEBUG (ScheduledTrigger-10115-thread-4) [ ] o.a.s.c.a.NodeLostTrigger Tracking lost node: 127.0.0.1:10001_solr
[junit4] 2> 1904898 DEBUG (ScheduledTrigger-10115-thread-3) [ ] o.a.s.c.a.NodeAddedTrigger Running NodeAddedTrigger node_added_triggerMR
[junit4] 2> 1904898 DEBUG (ScheduledTrigger-10115-thread-3) [ ] o.a.s.c.a.NodeAddedTrigger Found livenodes: 1
[junit4] 2> 1904918 DEBUG (ScheduledTrigger-10115-thread-1) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: node_lost_triggerMR with currently live nodes: 1 and last live nodes: 1
[junit4] 2> 1904918 DEBUG (ScheduledTrigger-10115-thread-3) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 1 and last live nodes: 1
[junit4] 2> 1904918 DEBUG (ScheduledTrigger-10115-thread-1) [ ] o.a.s.c.a.NodeLostTrigger NodeLostTrigger firing registered processor for lost nodes: [127.0.0.1:10001_solr]
[junit4] 2> 1904918 DEBUG (ScheduledTrigger-10115-thread-2) [ ] o.a.s.c.a.NodeAddedTrigger Running NodeAddedTrigger node_added_triggerMR
[junit4] 2> 1904918 DEBUG (ScheduledTrigger-10115-thread-2) [ ] o.a.s.c.a.NodeAddedTrigger Found livenodes: 1
[junit4] 2> 1904918 DEBUG (ScheduledTrigger-10115-thread-1) [ ] o.a.s.c.a.ScheduledTriggers ++++++++ Cooldown inactive - processing event: {
[junit4] 2> "id":"2309f396d4f1a0Taeijcq2todj4jxogzau7scz2f",
[junit4] 2> "source":"node_lost_triggerMR",
[junit4] 2> "eventTime":9862565997113760,
[junit4] 2> "eventType":"NODELOST",
[junit4] 2> "properties":{
[junit4] 2> "eventTimes":[9862565997113760],
[junit4] 2> "preferredOperation":"movereplica",
[junit4] 2> "nodeNames":["127.0.0.1:10001_solr"]}}
[junit4] 2> 1904918 DEBUG (ScheduledTrigger-10115-thread-1) [ ] o.a.s.c.a.ScheduledTriggers Pausing all triggers: [node_lost_triggerMR, node_added_triggerMR, .auto_add_replicas]
[junit4] 2> 1904918 DEBUG (ScheduledTrigger-10115-thread-1) [ ] o.a.s.c.a.SystemLogListener Collection .system missing, skip sending event {
[junit4] 2> "id":"2309f396d4f1a0Taeijcq2todj4jxogzau7scz2f",
[junit4] 2> "source":"node_lost_triggerMR",
[junit4] 2> "eventTime":9862565997113760,
[junit4] 2> "eventType":"NODELOST",
[junit4] 2> "properties":{
[junit4] 2> "eventTimes":[9862565997113760],
[junit4] 2> "preferredOperation":"movereplica",
[junit4] 2> "_enqueue_time_":9862567011115460,
[junit4] 2> "nodeNames":["127.0.0.1:10001_solr"]}}
[junit4] 2> 1904918 DEBUG (AutoscalingActionExecutor-10116-thread-1) [ ] o.a.s.c.a.ScheduledTriggers -- processing actions for {
[junit4] 2> "id":"2309f396d4f1a0Taeijcq2todj4jxogzau7scz2f",
[junit4] 2> "source":"node_lost_triggerMR",
[junit4] 2> "eventTime":9862565997113760,
[junit4] 2> "eventType":"NODELOST",
[junit4] 2> "properties":{
[junit4] 2> "eventTimes":[9862565997113760],
[junit4] 2> "preferredOperation":"movereplica",
[junit4] 2> "_enqueue_time_":9862567011115460,
[junit4] 2> "nodeNames":["127.0.0.1:10001_solr"]}}
[junit4] 2> 1904918 DEBUG (AutoscalingActionExecutor-10116-thread-1) [ ] o.a.s.c.a.SystemLogListener Collection .system missing, skip sending event {
[junit4] 2> "id":"2309f396d4f1a0Taeijcq2todj4jxogzau7scz2f",
[junit4] 2> "source":"node_lost_triggerMR",
[junit4] 2> "eventTime":9862565997113760,
[junit4] 2> "eventType":"NODELOST",
[junit4] 2> "properties":{
[junit4] 2> "eventTimes":[9862565997113760],
[junit4] 2> "preferredOperation":"movereplica",
[junit4] 2> "_enqueue_time_":9862567011115460,
[junit4] 2> "nodeNames":["127.0.0.1:10001_solr"]}}
[junit4] 2> 1904918 DEBUG (AutoscalingActionExecutor-10116-thread-1) [ ] o.a.s.c.a.ScheduledTriggers Resuming trigger: node_lost_triggerMR after 100ms
[junit4] 2> 1904918 DEBUG (AutoscalingActionExecutor-10116-thread-1) [ ] o.a.s.c.a.ScheduledTriggers Resuming trigger: node_added_triggerMR after 100ms
[junit4] 2> 1904918 DEBUG (AutoscalingActionExecutor-10116-thread-1) [ ] o.a.s.c.a.ScheduledTriggers Resuming trigger: .auto_add_replicas after 100ms
[junit4] 2> 1904918 DEBUG (AutoscalingActionExecutor-10116-thread-1) [ ] o.a.s.c.a.ScheduledTriggers -- processing took 9 ms for event id=2309f396d4f1a0Taeijcq2todj4jxogzau7scz2f
[junit4] 2> 1904919 INFO (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread OverseerTriggerThread woken up but we are closed, exiting.
[junit4] 2> 1904919 DEBUG (TEST-TestSimTriggerIntegration.testNodeMarkersRegistration-seed#[6025CDAA20F4310C]) [ ] o.a.s.c.a.ScheduledTriggers Shutting down scheduled thread pool executor now
[junit4] 2> 1904919 DEBUG (TEST-TestSimTriggerIntegration.testNodeMarkersRegistration-seed#[6025CDAA20F4310C]) [ ] o.a.s.c.a.ScheduledTriggers Shutting down action executor now
[junit4] 2> 1904919 DEBUG (TEST-TestSimTriggerIntegration.testNodeMarkersRegistration-seed#[6025CDAA20F4310C]) [ ] o.a.s.c.a.ScheduledTriggers Awaiting termination for action executor
[junit4] 2> 1904919 DEBUG (TEST-TestSimTriggerIntegration.testNodeMarkersRegistration-seed#[6025CDAA20F4310C]) [ ] o.a.s.c.a.ScheduledTriggers Awaiting termination for scheduled thread pool executor
[junit4] 2> 1904919 DEBUG (TEST-TestSimTriggerIntegration.testNodeMarkersRegistration-seed#[6025CDAA20F4310C]) [ ] o.a.s.c.a.ScheduledTriggers ScheduledTriggers closed completely
[junit4] 2> 1904919 DEBUG (TEST-TestSimTriggerIntegration.testNodeMarkersRegistration-seed#[6025CDAA20F4310C]) [ ] o.a.s.c.a.OverseerTriggerThread OverseerTriggerThread has been closed explicitly
[junit4] 2> 1904920 INFO (TEST-TestSimTriggerIntegration.testNodeMarkersRegistration-seed#[6025CDAA20F4310C]) [ ] o.a.s.SolrTestCaseJ4 ###Ending testNodeMarkersRegistration
[junit4] 2> 1904923 INFO (TEST-TestSimTriggerIntegration.testEventQueue-seed#[6025CDAA20F4310C]) [ ] o.a.s.SolrTestCaseJ4 ###Starting testEventQueue
[junit4] 2> 1904925 DEBUG (TEST-TestSimTriggerIntegration.testEventQueue-seed#[6025CDAA20F4310C]) [ ] o.a.s.c.a.s.SimClusterStateProvider --- new Overseer leader: 127.0.0.1:10004_solr
[junit4] 2> 1904926 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Adding .auto_add_replicas and .scheduled_maintenance triggers
[junit4] 2> 1904926 DEBUG (TEST-TestSimTriggerIntegration.testEventQueue-seed#[6025CDAA20F4310C]) [ ] o.a.s.c.a.s.SimClusterStateProvider ** creating new collection states, currentVersion=0
[junit4] 2> 1904926 DEBUG (TEST-TestSimTriggerIntegration.testEventQueue-seed#[6025CDAA20F4310C]) [ ] o.a.s.c.a.s.SimClusterStateProvider ** saved cluster state version 0
[junit4] 2> 1904926 INFO (TEST-TestSimTriggerIntegration.testEventQueue-seed#[6025CDAA20F4310C]) [ ] o.a.s.h.a.MetricsHistoryHandler No .system collection, keeping metrics history in memory.
[junit4] 2> 1904926 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Refreshing /autoscaling.json with znode version 1
[junit4] 2> 1904926 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Current znodeVersion 1, lastZnodeVersion 0
[junit4] 2> 1904926 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Processed trigger updates upto znodeVersion 1
[junit4] 2> 1904927 DEBUG (simCloudManagerPool-10118-thread-2) [ ] o.a.s.c.a.AutoScalingHandler Verified autoscaling configuration
[junit4] 2> 1904927 DEBUG (simCloudManagerPool-10118-thread-2) [ ] o.a.s.c.a.OverseerTriggerThread Refreshing /autoscaling.json with znode version 2
[junit4] 2> 1904931 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.NodeLostTrigger NodeLostTrigger .auto_add_replicas - Initial livenodes: [127.0.0.1:10004_solr, 127.0.0.1:10005_solr]
[junit4] 2> 1904931 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread -- deactivating old nodeLost / nodeAdded markers
[junit4] 2> 1904931 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Current znodeVersion 2, lastZnodeVersion 1
[junit4] 2> 1904931 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Processed trigger updates upto znodeVersion 2
[junit4] 2> 1904932 DEBUG (ScheduledTrigger-10119-thread-2) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 2 and last live nodes: 2
[junit4] 2> 1904934 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread -- deactivating old nodeLost / nodeAdded markers
[junit4] 2> 1904934 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Current znodeVersion 2, lastZnodeVersion 2
[junit4] 2> 1904934 INFO (simCloudManagerPool-10118-thread-3) [ ] o.a.s.c.a.s.TestSimTriggerIntegration$TestEventQueueAction TestEventQueueAction instantiated
[junit4] 2> 1904934 DEBUG (simCloudManagerPool-10118-thread-3) [ ] o.a.s.c.a.AutoScalingHandler Verified autoscaling configuration
[junit4] 2> 1904934 DEBUG (simCloudManagerPool-10118-thread-3) [ ] o.a.s.c.a.OverseerTriggerThread Refreshing /autoscaling.json with znode version 3
[junit4] 2> 1904934 INFO (simCloudManagerPool-10118-thread-3) [ ] o.a.s.c.a.s.TestSimTriggerIntegration$TestEventQueueAction TestEventQueueAction instantiated
[junit4] 2> 1904934 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Processed trigger updates upto znodeVersion 3
[junit4] 2> 1904934 INFO (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.s.TestSimTriggerIntegration$TestEventQueueAction TestEventQueueAction init
[junit4] 2> 1904934 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.NodeAddedTrigger NodeAddedTrigger node_added_trigger1 - Initial livenodes: [127.0.0.1:10004_solr, 127.0.0.1:10005_solr]
[junit4] 2> 1904934 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.TestSimTriggerIntegration$TestEventQueueAction}], enabled=true}
[junit4] 2> 1904935 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread -- deactivating old nodeLost / nodeAdded markers
[junit4] 2> 1904935 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Current znodeVersion 3, lastZnodeVersion 3
[junit4] 2> 1904935 DEBUG (ScheduledTrigger-10119-thread-2) [ ] o.a.s.c.a.NodeAddedTrigger Running NodeAddedTrigger node_added_trigger1
[junit4] 2> 1904935 DEBUG (ScheduledTrigger-10119-thread-2) [ ] o.a.s.c.a.NodeAddedTrigger Found livenodes: 2
[junit4] 2> 1904940 DEBUG (TEST-TestSimTriggerIntegration.testEventQueue-seed#[6025CDAA20F4310C]) [ ] o.a.s.c.a.s.SimClusterStateProvider -- creating marker: /autoscaling/nodeAdded/127.0.0.1:10006_solr
[junit4] 2> 1904953 DEBUG (ScheduledTrigger-10119-thread-4) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 3 and last live nodes: 2
[junit4] 2> 1904955 DEBUG (ScheduledTrigger-10119-thread-1) [ ] o.a.s.c.a.NodeAddedTrigger Running NodeAddedTrigger node_added_trigger1
[junit4] 2> 1904955 DEBUG (ScheduledTrigger-10119-thread-1) [ ] o.a.s.c.a.NodeAddedTrigger Found livenodes: 3
[junit4] 2> 1904955 DEBUG (ScheduledTrigger-10119-thread-1) [ ] o.a.s.c.a.NodeAddedTrigger Tracking new node: 127.0.0.1:10006_solr at time 9862568860665660
[junit4] 2> 1904973 DEBUG (ScheduledTrigger-10119-thread-2) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 3 and last live nodes: 3
[junit4] 2> 1904975 DEBUG (ScheduledTrigger-10119-thread-3) [ ] o.a.s.c.a.NodeAddedTrigger Running NodeAddedTrigger node_added_trigger1
[junit4] 2> 1904975 DEBUG (ScheduledTrigger-10119-thread-3) [ ] o.a.s.c.a.NodeAddedTrigger Found livenodes: 3
[junit4] 2> 1904975 DEBUG (ScheduledTrigger-10119-thread-3) [ ] o.a.s.c.a.NodeAddedTrigger NodeAddedTrigger node_added_trigger1 firing registered processor for nodes: [127.0.0.1:10006_solr] added at times [9862568860665660], now=9862569869753260
[junit4] 2> 1904975 DEBUG (ScheduledTrigger-10119-thread-3) [ ] o.a.s.c.a.ScheduledTriggers ++++++++ Cooldown inactive - processing event: {
[junit4] 2> "id":"2309f44183473cTaeijcq2todj4jxogzau7scz2h",
[junit4] 2> "source":"node_added_trigger1",
[junit4] 2> "eventTime":9862568860665660,
[junit4] 2> "eventType":"NODEADDED",
[junit4] 2> "properties":{
[junit4] 2> "eventTimes":[9862568860665660],
[junit4] 2> "preferredOperation":"movereplica",
[junit4] 2> "nodeNames":["127.0.0.1:10006_solr"],
[junit4] 2> "replicaType":"NRT"}}
[junit4] 2> 1904976 DEBUG (ScheduledTrigger-10119-thread-3) [ ] o.a.s.c.a.ScheduledTriggers Pausing all triggers: [.auto_add_replicas, node_added_trigger1]
[junit4] 2> 1904976 DEBUG (ScheduledTrigger-10119-thread-3) [ ] o.a.s.c.a.SystemLogListener Collection .system missing, skip sending event {
[junit4] 2> "id":"2309f44183473cTaeijcq2todj4jxogzau7scz2h",
[junit4] 2> "source":"node_added_trigger1",
[junit4] 2> "eventTime":9862568860665660,
[junit4] 2> "eventType":"NODEADDED",
[junit4] 2> "properties":{
[junit4] 2> "eventTimes":[9862568860665660],
[junit4] 2> "preferredOperation":"movereplica",
[junit4] 2> "_enqueue_time_":9862569887415210,
[junit4] 2> "nodeNames":["127.0.0.1:10006_solr"],
[junit4] 2> "replicaType":"NRT"}}
[junit4] 2> 1904976 DEBUG (ScheduledTrigger-10119-thread-3) [ ] o.a.s.c.a.NodeAddedTrigger Removing new node from tracking: 127.0.0.1:10006_solr
[junit4] 2> 1904976 DEBUG (AutoscalingActionExecutor-10120-thread-1) [ ] o.a.s.c.a.ScheduledTriggers -- processing actions for {
[junit4] 2> "id":"2309f44183473cTaeijcq2todj4jxogzau7scz2h",
[junit4] 2> "source":"node_added_trigger1",
[junit4] 2> "eventTime":9862568860665660,
[junit4] 2> "eventType":"NODEADDED",
[junit4] 2> "properties":{
[junit4] 2> "eventTimes":[9862568860665660],
[junit4] 2> "preferredOperation":"movereplica",
[junit4] 2> "_enqueue_time_":9862569887415210,
[junit4] 2> "nodeNames":["127.0.0.1:10006_solr"],
[junit4] 2> "replicaType":"NRT"}}
[junit4] 2> 1904976 INFO (AutoscalingActionExecutor-10120-thread-1) [ ] o.a.s.c.a.s.TestSimTriggerIntegration$TestEventQueueAction processing: stall=java.util.concurrent.CountDownLatch@189b39c9[Count = 1] event={
[junit4] 2> "id":"2309f44183473cTaeijcq2todj4jxogzau7scz2h",
[junit4] 2> "source":"node_added_trigger1",
[junit4] 2> "eventTime":9862568860665660,
[junit4] 2> "eventType":"NODEADDED",
[junit4] 2> "properties":{
[junit4] 2> "eventTimes":[9862568860665660],
[junit4] 2> "preferredOperation":"movereplica",
[junit4] 2> "_enqueue_time_":9862569887415210,
[junit4] 2> "nodeNames":["127.0.0.1:10006_solr"],
[junit4] 2> "replicaType":"NRT"}}
[junit4] 2> 1904976 INFO (TEST-TestSimTriggerIntegration.testEventQueue-seed#[6025CDAA20F4310C]) [ ] o.a.s.c.a.s.SimCloudManager === Restarting OverseerTriggerThread and clearing object cache...
[junit4] 2> 1904976 DEBUG (TEST-TestSimTriggerIntegration.testEventQueue-seed#[6025CDAA20F4310C]) [ ] o.a.s.c.a.ScheduledTriggers Shutting down scheduled thread pool executor now
[junit4] 2> 1904976 INFO (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread OverseerTriggerThread woken up but we are closed, exiting.
[junit4] 2> 1904976 DEBUG (TEST-TestSimTriggerIntegration.testEventQueue-seed#[6025CDAA20F4310C]) [ ] o.a.s.c.a.ScheduledTriggers Shutting down action executor now
[junit4] 2> 1904976 DEBUG (TEST-TestSimTriggerIntegration.testEventQueue-seed#[6025CDAA20F4310C]) [ ] o.a.s.c.a.ScheduledTriggers Awaiting termination for action executor
[junit4] 2> 1904977 INFO (AutoscalingActionExecutor-10120-thread-1) [ ] o.a.s.c.a.s.TestSimTriggerIntegration$TestEventQueueAction Interrupted
[junit4] 2> 1904977 DEBUG (AutoscalingActionExecutor-10120-thread-1) [ ] o.a.s.c.a.SystemLogListener Collection .system missing, skip sending event {
[junit4] 2> "id":"2309f44183473cTaeijcq2todj4jxogzau7scz2h",
[junit4] 2> "source":"node_added_trigger1",
[junit4] 2> "eventTime":9862568860665660,
[junit4] 2> "eventType":"NODEADDED",
[junit4] 2> "properties":{
[junit4] 2> "eventTimes":[9862568860665660],
[junit4] 2> "preferredOperation":"movereplica",
[junit4] 2> "_enqueue_time_":9862569887415210,
[junit4] 2> "nodeNames":["127.0.0.1:10006_solr"],
[junit4] 2> "replicaType":"NRT"}}
[junit4] 2> 1904977 WARN (AutoscalingActionExecutor-10120-thread-1) [ ] o.a.s.c.a.ScheduledTriggers Unhandled exception executing actions
[junit4] 2> => org.apache.solr.common.AlreadyClosedException: ScheduledTrigger node_added_trigger1 has been closed.
[junit4] 2> at org.apache.solr.cloud.autoscaling.ScheduledTriggers$TriggerWrapper.dequeue(ScheduledTriggers.java:583)
[junit4] 2> org.apache.solr.common.AlreadyClosedException: ScheduledTrigger node_added_trigger1 has been closed.
[junit4] 2> at org.apache.solr.cloud.autoscaling.ScheduledTriggers$TriggerWrapper.dequeue(ScheduledTriggers.java:583) ~[java/:?]
[junit4] 2> at org.apache.solr.cloud.autoscaling.ScheduledTriggers.lambda$null$3(ScheduledTriggers.java:334) ~[java/:?]
[junit4] 2> at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511) ~[?:1.8.0_191]
[junit4] 2> at java.util.concurrent.FutureTask.run(FutureTask.java:266) ~[?:1.8.0_191]
[junit4] 2> at org.apache.solr.common.util.ExecutorUtil$MDCAwareThreadPoolExecutor.lambda$execute$0(ExecutorUtil.java:210) ~[java/:?]
[junit4] 2> at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149) ~[?:1.8.0_191]
[junit4] 2> at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624) ~[?:1.8.0_191]
[junit4] 2> at java.lang.Thread.run(Thread.java:748) [?:1.8.0_191]
[junit4] 2> 1904977 DEBUG (AutoscalingActionExecutor-10120-thread-1) [ ] o.a.s.c.a.ScheduledTriggers -- processing took 34 ms for event id=2309f44183473cTaeijcq2todj4jxogzau7scz2h
[junit4] 2> 1904977 DEBUG (TEST-TestSimTriggerIntegration.testEventQueue-seed#[6025CDAA20F4310C]) [ ] o.a.s.c.a.ScheduledTriggers Awaiting termination for scheduled thread pool executor
[junit4] 2> 1904977 DEBUG (TEST-TestSimTriggerIntegration.testEventQueue-seed#[6025CDAA20F4310C]) [ ] o.a.s.c.a.ScheduledTriggers ScheduledTriggers closed completely
[junit4] 2> 1904977 DEBUG (TEST-TestSimTriggerIntegration.testEventQueue-seed#[6025CDAA20F4310C]) [ ] o.a.s.c.a.OverseerTriggerThread OverseerTriggerThread has been closed explicitly
[junit4] 2> 1904977 INFO (TEST-TestSimTriggerIntegration.testEventQueue-seed#[6025CDAA20F4310C]) [ ] o.a.s.c.a.s.SimCloudManager = killing node 127.0.0.1:10005_solr
[junit4] 2> 1904977 DEBUG (TEST-TestSimTriggerIntegration.testEventQueue-seed#[6025CDAA20F4310C]) [ ] o.a.s.c.a.s.SimClusterStateProvider -- created marker: /autoscaling/nodeLost/127.0.0.1:10005_solr
[junit4] 2> 1904977 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Refreshing /autoscaling.json with znode version 3
[junit4] 2> 1904977 INFO (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.s.TestSimTriggerIntegration$TestEventQueueAction TestEventQueueAction instantiated
[junit4] 2> 1904978 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Current znodeVersion 3, lastZnodeVersion 0
[junit4] 2> 1904978 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Processed trigger updates upto znodeVersion 3
[junit4] 2> 1904978 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.NodeLostTrigger NodeLostTrigger .auto_add_replicas - Initial livenodes: [127.0.0.1:10004_solr, 127.0.0.1:10006_solr]
[junit4] 2> 1904978 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.NodeLostTrigger Adding lost node from marker path: 127.0.0.1:10005_solr
[junit4] 2> 1904978 INFO (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.s.TestSimTriggerIntegration$TestEventQueueAction TestEventQueueAction init
[junit4] 2> 1904978 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.NodeAddedTrigger NodeAddedTrigger node_added_trigger1 - Initial livenodes: [127.0.0.1:10004_solr, 127.0.0.1:10006_solr]
[junit4] 2> 1904978 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.TestSimTriggerIntegration$TestEventQueueAction}], enabled=true}
[junit4] 2> 1904978 DEBUG (ScheduledTrigger-10124-thread-1) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 2 and last live nodes: 3
[junit4] 2> 1904978 DEBUG (ScheduledTrigger-10124-thread-1) [ ] o.a.s.c.a.NodeLostTrigger Tracking lost node: 127.0.0.1:10005_solr
[junit4] 2> 1904978 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.NodeAddedTrigger Adding node from marker path: 127.0.0.1:10006_solr
[junit4] 2> 1904980 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread -- deactivating old nodeLost / nodeAdded markers
[junit4] 2> 1904980 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Current znodeVersion 3, lastZnodeVersion 3
[junit4] 2> 1904980 DEBUG (ScheduledTrigger-10124-thread-2) [ ] o.a.s.c.a.ScheduledTriggers ++++++++ Cooldown inactive - processing event: {
[junit4] 2> "id":"2309f44183473cTaeijcq2todj4jxogzau7scz2h",
[junit4] 2> "source":"node_added_trigger1",
[junit4] 2> "eventTime":9862568860665660,
[junit4] 2> "eventType":"NODEADDED",
[junit4] 2> "properties":{
[junit4] 2> "eventTimes":[9862568860665660],
[junit4] 2> "_dequeue_time_":9862570106830410,
[junit4] 2> "preferredOperation":"movereplica",
[junit4] 2> "_enqueue_time_":9862569887415210,
[junit4] 2> "nodeNames":["127.0.0.1:10006_solr"],
[junit4] 2> "replicaType":"NRT",
[junit4] 2> "replaying":true}}
[junit4] 2> 1904980 DEBUG (ScheduledTrigger-10124-thread-2) [ ] o.a.s.c.a.ScheduledTriggers Pausing all triggers: [.auto_add_replicas, node_added_trigger1]
[junit4] 2> 1904980 DEBUG (ScheduledTrigger-10124-thread-2) [ ] o.a.s.c.a.SystemLogListener Collection .system missing, skip sending event {
[junit4] 2> "id":"2309f44183473cTaeijcq2todj4jxogzau7scz2h",
[junit4] 2> "source":"node_added_trigger1",
[junit4] 2> "eventTime":9862568860665660,
[junit4] 2> "eventType":"NODEADDED",
[junit4] 2> "properties":{
[junit4] 2> "eventTimes":[9862568860665660],
[junit4] 2> "_dequeue_time_":9862570106830410,
[junit4] 2> "preferredOperation":"movereplica",
[junit4] 2> "_enqueue_time_":9862569887415210,
[junit4] 2> "nodeNames":["127.0.0.1:10006_solr"],
[junit4] 2> "replicaType":"NRT",
[junit4] 2> "replaying":true}}
[junit4] 2> 1904981 DEBUG (ScheduledTrigger-10124-thread-2) [ ] o.a.s.c.a.NodeAddedTrigger Running NodeAddedTrigger node_added_trigger1
[junit4] 2> 1904981 DEBUG (ScheduledTrigger-10124-thread-2) [ ] o.a.s.c.a.NodeAddedTrigger Found livenodes: 2
[junit4] 2> 1904981 DEBUG (AutoscalingActionExecutor-10125-thread-1) [ ] o.a.s.c.a.ScheduledTriggers -- processing actions for {
[junit4] 2> "id":"2309f44183473cTaeijcq2todj4jxogzau7scz2h",
[junit4] 2> "source":"node_added_trigger1",
[junit4] 2> "eventTime":9862568860665660,
[junit4] 2> "eventType":"NODEADDED",
[junit4] 2> "properties":{
[junit4] 2> "eventTimes":[9862568860665660],
[junit4] 2> "_dequeue_time_":9862570106830410,
[junit4] 2> "preferredOperation":"movereplica",
[junit4] 2> "_enqueue_time_":9862569887415210,
[junit4] 2> "nodeNames":["127.0.0.1:10006_solr"],
[junit4] 2> "replicaType":"NRT",
[junit4] 2> "replaying":true}}
[junit4] 2> 1904981 INFO (AutoscalingActionExecutor-10125-thread-1) [ ] o.a.s.c.a.s.TestSimTriggerIntegration$TestEventQueueAction processing: stall=java.util.concurrent.CountDownLatch@4e10ebe2[Count = 0] event={
[junit4] 2> "id":"2309f44183473cTaeijcq2todj4jxogzau7scz2h",
[junit4] 2> "source":"node_added_trigger1",
[junit4] 2> "eventTime":9862568860665660,
[junit4] 2> "eventType":"NODEADDED",
[junit4] 2> "properties":{
[junit4] 2> "eventTimes":[9862568860665660],
[junit4] 2> "_dequeue_time_":9862570106830410,
[junit4] 2> "preferredOperation":"movereplica",
[junit4] 2> "_enqueue_time_":9862569887415210,
[junit4] 2> "nodeNames":["127.0.0.1:10006_solr"],
[junit4] 2> "replicaType":"NRT",
[junit4] 2> "replaying":true}}
[junit4] 2> 1904981 INFO (AutoscalingActionExecutor-10125-thread-1) [ ] o.a.s.c.a.s.TestSimTriggerIntegration$TestEventQueueAction Firing trigger event after await()ing 'stall' countdown
[junit4] 2> 1904981 DEBUG (AutoscalingActionExecutor-10125-thread-1) [ ] o.a.s.c.a.SystemLogListener Collection .system missing, skip sending event {
[junit4] 2> "id":"2309f44183473cTaeijcq2todj4jxogzau7scz2h",
[junit4] 2> "source":"node_added_trigger1",
[junit4] 2> "eventTime":9862568860665660,
[junit4] 2> "eventType":"NODEADDED",
[junit4] 2> "properties":{
[junit4] 2> "eventTimes":[9862568860665660],
[junit4] 2> "_dequeue_time_":9862570106830410,
[junit4] 2> "preferredOperation":"movereplica",
[junit4] 2> "_enqueue_time_":9862569887415210,
[junit4] 2> "nodeNames":["127.0.0.1:10006_solr"],
[junit4] 2> "replicaType":"NRT",
[junit4] 2> "replaying":true}}
[junit4] 2> 1904981 DEBUG (AutoscalingActionExecutor-10125-thread-1) [ ] o.a.s.c.a.ScheduledTriggers Resuming trigger: .auto_add_replicas after 100ms
[junit4] 2> 1904981 DEBUG (AutoscalingActionExecutor-10125-thread-1) [ ] o.a.s.c.a.ScheduledTriggers Resuming trigger: node_added_trigger1 after 100ms
[junit4] 2> 1904981 DEBUG (AutoscalingActionExecutor-10125-thread-1) [ ] o.a.s.c.a.ScheduledTriggers -- processing took 11 ms for event id=2309f44183473cTaeijcq2todj4jxogzau7scz2h
[junit4] 2> 1905078 INFO (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread OverseerTriggerThread woken up but we are closed, exiting.
[junit4] 2> 1905079 DEBUG (TEST-TestSimTriggerIntegration.testEventQueue-seed#[6025CDAA20F4310C]) [ ] o.a.s.c.a.ScheduledTriggers Shutting down scheduled thread pool executor now
[junit4] 2> 1905079 DEBUG (TEST-TestSimTriggerIntegration.testEventQueue-seed#[6025CDAA20F4310C]) [ ] o.a.s.c.a.ScheduledTriggers Shutting down action executor now
[junit4] 2> 1905079 DEBUG (TEST-TestSimTriggerIntegration.testEventQueue-seed#[6025CDAA20F4310C]) [ ] o.a.s.c.a.ScheduledTriggers Awaiting termination for action executor
[junit4] 2> 1905079 DEBUG (TEST-TestSimTriggerIntegration.testEventQueue-seed#[6025CDAA20F4310C]) [ ] o.a.s.c.a.ScheduledTriggers Awaiting termination for scheduled thread pool executor
[junit4] 2> 1905079 DEBUG (TEST-TestSimTriggerIntegration.testEventQueue-seed#[6025CDAA20F4310C]) [ ] o.a.s.c.a.ScheduledTriggers ScheduledTriggers closed completely
[junit4] 2> 1905079 DEBUG (TEST-TestSimTriggerIntegration.testEventQueue-seed#[6025CDAA20F4310C]) [ ] o.a.s.c.a.OverseerTriggerThread OverseerTriggerThread has been closed explicitly
[junit4] 2> 1905080 INFO (TEST-TestSimTriggerIntegration.testEventQueue-seed#[6025CDAA20F4310C]) [ ] o.a.s.SolrTestCaseJ4 ###Ending testEventQueue
[junit4] 2> 1905082 INFO (TEST-TestSimTriggerIntegration.testNodeLostTriggerRestoreState-seed#[6025CDAA20F4310C]) [ ] o.a.s.SolrTestCaseJ4 ###Starting testNodeLostTriggerRestoreState
[junit4] 2> 1905087 DEBUG (TEST-TestSimTriggerIntegration.testNodeLostTriggerRestoreState-seed#[6025CDAA20F4310C]) [ ] o.a.s.c.a.s.SimClusterStateProvider --- new Overseer leader: 127.0.0.1:10007_solr
[junit4] 2> 1905087 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Adding .auto_add_replicas and .scheduled_maintenance triggers
[junit4] 2> 1905087 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Refreshing /autoscaling.json with znode version 1
[junit4] 2> 1905087 DEBUG (TEST-TestSimTriggerIntegration.testNodeLostTriggerRestoreState-seed#[6025CDAA20F4310C]) [ ] o.a.s.c.a.s.SimClusterStateProvider ** creating new collection states, currentVersion=0
[junit4] 2> 1905087 DEBUG (TEST-TestSimTriggerIntegration.testNodeLostTriggerRestoreState-seed#[6025CDAA20F4310C]) [ ] o.a.s.c.a.s.SimClusterStateProvider ** saved cluster state version 0
[junit4] 2> 1905087 INFO (TEST-TestSimTriggerIntegration.testNodeLostTriggerRestoreState-seed#[6025CDAA20F4310C]) [ ] o.a.s.h.a.MetricsHistoryHandler No .system collection, keeping metrics history in memory.
[junit4] 2> 1905087 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Current znodeVersion 1, lastZnodeVersion 0
[junit4] 2> 1905087 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Processed trigger updates upto znodeVersion 1
[junit4] 2> 1905087 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.NodeLostTrigger NodeLostTrigger .auto_add_replicas - Initial livenodes: [127.0.0.1:10008_solr, 127.0.0.1:10007_solr]
[junit4] 2> 1905087 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread -- deactivating old nodeLost / nodeAdded markers
[junit4] 2> 1905087 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Current znodeVersion 1, lastZnodeVersion 1
[junit4] 2> 1905088 DEBUG (ScheduledTrigger-10128-thread-2) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 2 and last live nodes: 2
[junit4] 2> 1905091 DEBUG (simCloudManagerPool-10127-thread-2) [ ] o.a.s.c.a.AutoScalingHandler Verified autoscaling configuration
[junit4] 2> 1905091 DEBUG (simCloudManagerPool-10127-thread-2) [ ] o.a.s.c.a.OverseerTriggerThread Refreshing /autoscaling.json with znode version 2
[junit4] 2> 1905092 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Processed trigger updates upto znodeVersion 2
[junit4] 2> 1905092 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread -- deactivating old nodeLost / nodeAdded markers
[junit4] 2> 1905092 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Current znodeVersion 2, lastZnodeVersion 2
[junit4] 2> 1905093 DEBUG (simCloudManagerPool-10127-thread-3) [ ] o.a.s.c.a.AutoScalingHandler Verified autoscaling configuration
[junit4] 2> 1905093 DEBUG (simCloudManagerPool-10127-thread-3) [ ] o.a.s.c.a.OverseerTriggerThread Refreshing /autoscaling.json with znode version 3
[junit4] 2> 1905096 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Processed trigger updates upto znodeVersion 3
[junit4] 2> 1905096 INFO (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.s.TestSimTriggerIntegration TestTriggerAction init
[junit4] 2> 1905096 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.NodeLostTrigger NodeLostTrigger node_lost_restore_trigger - Initial livenodes: [127.0.0.1:10008_solr, 127.0.0.1:10007_solr]
[junit4] 2> 1905096 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread -- deactivating old nodeLost / nodeAdded markers
[junit4] 2> 1905096 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Current znodeVersion 3, lastZnodeVersion 3
[junit4] 2> 1905759 DEBUG (ScheduledTrigger-10128-thread-1) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: node_lost_restore_trigger with currently live nodes: 2 and last live nodes: 2
[junit4] 2> 1905760 INFO (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread OverseerTriggerThread woken up but we are closed, exiting.
[junit4] 2> 1905760 DEBUG (ScheduledTrigger-10128-thread-3) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 2 and last live nodes: 2
[junit4] 2> 1905761 DEBUG (TEST-TestSimTriggerIntegration.testNodeLostTriggerRestoreState-seed#[6025CDAA20F4310C]) [ ] o.a.s.c.a.ScheduledTriggers Shutting down scheduled thread pool executor now
[junit4] 2> 1905762 DEBUG (TEST-TestSimTriggerIntegration.testNodeLostTriggerRestoreState-seed#[6025CDAA20F4310C]) [ ] o.a.s.c.a.ScheduledTriggers Shutting down action executor now
[junit4] 2> 1905762 DEBUG (TEST-TestSimTriggerIntegration.testNodeLostTriggerRestoreState-seed#[6025CDAA20F4310C]) [ ] o.a.s.c.a.ScheduledTriggers Awaiting termination for action executor
[junit4] 2> 1905762 DEBUG (TEST-TestSimTriggerIntegration.testNodeLostTriggerRestoreState-seed#[6025CDAA20F4310C]) [ ] o.a.s.c.a.ScheduledTriggers Awaiting termination for scheduled thread pool executor
[junit4] 2> 1905762 DEBUG (TEST-TestSimTriggerIntegration.testNodeLostTriggerRestoreState-seed#[6025CDAA20F4310C]) [ ] o.a.s.c.a.ScheduledTriggers ScheduledTriggers closed completely
[junit4] 2> 1905762 DEBUG (TEST-TestSimTriggerIntegration.testNodeLostTriggerRestoreState-seed#[6025CDAA20F4310C]) [ ] o.a.s.c.a.OverseerTriggerThread OverseerTriggerThread has been closed explicitly
[junit4] 2> 1905763 INFO (TEST-TestSimTriggerIntegration.testNodeLostTriggerRestoreState-seed#[6025CDAA20F4310C]) [ ] o.a.s.SolrTestCaseJ4 ###Ending testNodeLostTriggerRestoreState
[junit4] 2> NOTE: reproduce with: ant test -Dtestcase=TestSimTriggerIntegration -Dtests.method=testNodeLostTriggerRestoreState -Dtests.seed=6025CDAA20F4310C -Dtests.multiplier=2 -Dtests.slow=true -Dtests.locale=mk-MK -Dtests.timezone=CST -Dtests.asserts=true -Dtests.file.encoding=US-ASCII
[junit4] ERROR 0.69s J1 | TestSimTriggerIntegration.testNodeLostTriggerRestoreState <<<
[junit4] > Throwable #1: java.util.concurrent.TimeoutException: OverseerTriggerThread never caught up to the latest znodeVersion
[junit4] > at __randomizedtesting.SeedInfo.seed([6025CDAA20F4310C:4BDA18F1BA8C24DC]:0)
[junit4] > at org.apache.solr.util.TimeOut.waitFor(TimeOut.java:66)
[junit4] > at org.apache.solr.cloud.autoscaling.sim.SimSolrCloudTestCase.assertAutoscalingUpdateComplete(SimSolrCloudTestCase.java:98)
[junit4] > at org.apache.solr.cloud.autoscaling.sim.TestSimTriggerIntegration.testNodeLostTriggerRestoreState(TestSimTriggerIntegration.java:300)
[junit4] > at java.lang.Thread.run(Thread.java:748)
[junit4] 2> 1905769 INFO (TEST-TestSimTriggerIntegration.testEventFromRestoredState-seed#[6025CDAA20F4310C]) [ ] o.a.s.SolrTestCaseJ4 ###Starting testEventFromRestoredState
[junit4] 2> 1905772 DEBUG (TEST-TestSimTriggerIntegration.testEventFromRestoredState-seed#[6025CDAA20F4310C]) [ ] o.a.s.c.a.s.SimClusterStateProvider --- new Overseer leader: 127.0.0.1:10009_solr
[junit4] 2> 1905772 DEBUG (TEST-TestSimTriggerIntegration.testEventFromRestoredState-seed#[6025CDAA20F4310C]) [ ] o.a.s.c.a.s.SimClusterStateProvider ** creating new collection states, currentVersion=0
[junit4] 2> 1905772 DEBUG (TEST-TestSimTriggerIntegration.testEventFromRestoredState-seed#[6025CDAA20F4310C]) [ ] o.a.s.c.a.s.SimClusterStateProvider ** saved cluster state version 0
[junit4] 2> 1905772 INFO (TEST-TestSimTriggerIntegration.testEventFromRestoredState-seed#[6025CDAA20F4310C]) [ ] o.a.s.h.a.MetricsHistoryHandler No .system collection, keeping metrics history in memory.
[junit4] 2> 1905773 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Adding .auto_add_replicas and .scheduled_maintenance triggers
[junit4] 2> 1905773 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Refreshing /autoscaling.json with znode version 1
[junit4] 2> 1905774 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Current znodeVersion 1, lastZnodeVersion 0
[junit4] 2> 1905774 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Processed trigger updates upto znodeVersion 1
[junit4] 2> 1905775 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.NodeLostTrigger NodeLostTrigger .auto_add_replicas - Initial livenodes: [127.0.0.1:10010_solr, 127.0.0.1:10009_solr]
[junit4] 2> 1905775 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread -- deactivating old nodeLost / nodeAdded markers
[junit4] 2> 1905775 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Current znodeVersion 1, lastZnodeVersion 1
[junit4] 2> 1905775 DEBUG (simCloudManagerPool-10133-thread-2) [ ] o.a.s.c.a.AutoScalingHandler Verified autoscaling configuration
[junit4] 2> 1905775 DEBUG (ScheduledTrigger-10134-thread-2) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 2 and last live nodes: 2
[junit4] 2> 1905775 DEBUG (simCloudManagerPool-10133-thread-2) [ ] o.a.s.c.a.OverseerTriggerThread Refreshing /autoscaling.json with znode version 2
[junit4] 2> 1905777 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Processed trigger updates upto znodeVersion 2
[junit4] 2> 1905778 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread -- deactivating old nodeLost / nodeAdded markers
[junit4] 2> 1905778 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Current znodeVersion 2, lastZnodeVersion 2
[junit4] 2> 1905778 DEBUG (simCloudManagerPool-10133-thread-3) [ ] o.a.s.c.a.AutoScalingHandler Verified autoscaling configuration
[junit4] 2> 1905778 DEBUG (simCloudManagerPool-10133-thread-3) [ ] o.a.s.c.a.OverseerTriggerThread Refreshing /autoscaling.json with znode version 3
[junit4] 2> 1905778 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Processed trigger updates upto znodeVersion 3
[junit4] 2> 1905778 INFO (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.s.TestSimTriggerIntegration TestTriggerAction init
[junit4] 2> 1905778 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.NodeAddedTrigger NodeAddedTrigger node_added_trigger - Initial livenodes: [127.0.0.1:10010_solr, 127.0.0.1:10009_solr]
[junit4] 2> 1905778 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.TestSimTriggerIntegration$TestTriggerAction}], enabled=true}
[junit4] 2> 1905778 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread -- deactivating old nodeLost / nodeAdded markers
[junit4] 2> 1905778 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Current znodeVersion 3, lastZnodeVersion 3
[junit4] 2> 1905778 DEBUG (ScheduledTrigger-10134-thread-1) [ ] o.a.s.c.a.NodeAddedTrigger Running NodeAddedTrigger node_added_trigger
[junit4] 2> 1905778 DEBUG (ScheduledTrigger-10134-thread-1) [ ] o.a.s.c.a.NodeAddedTrigger Found livenodes: 2
[junit4] 2> 1905783 DEBUG (TEST-TestSimTriggerIntegration.testEventFromRestoredState-seed#[6025CDAA20F4310C]) [ ] o.a.s.c.a.s.SimClusterStateProvider -- creating marker: /autoscaling/nodeAdded/127.0.0.1:10011_solr
[junit4] 2> 1905796 DEBUG (ScheduledTrigger-10134-thread-1) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 3 and last live nodes: 2
[junit4] 2> 1905799 DEBUG (ScheduledTrigger-10134-thread-2) [ ] o.a.s.c.a.NodeAddedTrigger Running NodeAddedTrigger node_added_trigger
[junit4] 2> 1905799 DEBUG (ScheduledTrigger-10134-thread-2) [ ] o.a.s.c.a.NodeAddedTrigger Found livenodes: 3
[junit4] 2> 1905799 DEBUG (ScheduledTrigger-10134-thread-2) [ ] o.a.s.c.a.NodeAddedTrigger Tracking new node: 127.0.0.1:10011_solr at time 9862611067898610
[junit4] 2> 1905816 DEBUG (ScheduledTrigger-10134-thread-4) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 3 and last live nodes: 3
[junit4] 2> 1905820 DEBUG (ScheduledTrigger-10134-thread-3) [ ] o.a.s.c.a.NodeAddedTrigger Running NodeAddedTrigger node_added_trigger
[junit4] 2> 1905820 DEBUG (ScheduledTrigger-10134-thread-3) [ ] o.a.s.c.a.NodeAddedTrigger Found livenodes: 3
[junit4] 2> 1905836 DEBUG (ScheduledTrigger-10134-thread-1) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 3 and last live nodes: 3
[junit4] 2> 1905840 DEBUG (ScheduledTrigger-10134-thread-2) [ ] o.a.s.c.a.NodeAddedTrigger Running NodeAddedTrigger node_added_trigger
[junit4] 2> 1905840 DEBUG (ScheduledTrigger-10134-thread-2) [ ] o.a.s.c.a.NodeAddedTrigger Found livenodes: 3
[junit4] 2> 1905856 DEBUG (ScheduledTrigger-10134-thread-4) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 3 and last live nodes: 3
[junit4] 2> 1905860 DEBUG (ScheduledTrigger-10134-thread-3) [ ] o.a.s.c.a.NodeAddedTrigger Running NodeAddedTrigger node_added_trigger
[junit4] 2> 1905860 DEBUG (ScheduledTrigger-10134-thread-3) [ ] o.a.s.c.a.NodeAddedTrigger Found livenodes: 3
[junit4] 2> 1905876 DEBUG (ScheduledTrigger-10134-thread-1) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 3 and last live nodes: 3
[junit4] 2> 1905880 DEBUG (ScheduledTrigger-10134-thread-2) [ ] o.a.s.c.a.NodeAddedTrigger Running NodeAddedTrigger node_added_trigger
[junit4] 2> 1905880 DEBUG (ScheduledTrigger-10134-thread-2) [ ] o.a.s.c.a.NodeAddedTrigger Found livenodes: 3
[junit4] 2> 1905896 DEBUG (ScheduledTrigger-10134-thread-4) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 3 and last live nodes: 3
[junit4] 2> 1905900 DEBUG (ScheduledTrigger-10134-thread-3) [ ] o.a.s.c.a.NodeAddedTrigger Running NodeAddedTrigger node_added_trigger
[junit4] 2> 1905900 DEBUG (ScheduledTrigger-10134-thread-3) [ ] o.a.s.c.a.NodeAddedTrigger Found livenodes: 3
[junit4] 2> 1905917 DEBUG (ScheduledTrigger-10134-thread-1) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 3 and last live nodes: 3
[junit4] 2> 1905921 DEBUG (ScheduledTrigger-10134-thread-2) [ ] o.a.s.c.a.NodeAddedTrigger Running NodeAddedTrigger node_added_trigger
[junit4] 2> 1905921 DEBUG (ScheduledTrigger-10134-thread-2) [ ] o.a.s.c.a.NodeAddedTrigger Found livenodes: 3
[junit4] 2> 1905937 DEBUG (ScheduledTrigger-10134-thread-2) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 3 and last live nodes: 3
[junit4] 2> 1905941 DEBUG (ScheduledTrigger-10134-thread-2) [ ] o.a.s.c.a.NodeAddedTrigger Running NodeAddedTrigger node_added_trigger
[junit4] 2> 1905941 DEBUG (ScheduledTrigger-10134-thread-2) [ ] o.a.s.c.a.NodeAddedTrigger Found livenodes: 3
[junit4] 2> 1905957 DEBUG (ScheduledTrigger-10134-thread-2) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 3 and last live nodes: 3
[junit4] 2> 1905961 DEBUG (ScheduledTrigger-10134-thread-4) [ ] o.a.s.c.a.NodeAddedTrigger Running NodeAddedTrigger node_added_trigger
[junit4] 2> 1905961 DEBUG (ScheduledTrigger-10134-thread-4) [ ] o.a.s.c.a.NodeAddedTrigger Found livenodes: 3
[junit4] 2> 1905977 DEBUG (ScheduledTrigger-10134-thread-3) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 3 and last live nodes: 3
[junit4] 2> 1905981 DEBUG (ScheduledTrigger-10134-thread-1) [ ] o.a.s.c.a.NodeAddedTrigger Running NodeAddedTrigger node_added_trigger
[junit4] 2> 1905981 DEBUG (ScheduledTrigger-10134-thread-1) [ ] o.a.s.c.a.NodeAddedTrigger Found livenodes: 3
[junit4] 2> 1905997 DEBUG (ScheduledTrigger-10134-thread-1) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 3 and last live nodes: 3
[junit4] 2> 1906001 DEBUG (ScheduledTrigger-10134-thread-1) [ ] o.a.s.c.a.NodeAddedTrigger Running NodeAddedTrigger node_added_trigger
[junit4] 2> 1906001 DEBUG (ScheduledTrigger-10134-thread-1) [ ] o.a.s.c.a.NodeAddedTrigger Found livenodes: 3
[junit4] 2> 1906001 DEBUG (ScheduledTrigger-10134-thread-1) [ ] o.a.s.c.a.NodeAddedTrigger NodeAddedTrigger node_added_trigger firing registered processor for nodes: [127.0.0.1:10011_solr] added at times [9862611067898610], now=9862621157557910
[junit4] 2> 1906001 DEBUG (ScheduledTrigger-10134-thread-1) [ ] o.a.s.c.a.ScheduledTriggers ++++++++ Cooldown inactive - processing event: {
[junit4] 2> "id":"2309fe15428af2Taeijcq2todj4jxogzau7scz2k",
[junit4] 2> "source":"node_added_trigger",
[junit4] 2> "eventTime":9862611067898610,
[junit4] 2> "eventType":"NODEADDED",
[junit4] 2> "properties":{
[junit4] 2> "eventTimes":[9862611067898610],
[junit4] 2> "preferredOperation":"movereplica",
[junit4] 2> "nodeNames":["127.0.0.1:10011_solr"],
[junit4] 2> "replicaType":"NRT"}}
[junit4] 2> 1906002 DEBUG (ScheduledTrigger-10134-thread-1) [ ] o.a.s.c.a.ScheduledTriggers Pausing all triggers: [.auto_add_replicas, node_added_trigger]
[junit4] 2> 1906002 DEBUG (ScheduledTrigger-10134-thread-1) [ ] o.a.s.c.a.SystemLogListener Collection .system missing, skip sending event {
[junit4] 2> "id":"2309fe15428af2Taeijcq2todj4jxogzau7scz2k",
[junit4] 2> "source":"node_added_trigger",
[junit4] 2> "eventTime":9862611067898610,
[junit4] 2> "eventType":"NODEADDED",
[junit4] 2> "properties":{
[junit4] 2> "eventTimes":[9862611067898610],
[junit4] 2> "preferredOperation":"movereplica",
[junit4] 2> "_enqueue_time_":9862621196475960,
[junit4] 2> "nodeNames":["127.0.0.1:10011_solr"],
[junit4] 2> "replicaType":"NRT"}}
[junit4] 2> 1906002 DEBUG (ScheduledTrigger-10134-thread-1) [ ] o.a.s.c.a.NodeAddedTrigger Removing new node from tracking: 127.0.0.1:10011_solr
[junit4] 2> 1906002 DEBUG (AutoscalingActionExecutor-10135-thread-1) [ ] o.a.s.c.a.ScheduledTriggers -- processing actions for {
[junit4] 2> "id":"2309fe15428af2Taeijcq2todj4jxogzau7scz2k",
[junit4] 2> "source":"node_added_trigger",
[junit4] 2> "eventTime":9862611067898610,
[junit4] 2> "eventType":"NODEADDED",
[junit4] 2> "properties":{
[junit4] 2> "eventTimes":[9862611067898610],
[junit4] 2> "preferredOperation":"movereplica",
[junit4] 2> "_enqueue_time_":9862621196475960,
[junit4] 2> "nodeNames":["127.0.0.1:10011_solr"],
[junit4] 2> "replicaType":"NRT"}}
[junit4] 2> 1906003 DEBUG (AutoscalingActionExecutor-10135-thread-1) [ ] o.a.s.c.a.SystemLogListener Collection .system missing, skip sending event {
[junit4] 2> "id":"2309fe15428af2Taeijcq2todj4jxogzau7scz2k",
[junit4] 2> "source":"node_added_trigger",
[junit4] 2> "eventTime":9862611067898610,
[junit4] 2> "eventType":"NODEADDED",
[junit4] 2> "properties":{
[junit4] 2> "eventTimes":[9862611067898610],
[junit4] 2> "preferredOperation":"movereplica",
[junit4] 2> "_enqueue_time_":9862621196475960,
[junit4] 2> "nodeNames":["127.0.0.1:10011_solr"],
[junit4] 2> "replicaType":"NRT"}}
[junit4] 2> 1906003 DEBUG (AutoscalingActionExecutor-10135-thread-1) [ ] o.a.s.c.a.ScheduledTriggers Resuming trigger: .auto_add_replicas after 100ms
[junit4] 2> 1906003 DEBUG (AutoscalingActionExecutor-10135-thread-1) [ ] o.a.s.c.a.ScheduledTriggers Resuming trigger: node_added_trigger after 100ms
[junit4] 2> 1906003 DEBUG (AutoscalingActionExecutor-10135-thread-1) [ ] o.a.s.c.a.ScheduledTriggers -- processing took 17 ms for event id=2309fe15428af2Taeijcq2todj4jxogzau7scz2k
[junit4] 2> 1906003 DEBUG (TEST-TestSimTriggerIntegration.testEventFromRestoredState-seed#[6025CDAA20F4310C]) [ ] o.a.s.c.a.s.SimClusterStateProvider -- creating marker: /autoscaling/nodeAdded/127.0.0.1:10012_solr
[junit4] 2> 1906103 DEBUG (ScheduledTrigger-10134-thread-2) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 4 and last live nodes: 3
[junit4] 2> 1906103 DEBUG (ScheduledTrigger-10134-thread-4) [ ] o.a.s.c.a.NodeAddedTrigger Running NodeAddedTrigger node_added_trigger
[junit4] 2> 1906103 DEBUG (ScheduledTrigger-10134-thread-4) [ ] o.a.s.c.a.NodeAddedTrigger Found livenodes: 4
[junit4] 2> 1906103 DEBUG (ScheduledTrigger-10134-thread-4) [ ] o.a.s.c.a.NodeAddedTrigger Tracking new node: 127.0.0.1:10012_solr at time 9862626243589210
[junit4] 2> 1906123 DEBUG (ScheduledTrigger-10134-thread-2) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 4 and last live nodes: 4
[junit4] 2> 1906123 DEBUG (ScheduledTrigger-10134-thread-3) [ ] o.a.s.c.a.NodeAddedTrigger Running NodeAddedTrigger node_added_trigger
[junit4] 2> 1906123 DEBUG (ScheduledTrigger-10134-thread-3) [ ] o.a.s.c.a.NodeAddedTrigger Found livenodes: 4
[junit4] 2> 1906143 DEBUG (ScheduledTrigger-10134-thread-1) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 4 and last live nodes: 4
[junit4] 2> 1906143 DEBUG (ScheduledTrigger-10134-thread-4) [ ] o.a.s.c.a.NodeAddedTrigger Running NodeAddedTrigger node_added_trigger
[junit4] 2> 1906143 DEBUG (ScheduledTrigger-10134-thread-4) [ ] o.a.s.c.a.NodeAddedTrigger Found livenodes: 4
[junit4] 2> 1906163 DEBUG (ScheduledTrigger-10134-thread-2) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 4 and last live nodes: 4
[junit4] 2> 1906163 DEBUG (ScheduledTrigger-10134-thread-3) [ ] o.a.s.c.a.NodeAddedTrigger Running NodeAddedTrigger node_added_trigger
[junit4] 2> 1906163 DEBUG (ScheduledTrigger-10134-thread-3) [ ] o.a.s.c.a.NodeAddedTrigger Found livenodes: 4
[junit4] 2> 1906183 DEBUG (ScheduledTrigger-10134-thread-1) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 4 and last live nodes: 4
[junit4] 2> 1906183 DEBUG (ScheduledTrigger-10134-thread-1) [ ] o.a.s.c.a.NodeAddedTrigger Running NodeAddedTrigger node_added_trigger
[junit4] 2> 1906183 DEBUG (ScheduledTrigger-10134-thread-1) [ ] o.a.s.c.a.NodeAddedTrigger Found livenodes: 4
[junit4] 2> 1906203 INFO (TEST-TestSimTriggerIntegration.testEventFromRestoredState-seed#[6025CDAA20F4310C]) [ ] o.a.s.c.a.s.SimCloudManager === Restarting OverseerTriggerThread and clearing object cache...
[junit4] 2> 1906203 INFO (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread OverseerTriggerThread woken up but we are closed, exiting.
[junit4] 2> 1906203 DEBUG (TEST-TestSimTriggerIntegration.testEventFromRestoredState-seed#[6025CDAA20F4310C]) [ ] o.a.s.c.a.ScheduledTriggers Shutting down scheduled thread pool executor now
[junit4] 2> 1906203 DEBUG (TEST-TestSimTriggerIntegration.testEventFromRestoredState-seed#[6025CDAA20F4310C]) [ ] o.a.s.c.a.ScheduledTriggers Shutting down action executor now
[junit4] 2> 1906203 DEBUG (TEST-TestSimTriggerIntegration.testEventFromRestoredState-seed#[6025CDAA20F4310C]) [ ] o.a.s.c.a.ScheduledTriggers Awaiting termination for action executor
[junit4] 2> 1906203 DEBUG (TEST-TestSimTriggerIntegration.testEventFromRestoredState-seed#[6025CDAA20F4310C]) [ ] o.a.s.c.a.ScheduledTriggers Awaiting termination for scheduled thread pool executor
[junit4] 2> 1906203 DEBUG (TEST-TestSimTriggerIntegration.testEventFromRestoredState-seed#[6025CDAA20F4310C]) [ ] o.a.s.c.a.ScheduledTriggers ScheduledTriggers closed completely
[junit4] 2> 1906203 DEBUG (TEST-TestSimTriggerIntegration.testEventFromRestoredState-seed#[6025CDAA20F4310C]) [ ] o.a.s.c.a.OverseerTriggerThread OverseerTriggerThread has been closed explicitly
[junit4] 2> 1906204 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Refreshing /autoscaling.json with znode version 3
[junit4] 2> 1906204 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Current znodeVersion 3, lastZnodeVersion 0
[junit4] 2> 1906204 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Processed trigger updates upto znodeVersion 3
[junit4] 2> 1906204 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.NodeLostTrigger NodeLostTrigger .auto_add_replicas - Initial livenodes: [127.0.0.1:10010_solr, 127.0.0.1:10009_solr, 127.0.0.1:10012_solr, 127.0.0.1:10011_solr]
[junit4] 2> 1906204 INFO (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.s.TestSimTriggerIntegration TestTriggerAction init
[junit4] 2> 1906204 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.NodeAddedTrigger NodeAddedTrigger node_added_trigger - Initial livenodes: [127.0.0.1:10010_solr, 127.0.0.1:10009_solr, 127.0.0.1:10012_solr, 127.0.0.1:10011_solr]
[junit4] 2> 1906204 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.TestSimTriggerIntegration$TestTriggerAction}], enabled=true}
[junit4] 2> 1906204 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.NodeAddedTrigger Adding node from marker path: 127.0.0.1:10011_solr
[junit4] 2> 1906204 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.NodeAddedTrigger Adding node from marker path: 127.0.0.1:10012_solr
[junit4] 2> 1906204 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread -- deactivating old nodeLost / nodeAdded markers
[junit4] 2> 1906204 DEBUG (ScheduledTrigger-10139-thread-1) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 4 and last live nodes: 4
[junit4] 2> 1906204 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Current znodeVersion 3, lastZnodeVersion 3
[junit4] 2> 1906205 DEBUG (ScheduledTrigger-10139-thread-2) [ ] o.a.s.c.a.NodeAddedTrigger Running NodeAddedTrigger node_added_trigger
[junit4] 2> 1906205 DEBUG (ScheduledTrigger-10139-thread-2) [ ] o.a.s.c.a.NodeAddedTrigger Found livenodes: 4
[junit4] 2> 1906225 DEBUG (ScheduledTrigger-10139-thread-1) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 4 and last live nodes: 4
[junit4] 2> 1906226 DEBUG (ScheduledTrigger-10139-thread-3) [ ] o.a.s.c.a.NodeAddedTrigger Running NodeAddedTrigger node_added_trigger
[junit4] 2> 1906226 DEBUG (ScheduledTrigger-10139-thread-3) [ ] o.a.s.c.a.NodeAddedTrigger Found livenodes: 4
[junit4] 2> 1906245 DEBUG (ScheduledTrigger-10139-thread-2) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 4 and last live nodes: 4
[junit4] 2> 1906246 DEBUG (ScheduledTrigger-10139-thread-4) [ ] o.a.s.c.a.NodeAddedTrigger Running NodeAddedTrigger node_added_trigger
[junit4] 2> 1906246 DEBUG (ScheduledTrigger-10139-thread-4) [ ] o.a.s.c.a.NodeAddedTrigger Found livenodes: 4
[junit4] 2> 1906265 DEBUG (ScheduledTrigger-10139-thread-1) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 4 and last live nodes: 4
[junit4] 2> 1906266 DEBUG (ScheduledTrigger-10139-thread-1) [ ] o.a.s.c.a.NodeAddedTrigger Running NodeAddedTrigger node_added_trigger
[junit4] 2> 1906266 DEBUG (ScheduledTrigger-10139-thread-1) [ ] o.a.s.c.a.NodeAddedTrigger Fou
[...truncated too long message...]
"eventTimes":[9862980140953060],
[junit4] 2> "preferredOperation":"movereplica",
[junit4] 2> "nodeNames":["127.0.0.1:10033_solr"],
[junit4] 2> "replicaType":"NRT"}}
[junit4] 2> 1913201 DEBUG (ScheduledTrigger-10179-thread-2) [ ] o.a.s.c.a.ScheduledTriggers Pausing all triggers: [.auto_add_replicas, node_added_cooldown_trigger]
[junit4] 2> 1913201 DEBUG (ScheduledTrigger-10179-thread-2) [ ] o.a.s.c.a.SystemLogListener Collection .system missing, skip sending event {
[junit4] 2> "id":"230a5403ba6de4Taeijcq2todj4jxogzau7scz33",
[junit4] 2> "source":"node_added_cooldown_trigger",
[junit4] 2> "eventTime":9862980140953060,
[junit4] 2> "eventType":"NODEADDED",
[junit4] 2> "properties":{
[junit4] 2> "eventTimes":[9862980140953060],
[junit4] 2> "preferredOperation":"movereplica",
[junit4] 2> "_enqueue_time_":9862981154990060,
[junit4] 2> "nodeNames":["127.0.0.1:10033_solr"],
[junit4] 2> "replicaType":"NRT"}}
[junit4] 2> 1913201 DEBUG (ScheduledTrigger-10179-thread-2) [ ] o.a.s.c.a.NodeAddedTrigger Removing new node from tracking: 127.0.0.1:10033_solr
[junit4] 2> 1913201 DEBUG (AutoscalingActionExecutor-10180-thread-1) [ ] o.a.s.c.a.ScheduledTriggers -- processing actions for {
[junit4] 2> "id":"230a5403ba6de4Taeijcq2todj4jxogzau7scz33",
[junit4] 2> "source":"node_added_cooldown_trigger",
[junit4] 2> "eventTime":9862980140953060,
[junit4] 2> "eventType":"NODEADDED",
[junit4] 2> "properties":{
[junit4] 2> "eventTimes":[9862980140953060],
[junit4] 2> "preferredOperation":"movereplica",
[junit4] 2> "_enqueue_time_":9862981154990060,
[junit4] 2> "nodeNames":["127.0.0.1:10033_solr"],
[junit4] 2> "replicaType":"NRT"}}
[junit4] 2> 1913201 DEBUG (AutoscalingActionExecutor-10180-thread-1) [ ] o.a.s.c.a.SystemLogListener Collection .system missing, skip sending event {
[junit4] 2> "id":"230a5403ba6de4Taeijcq2todj4jxogzau7scz33",
[junit4] 2> "source":"node_added_cooldown_trigger",
[junit4] 2> "eventTime":9862980140953060,
[junit4] 2> "eventType":"NODEADDED",
[junit4] 2> "properties":{
[junit4] 2> "eventTimes":[9862980140953060],
[junit4] 2> "preferredOperation":"movereplica",
[junit4] 2> "_enqueue_time_":9862981154990060,
[junit4] 2> "nodeNames":["127.0.0.1:10033_solr"],
[junit4] 2> "replicaType":"NRT"}}
[junit4] 2> 1913202 DEBUG (TEST-TestSimTriggerIntegration.testCooldown-seed#[6025CDAA20F4310C]) [ ] o.a.s.c.a.ScheduledTriggers Shutting down scheduled thread pool executor now
[junit4] 2> 1913202 DEBUG (TEST-TestSimTriggerIntegration.testCooldown-seed#[6025CDAA20F4310C]) [ ] o.a.s.c.a.ScheduledTriggers Shutting down action executor now
[junit4] 2> 1913202 DEBUG (TEST-TestSimTriggerIntegration.testCooldown-seed#[6025CDAA20F4310C]) [ ] o.a.s.c.a.ScheduledTriggers Awaiting termination for action executor
[junit4] 2> 1913202 INFO (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread OverseerTriggerThread woken up but we are closed, exiting.
[junit4] 2> 1913202 DEBUG (AutoscalingActionExecutor-10180-thread-1) [ ] o.a.s.c.a.ScheduledTriggers -- processing took 56 ms for event id=230a5403ba6de4Taeijcq2todj4jxogzau7scz33
[junit4] 2> 1913202 DEBUG (TEST-TestSimTriggerIntegration.testCooldown-seed#[6025CDAA20F4310C]) [ ] o.a.s.c.a.ScheduledTriggers Awaiting termination for scheduled thread pool executor
[junit4] 2> 1913202 DEBUG (TEST-TestSimTriggerIntegration.testCooldown-seed#[6025CDAA20F4310C]) [ ] o.a.s.c.a.ScheduledTriggers ScheduledTriggers closed completely
[junit4] 2> 1913202 DEBUG (TEST-TestSimTriggerIntegration.testCooldown-seed#[6025CDAA20F4310C]) [ ] o.a.s.c.a.OverseerTriggerThread OverseerTriggerThread has been closed explicitly
[junit4] 2> 1913203 INFO (TEST-TestSimTriggerIntegration.testCooldown-seed#[6025CDAA20F4310C]) [ ] o.a.s.SolrTestCaseJ4 ###Ending testCooldown
[junit4] 2> NOTE: leaving temporary files on disk at: /home/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-8.3/solr/build/solr-core/test/J1/temp/solr.cloud.autoscaling.sim.TestSimTriggerIntegration_6025CDAA20F4310C-001
[junit4] 2> NOTE: test params are: codec=Asserting(Lucene80): {}, docValues:{}, maxPointsInLeafNode=1982, maxMBSortInHeap=6.199223236784361, sim=Asserting(org.apache.lucene.search.similarities.AssertingSimilarity@6aa8659a), locale=mk-MK, timezone=CST
[junit4] 2> NOTE: Linux 4.15.0-54-generic amd64/Oracle Corporation 1.8.0_191 (64-bit)/cpus=4,threads=1,free=287614336,total=514850816
[junit4] 2> NOTE: All tests run in this JVM: [TestNoOpRegenerator, CachingDirectoryFactoryTest, TestExceedMaxTermLength, LeaderFailoverAfterPartitionTest, AnalysisErrorHandlingTest, TestExactSharedStatsCache, TestRandomFaceting, BinaryUpdateRequestHandlerTest, TestPayloadScoreQParserPlugin, CollectionsAPIDistributedZkTest, SyncSliceTest, TestBinaryField, TestSolrConfigHandler, TestLRUCache, MetricTriggerIntegrationTest, DistributedVersionInfoTest, CreateCollectionCleanupTest, TestFacetMethods, TestUnifiedSolrHighlighter, OverseerStatusTest, DisMaxRequestHandlerTest, ZkFailoverTest, AddReplicaTest, TransactionLogTest, SharedFSAutoReplicaFailoverTest, TestSchemaSimilarityResource, TestClusterProperties, HdfsCollectionsAPIDistributedZkTest, TestReloadDeadlock, DistributedFacetPivotLargeTest, TestRangeQuery, TestHdfsCloudBackupRestore, CoreAdminCreateDiscoverTest, TestJettySolrRunner, TestFieldCacheWithThreads, DeleteShardTest, MultiDestinationAuditLoggerTest, TestCloudRecovery, ScheduledTriggerIntegrationTest, TestSimExtremeIndexing, JSONWriterTest, TestRemoteStreaming, TestSurroundQueryParser, TestHighlightDedupGrouping, HdfsRestartWhileUpdatingTest, SplitByPrefixTest, CurrencyFieldTypeTest, TestDFRSimilarityFactory, TestFieldSortValues, CollectionPropsTest, TestQueryUtils, TlogReplayBufferedWhileIndexingTest, URLClassifyProcessorTest, TestImplicitCoreProperties, HdfsBasicDistributedZkTest, TestCorePropertiesReload, PathHierarchyTokenizerFactoryTest, BooleanFieldTest, TestPerFieldSimilarity, TestConfigSetsAPIZkFailure, HLLUtilTest, PreAnalyzedFieldManagedSchemaCloudTest, BlockCacheTest, EnumFieldTest, StatsComponentTest, ChaosMonkeyNothingIsSafeTest, TestGraphMLResponseWriter, DistributedDebugComponentTest, CollectionReloadTest, TestBlendedInfixSuggestions, TestSolrJ, DistributedSpellCheckComponentTest, TestElisionMultitermQuery, TestUseDocValuesAsStored, TestSizeLimitedDistributedMap, HdfsAutoAddReplicasIntegrationTest, TestDistributedStatsComponentCardinality, NodeMutatorTest, TestTestInjection, SolrMetricReporterTest, DistributedQueryComponentCustomSortTest, CircularListTest, TestComponentsName, NestedAtomicUpdateTest, MetricsConfigTest, OrderedExecutorTest, TestEmbeddedSolrServerAdminHandler, TestFuzzyAnalyzedSuggestions, LeaderVoteWaitTimeoutTest, ChaosMonkeySafeLeaderWithPullReplicasTest, BigEndianAscendingWordDeserializerTest, SaslZkACLProviderTest, SpellCheckCollatorTest, TestDynamicLoading, MoveReplicaHDFSFailoverTest, TestChildDocTransformerHierarchy, TestLegacyFieldReuse, TestFieldCacheSort, SolrCoreCheckLockOnStartupTest, TestSolrConfigHandlerCloud, ZkStateReaderTest, TestXmlQParser, TestPushWriter, DistanceUnitsTest, TestSortByMinMaxFunction, TestCloudPhrasesIdentificationComponent, TestSha256AuthenticationProvider, CloudExitableDirectoryReaderTest, TestMultiValuedNumericRangeQuery, SolrJmxReporterCloudTest, SolrIndexMetricsTest, TestManagedSchemaThreadSafety, BlockJoinFacetDistribTest, NodeMarkersRegistrationTest, RuleEngineTest, SoftAutoCommitTest, TriggerSetPropertiesIntegrationTest, CdcrBidirectionalTest, TestCoreBackup, TestRequestStatusCollectionAPI, DocValuesMissingTest, FieldAnalysisRequestHandlerTest, ClassificationUpdateProcessorFactoryTest, TestRandomRequestDistribution, DistributedUpdateProcessorTest, HttpPartitionOnCommitTest, MinimalSchemaTest, TestPullReplicaErrorHandling, NumericFieldsTest, AnalyticsMergeStrategyTest, HighlighterMaxOffsetTest, SolrPluginUtilsTest, SegmentsInfoRequestHandlerTest, PingRequestHandlerTest, ExplicitHLLTest, V2ApiIntegrationTest, RequestHandlersTest, TestApiFramework, TestInPlaceUpdatesDistrib, TestStressReorder, TemplateUpdateProcessorTest, TestCopyFieldCollectionResource, DirectoryFactoryTest, AnalysisAfterCoreReloadTest, BasicFunctionalityTest, ConvertedLegacyTest, SolrInfoBeanTest, SolrTestCaseJ4Test, TestCrossCoreJoin, TestCursorMarkWithoutUniqueKey, TestDistributedGrouping, TestDistributedSearch, TestDocumentBuilder, TestRandomDVFaceting, TestSolrTestCaseJ4, TestTolerantSearch, TestDeprecatedFilters, TestLuceneMatchVersion, TestWordDelimiterFilterFactory, TokenizerChainTest, TestEmbeddedSolrServerSchemaAPI, ActionThrottleTest, AssignBackwardCompatibilityTest, BasicDistributedZkTest, DeleteReplicaTest, LeaderElectionContextKeyTest, LeaderElectionIntegrationTest, LeaderElectionTest, LeaderTragicEventTest, MetricsHistoryWithAuthIntegrationTest, MigrateRouteKeyTest, MultiSolrCloudTestCaseTest, PeerSyncReplicationTest, RollingRestartTest, RoutingToNodesWithPropertiesTest, SSLMigrationTest, SolrCLIZkUtilsTest, SolrCloudExampleTest, SolrXmlInZkTest, TestCloudConsistency, TestHashPartitioner, TestPrepRecovery, TestSolrCloudWithKerberosAlt, TestStressCloudBlindAtomicUpdates, TestTolerantUpdateProcessorCloud, TestWaitForStateWithJettyShutdowns, TestZkChroot, UnloadDistributedZkTest, VMParamsZkACLAndCredentialsProvidersTest, ZkCLITest, AssignTest, AsyncCallRequestStatusResponseTest, CollectionsAPIAsyncDistributedZkTest, NodeAddedTriggerTest, NodeLostTriggerIntegrationTest, NodeLostTriggerTest, SystemLogListenerTest, TestSimDistributedQueue, TestSimTriggerIntegration]
[junit4] Completed [556/880 (1!)] on J1 in 8.80s, 11 tests, 1 error <<< FAILURES!
[...truncated 53766 lines...]