You are viewing a plain text version of this content. The canonical link for it is here.
Posted to dev@lucene.apache.org by Apache Jenkins Server <je...@builds.apache.org> on 2018/10/04 11:31:34 UTC
[JENKINS] Lucene-Solr-NightlyTests-master - Build # 1657 - Still
Unstable
Build: https://builds.apache.org/job/Lucene-Solr-NightlyTests-master/1657/
2 tests failed.
FAILED: org.apache.solr.cloud.autoscaling.sim.TestSimComputePlanAction.testNodeWithMultipleReplicasLost
Error Message:
Test abandoned because suite timeout was reached.
Stack Trace:
java.lang.Exception: Test abandoned because suite timeout was reached.
at __randomizedtesting.SeedInfo.seed([A173528524A1CB0E]:0)
FAILED: junit.framework.TestSuite.org.apache.solr.cloud.autoscaling.sim.TestSimComputePlanAction
Error Message:
Suite timeout exceeded (>= 7200000 msec).
Stack Trace:
java.lang.Exception: Suite timeout exceeded (>= 7200000 msec).
at __randomizedtesting.SeedInfo.seed([A173528524A1CB0E]:0)
Build Log:
[...truncated 15682 lines...]
[junit4] Suite: org.apache.solr.cloud.autoscaling.sim.TestSimComputePlanAction
[junit4] 2> Creating dataDir: /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-master/checkout/solr/build/solr-core/test/J0/temp/solr.cloud.autoscaling.sim.TestSimComputePlanAction_A173528524A1CB0E-001/init-core-data-001
[junit4] 2> 1044927 DEBUG (SUITE-TestSimComputePlanAction-seed#[A173528524A1CB0E]-worker) [ ] o.a.s.c.a.s.SimClusterStateProvider --- new Overseer leader: 127.0.0.1:10000_solr
[junit4] 2> 1044928 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Adding .auto_add_replicas and .scheduled_maintenance triggers
[junit4] 2> 1044928 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Refreshing /autoscaling.json with znode version 0
[junit4] 2> 1044928 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Current znodeVersion 0, lastZnodeVersion -1
[junit4] 2> 1044929 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Processed trigger updates upto znodeVersion 0
[junit4] 2> 1044932 DEBUG (SUITE-TestSimComputePlanAction-seed#[A173528524A1CB0E]-worker) [ ] o.a.s.c.a.s.SimClusterStateProvider ** creating new collection states, currentVersion=0
[junit4] 2> 1044933 DEBUG (SUITE-TestSimComputePlanAction-seed#[A173528524A1CB0E]-worker) [ ] o.a.s.c.a.s.SimClusterStateProvider ** saved cluster state version 0
[junit4] 2> 1044933 INFO (SUITE-TestSimComputePlanAction-seed#[A173528524A1CB0E]-worker) [ ] o.a.s.h.a.MetricsHistoryHandler No .system collection, keeping metrics history in memory.
[junit4] 2> 1044941 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.NodeLostTrigger NodeLostTrigger .auto_add_replicas - Initial livenodes: [127.0.0.1:10000_solr]
[junit4] 2> 1044943 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread -- clean old nodeAdded markers
[junit4] 2> 1044943 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Current znodeVersion 0, lastZnodeVersion 0
[junit4] 2> 1044949 DEBUG (TEST-TestSimComputePlanAction.testNodeAdded-seed#[A173528524A1CB0E]) [ ] o.a.s.c.a.OverseerTriggerThread Refreshing /autoscaling.json with znode version 1
[junit4] 2> 1044949 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Processed trigger updates upto znodeVersion 1
[junit4] 2> 1044950 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread -- clean old nodeLost markers
[junit4] 2> 1044950 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread -- clean old nodeAdded markers
[junit4] 2> 1044950 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Current znodeVersion 1, lastZnodeVersion 1
[junit4] 2> 1044950 INFO (TEST-TestSimComputePlanAction.testNodeAdded-seed#[A173528524A1CB0E]) [ ] o.a.s.c.a.s.SimCloudManager === Restarting OverseerTriggerThread and clearing object cache...
[junit4] 2> 1044950 WARN (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread OverseerTriggerThread woken up but we are closed, exiting.
[junit4] 2> 1044951 DEBUG (TEST-TestSimComputePlanAction.testNodeAdded-seed#[A173528524A1CB0E]) [ ] o.a.s.c.a.ScheduledTriggers Shutting down scheduled thread pool executor now
[junit4] 2> 1044951 DEBUG (TEST-TestSimComputePlanAction.testNodeAdded-seed#[A173528524A1CB0E]) [ ] o.a.s.c.a.ScheduledTriggers Shutting down action executor now
[junit4] 2> 1044951 DEBUG (TEST-TestSimComputePlanAction.testNodeAdded-seed#[A173528524A1CB0E]) [ ] o.a.s.c.a.ScheduledTriggers Awaiting termination for action executor
[junit4] 2> 1044951 DEBUG (TEST-TestSimComputePlanAction.testNodeAdded-seed#[A173528524A1CB0E]) [ ] o.a.s.c.a.ScheduledTriggers Awaiting termination for scheduled thread pool executor
[junit4] 2> 1044961 DEBUG (TEST-TestSimComputePlanAction.testNodeAdded-seed#[A173528524A1CB0E]) [ ] o.a.s.c.a.ScheduledTriggers ScheduledTriggers closed completely
[junit4] 2> 1044961 DEBUG (TEST-TestSimComputePlanAction.testNodeAdded-seed#[A173528524A1CB0E]) [ ] o.a.s.c.a.OverseerTriggerThread OverseerTriggerThread has been closed explicitly
[junit4] 2> 1044962 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Adding .auto_add_replicas and .scheduled_maintenance triggers
[junit4] 2> 1044963 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Refreshing /autoscaling.json with znode version 2
[junit4] 2> 1044963 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Current znodeVersion 2, lastZnodeVersion -1
[junit4] 2> 1044963 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Processed trigger updates upto znodeVersion 2
[junit4] 2> 1044963 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.NodeLostTrigger NodeLostTrigger .auto_add_replicas - Initial livenodes: [127.0.0.1:10000_solr]
[junit4] 2> 1044965 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread -- clean old nodeAdded markers
[junit4] 2> 1044965 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Current znodeVersion 2, lastZnodeVersion 2
[junit4] 2> 1044965 DEBUG (ScheduledTrigger-3121-thread-2) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 1
[junit4] 2> 1044986 DEBUG (ScheduledTrigger-3121-thread-1) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 1
[junit4] 2> 1045006 DEBUG (ScheduledTrigger-3121-thread-4) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 1
[junit4] 2> 1045027 DEBUG (ScheduledTrigger-3121-thread-3) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 1
[junit4] 2> 1045047 DEBUG (ScheduledTrigger-3121-thread-4) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 1
[junit4] 2> 1045068 DEBUG (ScheduledTrigger-3121-thread-4) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 1
[junit4] 2> 1045088 DEBUG (ScheduledTrigger-3121-thread-4) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 1
[junit4] 2> 1045108 DEBUG (ScheduledTrigger-3121-thread-4) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 1
[junit4] 2> 1045129 DEBUG (ScheduledTrigger-3121-thread-4) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 1
[junit4] 2> 1045229 DEBUG (ScheduledTrigger-3121-thread-1) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 1
[junit4] 2> 1045239 DEBUG (simCloudManagerPool-3120-thread-1) [ ] o.a.s.c.a.s.SimClusterStateProvider ** creating new collection states, currentVersion=1
[junit4] 2> 1045239 DEBUG (simCloudManagerPool-3120-thread-1) [ ] o.a.s.c.a.s.SimClusterStateProvider ** saved cluster state version 1
[junit4] 2> 1045242 DEBUG (simCloudManagerPool-3120-thread-1) [ ] o.a.s.c.a.AutoScalingHandler Verified autoscaling configuration
[junit4] 2> 1045242 DEBUG (simCloudManagerPool-3120-thread-1) [ ] o.a.s.c.a.OverseerTriggerThread Refreshing /autoscaling.json with znode version 3
[junit4] 2> 1045243 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Processed trigger updates upto znodeVersion 3
[junit4] 2> 1045243 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread -- clean old nodeAdded markers
[junit4] 2> 1045243 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Current znodeVersion 3, lastZnodeVersion 3
[junit4] 2> 1045246 DEBUG (simCloudManagerPool-3120-thread-2) [ ] o.a.s.c.a.AutoScalingHandler Verified autoscaling configuration
[junit4] 2> 1045246 DEBUG (simCloudManagerPool-3120-thread-2) [ ] o.a.s.c.a.OverseerTriggerThread Refreshing /autoscaling.json with znode version 4
[junit4] 2> 1045246 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Processed trigger updates upto znodeVersion 4
[junit4] 2> 1045247 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread -- clean old nodeAdded markers
[junit4] 2> 1045247 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Current znodeVersion 4, lastZnodeVersion 4
[junit4] 2> 1045249 DEBUG (ScheduledTrigger-3121-thread-4) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 1
[junit4] 2> 1045269 DEBUG (ScheduledTrigger-3121-thread-4) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 1
[junit4] 2> 1045290 DEBUG (ScheduledTrigger-3121-thread-4) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 1
[junit4] 2> 1045313 DEBUG (ScheduledTrigger-3121-thread-4) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 1
[junit4] 2> 1045333 DEBUG (ScheduledTrigger-3121-thread-4) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 1
[junit4] 2> 1045353 DEBUG (ScheduledTrigger-3121-thread-4) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 1
[junit4] 2> 1045354 DEBUG (simCloudManagerPool-3120-thread-3) [ ] o.a.s.c.a.AutoScalingHandler Verified autoscaling configuration
[junit4] 2> 1045354 DEBUG (simCloudManagerPool-3120-thread-3) [ ] o.a.s.c.a.OverseerTriggerThread Refreshing /autoscaling.json with znode version 5
[junit4] 2> 1045354 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Processed trigger updates upto znodeVersion 5
[junit4] 2> 1045355 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.NodeAddedTrigger NodeAddedTrigger node_added_trigger - Initial livenodes: [127.0.0.1:10000_solr]
[junit4] 2> 1045355 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.NodeAddedTrigger NodeAddedTrigger node_added_trigger instantiated with properties: {event=nodeAdded, waitFor=1, actions=[{name=compute_plan, class=solr.ComputePlanAction}, {name=test, class=org.apache.solr.cloud.autoscaling.sim.TestSimComputePlanAction$AssertingTriggerAction}], enabled=true}
[junit4] 2> 1045355 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Current znodeVersion 5, lastZnodeVersion 5
[junit4] 2> 1045355 DEBUG (ScheduledTrigger-3121-thread-1) [ ] o.a.s.c.a.NodeAddedTrigger Running NodeAddedTrigger node_added_trigger
[junit4] 2> 1045355 DEBUG (ScheduledTrigger-3121-thread-1) [ ] o.a.s.c.a.NodeAddedTrigger Found livenodes: 1
[junit4] 2> 1045362 DEBUG (simCloudManagerPool-3120-thread-4) [ ] o.a.s.c.a.AutoScalingHandler Verified autoscaling configuration
[junit4] 2> 1045362 DEBUG (simCloudManagerPool-3120-thread-4) [ ] o.a.s.c.a.OverseerTriggerThread Refreshing /autoscaling.json with znode version 6
[junit4] 2> 1045369 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Processed trigger updates upto znodeVersion 6
[junit4] 2> 1045369 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Current znodeVersion 6, lastZnodeVersion 6
[junit4] 2> 1045370 DEBUG (simCloudManagerPool-3120-thread-5) [ ] o.a.s.c.a.s.SimClusterStateProvider -- simCreateCollection testNodeAdded, currentVersion=2
[junit4] 2> 1045371 DEBUG (simCloudManagerPool-3120-thread-5) [ ] o.a.s.c.a.s.SimClusterStateProvider ** creating new collection states, currentVersion=2
[junit4] 2> 1045371 DEBUG (simCloudManagerPool-3120-thread-5) [ ] o.a.s.c.a.s.SimClusterStateProvider ** saved cluster state version 2
[junit4] 2> 1045371 DEBUG (simCloudManagerPool-3120-thread-5) [ ] o.a.s.c.o.ClusterStateMutator building a new cName: testNodeAdded
[junit4] 2> 1045374 DEBUG (ScheduledTrigger-3121-thread-2) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 1
[junit4] 2> 1045376 DEBUG (ScheduledTrigger-3121-thread-1) [ ] o.a.s.c.a.NodeAddedTrigger Running NodeAddedTrigger node_added_trigger
[junit4] 2> 1045376 DEBUG (ScheduledTrigger-3121-thread-1) [ ] o.a.s.c.a.NodeAddedTrigger Found livenodes: 1
[junit4] 2> 1045385 DEBUG (simCloudManagerPool-3120-thread-5) [ ] o.a.s.c.a.s.SimClusterStateProvider ** creating new collection states, currentVersion=3
[junit4] 2> 1045388 DEBUG (simCloudManagerPool-3120-thread-5) [ ] o.a.s.c.a.s.SimClusterStateProvider ** saved cluster state version 3
[junit4] 2> 1045394 DEBUG (ScheduledTrigger-3121-thread-1) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 1
[junit4] 2> 1045396 DEBUG (ScheduledTrigger-3121-thread-1) [ ] o.a.s.c.a.NodeAddedTrigger Running NodeAddedTrigger node_added_trigger
[junit4] 2> 1045396 DEBUG (ScheduledTrigger-3121-thread-1) [ ] o.a.s.c.a.NodeAddedTrigger Found livenodes: 1
[junit4] 2> 1045398 WARN (simCloudManagerPool-3120-thread-5) [ ] o.a.s.c.a.c.CreateCollectionCmd Specified number of replicas of 4 on collection testNodeAdded is higher than the number of Solr instances currently live or live and part of your createNodeSet(1). It's unusual to run two replica of the same slice on the same Solr-instance.
[junit4] 2> 1045400 DEBUG (simCloudManagerPool-3120-thread-5) [ ] o.a.s.c.s.c.a.PolicyHelper Creating a new session
[junit4] 2> 1045401 DEBUG (simCloudManagerPool-3120-thread-5) [ ] o.a.s.c.s.c.a.PolicyHelper New session created
[junit4] 2> 1045404 DEBUG (simCloudManagerPool-3120-thread-5) [ ] o.a.s.c.s.c.a.PolicyHelper returnSession, curr-time 5933011054 sessionWrapper.createTime 5933010909143632, this.sessionWrapper.createTime 5933010909143632
[junit4] 2> 1045404 DEBUG (simCloudManagerPool-3120-thread-5) [ ] o.a.s.c.s.c.a.PolicyHelper session set to NULL
[junit4] 2> 1045414 DEBUG (ScheduledTrigger-3121-thread-1) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 1
[junit4] 2> 1045416 DEBUG (ScheduledTrigger-3121-thread-1) [ ] o.a.s.c.a.NodeAddedTrigger Running NodeAddedTrigger node_added_trigger
[junit4] 2> 1045416 DEBUG (ScheduledTrigger-3121-thread-1) [ ] o.a.s.c.a.NodeAddedTrigger Found livenodes: 1
[junit4] 2> 1045434 DEBUG (ScheduledTrigger-3121-thread-1) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 1
[junit4] 2> 1045436 DEBUG (ScheduledTrigger-3121-thread-1) [ ] o.a.s.c.a.NodeAddedTrigger Running NodeAddedTrigger node_added_trigger
[junit4] 2> 1045436 DEBUG (ScheduledTrigger-3121-thread-1) [ ] o.a.s.c.a.NodeAddedTrigger Found livenodes: 1
[junit4] 2> 1045452 DEBUG (simCloudManagerPool-3120-thread-6) [ ] o.a.s.c.a.s.SimClusterStateProvider ** creating new collection states, currentVersion=4
[junit4] 2> 1045454 DEBUG (ScheduledTrigger-3121-thread-1) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 1
[junit4] 2> 1045454 DEBUG (simCloudManagerPool-3120-thread-6) [ ] o.a.s.c.a.s.SimClusterStateProvider ** saved cluster state version 4
[junit4] 2> 1045457 DEBUG (ScheduledTrigger-3121-thread-1) [ ] o.a.s.c.a.NodeAddedTrigger Running NodeAddedTrigger node_added_trigger
[junit4] 2> 1045457 DEBUG (ScheduledTrigger-3121-thread-1) [ ] o.a.s.c.a.NodeAddedTrigger Found livenodes: 1
[junit4] 2> 1045465 DEBUG (simCloudManagerPool-3120-thread-5) [ ] o.a.s.c.a.s.SimClusterStateProvider -- finished createCollection testNodeAdded, currentVersion=5
[junit4] 2> 1045474 DEBUG (ScheduledTrigger-3121-thread-1) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 1
[junit4] 2> 1045477 DEBUG (ScheduledTrigger-3121-thread-1) [ ] o.a.s.c.a.NodeAddedTrigger Running NodeAddedTrigger node_added_trigger
[junit4] 2> 1045477 DEBUG (ScheduledTrigger-3121-thread-1) [ ] o.a.s.c.a.NodeAddedTrigger Found livenodes: 1
[junit4] 2> 1045482 DEBUG (simCloudManagerPool-3120-thread-10) [ ] o.a.s.c.a.s.SimClusterStateProvider -- elected new leader for testNodeAdded / shard1 (currentVersion=5): {"core_node1":{
[junit4] 2> "core":"testNodeAdded_shard1_replica_n1",
[junit4] 2> "shard":"shard1",
[junit4] 2> "collection":"testNodeAdded",
[junit4] 2> "node_name":"127.0.0.1:10000_solr",
[junit4] 2> "type":"NRT",
[junit4] 2> "leader":"true",
[junit4] 2> "SEARCHER.searcher.maxDoc":0,
[junit4] 2> "SEARCHER.searcher.deletedDocs":0,
[junit4] 2> "INDEX.sizeInBytes":10240,
[junit4] 2> "state":"active",
[junit4] 2> "INDEX.sizeInGB":9.5367431640625E-6,
[junit4] 2> "SEARCHER.searcher.numDocs":0}}
[junit4] 2> 1045489 DEBUG (simCloudManagerPool-3120-thread-7) [ ] o.a.s.c.a.s.SimClusterStateProvider ** creating new collection states, currentVersion=5
[junit4] 2> 1045490 DEBUG (simCloudManagerPool-3120-thread-7) [ ] o.a.s.c.a.s.SimClusterStateProvider ** saved cluster state version 5
[junit4] 2> 1045495 DEBUG (ScheduledTrigger-3121-thread-1) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 1
[junit4] 2> 1045497 DEBUG (ScheduledTrigger-3121-thread-1) [ ] o.a.s.c.a.NodeAddedTrigger Running NodeAddedTrigger node_added_trigger
[junit4] 2> 1045497 DEBUG (ScheduledTrigger-3121-thread-1) [ ] o.a.s.c.a.NodeAddedTrigger Found livenodes: 1
[junit4] 2> 1045501 DEBUG (simCloudManagerPool-3120-thread-8) [ ] o.a.s.c.a.s.SimClusterStateProvider ** creating new collection states, currentVersion=6
[junit4] 2> 1045501 DEBUG (simCloudManagerPool-3120-thread-8) [ ] o.a.s.c.a.s.SimClusterStateProvider ** saved cluster state version 6
[junit4] 2> 1045515 DEBUG (ScheduledTrigger-3121-thread-1) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 1
[junit4] 2> 1045516 DEBUG (simCloudManagerPool-3120-thread-9) [ ] o.a.s.c.a.s.SimClusterStateProvider ** creating new collection states, currentVersion=7
[junit4] 2> 1045517 DEBUG (simCloudManagerPool-3120-thread-9) [ ] o.a.s.c.a.s.SimClusterStateProvider ** saved cluster state version 7
[junit4] 2> 1045517 DEBUG (ScheduledTrigger-3121-thread-1) [ ] o.a.s.c.a.NodeAddedTrigger Running NodeAddedTrigger node_added_trigger
[junit4] 2> 1045517 DEBUG (TEST-TestSimComputePlanAction.testNodeAdded-seed#[A173528524A1CB0E]) [ ] o.a.s.c.a.s.SimClusterStateProvider ** creating new collection states, currentVersion=8
[junit4] 2> 1045517 DEBUG (ScheduledTrigger-3121-thread-1) [ ] o.a.s.c.a.NodeAddedTrigger Found livenodes: 1
[junit4] 2> 1045518 DEBUG (TEST-TestSimComputePlanAction.testNodeAdded-seed#[A173528524A1CB0E]) [ ] o.a.s.c.a.s.SimClusterStateProvider ** saved cluster state version 8
[junit4] 2> 1045532 DEBUG (simCloudManagerPool-3120-thread-11) [ ] o.a.s.c.a.AutoScalingHandler Verified autoscaling configuration
[junit4] 2> 1045532 DEBUG (simCloudManagerPool-3120-thread-11) [ ] o.a.s.c.a.OverseerTriggerThread Refreshing /autoscaling.json with znode version 7
[junit4] 2> 1045532 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Processed trigger updates upto znodeVersion 7
[junit4] 2> 1045533 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Current znodeVersion 7, lastZnodeVersion 7
[junit4] 2> 1045535 DEBUG (ScheduledTrigger-3121-thread-4) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 1
[junit4] 2> 1045541 DEBUG (ScheduledTrigger-3121-thread-4) [ ] o.a.s.c.a.NodeAddedTrigger Running NodeAddedTrigger node_added_trigger
[junit4] 2> 1045542 DEBUG (ScheduledTrigger-3121-thread-4) [ ] o.a.s.c.a.NodeAddedTrigger Found livenodes: 2
[junit4] 2> 1045542 DEBUG (ScheduledTrigger-3121-thread-4) [ ] o.a.s.c.a.NodeAddedTrigger Tracking new node: 127.0.0.1:10001_solr at time 5933017951376982
[junit4] 2> 1045555 DEBUG (ScheduledTrigger-3121-thread-1) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 2
[junit4] 2> 1045562 DEBUG (ScheduledTrigger-3121-thread-3) [ ] o.a.s.c.a.NodeAddedTrigger Running NodeAddedTrigger node_added_trigger
[junit4] 2> 1045562 DEBUG (ScheduledTrigger-3121-thread-3) [ ] o.a.s.c.a.NodeAddedTrigger Found livenodes: 2
[junit4] 2> 1045562 DEBUG (ScheduledTrigger-3121-thread-3) [ ] o.a.s.c.a.NodeAddedTrigger NodeAddedTrigger node_added_trigger firing registered processor for nodes: [127.0.0.1:10001_solr] added at times [5933017951376982], now=5933018967778532
[junit4] 2> 1045562 DEBUG (ScheduledTrigger-3121-thread-3) [ ] o.a.s.c.a.ScheduledTriggers ++++++++ Cooldown inactive - processing event: {
[junit4] 2> "id":"15140c63701656T4dmzkn7wursdpjgxkl6ghyfii",
[junit4] 2> "source":"node_added_trigger",
[junit4] 2> "eventTime":5933017951376982,
[junit4] 2> "eventType":"NODEADDED",
[junit4] 2> "properties":{
[junit4] 2> "eventTimes":[5933017951376982],
[junit4] 2> "preferredOperation":"movereplica",
[junit4] 2> "nodeNames":["127.0.0.1:10001_solr"]}}
[junit4] 2> 1045562 DEBUG (ScheduledTrigger-3121-thread-3) [ ] o.a.s.c.a.ScheduledTriggers Pausing all triggers: [.auto_add_replicas, .scheduled_maintenance, node_added_trigger]
[junit4] 2> 1045582 DEBUG (simCloudManagerPool-3120-thread-12) [ ] o.a.s.c.a.s.SimClusterStateProvider -- simCreateCollection .system, currentVersion=9
[junit4] 2> 1045582 DEBUG (simCloudManagerPool-3120-thread-12) [ ] o.a.s.c.a.s.SimClusterStateProvider ** creating new collection states, currentVersion=9
[junit4] 2> 1045582 DEBUG (simCloudManagerPool-3120-thread-12) [ ] o.a.s.c.a.s.SimClusterStateProvider ** saved cluster state version 9
[junit4] 2> 1045582 DEBUG (simCloudManagerPool-3120-thread-12) [ ] o.a.s.c.o.ClusterStateMutator building a new cName: .system
[junit4] 2> 1045592 DEBUG (simCloudManagerPool-3120-thread-12) [ ] o.a.s.c.a.s.SimClusterStateProvider ** creating new collection states, currentVersion=10
[junit4] 2> 1045593 DEBUG (simCloudManagerPool-3120-thread-12) [ ] o.a.s.c.a.s.SimClusterStateProvider ** saved cluster state version 10
[junit4] 2> 1045594 DEBUG (simCloudManagerPool-3120-thread-12) [ ] o.a.s.c.s.c.a.PolicyHelper Creating a new session
[junit4] 2> 1045594 DEBUG (simCloudManagerPool-3120-thread-12) [ ] o.a.s.c.s.c.a.PolicyHelper New session created
[junit4] 2> 1045595 DEBUG (simCloudManagerPool-3120-thread-12) [ ] o.a.s.c.s.c.a.PolicyHelper returnSession, curr-time 5933020639 sessionWrapper.createTime 5933020596961882, this.sessionWrapper.createTime 5933020596961882
[junit4] 2> 1045595 DEBUG (simCloudManagerPool-3120-thread-12) [ ] o.a.s.c.s.c.a.PolicyHelper session set to NULL
[junit4] 2> 1045625 DEBUG (simCloudManagerPool-3120-thread-13) [ ] o.a.s.c.a.s.SimClusterStateProvider ** creating new collection states, currentVersion=11
[junit4] 2> 1045626 DEBUG (simCloudManagerPool-3120-thread-13) [ ] o.a.s.c.a.s.SimClusterStateProvider ** saved cluster state version 11
[junit4] 2> 1045630 DEBUG (simCloudManagerPool-3120-thread-15) [ ] o.a.s.c.a.s.SimClusterStateProvider -- elected new leader for .system / shard1 (currentVersion=12): {"core_node1":{
[junit4] 2> "core":".system_shard1_replica_n1",
[junit4] 2> "shard":"shard1",
[junit4] 2> "collection":".system",
[junit4] 2> "node_name":"127.0.0.1:10001_solr",
[junit4] 2> "type":"NRT",
[junit4] 2> "leader":"true",
[junit4] 2> "SEARCHER.searcher.maxDoc":0,
[junit4] 2> "SEARCHER.searcher.deletedDocs":0,
[junit4] 2> "INDEX.sizeInBytes":10240,
[junit4] 2> "state":"active",
[junit4] 2> "INDEX.sizeInGB":9.5367431640625E-6,
[junit4] 2> "SEARCHER.searcher.numDocs":0}}
[junit4] 2> 1045639 DEBUG (simCloudManagerPool-3120-thread-14) [ ] o.a.s.c.a.s.SimClusterStateProvider ** creating new collection states, currentVersion=12
[junit4] 2> 1045640 DEBUG (simCloudManagerPool-3120-thread-14) [ ] o.a.s.c.a.s.SimClusterStateProvider ** saved cluster state version 12
[junit4] 2> 1045640 DEBUG (simCloudManagerPool-3120-thread-12) [ ] o.a.s.c.a.s.SimClusterStateProvider -- finished createCollection .system, currentVersion=13
[junit4] 2> 1045662 DEBUG (ScheduledTrigger-3121-thread-3) [ ] o.a.s.c.a.NodeAddedTrigger NodeAddedTrigger node_added_trigger - removing marker path: /autoscaling/nodeAdded/127.0.0.1:10001_solr
[junit4] 2> 1045663 DEBUG (AutoscalingActionExecutor-3122-thread-1) [ ] o.a.s.c.a.ScheduledTriggers -- processing actions for {
[junit4] 2> "id":"15140c63701656T4dmzkn7wursdpjgxkl6ghyfii",
[junit4] 2> "source":"node_added_trigger",
[junit4] 2> "eventTime":5933017951376982,
[junit4] 2> "eventType":"NODEADDED",
[junit4] 2> "properties":{
[junit4] 2> "eventTimes":[5933017951376982],
[junit4] 2> "preferredOperation":"movereplica",
[junit4] 2> "_enqueue_time_":5933018998877482,
[junit4] 2> "nodeNames":["127.0.0.1:10001_solr"]}}
[junit4] 2> 1045663 DEBUG (AutoscalingActionExecutor-3122-thread-1) [ ] o.a.s.c.a.ComputePlanAction -- processing event: {
[junit4] 2> "id":"15140c63701656T4dmzkn7wursdpjgxkl6ghyfii",
[junit4] 2> "source":"node_added_trigger",
[junit4] 2> "eventTime":5933017951376982,
[junit4] 2> "eventType":"NODEADDED",
[junit4] 2> "properties":{
[junit4] 2> "eventTimes":[5933017951376982],
[junit4] 2> "preferredOperation":"movereplica",
[junit4] 2> "_enqueue_time_":5933018998877482,
[junit4] 2> "nodeNames":["127.0.0.1:10001_solr"]}} with context properties: {BEFORE_ACTION=[compute_plan]}
[junit4] 2> 1045663 DEBUG (AutoscalingActionExecutor-3122-thread-1) [ ] o.a.s.c.s.c.a.PolicyHelper Creating a new session
[junit4] 2> 1045670 DEBUG (AutoscalingActionExecutor-3122-thread-1) [ ] o.a.s.c.s.c.a.PolicyHelper New session created
[junit4] 2> 1045671 DEBUG (AutoscalingActionExecutor-3122-thread-1) [ ] o.a.s.c.a.ComputePlanAction Computed Plan: action=MOVEREPLICA&collection=testNodeAdded&targetNode=127.0.0.1:10001_solr&inPlaceMove=true&replica=core_node1
[junit4] 2> 1045676 DEBUG (AutoscalingActionExecutor-3122-thread-1) [ ] o.a.s.c.s.c.a.PolicyHelper returnSession, curr-time 5933024671 sessionWrapper.createTime 5933024364953882, this.sessionWrapper.createTime 5933024364953882
[junit4] 2> 1045676 DEBUG (AutoscalingActionExecutor-3122-thread-1) [ ] o.a.s.c.s.c.a.PolicyHelper session set to NULL
[junit4] 2> 1045683 INFO (TEST-TestSimComputePlanAction.testNodeAdded-seed#[A173528524A1CB0E]) [ ] o.a.s.c.a.s.TestSimComputePlanAction Node values: {
[junit4] 2> "127.0.0.1:10001_solr":{
[junit4] 2> "sysprop.java.vendor":"Oracle Corporation",
[junit4] 2> "cores":2,
[junit4] 2> "host":"127.0.0.1",
[junit4] 2> "freedisk":1022,
[junit4] 2> "sysprop.java.version":"1.8.0_172",
[junit4] 2> "ip_1":"127",
[junit4] 2> "ip_3":"0",
[junit4] 2> "ip_2":"0",
[junit4] 2> "ip_4":"1",
[junit4] 2> "node":"127.0.0.1:10001_solr",
[junit4] 2> "metrics:solr.jvm:buffers.direct.Count":0,
[junit4] 2> "port":10001,
[junit4] 2> "heapUsage":123450000,
[junit4] 2> "sysLoadAvg":1.0,
[junit4] 2> "metrics:solr.node:ADMIN./admin/authorization.clientErrors:count":0,
[junit4] 2> "totaldisk":10240},
[junit4] 2> "127.0.0.1:10000_solr":{
[junit4] 2> "sysprop.java.vendor":"Oracle Corporation",
[junit4] 2> "cores":4,
[junit4] 2> "host":"127.0.0.1",
[junit4] 2> "freedisk":1020,
[junit4] 2> "sysprop.java.version":"1.8.0_172",
[junit4] 2> "ip_1":"127",
[junit4] 2> "ip_3":"0",
[junit4] 2> "ip_2":"0",
[junit4] 2> "ip_4":"1",
[junit4] 2> "node":"127.0.0.1:10000_solr",
[junit4] 2> "metrics:solr.jvm:buffers.direct.Count":0,
[junit4] 2> "port":10000,
[junit4] 2> "heapUsage":123450000,
[junit4] 2> "sysLoadAvg":1.0,
[junit4] 2> "metrics:solr.node:ADMIN./admin/authorization.clientErrors:count":0,
[junit4] 2> "totaldisk":10240}}
[junit4] 2> 1045684 INFO (TEST-TestSimComputePlanAction.testNodeAdded-seed#[A173528524A1CB0E]) [ ] o.a.s.c.a.s.TestSimComputePlanAction Live nodes: [127.0.0.1:10001_solr, 127.0.0.1:10000_solr], collection state: DocCollection(testNodeAdded//clusterstate.json/12)={
[junit4] 2> "replicationFactor":"1",
[junit4] 2> "pullReplicas":"0",
[junit4] 2> "router":{"name":"compositeId"},
[junit4] 2> "maxShardsPerNode":"1",
[junit4] 2> "autoAddReplicas":"false",
[junit4] 2> "nrtReplicas":"4",
[junit4] 2> "tlogReplicas":"0",
[junit4] 2> "autoCreated":"true",
[junit4] 2> "shards":{"shard1":{
[junit4] 2> "replicas":{
[junit4] 2> "core_node1":{
[junit4] 2> "core":"testNodeAdded_shard1_replica_n1",
[junit4] 2> "leader":"true",
[junit4] 2> "SEARCHER.searcher.maxDoc":0,
[junit4] 2> "SEARCHER.searcher.deletedDocs":0,
[junit4] 2> "INDEX.sizeInBytes":10240,
[junit4] 2> "node_name":"127.0.0.1:10000_solr",
[junit4] 2> "state":"active",
[junit4] 2> "type":"NRT",
[junit4] 2> "INDEX.sizeInGB":9.5367431640625E-6,
[junit4] 2> "SEARCHER.searcher.numDocs":0},
[junit4] 2> "core_node2":{
[junit4] 2> "core":"testNodeAdded_shard1_replica_n2",
[junit4] 2> "SEARCHER.searcher.maxDoc":0,
[junit4] 2> "SEARCHER.searcher.deletedDocs":0,
[junit4] 2> "INDEX.sizeInBytes":10240,
[junit4] 2> "node_name":"127.0.0.1:10000_solr",
[junit4] 2> "state":"active",
[junit4] 2> "type":"NRT",
[junit4] 2> "INDEX.sizeInGB":9.5367431640625E-6,
[junit4] 2> "SEARCHER.searcher.numDocs":0},
[junit4] 2> "core_node3":{
[junit4] 2> "core":"testNodeAdded_shard1_replica_n3",
[junit4] 2> "SEARCHER.searcher.maxDoc":0,
[junit4] 2> "SEARCHER.searcher.deletedDocs":0,
[junit4] 2> "INDEX.sizeInBytes":10240,
[junit4] 2> "node_name":"127.0.0.1:10000_solr",
[junit4] 2> "state":"active",
[junit4] 2> "type":"NRT",
[junit4] 2> "INDEX.sizeInGB":9.5367431640625E-6,
[junit4] 2> "SEARCHER.searcher.numDocs":0},
[junit4] 2> "core_node4":{
[junit4] 2> "core":"testNodeAdded_shard1_replica_n4",
[junit4] 2> "SEARCHER.searcher.maxDoc":0,
[junit4] 2> "SEARCHER.searcher.deletedDocs":0,
[junit4] 2> "INDEX.sizeInBytes":10240,
[junit4] 2> "node_name":"127.0.0.1:10000_solr",
[junit4] 2> "state":"active",
[junit4] 2> "type":"NRT",
[junit4] 2> "INDEX.sizeInGB":9.5367431640625E-6,
[junit4] 2> "SEARCHER.searcher.numDocs":0}},
[junit4] 2> "range":"80000000-7fffffff",
[junit4] 2> "state":"active"}}}
[junit4] 2> 1045684 INFO (TEST-TestSimComputePlanAction.testNodeAdded-seed#[A173528524A1CB0E]) [ ] o.a.s.c.a.s.TestSimComputePlanAction -------------_ FINAL STATE --------------
[junit4] 2> 1045684 INFO (TEST-TestSimComputePlanAction.testNodeAdded-seed#[A173528524A1CB0E]) [ ] o.a.s.c.a.s.TestSimComputePlanAction * Node values: {
[junit4] 2> "127.0.0.1:10001_solr":{
[junit4] 2> "sysprop.java.vendor":"Oracle Corporation",
[junit4] 2> "cores":2,
[junit4] 2> "host":"127.0.0.1",
[junit4] 2> "freedisk":1022,
[junit4] 2> "sysprop.java.version":"1.8.0_172",
[junit4] 2> "ip_1":"127",
[junit4] 2> "ip_3":"0",
[junit4] 2> "ip_2":"0",
[junit4] 2> "ip_4":"1",
[junit4] 2> "node":"127.0.0.1:10001_solr",
[junit4] 2> "metrics:solr.jvm:buffers.direct.Count":0,
[junit4] 2> "port":10001,
[junit4] 2> "heapUsage":123450000,
[junit4] 2> "sysLoadAvg":1.0,
[junit4] 2> "metrics:solr.node:ADMIN./admin/authorization.clientErrors:count":0,
[junit4] 2> "totaldisk":10240},
[junit4] 2> "127.0.0.1:10000_solr":{
[junit4] 2> "sysprop.java.vendor":"Oracle Corporation",
[junit4] 2> "cores":4,
[junit4] 2> "host":"127.0.0.1",
[junit4] 2> "freedisk":1020,
[junit4] 2> "sysprop.java.version":"1.8.0_172",
[junit4] 2> "ip_1":"127",
[junit4] 2> "ip_3":"0",
[junit4] 2> "ip_2":"0",
[junit4] 2> "ip_4":"1",
[junit4] 2> "node":"127.0.0.1:10000_solr",
[junit4] 2> "metrics:solr.jvm:buffers.direct.Count":0,
[junit4] 2> "port":10000,
[junit4] 2> "heapUsage":123450000,
[junit4] 2> "sysLoadAvg":1.0,
[junit4] 2> "metrics:solr.node:ADMIN./admin/authorization.clientErrors:count":0,
[junit4] 2> "totaldisk":10240}}
[junit4] 2> 1045684 INFO (TEST-TestSimComputePlanAction.testNodeAdded-seed#[A173528524A1CB0E]) [ ] o.a.s.c.a.s.TestSimComputePlanAction * Live nodes: [127.0.0.1:10001_solr, 127.0.0.1:10000_solr]
[junit4] 2> 1045684 INFO (TEST-TestSimComputePlanAction.testNodeAdded-seed#[A173528524A1CB0E]) [ ] o.a.s.c.a.s.TestSimComputePlanAction * Collection .system state: DocCollection(.system//clusterstate.json/12)={
[junit4] 2> "replicationFactor":"2",
[junit4] 2> "pullReplicas":"0",
[junit4] 2> "router":{"name":"compositeId"},
[junit4] 2> "maxShardsPerNode":"1",
[junit4] 2> "autoAddReplicas":"false",
[junit4] 2> "nrtReplicas":"1",
[junit4] 2> "tlogReplicas":"0",
[junit4] 2> "autoCreated":"true",
[junit4] 2> "shards":{"shard1":{
[junit4] 2> "replicas":{
[junit4] 2> "core_node1":{
[junit4] 2> "core":".system_shard1_replica_n1",
[junit4] 2> "leader":"true",
[junit4] 2> "SEARCHER.searcher.maxDoc":2,
[junit4] 2> "SEARCHER.searcher.deletedDocs":0,
[junit4] 2> "INDEX.sizeInBytes":11240,
[junit4] 2> "node_name":"127.0.0.1:10001_solr",
[junit4] 2> "state":"active",
[junit4] 2> "type":"NRT",
[junit4] 2> "INDEX.sizeInGB":1.0468065738677979E-5,
[junit4] 2> "SEARCHER.searcher.numDocs":2},
[junit4] 2> "core_node2":{
[junit4] 2> "core":".system_shard1_replica_n2",
[junit4] 2> "SEARCHER.searcher.maxDoc":2,
[junit4] 2> "SEARCHER.searcher.deletedDocs":0,
[junit4] 2> "INDEX.sizeInBytes":11240,
[junit4] 2> "node_name":"127.0.0.1:10001_solr",
[junit4] 2> "state":"active",
[junit4] 2> "type":"NRT",
[junit4] 2> "INDEX.sizeInGB":1.0468065738677979E-5,
[junit4] 2> "SEARCHER.searcher.numDocs":2}},
[junit4] 2> "range":"80000000-7fffffff",
[junit4] 2> "state":"active"}}}
[junit4] 2> 1045684 INFO (TEST-TestSimComputePlanAction.testNodeAdded-seed#[A173528524A1CB0E]) [ ] o.a.s.c.a.s.TestSimComputePlanAction * Collection testNodeAdded state: DocCollection(testNodeAdded//clusterstate.json/12)={
[junit4] 2> "replicationFactor":"1",
[junit4] 2> "pullReplicas":"0",
[junit4] 2> "router":{"name":"compositeId"},
[junit4] 2> "maxShardsPerNode":"1",
[junit4] 2> "autoAddReplicas":"false",
[junit4] 2> "nrtReplicas":"4",
[junit4] 2> "tlogReplicas":"0",
[junit4] 2> "autoCreated":"true",
[junit4] 2> "shards":{"shard1":{
[junit4] 2> "replicas":{
[junit4] 2> "core_node1":{
[junit4] 2> "core":"testNodeAdded_shard1_replica_n1",
[junit4] 2> "leader":"true",
[junit4] 2> "SEARCHER.searcher.maxDoc":0,
[junit4] 2> "SEARCHER.searcher.deletedDocs":0,
[junit4] 2> "INDEX.sizeInBytes":10240,
[junit4] 2> "node_name":"127.0.0.1:10000_solr",
[junit4] 2> "state":"active",
[junit4] 2> "type":"NRT",
[junit4] 2> "INDEX.sizeInGB":9.5367431640625E-6,
[junit4] 2> "SEARCHER.searcher.numDocs":0},
[junit4] 2> "core_node2":{
[junit4] 2> "core":"testNodeAdded_shard1_replica_n2",
[junit4] 2> "SEARCHER.searcher.maxDoc":0,
[junit4] 2> "SEARCHER.searcher.deletedDocs":0,
[junit4] 2> "INDEX.sizeInBytes":10240,
[junit4] 2> "node_name":"127.0.0.1:10000_solr",
[junit4] 2> "state":"active",
[junit4] 2> "type":"NRT",
[junit4] 2> "INDEX.sizeInGB":9.5367431640625E-6,
[junit4] 2> "SEARCHER.searcher.numDocs":0},
[junit4] 2> "core_node3":{
[junit4] 2> "core":"testNodeAdded_shard1_replica_n3",
[junit4] 2> "SEARCHER.searcher.maxDoc":0,
[junit4] 2> "SEARCHER.searcher.deletedDocs":0,
[junit4] 2> "INDEX.sizeInBytes":10240,
[junit4] 2> "node_name":"127.0.0.1:10000_solr",
[junit4] 2> "state":"active",
[junit4] 2> "type":"NRT",
[junit4] 2> "INDEX.sizeInGB":9.5367431640625E-6,
[junit4] 2> "SEARCHER.searcher.numDocs":0},
[junit4] 2> "core_node4":{
[junit4] 2> "core":"testNodeAdded_shard1_replica_n4",
[junit4] 2> "SEARCHER.searcher.maxDoc":0,
[junit4] 2> "SEARCHER.searcher.deletedDocs":0,
[junit4] 2> "INDEX.sizeInBytes":10240,
[junit4] 2> "node_name":"127.0.0.1:10000_solr",
[junit4] 2> "state":"active",
[junit4] 2> "type":"NRT",
[junit4] 2> "INDEX.sizeInGB":9.5367431640625E-6,
[junit4] 2> "SEARCHER.searcher.numDocs":0}},
[junit4] 2> "range":"80000000-7fffffff",
[junit4] 2> "state":"active"}}}
[junit4] 2> 1045686 DEBUG (TEST-TestSimComputePlanAction.testNodeAdded-seed#[A173528524A1CB0E]) [ ] o.a.s.c.a.s.SimClusterStateProvider ** creating new collection states, currentVersion=13
[junit4] 2> 1045687 DEBUG (TEST-TestSimComputePlanAction.testNodeAdded-seed#[A173528524A1CB0E]) [ ] o.a.s.c.a.s.SimClusterStateProvider ** saved cluster state version 13
[junit4] 2> 1045919 INFO (TEST-TestSimComputePlanAction.testNodeAdded-seed#[A173528524A1CB0E]) [ ] o.a.s.c.a.s.SimSolrCloudTestCase #######################################
[junit4] 2> ############ CLUSTER STATE ############
[junit4] 2> #######################################
[junit4] 2> ## Live nodes: 2
[junit4] 2> ## Empty nodes: 0
[junit4] 2> ## Dead nodes: 0
[junit4] 2> ## Collections:
[junit4] 2> ## * .system
[junit4] 2> ## shardsTotal 1
[junit4] 2> ## shardsState {active=1}
[junit4] 2> ## shardsWithoutLeader 0
[junit4] 2> ## totalReplicas 2
[junit4] 2> ## activeReplicas 2
[junit4] 2> ## inactiveReplicas 0
[junit4] 2> ## totalActiveDocs 2
[junit4] 2> ## bufferedDocs 0
[junit4] 2> ## maxActiveSliceDocs 2
[junit4] 2> ## minActiveSliceDocs 2
[junit4] 2> ## avgActiveSliceDocs 2
[junit4] 2> ## totalInactiveDocs 0
[junit4] 2> ## maxInactiveSliceDocs 0
[junit4] 2> ## minInactiveSliceDocs 0
[junit4] 2> ## avgInactiveSliceDocs NaN
[junit4] 2> ## totalActiveBytes 11,240
[junit4] 2> ## maxActiveSliceBytes 11,240
[junit4] 2> ## minActiveSliceBytes 11,240
[junit4] 2> ## avgActiveSliceBytes 11,240
[junit4] 2> ## totalInactiveBytes 0
[junit4] 2> ## maxInactiveSliceBytes 0
[junit4] 2> ## minInactiveSliceBytes 0
[junit4] 2> ## avgInactiveSliceBytes NaN
[junit4] 2> ## totalActiveDeletedDocs 0
[junit4] 2> ## * testNodeAdded
[junit4] 2> ## shardsTotal 1
[junit4] 2> ## shardsState {active=1}
[junit4] 2> ## shardsWithoutLeader 0
[junit4] 2> ## totalReplicas 4
[junit4] 2> ## activeReplicas 4
[junit4] 2> ## inactiveReplicas 0
[junit4] 2> ## totalActiveDocs 0
[junit4] 2> ## bufferedDocs 0
[junit4] 2> ## maxActiveSliceDocs 0
[junit4] 2> ## minActiveSliceDocs 0
[junit4] 2> ## avgActiveSliceDocs 0
[junit4] 2> ## totalInactiveDocs 0
[junit4] 2> ## maxInactiveSliceDocs 0
[junit4] 2> ## minInactiveSliceDocs 0
[junit4] 2> ## avgInactiveSliceDocs NaN
[junit4] 2> ## totalActiveBytes 10,240
[junit4] 2> ## maxActiveSliceBytes 10,240
[junit4] 2> ## minActiveSliceBytes 10,240
[junit4] 2> ## avgActiveSliceBytes 10,240
[junit4] 2> ## totalInactiveBytes 0
[junit4] 2> ## maxInactiveSliceBytes 0
[junit4] 2> ## minInactiveSliceBytes 0
[junit4] 2> ## avgInactiveSliceBytes NaN
[junit4] 2> ## totalActiveDeletedDocs 0
[junit4] 2> ## Max replicas per node: 4
[junit4] 2> ## Min replicas per node: 2
[junit4] 2> ## Total replicas: 6
[junit4] 2> ## * .system 2
[junit4] 2> ## - active 2
[junit4] 2> ## * testNodeAdded 4
[junit4] 2> ## - active 4
[junit4] 2> ######### Solr op counts ##########
[junit4] 2> ## - CREATE 1
[junit4] 2> ## - autoscaling 5
[junit4] 2> ## - update 3
[junit4] 2> ######### Autoscaling event counts ###########
[junit4] 2> ## * Trigger: node_added_trigger
[junit4] 2> ## - STARTED 1
[junit4] 2> ## - AFTER_ACTION 1
[junit4] 2> ## - BEFORE_ACTION 1
[junit4] 2>
[junit4] 2> 1045930 DEBUG (AutoscalingActionExecutor-3122-thread-1) [ ] o.a.s.c.a.ScheduledTriggers Resuming trigger: .auto_add_replicas after 100ms
[junit4] 2> 1045930 DEBUG (AutoscalingActionExecutor-3122-thread-1) [ ] o.a.s.c.a.ScheduledTriggers Resuming trigger: .scheduled_maintenance after 100ms
[junit4] 2> 1045930 DEBUG (AutoscalingActionExecutor-3122-thread-1) [ ] o.a.s.c.a.ScheduledTriggers Resuming trigger: node_added_trigger after 100ms
[junit4] 2> 1045930 DEBUG (AutoscalingActionExecutor-3122-thread-1) [ ] o.a.s.c.a.ScheduledTriggers -- processing took 13371 ms for event id=15140c63701656T4dmzkn7wursdpjgxkl6ghyfii
[junit4] 2> 1045935 DEBUG (TEST-TestSimComputePlanAction.testNodeLost-seed#[A173528524A1CB0E]) [ ] o.a.s.c.a.OverseerTriggerThread Refreshing /autoscaling.json with znode version 8
[junit4] 2> 1045935 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Processed trigger updates upto znodeVersion 8
[junit4] 2> 1045936 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread -- clean old nodeLost markers
[junit4] 2> 1045936 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread -- clean old nodeAdded markers
[junit4] 2> 1045936 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Current znodeVersion 8, lastZnodeVersion 8
[junit4] 2> 1045936 DEBUG (TEST-TestSimComputePlanAction.testNodeLost-seed#[A173528524A1CB0E]) [ ] o.a.s.c.a.s.SimClusterStateProvider ** creating new collection states, currentVersion=14
[junit4] 2> 1045937 DEBUG (TEST-TestSimComputePlanAction.testNodeLost-seed#[A173528524A1CB0E]) [ ] o.a.s.c.a.s.SimClusterStateProvider ** saved cluster state version 14
[junit4] 2> 1045949 DEBUG (TEST-TestSimComputePlanAction.testNodeLost-seed#[A173528524A1CB0E]) [ ] o.a.s.c.a.s.SimNodeStateProvider --removing value for 127.0.0.1:10001_solr
[junit4] 2> 1045950 INFO (TEST-TestSimComputePlanAction.testNodeLost-seed#[A173528524A1CB0E]) [ ] o.a.s.c.a.s.SimCloudManager === Restarting OverseerTriggerThread and clearing object cache...
[junit4] 2> 1045950 DEBUG (TEST-TestSimComputePlanAction.testNodeLost-seed#[A173528524A1CB0E]) [ ] o.a.s.c.a.ScheduledTriggers Shutting down scheduled thread pool executor now
[junit4] 2> 1045950 DEBUG (TEST-TestSimComputePlanAction.testNodeLost-seed#[A173528524A1CB0E]) [ ] o.a.s.c.a.ScheduledTriggers Shutting down action executor now
[junit4] 2> 1045950 DEBUG (TEST-TestSimComputePlanAction.testNodeLost-seed#[A173528524A1CB0E]) [ ] o.a.s.c.a.ScheduledTriggers Awaiting termination for action executor
[junit4] 2> 1045950 WARN (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread OverseerTriggerThread woken up but we are closed, exiting.
[junit4] 2> 1045950 DEBUG (TEST-TestSimComputePlanAction.testNodeLost-seed#[A173528524A1CB0E]) [ ] o.a.s.c.a.ScheduledTriggers Awaiting termination for scheduled thread pool executor
[junit4] 2> 1045950 DEBUG (TEST-TestSimComputePlanAction.testNodeLost-seed#[A173528524A1CB0E]) [ ] o.a.s.c.a.ScheduledTriggers ScheduledTriggers closed completely
[junit4] 2> 1045950 DEBUG (TEST-TestSimComputePlanAction.testNodeLost-seed#[A173528524A1CB0E]) [ ] o.a.s.c.a.OverseerTriggerThread OverseerTriggerThread has been closed explicitly
[junit4] 2> 1045969 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Adding .auto_add_replicas and .scheduled_maintenance triggers
[junit4] 2> 1045969 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Refreshing /autoscaling.json with znode version 9
[junit4] 2> 1045970 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Current znodeVersion 9, lastZnodeVersion -1
[junit4] 2> 1045970 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Processed trigger updates upto znodeVersion 9
[junit4] 2> 1045978 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.NodeLostTrigger NodeLostTrigger .auto_add_replicas - Initial livenodes: [127.0.0.1:10000_solr]
[junit4] 2> 1045985 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread -- clean old nodeAdded markers
[junit4] 2> 1045985 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Current znodeVersion 9, lastZnodeVersion 9
[junit4] 2> 1045986 DEBUG (ScheduledTrigger-3124-thread-2) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 1
[junit4] 2> 1046009 DEBUG (ScheduledTrigger-3124-thread-2) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 1
[junit4] 2> 1046030 DEBUG (ScheduledTrigger-3124-thread-1) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 1
[junit4] 2> 1046053 DEBUG (ScheduledTrigger-3124-thread-4) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 1
[junit4] 2> 1046074 DEBUG (ScheduledTrigger-3124-thread-3) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 1
[junit4] 2> 1046094 DEBUG (ScheduledTrigger-3124-thread-3) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 1
[junit4] 2> 1046114 DEBUG (ScheduledTrigger-3124-thread-3) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 1
[junit4] 2> 1046132 DEBUG (MetricsHistoryHandler-3119-thread-1) [ ] o.a.s.c.a.s.SimClusterStateProvider ** creating new collection states, currentVersion=15
[junit4] 2> 1046132 DEBUG (MetricsHistoryHandler-3119-thread-1) [ ] o.a.s.c.a.s.SimClusterStateProvider ** saved cluster state version 15
[junit4] 2> 1046135 DEBUG (ScheduledTrigger-3124-thread-3) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 1
[junit4] 2> 1046155 DEBUG (ScheduledTrigger-3124-thread-3) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 1
[junit4] 2> 1046163 DEBUG (simCloudManagerPool-3123-thread-1) [ ] o.a.s.c.a.AutoScalingHandler Verified autoscaling configuration
[junit4] 2> 1046164 DEBUG (simCloudManagerPool-3123-thread-1) [ ] o.a.s.c.a.OverseerTriggerThread Refreshing /autoscaling.json with znode version 10
[junit4] 2> 1046165 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Processed trigger updates upto znodeVersion 10
[junit4] 2> 1046165 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread -- clean old nodeAdded markers
[junit4] 2> 1046165 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Current znodeVersion 10, lastZnodeVersion 10
[junit4] 2> 1046176 DEBUG (ScheduledTrigger-3124-thread-3) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 1
[junit4] 2> 1046193 DEBUG (simCloudManagerPool-3123-thread-2) [ ] o.a.s.c.a.AutoScalingHandler Verified autoscaling configuration
[junit4] 2> 1046193 DEBUG (simCloudManagerPool-3123-thread-2) [ ] o.a.s.c.a.OverseerTriggerThread Refreshing /autoscaling.json with znode version 11
[junit4] 2> 1046194 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Processed trigger updates upto znodeVersion 11
[junit4] 2> 1046194 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread -- clean old nodeAdded markers
[junit4] 2> 1046194 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Current znodeVersion 11, lastZnodeVersion 11
[junit4] 2> 1046196 DEBUG (ScheduledTrigger-3124-thread-3) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 1
[junit4] 2> 1046216 DEBUG (ScheduledTrigger-3124-thread-3) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 1
[junit4] 2> 1046238 DEBUG (ScheduledTrigger-3124-thread-3) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 1
[junit4] 2> 1046258 DEBUG (ScheduledTrigger-3124-thread-3) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 1
[junit4] 2> 1046278 DEBUG (ScheduledTrigger-3124-thread-3) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 1
[junit4] 2> 1046299 DEBUG (ScheduledTrigger-3124-thread-3) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 2
[junit4] 2> 1046302 DEBUG (simCloudManagerPool-3123-thread-3) [ ] o.a.s.c.a.AutoScalingHandler Verified autoscaling configuration
[junit4] 2> 1046303 DEBUG (simCloudManagerPool-3123-thread-3) [ ] o.a.s.c.a.OverseerTriggerThread Refreshing /autoscaling.json with znode version 12
[junit4] 2> 1046306 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Processed trigger updates upto znodeVersion 12
[junit4] 2> 1046306 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.NodeLostTrigger NodeLostTrigger node_lost_trigger - Initial livenodes: [127.0.0.1:10000_solr, 127.0.0.1:10002_solr]
[junit4] 2> 1046306 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread -- clean old nodeAdded markers
[junit4] 2> 1046306 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Current znodeVersion 12, lastZnodeVersion 12
[junit4] 2> 1046306 DEBUG (ScheduledTrigger-3124-thread-1) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: node_lost_trigger with currently live nodes: 2
[junit4] 2> 1046319 DEBUG (ScheduledTrigger-3124-thread-4) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 2
[junit4] 2> 1046327 DEBUG (ScheduledTrigger-3124-thread-4) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: node_lost_trigger with currently live nodes: 2
[junit4] 2> 1046337 DEBUG (simCloudManagerPool-3123-thread-4) [ ] o.a.s.c.a.s.SimClusterStateProvider -- simCreateCollection testNodeLost, currentVersion=16
[junit4] 2> 1046337 DEBUG (simCloudManagerPool-3123-thread-4) [ ] o.a.s.c.a.s.SimClusterStateProvider ** creating new collection states, currentVersion=16
[junit4] 2> 1046337 DEBUG (simCloudManagerPool-3123-thread-4) [ ] o.a.s.c.a.s.SimClusterStateProvider ** saved cluster state version 16
[junit4] 2> 1046338 DEBUG (simCloudManagerPool-3123-thread-4) [ ] o.a.s.c.o.ClusterStateMutator building a new cName: testNodeLost
[junit4] 2> 1046339 DEBUG (ScheduledTrigger-3124-thread-3) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 2
[junit4] 2> 1046347 DEBUG (ScheduledTrigger-3124-thread-3) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: node_lost_trigger with currently live nodes: 2
[junit4] 2> 1046348 DEBUG (simCloudManagerPool-3123-thread-4) [ ] o.a.s.c.a.s.SimClusterStateProvider ** creating new collection states, currentVersion=17
[junit4] 2> 1046348 DEBUG (simCloudManagerPool-3123-thread-4) [ ] o.a.s.c.a.s.SimClusterStateProvider ** saved cluster state version 17
[junit4] 2> 1046349 DEBUG (simCloudManagerPool-3123-thread-4) [ ] o.a.s.c.s.c.a.PolicyHelper Creating a new session
[junit4] 2> 1046349 DEBUG (simCloudManagerPool-3123-thread-4) [ ] o.a.s.c.s.c.a.PolicyHelper New session created
[junit4] 2> 1046350 DEBUG (simCloudManagerPool-3123-thread-4) [ ] o.a.s.c.s.c.a.PolicyHelper returnSession, curr-time 5933058348 sessionWrapper.createTime 5933058314336732, this.sessionWrapper.createTime 5933058314336732
[junit4] 2> 1046350 DEBUG (simCloudManagerPool-3123-thread-4) [ ] o.a.s.c.s.c.a.PolicyHelper session set to NULL
[junit4] 2> 1046359 DEBUG (ScheduledTrigger-3124-thread-3) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 2
[junit4] 2> 1046367 DEBUG (ScheduledTrigger-3124-thread-3) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: node_lost_trigger with currently live nodes: 2
[junit4] 2> 1046379 DEBUG (ScheduledTrigger-3124-thread-3) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 2
[junit4] 2> 1046387 DEBUG (ScheduledTrigger-3124-thread-3) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: node_lost_trigger with currently live nodes: 2
[junit4] 2> 1046390 DEBUG (simCloudManagerPool-3123-thread-5) [ ] o.a.s.c.a.s.SimClusterStateProvider ** creating new collection states, currentVersion=18
[junit4] 2> 1046390 DEBUG (simCloudManagerPool-3123-thread-5) [ ] o.a.s.c.a.s.SimClusterStateProvider ** saved cluster state version 18
[junit4] 2> 1046391 DEBUG (simCloudManagerPool-3123-thread-4) [ ] o.a.s.c.a.s.SimClusterStateProvider -- finished createCollection testNodeLost, currentVersion=19
[junit4] 2> 1046400 DEBUG (ScheduledTrigger-3124-thread-3) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 2
[junit4] 2> 1046401 DEBUG (TEST-TestSimComputePlanAction.testNodeLost-seed#[A173528524A1CB0E]) [ ] o.a.s.c.a.s.SimClusterStateProvider ** creating new collection states, currentVersion=19
[junit4] 2> 1046402 DEBUG (TEST-TestSimComputePlanAction.testNodeLost-seed#[A173528524A1CB0E]) [ ] o.a.s.c.a.s.SimClusterStateProvider ** saved cluster state version 19
[junit4] 2> 1046402 DEBUG (simCloudManagerPool-3123-thread-7) [ ] o.a.s.c.a.s.SimClusterStateProvider -- elected new leader for testNodeLost / shard1 (currentVersion=19): {"core_node1":{
[junit4] 2> "core":"testNodeLost_shard1_replica_n1",
[junit4] 2> "shard":"shard1",
[junit4] 2> "collection":"testNodeLost",
[junit4] 2> "node_name":"127.0.0.1:10002_solr",
[junit4] 2> "type":"NRT",
[junit4] 2> "leader":"true",
[junit4] 2> "SEARCHER.searcher.maxDoc":0,
[junit4] 2> "SEARCHER.searcher.deletedDocs":0,
[junit4] 2> "INDEX.sizeInBytes":10240,
[junit4] 2> "state":"active",
[junit4] 2> "INDEX.sizeInGB":9.5367431640625E-6,
[junit4] 2> "SEARCHER.searcher.numDocs":0}}
[junit4] 2> 1046408 DEBUG (ScheduledTrigger-3124-thread-1) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: node_lost_trigger with currently live nodes: 2
[junit4] 2> 1046412 DEBUG (simCloudManagerPool-3123-thread-6) [ ] o.a.s.c.a.s.SimClusterStateProvider ** creating new collection states, currentVersion=20
[junit4] 2> 1046412 DEBUG (simCloudManagerPool-3123-thread-6) [ ] o.a.s.c.a.s.SimClusterStateProvider ** saved cluster state version 20
[junit4] 2> 1046412 DEBUG (TEST-TestSimComputePlanAction.testNodeLost-seed#[A173528524A1CB0E]) [ ] o.a.s.c.a.s.SimClusterStateProvider ** creating new collection states, currentVersion=21
[junit4] 2> 1046413 DEBUG (TEST-TestSimComputePlanAction.testNodeLost-seed#[A173528524A1CB0E]) [ ] o.a.s.c.a.s.SimClusterStateProvider ** saved cluster state version 21
[junit4] 2> 1046413 DEBUG (TEST-TestSimComputePlanAction.testNodeLost-seed#[A173528524A1CB0E]) [ ] o.a.s.c.a.s.TestSimComputePlanAction -- cluster state: znodeVersion: 22
[junit4] 2> live nodes:[127.0.0.1:10000_solr, 127.0.0.1:10002_solr]
[junit4] 2> collections:{testNodeLost=DocCollection(testNodeLost//clusterstate.json/21)={
[junit4] 2> "replicationFactor":"1",
[junit4] 2> "pullReplicas":"0",
[junit4] 2> "router":{"name":"compositeId"},
[junit4] 2> "maxShardsPerNode":"1",
[junit4] 2> "autoAddReplicas":"false",
[junit4] 2> "nrtReplicas":"2",
[junit4] 2> "tlogReplicas":"0",
[junit4] 2> "autoCreated":"true",
[junit4] 2> "shards":{"shard1":{
[junit4] 2> "replicas":{
[junit4] 2> "core_node1":{
[junit4] 2> "core":"testNodeLost_shard1_replica_n1",
[junit4] 2> "leader":"true",
[junit4] 2> "SEARCHER.searcher.maxDoc":0,
[junit4] 2> "SEARCHER.searcher.deletedDocs":0,
[junit4] 2> "INDEX.sizeInBytes":10240,
[junit4] 2> "node_name":"127.0.0.1:10002_solr",
[junit4] 2> "state":"active",
[junit4] 2> "type":"NRT",
[junit4] 2> "INDEX.sizeInGB":9.5367431640625E-6,
[junit4] 2> "SEARCHER.searcher.numDocs":0},
[junit4] 2> "core_node2":{
[junit4] 2> "core":"testNodeLost_shard1_replica_n2",
[junit4] 2> "SEARCHER.searcher.maxDoc":0,
[junit4] 2> "SEARCHER.searcher.deletedDocs":0,
[junit4] 2> "INDEX.sizeInBytes":10240,
[junit4] 2> "node_name":"127.0.0.1:10000_solr",
[junit4] 2> "state":"active",
[junit4] 2> "type":"NRT",
[junit4] 2> "INDEX.sizeInGB":9.5367431640625E-6,
[junit4] 2> "SEARCHER.searcher.numDocs":0}},
[junit4] 2> "range":"80000000-7fffffff",
[junit4] 2> "state":"active"}}}}
[junit4] 2> 1046414 DEBUG (TEST-TestSimComputePlanAction.testNodeLost-seed#[A173528524A1CB0E]) [ ] o.a.s.c.a.s.SimClusterStateProvider ** creating new collection states, currentVersion=22
[junit4] 2> 1046414 DEBUG (TEST-TestSimComputePlanAction.testNodeLost-seed#[A173528524A1CB0E]) [ ] o.a.s.c.a.s.SimClusterStateProvider ** saved cluster state version 22
[junit4] 2> 1046420 DEBUG (ScheduledTrigger-3124-thread-1) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 2
[junit4] 2> 1046420 DEBUG (ScheduledTrigger-3124-thread-1) [ ] o.a.s.c.a.NodeLostTrigger Tracking lost node: 127.0.0.1:10002_solr
[junit4] 2> 1046420 INFO (TEST-TestSimComputePlanAction.testNodeLost-seed#[A173528524A1CB0E]) [ ] o.a.s.c.a.s.TestSimComputePlanAction Stopped_node : 127.0.0.1:10002_solr
[junit4] 2> 1046421 INFO (simCloudManagerPool-3123-thread-8) [ ] o.a.s.c.ActionThrottle Throttling leader attempts - waiting for 4042ms
[junit4] 2> 1046428 DEBUG (ScheduledTrigger-3124-thread-1) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: node_lost_trigger with currently live nodes: 2
[junit4] 2> 1046428 DEBUG (ScheduledTrigger-3124-thread-1) [ ] o.a.s.c.a.NodeLostTrigger Tracking lost node: 127.0.0.1:10002_solr
[junit4] 2> 1046440 DEBUG (ScheduledTrigger-3124-thread-1) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 2
[junit4] 2> 1046448 DEBUG (ScheduledTrigger-3124-thread-1) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: node_lost_trigger with currently live nodes: 2
[junit4] 2> 1046460 DEBUG (ScheduledTrigger-3124-thread-1) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 2
[junit4] 2> 1046469 DEBUG (ScheduledTrigger-3124-thread-1) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: node_lost_trigger with currently live nodes: 2
[junit4] 2> 1046481 DEBUG (ScheduledTrigger-3124-thread-1) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 2
[junit4] 2> 1046489 DEBUG (ScheduledTrigger-3124-thread-1) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: node_lost_trigger with currently live nodes: 2
[junit4] 2> 1046501 DEBUG (ScheduledTrigger-3124-thread-1) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 2
[junit4] 2> 1046502 DEBUG (simCloudManagerPool-3123-thread-8) [ ] o.a.s.c.a.s.SimClusterStateProvider -- elected new leader for testNodeLost / shard1 (currentVersion=23): {"core_node2":{
[junit4] 2> "core":"testNodeLost_shard1_replica_n2",
[junit4] 2> "shard":"shard1",
[junit4] 2> "collection":"testNodeLost",
[junit4] 2> "node_name":"127.0.0.1:10000_solr",
[junit4] 2> "type":"NRT",
[junit4] 2> "leader":"true",
[junit4] 2> "SEARCHER.searcher.maxDoc":0,
[junit4] 2> "SEARCHER.searcher.deletedDocs":0,
[junit4] 2> "INDEX.sizeInBytes":10240,
[junit4] 2> "state":"active",
[junit4] 2> "INDEX.sizeInGB":9.5367431640625E-6,
[junit4] 2> "SEARCHER.searcher.numDocs":0}}
[junit4] 2> 1046510 DEBUG (ScheduledTrigger-3124-thread-1) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: node_lost_trigger with currently live nodes: 2
[junit4] 2> 1046521 DEBUG (ScheduledTrigger-3124-thread-1) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 2
[junit4] 2> 1046530 DEBUG (ScheduledTrigger-3124-thread-1) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: node_lost_trigger with currently live nodes: 2
[junit4] 2> 1046542 DEBUG (ScheduledTrigger-3124-thread-1) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 2
[junit4] 2> 1046550 DEBUG (ScheduledTrigger-3124-thread-1) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: node_lost_trigger with currently live nodes: 2
[junit4] 2> 1046562 DEBUG (ScheduledTrigger-3124-thread-1) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 2
[junit4] 2> 1046571 DEBUG (ScheduledTrigger-3124-thread-1) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: node_lost_trigger with currently live nodes: 2
[junit4] 2> 1046571 DEBUG (ScheduledTrigger-3124-thread-1) [ ] o.a.s.c.a.NodeLostTrigger NodeLostTrigger firing registered processor for lost nodes: [127.0.0.1:10002_solr]
[junit4] 2> 1046571 DEBUG (ScheduledTrigger-3124-thread-1) [ ] o.a.s.c.a.ScheduledTriggers ++++++++ Cooldown inactive - processing event: {
[junit4] 2> "id":"151416b5095aa4T4dmzkn7wursdpjgxkl6ghyfin",
[junit4] 2> "source":"node_lost_trigger",
[junit4] 2> "eventTime":5933062270048932,
[junit4] 2> "eventType":"NODELOST",
[junit4] 2> "properties":{
[junit4] 2> "eventTimes":[5933062270048932],
[junit4] 2> "preferredOperation":"movereplica",
[junit4] 2> "nodeNames":["127.0.0.1:10002_solr"]}}
[junit4] 2> 1046571 DEBUG (ScheduledTrigger-3124-thread-1) [ ] o.a.s.c.a.ScheduledTriggers Pausing all triggers: [.auto_add_replicas, .scheduled_maintenance, node_lost_trigger]
[junit4] 2> 1046582 DEBUG (simCloudManagerPool-3123-thread-9) [ ] o.a.s.c.a.s.SimClusterStateProvider -- simCreateCollection .system, currentVersion=23
[junit4] 2> 1046582 DEBUG (simCloudManagerPool-3123-thread-9) [ ] o.a.s.c.a.s.SimClusterStateProvider ** creating new collection states, currentVersion=23
[junit4] 2> 1046583 DEBUG (simCloudManagerPool-3123-thread-9) [ ] o.a.s.c.a.s.SimClusterStateProvider ** saved cluster state version 23
[junit4] 2> 1046583 DEBUG (simCloudManagerPool-3123-thread-9) [ ] o.a.s.c.o.ClusterStateMutator building a new cName: .system
[junit4] 2> 1046593 DEBUG (simCloudManagerPool-3123-thread-9) [ ] o.a.s.c.a.s.SimClusterStateProvider ** creating new collection states, currentVersion=24
[junit4] 2> 1046593 DEBUG (simCloudManagerPool-3123-thread-9) [ ] o.a.s.c.a.s.SimClusterStateProvider ** saved cluster state version 24
[junit4] 2> 1046594 DEBUG (simCloudManagerPool-3123-thread-9) [ ] o.a.s.c.s.c.a.PolicyHelper Creating a new session
[junit4] 2> 1046596 DEBUG (simCloudManagerPool-3123-thread-9) [ ] o.a.s.c.s.c.a.PolicyHelper New session created
[junit4] 2> 1046597 DEBUG (simCloudManagerPool-3123-thread-9) [ ] o.a.s.c.s.c.a.PolicyHelper returnSession, curr-time 5933070699 sessionWrapper.createTime 5933070651201632, this.sessionWrapper.createTime 5933070651201632
[junit4] 2> 1046597 DEBUG (simCloudManagerPool-3123-thread-9) [ ] o.a.s.c.s.c.a.PolicyHelper session set to NULL
[junit4] 2> 1046617 DEBUG (simCloudManagerPool-3123-thread-10) [ ] o.a.s.c.a.s.SimClusterStateProvider ** creating new collection states, currentVersion=25
[junit4] 2> 1046617 DEBUG (simCloudManagerPool-3123-thread-10) [ ] o.a.s.c.a.s.SimClusterStateProvider ** saved cluster state version 25
[junit4] 2> 1046630 DEBUG (simCloudManagerPool-3123-thread-12) [ ] o.a.s.c.a.s.SimClusterStateProvider -- elected new leader for .system / shard1 (currentVersion=26): {"core_node3":{
[junit4] 2> "core":".system_shard1_replica_n1",
[junit4] 2> "shard":"shard1",
[junit4] 2> "collection":".system",
[junit4] 2> "node_name":"127.0.0.1:10003_solr",
[junit4] 2> "type":"NRT",
[junit4] 2> "leader":"true",
[junit4] 2> "SEARCHER.searcher.maxDoc":0,
[junit4] 2> "SEARCHER.searcher.deletedDocs":0,
[junit4] 2> "INDEX.sizeInBytes":10240,
[junit4] 2> "state":"active",
[junit4] 2> "INDEX.sizeInGB":9.5367431640625E-6,
[junit4] 2> "SEARCHER.searcher.numDocs":0}}
[junit4] 2> 1046639 DEBUG (simCloudManagerPool-3123-thread-11) [ ] o.a.s.c.a.s.SimClusterStateProvider ** creating new collection states, currentVersion=26
[junit4] 2> 1046640 DEBUG (simCloudManagerPool-3123-thread-11) [ ] o.a.s.c.a.s.SimClusterStateProvider ** saved cluster state version 26
[junit4] 2> 1046640 DEBUG (simCloudManagerPool-3123-thread-9) [ ] o.a.s.c.a.s.SimClusterStateProvider -- finished createCollection .system, currentVersion=27
[junit4] 2> 1046644 DEBUG (AutoscalingActionExecutor-3125-thread-1) [ ] o.a.s.c.a.ScheduledTriggers -- processing actions for {
[junit4] 2> "id":"151416b5095aa4T4dmzkn7wursdpjgxkl6ghyfin",
[junit4] 2> "source":"node_lost_trigger",
[junit4] 2> "eventTime":5933062270048932,
[junit4] 2> "eventType":"NODELOST",
[junit4] 2> "properties":{
[junit4] 2> "eventTimes":[5933062270048932],
[junit4] 2> "preferredOperation":"movereplica",
[junit4] 2> "_enqueue_time_":5933069446430182,
[junit4] 2> "nodeNames":["127.0.0.1:10002_solr"]}}
[junit4] 2> 1046644 DEBUG (AutoscalingActionExecutor-3125-thread-1) [ ] o.a.s.c.a.ComputePlanAction -- processing event: {
[junit4] 2> "id":"151416b5095aa4T4dmzkn7wursdpjgxkl6ghyfin",
[junit4] 2> "source":"node_lost_trigger",
[junit4] 2> "eventTime":5933062270048932,
[junit4] 2> "eventType":"NODELOST",
[junit4] 2> "properties":{
[junit4] 2> "eventTimes":[5933062270048932],
[junit4] 2> "preferredOperation":"movereplica",
[junit4] 2> "_enqueue_time_":5933069446430182,
[junit4] 2> "nodeNames":["127.0.0.1:10002_solr"]}} with context properties: {BEFORE_ACTION=[compute_plan]}
[junit4] 2> 1046644 DEBUG (AutoscalingActionExecutor-3125-thread-1) [ ] o.a.s.c.s.c.a.PolicyHelper Creating a new session
[junit4] 2> 1046645 DEBUG (AutoscalingActionExecutor-3125-thread-1) [ ] o.a.s.c.s.c.a.PolicyHelper New session created
[junit4] 2> 1046646 DEBUG (AutoscalingActionExecutor-3125-thread-1) [ ] o.a.s.c.a.ComputePlanAction Computed Plan: action=MOVEREPLICA&collection=testNodeLost&targetNode=127.0.0.1:10003_solr&inPlaceMove=true&replica=core_node1
[junit4] 2> 1046646 DEBUG (AutoscalingActionExecutor-3125-thread-1) [ ] o.a.s.c.s.c.a.PolicyHelper returnSession, curr-time 5933073194 sessionWrapper.createTime 5933073112756732, this.sessionWrapper.createTime 5933073112756732
[junit4] 2> 1046646 DEBUG (AutoscalingActionExecutor-3125-thread-1) [ ] o.a.s.c.s.c.a.PolicyHelper session set to NULL
[junit4] 2> 1046647 DEBUG (TEST-TestSimComputePlanAction.testNodeLost-seed#[A173528524A1CB0E]) [ ] o.a.s.c.a.s.SimClusterStateProvider ** creating new collection states, currentVersion=27
[junit4] 2> 1046648 DEBUG (TEST-TestSimComputePlanAction.testNodeLost-seed#[A173528524A1CB0E]) [ ] o.a.s.c.a.s.SimClusterStateProvider ** saved cluster state version 27
[junit4] 2> 1046657 INFO (TEST-TestSimComputePlanAction.testNodeLost-seed#[A173528524A1CB0E]) [ ] o.a.s.c.a.s.TestSimComputePlanAction -------------_ FINAL STATE --------------
[junit4] 2> 1046657 INFO (TEST-TestSimComputePlanAction.testNodeLost-seed#[A173528524A1CB0E]) [ ] o.a.s.c.a.s.TestSimComputePlanAction * Node values: {
[junit4] 2> "127.0.0.1:10000_solr":{
[junit4] 2> "sysprop.java.vendor":"Oracle Corporation",
[junit4] 2> "cores":2,
[junit4] 2> "host":"127.0.0.1",
[junit4] 2> "freedisk":1022,
[junit4] 2> "sysprop.java.version":"1.8.0_172",
[junit4] 2> "ip_1":"127",
[junit4] 2> "ip_3":"0",
[junit4] 2> "ip_2":"0",
[junit4] 2> "ip_4":"1",
[junit4] 2> "node":"127.0.0.1:10000_solr",
[junit4] 2> "metrics:solr.jvm:buffers.direct.Count":0,
[junit4] 2> "port":10000,
[junit4] 2> "heapUsage":123450000,
[junit4] 2> "sysLoadAvg":1.0,
[junit4] 2> "metrics:solr.node:ADMIN./admin/authorization.clientErrors:count":0,
[junit4] 2> "totaldisk":10240},
[junit4] 2> "127.0.0.1:10002_solr":{
[junit4] 2> "sysprop.java.vendor":"Oracle Corporation",
[junit4] 2> "cores":1,
[junit4] 2> "host":"127.0.0.1",
[junit4] 2> "freedisk":1023,
[junit4] 2> "sysprop.java.version":"1.8.0_172",
[junit4] 2> "ip_1":"127",
[junit4] 2> "ip_3":"0",
[junit4] 2> "ip_2":"0",
[junit4] 2> "ip_4":"1",
[junit4] 2> "node":"127.0.0.1:10002_solr",
[junit4] 2> "metrics:solr.jvm:buffers.direct.Count":0,
[junit4] 2> "port":10002,
[junit4] 2> "heapUsage":123450000,
[junit4] 2> "sysLoadAvg":1.0,
[junit4] 2> "metrics:solr.node:ADMIN./admin/authorization.clientErrors:count":0,
[junit4] 2> "totaldisk":10240},
[junit4] 2> "127.0.0.1:10003_solr":{
[junit4] 2> "sysprop.java.vendor":"Oracle Corporation",
[junit4] 2> "cores":1,
[junit4] 2> "host":"127.0.0.1",
[junit4] 2> "freedisk":1023,
[junit4] 2> "sysprop.java.version":"1.8.0_172",
[junit4] 2> "ip_1":"127",
[junit4] 2> "ip_3":"0",
[junit4] 2> "ip_2":"0",
[junit4] 2> "ip_4":"1",
[junit4] 2> "node":"127.0.0.1:10003_solr",
[junit4] 2> "metrics:solr.jvm:buffers.direct.Count":0,
[junit4] 2> "port":10003,
[junit4] 2> "heapUsage":123450000,
[junit4] 2> "sysLoadAvg":1.0,
[junit4] 2> "metrics:solr.node:ADMIN./admin/authorization.clientErrors:count":0,
[junit4] 2> "totaldisk":10240}}
[junit4] 2> 1046657 INFO (TEST-TestSimComputePlanAction.testNodeLost-seed#[A173528524A1CB0E]) [ ] o.a.s.c.a.s.TestSimComputePlanAction * Live nodes: [127.0.0.1:10000_solr]
[junit4] 2> 1046658 INFO (TEST-TestSimComputePlanAction.testNodeLost-seed#[A173528524A1CB0E]) [ ] o.a.s.c.a.s.TestSimComputePlanAction * Collection .system state: DocCollection(.system//clusterstate.json/27)={
[junit4] 2> "replicationFactor":"2",
[junit4] 2> "pullReplicas":"0",
[junit4] 2> "router":{"name":"compositeId"},
[junit4] 2> "maxShardsPerNode":"1",
[junit4] 2> "autoAddReplicas":"false",
[junit4] 2> "nrtReplicas":"1",
[junit4] 2> "tlogReplicas":"0",
[junit4] 2> "autoCreated":"true",
[junit4] 2> "shards":{"shard1":{
[junit4] 2> "replicas":{
[junit4] 2> "core_node3":{
[junit4] 2> "core":".system_shard1_replica_n1",
[junit4] 2> "SEARCHER.searcher.maxDoc":2,
[junit4] 2> "SEARCHER.searcher.deletedDocs":0,
[junit4] 2> "INDEX.sizeInBytes":11240,
[junit4] 2> "node_name":"127.0.0.1:10003_solr",
[junit4] 2> "state":"down",
[junit4] 2> "type":"NRT",
[junit4] 2> "INDEX.sizeInGB":1.0468065738677979E-5,
[junit4] 2> "SEARCHER.searcher.numDocs":2},
[junit4] 2> "core_node4":{
[junit4] 2> "core":".system_shard1_replica_n2",
[junit4] 2> "SEARCHER.searcher.maxDoc":2,
[junit4] 2> "SEARCHER.searcher.deletedDocs":0,
[junit4] 2> "INDEX.sizeInBytes":11240,
[junit4] 2> "node_name":"127.0.0.1:10000_solr",
[junit4] 2> "state":"active",
[junit4] 2> "type":"NRT",
[junit4] 2> "INDEX.sizeInGB":1.0468065738677979E-5,
[junit4] 2> "SEARCHER.searcher.numDocs":2}},
[junit4] 2> "range":"80000000-7fffffff",
[junit4] 2> "state":"active"}}}
[junit4] 2> 1046658 INFO (TEST-TestSimComputePlanAction.testNodeLost-seed#[A173528524A1CB0E]) [ ] o.a.s.c.a.s.TestSimComputePlanAction * Collection testNodeLost state: DocCollection(testNodeLost//clusterstate.json/27)={
[junit4] 2> "replicationFactor":"1",
[junit4] 2> "pullReplicas":"0",
[junit4] 2> "router":{"name":"compositeId"},
[junit4] 2> "maxShardsPerNode":"1",
[junit4] 2> "autoAddReplicas":"false",
[junit4] 2> "nrtReplicas":"2",
[junit4] 2> "tlogReplicas":"0",
[junit4] 2> "autoCreated":"true",
[junit4] 2> "shards":{"shard1":{
[junit4] 2> "replicas":{
[junit4] 2> "core_node1":{
[junit4] 2> "core":"testNodeLost_shard1_replica_n1",
[junit4] 2> "SEARCHER.searcher.maxDoc":0,
[junit4] 2> "SEARCHER.searcher.deletedDocs":0,
[junit4] 2> "INDEX.sizeInBytes":10240,
[junit4] 2> "node_name":"127.0.0.1:10002_solr",
[junit4] 2> "state":"down",
[junit4] 2> "type":"NRT",
[junit4] 2> "INDEX.sizeInGB":9.5367431640625E-6,
[junit4] 2> "SEARCHER.searcher.numDocs":0},
[junit4] 2> "core_node2":{
[junit4] 2> "core":"testNodeLost_shard1_replica_n2",
[junit4] 2> "leader":"true",
[junit4] 2> "SEARCHER.searcher.maxDoc":0,
[junit4] 2> "SEARCHER.searcher.deletedDocs":0,
[junit4] 2> "INDEX.sizeInBytes":10240,
[junit4] 2> "node_name":"127.0.0.1:10000_solr",
[junit4] 2> "state":"active",
[junit4] 2> "type":"NRT",
[junit4] 2> "INDEX.sizeInGB":9.5367431640625E-6,
[junit4] 2> "SEARCHER.searcher.numDocs":0}},
[junit4] 2> "range":"80000000-7fffffff",
[junit4] 2> "state":"active"}}}
[junit4] 2> 1046658 DEBUG (TEST-TestSimComputePlanAction.testNodeLost-seed#[A173528524A1CB0E]) [ ] o.a.s.c.a.s.SimClusterStateProvider ** creating new collection states, currentVersion=28
[junit4] 2> 1046659 DEBUG (TEST-TestSimComputePlanAction.testNodeLost-seed#[A173528524A1CB0E]) [ ] o.a.s.c.a.s.SimClusterStateProvider ** saved cluster state version 28
[junit4] 2> 1046659 INFO (TEST-TestSimComputePlanAction.testNodeLost-seed#[A173528524A1CB0E]) [ ] o.a.s.c.a.s.SimSolrCloudTestCase #######################################
[junit4] 2> ############ CLUSTER STATE ############
[junit4] 2> #######################################
[junit4] 2> ## Live nodes: 1
[junit4] 2> ## Empty nodes: 0
[junit4] 2> ## Dead nodes: 2
[junit4] 2> ## 127.0.0.1:10002_solr
[junit4] 2> ## 127.0.0.1:10003_solr
[junit4] 2> ## Collections:
[junit4] 2> ## * .system
[junit4] 2> ## shardsTotal 1
[junit4] 2> ## shardsState {active=1}
[junit4] 2> ## shardsWithoutLeader 1
[junit4] 2> ## totalReplicas 2
[junit4] 2> ## activeReplicas 2
[junit4] 2> ## inactiveReplicas 0
[junit4] 2> ## totalActiveDocs 2
[junit4] 2> ## bufferedDocs 0
[junit4] 2> ## maxActiveSliceDocs 2
[junit4] 2> ## minActiveSliceDocs 2
[junit4] 2> ## avgActiveSliceDocs 2
[junit4] 2> ## totalInactiveDocs 0
[junit4] 2> ## maxInactiveSliceDocs 0
[junit4] 2> ## minInactiveSliceDocs 0
[junit4] 2> ## avgInactiveSliceDocs NaN
[junit4] 2> ## totalActiveBytes 11,240
[junit4] 2> ## maxActiveSliceBytes 11,240
[junit4] 2> ## minActiveSliceBytes 11,240
[junit4] 2> ## avgActiveSliceBytes 11,240
[junit4] 2> ## totalInactiveBytes 0
[junit4] 2> ## maxInactiveSliceBytes 0
[junit4] 2> ## minInactiveSliceBytes 0
[junit4] 2> ## avgInactiveSliceBytes NaN
[junit4] 2> ## totalActiveDeletedDocs 0
[junit4] 2> ## * testNodeLost
[junit4] 2> ## shardsTotal 1
[junit4] 2> ## shardsState {active=1}
[junit4] 2> ## shardsWithoutLeader 0
[junit4] 2> ## totalReplicas 2
[junit4] 2> ## activeReplicas 2
[junit4] 2> ## inactiveReplicas 0
[junit4] 2> ## totalActiveDocs 0
[junit4] 2> ## bufferedDocs 0
[junit4] 2> ## maxActiveSliceDocs 0
[junit4] 2> ## minActiveSliceDocs 0
[junit4] 2> ## avgActiveSliceDocs 0
[junit4] 2> ## totalInactiveDocs 0
[junit4] 2> ## maxInactiveSliceDocs 0
[junit4] 2> ## minInactiveSliceDocs 0
[junit4] 2> ## avgInactiveSliceDocs NaN
[junit4] 2> ## totalActiveBytes 10,240
[junit4] 2> ## maxActiveSliceBytes 10,240
[junit4] 2> ## minActiveSliceBytes 10,240
[junit4] 2> ## avgActiveSliceBytes 10,240
[junit4] 2> ## totalInactiveBytes 0
[junit4] 2> ## maxInactiveSliceBytes 0
[junit4] 2> ## minInactiveSliceBytes 0
[junit4] 2> ## avgInactiveSliceBytes NaN
[junit4] 2> ## totalActiveDeletedDocs 0
[junit4] 2> ## Max replicas per node: 2
[junit4] 2> ## Min replicas per node: 2
[junit4] 2> ## Total replicas: 2
[junit4] 2> ## * .system 1
[junit4] 2> ## - active 1
[junit4] 2> ## * testNodeLost 1
[junit4] 2> ## - active 1
[junit4] 2> ######### Solr op counts ##########
[junit4] 2> ## - CREATE 1
[junit4] 2> ## - autoscaling 3
[junit4] 2> ## - update 3
[junit4] 2> ######### Autoscaling event counts ###########
[junit4] 2> ## * Trigger: node_added_trigger
[junit4] 2> ## - STARTED 1
[junit4] 2> ## - SUCCEEDED 1
[junit4] 2> ## - AFTER_ACTION 1
[junit4] 2> ## - BEFORE_ACTION 1
[junit4] 2> ## * Trigger: node_lost_trigger
[junit4] 2> ## - STARTED 1
[junit4] 2> ## - BEFORE_ACTION 1
[junit4] 2>
[junit4] 2> 1046671 DEBUG (simCloudManagerPool-3123-thread-14) [ ] o.a.s.c.a.s.SimClusterStateProvider ** creating new collection states, currentVersion=29
[junit4] 2> 1046672 DEBUG (simCloudManagerPool-3123-thread-14) [ ] o.a.s.c.a.s.SimClusterStateProvider ** saved cluster state version 29
[junit4] 2> 1046672 DEBUG (simCloudManagerPool-3123-thread-14) [ ] o.a.s.c.a.s.SimClusterStateProvider -- no leader in shard1:{
[junit4] 2> "replicas":{
[junit4] 2> "core_node3":{
[junit4] 2> "core":".system_shard1_replica_n1",
[junit4] 2> "SEARCHER.searcher.maxDoc":2,
[junit4] 2> "SEARCHER.searcher.deletedDocs":0,
[junit4] 2> "INDEX.sizeInBytes":11240,
[junit4] 2> "node_name":"127.0.0.1:10003_solr",
[junit4] 2> "state":"down",
[junit4] 2> "type":"NRT",
[junit4] 2> "INDEX.sizeInGB":1.0468065738677979E-5,
[junit4] 2> "SEARCHER.searcher.numDocs":2},
[junit4] 2> "core_node4":{
[junit4] 2> "core":".system_shard1_replica_n2",
[junit4] 2> "SEARCHER.searcher.maxDoc":2,
[junit4] 2> "SEARCHER.searcher.deletedDocs":0,
[junit4] 2> "INDEX.sizeInBytes":11240,
[junit4] 2> "node_name":"127.0.0.1:10000_solr",
[junit4] 2> "state":"active",
[junit4] 2> "type":"NRT",
[junit4] 2> "INDEX.sizeInGB":1.0468065738677979E-5,
[junit4] 2> "SEARCHER.searcher.numDocs":2}},
[junit4] 2> "range":"80000000-7fffffff",
[junit4] 2> "state":"active"}
[junit4] 2> 1046672 INFO (simCloudManagerPool-3123-thread-15) [ ] o.a.s.c.ActionThrottle Throttling leader attempts - waiting for 2885ms
[junit4] 2> 1046694 DEBUG (TEST-TestSimComputePlanAction.testNodeWithMultipleReplicasLost-seed#[A173528524A1CB0E]) [ ] o.a.s.c.a.OverseerTriggerThread Refreshing /autoscaling.json with znode version 13
[junit4] 2> 1046694 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Processed trigger updates upto znodeVersion 13
[junit4] 2> 1046694 DEBUG (TEST-TestSimComputePlanAction.testNodeWithMultipleReplicasLost-seed#[A173528524A1CB0E]) [ ] o.a.s.c.a.s.SimNodeStateProvider - removing dead node values: 127.0.0.1:10002_solr
[junit4] 2> 1046694 DEBUG (TEST-TestSimComputePlanAction.testNodeWithMultipleReplicasLost-seed#[A173528524A1CB0E]) [ ] o.a.s.c.a.s.SimNodeStateProvider - removing dead node values: 127.0.0.1:10003_solr
[junit4] 2> 1046730 DEBUG (simCloudManagerPool-3123-thread-15) [ ] o.a.s.c.a.s.SimClusterStateProvider -- elected new leader for .system / shard1 (currentVersion=30): {"core_node4":{
[junit4] 2> "core":".system_shard1_replica_n2",
[junit4] 2> "shard":"shard1",
[junit4] 2> "collection":".system",
[junit4] 2> "node_name":"127.0.0.1:10000_solr",
[junit4] 2> "type":"NRT",
[junit4] 2> "leader":"true",
[junit4] 2> "SEARCHER.searcher.maxDoc":2,
[junit4] 2> "SEARCHER.searcher.deletedDocs":0,
[junit4] 2> "INDEX.sizeInBytes":11240,
[junit4] 2> "state":"active",
[junit4] 2> "INDEX.sizeInGB":1.0468065738677979E-5,
[junit4] 2> "SEARCHER.searcher.numDocs":2}}
[junit4] 2> 1047335 DEBUG (MetricsHistoryHandler-3119-thread-1) [ ] o.a.s.c.a.s.SimClusterStateProvider ** creating new collection states, currentVersion=30
[junit4] 2> 10 04, 2018 5:11:09 ćć com.carrotsearch.randomizedtesting.ThreadLeakControl$2 evaluate
[junit4] 2> èŠć: Suite execution timed out: org.apache.solr.cloud.autoscaling.sim.TestSimComputePlanAction
[junit4] 2> ==== jstack at approximately timeout time ====
[junit4] 2> "simCloudManagerPool-3123-thread-15" ID=7148 WAITING on java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject@493edfd1
[junit4] 2> at sun.misc.Unsafe.park(Native Method)
[junit4] 2> - waiting on java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject@493edfd1
[junit4] 2> at java.util.concurrent.locks.LockSupport.park(LockSupport.java:175)
[junit4] 2> at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.await(AbstractQueuedSynchronizer.java:2039)
[junit4] 2> at java.util.concurrent.LinkedBlockingQueue.take(LinkedBlockingQueue.java:442)
[junit4] 2> at java.util.concurrent.ThreadPoolExecutor.getTask(ThreadPoolExecutor.java:1074)
[junit4] 2> at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1134)
[junit4] 2> at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
[junit4] 2> at java.lang.Thread.run(Thread.java:748)
[junit4] 2>
[junit4] 2> "simCloudManagerPool-3123-thread-14" ID=7147 WAITING on java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject@493edfd1
[junit4] 2> at sun.misc.Unsafe.park(Native Method)
[junit4] 2> - waiting on java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject@493edfd1
[junit4] 2> at java.util.concurrent.locks.LockSupport.park(LockSupport.java:175)
[junit4] 2> at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.await(AbstractQueuedSynchronizer.java:2039)
[junit4] 2> at java.util.concurrent.LinkedBlockingQueue.take(LinkedBlockingQueue.java:442)
[junit4] 2> at java.util.concurrent.ThreadPoolExecutor.getTask(ThreadPoolExecutor.java:1074)
[junit4] 2> at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1134)
[junit4] 2> at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
[junit4] 2> at java.lang.Thread.run(Thread.java:748)
[junit4] 2>
[junit4] 2> "simCloudManagerPool-3123-thread-13" ID=7146 WAITING on java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject@493edfd1
[junit4] 2> at sun.misc.Unsafe.park(Native Method)
[junit4] 2> - waiting on java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject@493edfd1
[junit4] 2> at java.util.concurrent.locks.Lo
[...truncated too long message...]
ve:
ivy-availability-check:
[loadresource] Do not set property disallowed.ivy.jars.list as its length is 0.
-ivy-fail-disallowed-ivy-version:
ivy-fail:
ivy-configure:
[ivy:configure] :: loading settings :: file = /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-master/checkout/lucene/top-level-ivy-settings.xml
resolve:
ivy-availability-check:
[loadresource] Do not set property disallowed.ivy.jars.list as its length is 0.
-ivy-fail-disallowed-ivy-version:
ivy-fail:
ivy-fail:
ivy-configure:
[ivy:configure] :: loading settings :: file = /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-master/checkout/lucene/top-level-ivy-settings.xml
resolve:
ivy-availability-check:
[loadresource] Do not set property disallowed.ivy.jars.list as its length is 0.
-ivy-fail-disallowed-ivy-version:
ivy-fail:
ivy-configure:
[ivy:configure] :: loading settings :: file = /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-master/checkout/lucene/top-level-ivy-settings.xml
resolve:
ivy-availability-check:
[loadresource] Do not set property disallowed.ivy.jars.list as its length is 0.
-ivy-fail-disallowed-ivy-version:
ivy-fail:
ivy-fail:
ivy-configure:
[ivy:configure] :: loading settings :: file = /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-master/checkout/lucene/top-level-ivy-settings.xml
resolve:
ivy-availability-check:
[loadresource] Do not set property disallowed.ivy.jars.list as its length is 0.
-ivy-fail-disallowed-ivy-version:
ivy-fail:
ivy-fail:
ivy-configure:
[ivy:configure] :: loading settings :: file = /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-master/checkout/lucene/top-level-ivy-settings.xml
resolve:
ivy-availability-check:
[loadresource] Do not set property disallowed.ivy.jars.list as its length is 0.
-ivy-fail-disallowed-ivy-version:
ivy-fail:
ivy-fail:
ivy-configure:
[ivy:configure] :: loading settings :: file = /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-master/checkout/lucene/top-level-ivy-settings.xml
resolve:
ivy-availability-check:
[loadresource] Do not set property disallowed.ivy.jars.list as its length is 0.
-ivy-fail-disallowed-ivy-version:
ivy-fail:
ivy-fail:
ivy-configure:
[ivy:configure] :: loading settings :: file = /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-master/checkout/lucene/top-level-ivy-settings.xml
resolve:
ivy-availability-check:
[loadresource] Do not set property disallowed.ivy.jars.list as its length is 0.
-ivy-fail-disallowed-ivy-version:
ivy-fail:
ivy-fail:
ivy-configure:
[ivy:configure] :: loading settings :: file = /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-master/checkout/lucene/top-level-ivy-settings.xml
resolve:
ivy-availability-check:
[loadresource] Do not set property disallowed.ivy.jars.list as its length is 0.
-ivy-fail-disallowed-ivy-version:
ivy-fail:
ivy-fail:
ivy-configure:
[ivy:configure] :: loading settings :: file = /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-master/checkout/lucene/top-level-ivy-settings.xml
resolve:
ivy-availability-check:
[loadresource] Do not set property disallowed.ivy.jars.list as its length is 0.
-ivy-fail-disallowed-ivy-version:
ivy-fail:
ivy-fail:
ivy-configure:
[ivy:configure] :: loading settings :: file = /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-master/checkout/lucene/top-level-ivy-settings.xml
resolve:
ivy-availability-check:
[loadresource] Do not set property disallowed.ivy.jars.list as its length is 0.
-ivy-fail-disallowed-ivy-version:
ivy-fail:
ivy-fail:
ivy-configure:
[ivy:configure] :: loading settings :: file = /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-master/checkout/lucene/top-level-ivy-settings.xml
resolve:
ivy-availability-check:
[loadresource] Do not set property disallowed.ivy.jars.list as its length is 0.
-ivy-fail-disallowed-ivy-version:
ivy-fail:
ivy-fail:
ivy-configure:
[ivy:configure] :: loading settings :: file = /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-master/checkout/lucene/top-level-ivy-settings.xml
resolve:
ivy-availability-check:
[loadresource] Do not set property disallowed.ivy.jars.list as its length is 0.
-ivy-fail-disallowed-ivy-version:
ivy-fail:
ivy-fail:
ivy-configure:
[ivy:configure] :: loading settings :: file = /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-master/checkout/lucene/top-level-ivy-settings.xml
resolve:
jar-checksums:
[mkdir] Created dir: /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-master/checkout/solr/null153533906
[copy] Copying 238 files to /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-master/checkout/solr/null153533906
[delete] Deleting directory /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-master/checkout/solr/null153533906
check-working-copy:
[ivy:cachepath] :: resolving dependencies :: org.eclipse.jgit#org.eclipse.jgit-caller;working
[ivy:cachepath] confs: [default]
[ivy:cachepath] found org.eclipse.jgit#org.eclipse.jgit;4.6.0.201612231935-r in public
[ivy:cachepath] found com.jcraft#jsch;0.1.53 in public
[ivy:cachepath] found com.googlecode.javaewah#JavaEWAH;1.1.6 in public
[ivy:cachepath] found org.apache.httpcomponents#httpclient;4.3.6 in public
[ivy:cachepath] found org.apache.httpcomponents#httpcore;4.3.3 in public
[ivy:cachepath] found commons-logging#commons-logging;1.1.3 in public
[ivy:cachepath] found commons-codec#commons-codec;1.6 in public
[ivy:cachepath] found org.slf4j#slf4j-api;1.7.2 in public
[ivy:cachepath] :: resolution report :: resolve 48ms :: artifacts dl 9ms
---------------------------------------------------------------------
| | modules || artifacts |
| conf | number| search|dwnlded|evicted|| number|dwnlded|
---------------------------------------------------------------------
| default | 8 | 0 | 0 | 0 || 8 | 0 |
---------------------------------------------------------------------
[wc-checker] Initializing working copy...
[wc-checker] SLF4J: Failed to load class "org.slf4j.impl.StaticLoggerBinder".
[wc-checker] SLF4J: Defaulting to no-operation (NOP) logger implementation
[wc-checker] SLF4J: See http://www.slf4j.org/codes.html#StaticLoggerBinder for further details.
[wc-checker] Checking working copy status...
-jenkins-base:
BUILD SUCCESSFUL
Total time: 344 minutes 33 seconds
Archiving artifacts
java.lang.InterruptedException: no matches found within 10000
at hudson.FilePath$34.hasMatch(FilePath.java:2678)
at hudson.FilePath$34.invoke(FilePath.java:2557)
at hudson.FilePath$34.invoke(FilePath.java:2547)
at hudson.FilePath$FileCallableWrapper.call(FilePath.java:2918)
Also: hudson.remoting.Channel$CallSiteStackTrace: Remote call to lucene
at hudson.remoting.Channel.attachCallSiteStackTrace(Channel.java:1741)
at hudson.remoting.UserRequest$ExceptionResponse.retrieve(UserRequest.java:357)
at hudson.remoting.Channel.call(Channel.java:955)
at hudson.FilePath.act(FilePath.java:1036)
at hudson.FilePath.act(FilePath.java:1025)
at hudson.FilePath.validateAntFileMask(FilePath.java:2547)
at hudson.tasks.ArtifactArchiver.perform(ArtifactArchiver.java:243)
at hudson.tasks.BuildStepCompatibilityLayer.perform(BuildStepCompatibilityLayer.java:81)
at hudson.tasks.BuildStepMonitor$1.perform(BuildStepMonitor.java:20)
at hudson.model.AbstractBuild$AbstractBuildExecution.perform(AbstractBuild.java:744)
at hudson.model.AbstractBuild$AbstractBuildExecution.performAllBuildSteps(AbstractBuild.java:690)
at hudson.model.Build$BuildExecution.post2(Build.java:186)
at hudson.model.AbstractBuild$AbstractBuildExecution.post(AbstractBuild.java:635)
at hudson.model.Run.execute(Run.java:1819)
at hudson.model.FreeStyleBuild.run(FreeStyleBuild.java:43)
at hudson.model.ResourceController.execute(ResourceController.java:97)
at hudson.model.Executor.run(Executor.java:429)
Caused: hudson.FilePath$TunneledInterruptedException
at hudson.FilePath$FileCallableWrapper.call(FilePath.java:2920)
at hudson.remoting.UserRequest.perform(UserRequest.java:212)
at hudson.remoting.UserRequest.perform(UserRequest.java:54)
at hudson.remoting.Request$2.run(Request.java:369)
at hudson.remoting.InterceptingExecutorService$1.call(InterceptingExecutorService.java:72)
at java.util.concurrent.FutureTask.run(FutureTask.java:266)
at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142)
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
at java.lang.Thread.run(Thread.java:748)
Caused: java.lang.InterruptedException: java.lang.InterruptedException: no matches found within 10000
at hudson.FilePath.act(FilePath.java:1038)
at hudson.FilePath.act(FilePath.java:1025)
at hudson.FilePath.validateAntFileMask(FilePath.java:2547)
at hudson.tasks.ArtifactArchiver.perform(ArtifactArchiver.java:243)
at hudson.tasks.BuildStepCompatibilityLayer.perform(BuildStepCompatibilityLayer.java:81)
at hudson.tasks.BuildStepMonitor$1.perform(BuildStepMonitor.java:20)
at hudson.model.AbstractBuild$AbstractBuildExecution.perform(AbstractBuild.java:744)
at hudson.model.AbstractBuild$AbstractBuildExecution.performAllBuildSteps(AbstractBuild.java:690)
at hudson.model.Build$BuildExecution.post2(Build.java:186)
at hudson.model.AbstractBuild$AbstractBuildExecution.post(AbstractBuild.java:635)
at hudson.model.Run.execute(Run.java:1819)
at hudson.model.FreeStyleBuild.run(FreeStyleBuild.java:43)
at hudson.model.ResourceController.execute(ResourceController.java:97)
at hudson.model.Executor.run(Executor.java:429)
No artifacts found that match the file pattern "**/*.events,heapdumps/**,**/hs_err_pid*". Configuration error?
Recording test results
Build step 'Publish JUnit test result report' changed build result to UNSTABLE
Email was triggered for: Unstable (Test Failures)
Sending email for trigger: Unstable (Test Failures)