You are viewing a plain text version of this content. The canonical link for it is here.
Posted to dev@lucene.apache.org by Policeman Jenkins Server <je...@thetaphi.de> on 2018/10/01 17:08:46 UTC
[JENKINS] Lucene-Solr-7.x-Windows (64bit/jdk-9.0.4) - Build # 813 -
Unstable!
Build: https://jenkins.thetaphi.de/job/Lucene-Solr-7.x-Windows/813/
Java: 64bit/jdk-9.0.4 -XX:-UseCompressedOops -XX:+UseG1GC
1 tests failed.
FAILED: org.apache.solr.cloud.autoscaling.sim.TestSimComputePlanAction.testNodeLost
Error Message:
ComputePlanAction should have computed exactly 1 operation expected:<1> but was:<2>
Stack Trace:
java.lang.AssertionError: ComputePlanAction should have computed exactly 1 operation expected:<1> but was:<2>
at __randomizedtesting.SeedInfo.seed([FB1D8D6D09040CB4:440843938AEE6932]:0)
at org.junit.Assert.fail(Assert.java:93)
at org.junit.Assert.failNotEquals(Assert.java:647)
at org.junit.Assert.assertEquals(Assert.java:128)
at org.junit.Assert.assertEquals(Assert.java:472)
at org.apache.solr.cloud.autoscaling.sim.TestSimComputePlanAction.testNodeLost(TestSimComputePlanAction.java:173)
at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
at java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
at java.base/java.lang.reflect.Method.invoke(Method.java:564)
at com.carrotsearch.randomizedtesting.RandomizedRunner.invoke(RandomizedRunner.java:1742)
at com.carrotsearch.randomizedtesting.RandomizedRunner$8.evaluate(RandomizedRunner.java:935)
at com.carrotsearch.randomizedtesting.RandomizedRunner$9.evaluate(RandomizedRunner.java:971)
at com.carrotsearch.randomizedtesting.RandomizedRunner$10.evaluate(RandomizedRunner.java:985)
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:944)
at com.carrotsearch.randomizedtesting.RandomizedRunner$5.evaluate(RandomizedRunner.java:830)
at com.carrotsearch.randomizedtesting.RandomizedRunner$6.evaluate(RandomizedRunner.java:880)
at com.carrotsearch.randomizedtesting.RandomizedRunner$7.evaluate(RandomizedRunner.java:891)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:57)
at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:45)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at org.apache.lucene.util.TestRuleStoreClassName$1.evaluate(TestRuleStoreClassName.java:41)
at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:40)
at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:40)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at org.apache.lucene.util.TestRuleAssertionsRequired$1.evaluate(TestRuleAssertionsRequired.java:53)
at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:47)
at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:64)
at org.apache.lucene.util.TestRuleIgnoreTestSuites$1.evaluate(TestRuleIgnoreTestSuites.java:54)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:368)
at java.base/java.lang.Thread.run(Thread.java:844)
Build Log:
[...truncated 12994 lines...]
[junit4] Suite: org.apache.solr.cloud.autoscaling.sim.TestSimComputePlanAction
[junit4] 2> 763670 INFO (SUITE-TestSimComputePlanAction-seed#[FB1D8D6D09040CB4]-worker) [ ] o.a.s.SolrTestCaseJ4 SecureRandom sanity checks: test.solr.allowed.securerandom=null & java.security.egd=file:/dev/./urandom
[junit4] 2> Creating dataDir: C:\Users\jenkins\workspace\Lucene-Solr-7.x-Windows\solr\build\solr-core\test\J1\temp\solr.cloud.autoscaling.sim.TestSimComputePlanAction_FB1D8D6D09040CB4-001\init-core-data-001
[junit4] 2> 763673 INFO (SUITE-TestSimComputePlanAction-seed#[FB1D8D6D09040CB4]-worker) [ ] o.a.s.SolrTestCaseJ4 Using PointFields (NUMERIC_POINTS_SYSPROP=true) w/NUMERIC_DOCVALUES_SYSPROP=true
[junit4] 2> 763675 INFO (SUITE-TestSimComputePlanAction-seed#[FB1D8D6D09040CB4]-worker) [ ] o.a.s.SolrTestCaseJ4 Randomized ssl (false) and clientAuth (true) via: @org.apache.solr.util.RandomizeSSL(reason="", value=0.0/0.0, ssl=0.0/0.0, clientAuth=0.0/0.0)
[junit4] 2> 763686 DEBUG (SUITE-TestSimComputePlanAction-seed#[FB1D8D6D09040CB4]-worker) [ ] o.a.s.c.a.s.SimClusterStateProvider --- new Overseer leader: 127.0.0.1:10100_solr
[junit4] 2> 763686 DEBUG (SUITE-TestSimComputePlanAction-seed#[FB1D8D6D09040CB4]-worker) [ ] o.a.s.c.a.s.SimClusterStateProvider ** creating new collection states
[junit4] 2> 763686 DEBUG (SUITE-TestSimComputePlanAction-seed#[FB1D8D6D09040CB4]-worker) [ ] o.a.s.c.a.s.SimClusterStateProvider ** saved cluster state version -1
[junit4] 2> 763686 INFO (SUITE-TestSimComputePlanAction-seed#[FB1D8D6D09040CB4]-worker) [ ] o.a.s.h.a.MetricsHistoryHandler No .system collection, keeping metrics history in memory.
[junit4] 2> 763718 INFO (TEST-TestSimComputePlanAction.testNodeAdded-seed#[FB1D8D6D09040CB4]) [ ] o.a.s.SolrTestCaseJ4 ###Starting testNodeAdded
[junit4] 2> 763718 INFO (TEST-TestSimComputePlanAction.testNodeAdded-seed#[FB1D8D6D09040CB4]) [ ] o.a.s.c.a.s.SimCloudManager === Restarting OverseerTriggerThread and clearing object cache...
[junit4] 2> 763718 DEBUG (TEST-TestSimComputePlanAction.testNodeAdded-seed#[FB1D8D6D09040CB4]) [ ] o.a.s.c.a.ScheduledTriggers Shutting down scheduled thread pool executor now
[junit4] 2> 763718 DEBUG (TEST-TestSimComputePlanAction.testNodeAdded-seed#[FB1D8D6D09040CB4]) [ ] o.a.s.c.a.ScheduledTriggers Shutting down action executor now
[junit4] 2> 763718 DEBUG (TEST-TestSimComputePlanAction.testNodeAdded-seed#[FB1D8D6D09040CB4]) [ ] o.a.s.c.a.ScheduledTriggers Awaiting termination for action executor
[junit4] 2> 763718 DEBUG (TEST-TestSimComputePlanAction.testNodeAdded-seed#[FB1D8D6D09040CB4]) [ ] o.a.s.c.a.ScheduledTriggers Awaiting termination for scheduled thread pool executor
[junit4] 2> 763718 DEBUG (TEST-TestSimComputePlanAction.testNodeAdded-seed#[FB1D8D6D09040CB4]) [ ] o.a.s.c.a.ScheduledTriggers ScheduledTriggers closed completely
[junit4] 2> 763718 DEBUG (TEST-TestSimComputePlanAction.testNodeAdded-seed#[FB1D8D6D09040CB4]) [ ] o.a.s.c.a.OverseerTriggerThread OverseerTriggerThread has been closed explicitly
[junit4] 2> 763724 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Adding .auto_add_replicas and .scheduled_maintenance triggers
[junit4] 2> 763725 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Refreshing /autoscaling.json with znode version 1
[junit4] 2> 763725 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Current znodeVersion 1, lastZnodeVersion -1
[junit4] 2> 763725 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Processed trigger updates upto znodeVersion 1
[junit4] 2> 763726 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.NodeLostTrigger NodeLostTrigger .auto_add_replicas - Initial livenodes: [127.0.0.1:10100_solr]
[junit4] 2> 763726 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread -- clean old nodeAdded markers
[junit4] 2> 763726 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Current znodeVersion 1, lastZnodeVersion 1
[junit4] 2> 763726 DEBUG (ScheduledTrigger-3168-thread-1) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 1
[junit4] 2> 763748 DEBUG (ScheduledTrigger-3168-thread-2) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 1
[junit4] 2> 763771 DEBUG (ScheduledTrigger-3168-thread-2) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 1
[junit4] 2> 763795 DEBUG (ScheduledTrigger-3168-thread-4) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 1
[junit4] 2> 763815 DEBUG (ScheduledTrigger-3168-thread-2) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 1
[junit4] 2> 763821 DEBUG (simCloudManagerPool-3167-thread-1) [ ] o.a.s.c.a.s.SimClusterStateProvider ** creating new collection states
[junit4] 2> 763821 DEBUG (simCloudManagerPool-3167-thread-1) [ ] o.a.s.c.a.s.SimClusterStateProvider ** saved cluster state version 0
[junit4] 2> 763821 DEBUG (simCloudManagerPool-3167-thread-1) [ ] o.a.s.c.a.AutoScalingHandler Verified autoscaling configuration
[junit4] 2> 763821 DEBUG (simCloudManagerPool-3167-thread-1) [ ] o.a.s.c.a.OverseerTriggerThread Refreshing /autoscaling.json with znode version 2
[junit4] 2> 763822 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Processed trigger updates upto znodeVersion 2
[junit4] 2> 763822 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread -- clean old nodeAdded markers
[junit4] 2> 763822 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Current znodeVersion 2, lastZnodeVersion 2
[junit4] 2> 763825 DEBUG (simCloudManagerPool-3167-thread-2) [ ] o.a.s.c.a.AutoScalingHandler Verified autoscaling configuration
[junit4] 2> 763825 DEBUG (simCloudManagerPool-3167-thread-2) [ ] o.a.s.c.a.OverseerTriggerThread Refreshing /autoscaling.json with znode version 3
[junit4] 2> 763826 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Processed trigger updates upto znodeVersion 3
[junit4] 2> 763826 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread -- clean old nodeAdded markers
[junit4] 2> 763826 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Current znodeVersion 3, lastZnodeVersion 3
[junit4] 2> 763838 DEBUG (ScheduledTrigger-3168-thread-1) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 1
[junit4] 2> 763859 DEBUG (ScheduledTrigger-3168-thread-1) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 1
[junit4] 2> 763880 DEBUG (ScheduledTrigger-3168-thread-4) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 1
[junit4] 2> 763904 DEBUG (ScheduledTrigger-3168-thread-4) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 1
[junit4] 2> 763928 DEBUG (ScheduledTrigger-3168-thread-4) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 1
[junit4] 2> 763949 DEBUG (ScheduledTrigger-3168-thread-1) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 1
[junit4] 2> 763951 DEBUG (simCloudManagerPool-3167-thread-3) [ ] o.a.s.c.a.AutoScalingHandler Verified autoscaling configuration
[junit4] 2> 763951 DEBUG (simCloudManagerPool-3167-thread-3) [ ] o.a.s.c.a.OverseerTriggerThread Refreshing /autoscaling.json with znode version 4
[junit4] 2> 763952 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Processed trigger updates upto znodeVersion 4
[junit4] 2> 763952 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.NodeAddedTrigger NodeAddedTrigger node_added_trigger - Initial livenodes: [127.0.0.1:10100_solr]
[junit4] 2> 763952 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> 763952 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Current znodeVersion 4, lastZnodeVersion 4
[junit4] 2> 763952 DEBUG (ScheduledTrigger-3168-thread-3) [ ] o.a.s.c.a.NodeAddedTrigger Running NodeAddedTrigger node_added_trigger
[junit4] 2> 763952 DEBUG (ScheduledTrigger-3168-thread-3) [ ] o.a.s.c.a.NodeAddedTrigger Found livenodes: 1
[junit4] 2> 763954 DEBUG (simCloudManagerPool-3167-thread-4) [ ] o.a.s.c.a.AutoScalingHandler Verified autoscaling configuration
[junit4] 2> 763954 DEBUG (simCloudManagerPool-3167-thread-4) [ ] o.a.s.c.a.OverseerTriggerThread Refreshing /autoscaling.json with znode version 5
[junit4] 2> 763955 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Processed trigger updates upto znodeVersion 5
[junit4] 2> 763955 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Current znodeVersion 5, lastZnodeVersion 5
[junit4] 2> 763956 DEBUG (simCloudManagerPool-3167-thread-5) [ ] o.a.s.c.a.s.SimClusterStateProvider ** creating new collection states
[junit4] 2> 763956 DEBUG (simCloudManagerPool-3167-thread-5) [ ] o.a.s.c.a.s.SimClusterStateProvider ** saved cluster state version 1
[junit4] 2> 763956 DEBUG (simCloudManagerPool-3167-thread-5) [ ] o.a.s.c.o.ClusterStateMutator building a new cName: testNodeAdded
[junit4] 2> 763967 WARN (simCloudManagerPool-3167-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> 763968 DEBUG (simCloudManagerPool-3167-thread-5) [ ] o.a.s.c.s.c.a.PolicyHelper Creating a new session
[junit4] 2> 763968 DEBUG (simCloudManagerPool-3167-thread-5) [ ] o.a.s.c.s.c.a.PolicyHelper New session created
[junit4] 2> 763968 DEBUG (simCloudManagerPool-3167-thread-5) [ ] o.a.s.c.s.c.a.PolicyHelper returnSession, curr-time 1413126145 sessionWrapper.createTime 1413126106157600, this.sessionWrapper.createTime 1413126106157600
[junit4] 2> 763968 DEBUG (simCloudManagerPool-3167-thread-5) [ ] o.a.s.c.s.c.a.PolicyHelper session set to NULL
[junit4] 2> 763968 DEBUG (TEST-TestSimComputePlanAction.testNodeAdded-seed#[FB1D8D6D09040CB4]) [ ] o.a.s.c.a.s.SimClusterStateProvider ** creating new collection states
[junit4] 2> 763968 DEBUG (TEST-TestSimComputePlanAction.testNodeAdded-seed#[FB1D8D6D09040CB4]) [ ] o.a.s.c.a.s.SimClusterStateProvider ** saved cluster state version 2
[junit4] 2> 763968 DEBUG (simCloudManagerPool-3167-thread-10) [ ] o.a.s.c.a.AutoScalingHandler Verified autoscaling configuration
[junit4] 2> 763968 DEBUG (simCloudManagerPool-3167-thread-10) [ ] o.a.s.c.a.OverseerTriggerThread Refreshing /autoscaling.json with znode version 6
[junit4] 2> 763968 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Processed trigger updates upto znodeVersion 6
[junit4] 2> 763968 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Current znodeVersion 6, lastZnodeVersion 6
[junit4] 2> 763976 DEBUG (ScheduledTrigger-3168-thread-1) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 2
[junit4] 2> 763978 DEBUG (simCloudManagerPool-3167-thread-6) [ ] o.a.s.c.a.s.SimClusterStateProvider ** creating new collection states
[junit4] 2> 763981 DEBUG (ScheduledTrigger-3168-thread-1) [ ] o.a.s.c.a.NodeAddedTrigger Running NodeAddedTrigger node_added_trigger
[junit4] 2> 763981 DEBUG (ScheduledTrigger-3168-thread-1) [ ] o.a.s.c.a.NodeAddedTrigger Found livenodes: 2
[junit4] 2> 763981 DEBUG (simCloudManagerPool-3167-thread-6) [ ] o.a.s.c.a.s.SimClusterStateProvider ** saved cluster state version 3
[junit4] 2> 763981 DEBUG (ScheduledTrigger-3168-thread-1) [ ] o.a.s.c.a.NodeAddedTrigger Tracking new node: 127.0.0.1:10101_solr at time 1413126737857600
[junit4] 2> 763981 DEBUG (simCloudManagerPool-3167-thread-11) [ ] o.a.s.c.a.s.SimClusterStateProvider -- elected new leader for testNodeAdded / shard1: {"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:10100_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> 763997 DEBUG (simCloudManagerPool-3167-thread-7) [ ] o.a.s.c.a.s.SimClusterStateProvider ** creating new collection states
[junit4] 2> 763998 DEBUG (ScheduledTrigger-3168-thread-2) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 2
[junit4] 2> 764001 DEBUG (simCloudManagerPool-3167-thread-7) [ ] o.a.s.c.a.s.SimClusterStateProvider ** saved cluster state version 4
[junit4] 2> 764002 DEBUG (ScheduledTrigger-3168-thread-2) [ ] o.a.s.c.a.NodeAddedTrigger Running NodeAddedTrigger node_added_trigger
[junit4] 2> 764002 DEBUG (ScheduledTrigger-3168-thread-2) [ ] o.a.s.c.a.NodeAddedTrigger Found livenodes: 2
[junit4] 2> 764002 DEBUG (ScheduledTrigger-3168-thread-2) [ ] o.a.s.c.a.NodeAddedTrigger NodeAddedTrigger node_added_trigger firing registered processor for nodes: [127.0.0.1:10101_solr] added at times [1413126737857600], now=1413127787007600
[junit4] 2> 764002 DEBUG (ScheduledTrigger-3168-thread-2) [ ] o.a.s.c.a.ScheduledTriggers ++++++++ Cooldown inactive - processing event: {
[junit4] 2> "id":"5053b353b8c40Tb5ava2ta1466re7k0hezrjk52",
[junit4] 2> "source":"node_added_trigger",
[junit4] 2> "eventTime":1413126737857600,
[junit4] 2> "eventType":"NODEADDED",
[junit4] 2> "properties":{
[junit4] 2> "eventTimes":[1413126737857600],
[junit4] 2> "preferredOperation":"movereplica",
[junit4] 2> "nodeNames":["127.0.0.1:10101_solr"]}}
[junit4] 2> 764002 DEBUG (ScheduledTrigger-3168-thread-2) [ ] o.a.s.c.a.ScheduledTriggers Pausing all triggers: [.auto_add_replicas, .scheduled_maintenance, node_added_trigger]
[junit4] 2> 764053 DEBUG (simCloudManagerPool-3167-thread-8) [ ] o.a.s.c.a.s.SimClusterStateProvider ** creating new collection states
[junit4] 2> 764053 DEBUG (simCloudManagerPool-3167-thread-8) [ ] o.a.s.c.a.s.SimClusterStateProvider ** saved cluster state version 5
[junit4] 2> 764063 DEBUG (simCloudManagerPool-3167-thread-9) [ ] o.a.s.c.a.s.SimClusterStateProvider ** creating new collection states
[junit4] 2> 764063 DEBUG (simCloudManagerPool-3167-thread-9) [ ] o.a.s.c.a.s.SimClusterStateProvider ** saved cluster state version 6
[junit4] 2> 764063 DEBUG (simCloudManagerPool-3167-thread-12) [ ] o.a.s.c.a.s.SimClusterStateProvider ** creating new collection states
[junit4] 2> 764063 DEBUG (simCloudManagerPool-3167-thread-12) [ ] o.a.s.c.a.s.SimClusterStateProvider ** saved cluster state version 7
[junit4] 2> 764063 DEBUG (simCloudManagerPool-3167-thread-12) [ ] o.a.s.c.o.ClusterStateMutator building a new cName: .system
[junit4] 2> 764074 DEBUG (simCloudManagerPool-3167-thread-12) [ ] o.a.s.c.s.c.a.PolicyHelper Creating a new session
[junit4] 2> 764074 DEBUG (simCloudManagerPool-3167-thread-12) [ ] o.a.s.c.s.c.a.PolicyHelper New session created
[junit4] 2> 764075 DEBUG (simCloudManagerPool-3167-thread-12) [ ] o.a.s.c.s.c.a.PolicyHelper returnSession, curr-time 1413131428 sessionWrapper.createTime 1413131405337600, this.sessionWrapper.createTime 1413131405337600
[junit4] 2> 764075 DEBUG (simCloudManagerPool-3167-thread-12) [ ] o.a.s.c.s.c.a.PolicyHelper session set to NULL
[junit4] 2> 764086 DEBUG (simCloudManagerPool-3167-thread-13) [ ] o.a.s.c.a.s.SimClusterStateProvider ** creating new collection states
[junit4] 2> 764086 DEBUG (simCloudManagerPool-3167-thread-13) [ ] o.a.s.c.a.s.SimClusterStateProvider ** saved cluster state version 8
[junit4] 2> 764089 DEBUG (simCloudManagerPool-3167-thread-14) [ ] o.a.s.c.a.s.SimClusterStateProvider -- elected new leader for .system / shard1: {"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:10101_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> 764090 DEBUG (simCloudManagerPool-3167-thread-12) [ ] o.a.s.c.a.s.SimClusterStateProvider ** creating new collection states
[junit4] 2> 764093 DEBUG (simCloudManagerPool-3167-thread-12) [ ] o.a.s.c.a.s.SimClusterStateProvider ** saved cluster state version 9
[junit4] 2> 764094 DEBUG (ScheduledTrigger-3168-thread-2) [ ] o.a.s.c.a.NodeAddedTrigger NodeAddedTrigger node_added_trigger - removing marker path: /autoscaling/nodeAdded/127.0.0.1:10101_solr
[junit4] 2> 764094 DEBUG (AutoscalingActionExecutor-3169-thread-1) [ ] o.a.s.c.a.ScheduledTriggers -- processing actions for {
[junit4] 2> "id":"5053b353b8c40Tb5ava2ta1466re7k0hezrjk52",
[junit4] 2> "source":"node_added_trigger",
[junit4] 2> "eventTime":1413126737857600,
[junit4] 2> "eventType":"NODEADDED",
[junit4] 2> "properties":{
[junit4] 2> "eventTimes":[1413126737857600],
[junit4] 2> "preferredOperation":"movereplica",
[junit4] 2> "_enqueue_time_":1413127817037600,
[junit4] 2> "nodeNames":["127.0.0.1:10101_solr"]}}
[junit4] 2> 764094 DEBUG (AutoscalingActionExecutor-3169-thread-1) [ ] o.a.s.c.a.ComputePlanAction -- processing event: {
[junit4] 2> "id":"5053b353b8c40Tb5ava2ta1466re7k0hezrjk52",
[junit4] 2> "source":"node_added_trigger",
[junit4] 2> "eventTime":1413126737857600,
[junit4] 2> "eventType":"NODEADDED",
[junit4] 2> "properties":{
[junit4] 2> "eventTimes":[1413126737857600],
[junit4] 2> "preferredOperation":"movereplica",
[junit4] 2> "_enqueue_time_":1413127817037600,
[junit4] 2> "nodeNames":["127.0.0.1:10101_solr"]}} with context properties: {BEFORE_ACTION=[compute_plan]}
[junit4] 2> 764094 DEBUG (AutoscalingActionExecutor-3169-thread-1) [ ] o.a.s.c.s.c.a.PolicyHelper Creating a new session
[junit4] 2> 764094 DEBUG (AutoscalingActionExecutor-3169-thread-1) [ ] o.a.s.c.s.c.a.PolicyHelper New session created
[junit4] 2> 764094 DEBUG (AutoscalingActionExecutor-3169-thread-1) [ ] o.a.s.c.a.ComputePlanAction Computed Plan: action=MOVEREPLICA&collection=testNodeAdded&targetNode=127.0.0.1:10101_solr&inPlaceMove=true&replica=core_node1
[junit4] 2> 764102 DEBUG (AutoscalingActionExecutor-3169-thread-1) [ ] o.a.s.c.s.c.a.PolicyHelper returnSession, curr-time 1413132791 sessionWrapper.createTime 1413132475012600, this.sessionWrapper.createTime 1413132475012600
[junit4] 2> 764102 DEBUG (AutoscalingActionExecutor-3169-thread-1) [ ] o.a.s.c.s.c.a.PolicyHelper session set to NULL
[junit4] 2> 764103 INFO (TEST-TestSimComputePlanAction.testNodeAdded-seed#[FB1D8D6D09040CB4]) [ ] o.a.s.c.a.s.TestSimComputePlanAction Node values: {
[junit4] 2> "127.0.0.1:10100_solr":{
[junit4] 2> "sysprop.java.vendor":"Oracle Corporation",
[junit4] 2> "cores":4,
[junit4] 2> "host":"127.0.0.1",
[junit4] 2> "freedisk":996,
[junit4] 2> "sysprop.java.version":"9.0.4",
[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:10100_solr",
[junit4] 2> "metrics:solr.jvm:buffers.direct.Count":0,
[junit4] 2> "port":10100,
[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:10101_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":"9.0.4",
[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:10101_solr",
[junit4] 2> "metrics:solr.jvm:buffers.direct.Count":0,
[junit4] 2> "port":10101,
[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> 764103 INFO (TEST-TestSimComputePlanAction.testNodeAdded-seed#[FB1D8D6D09040CB4]) [ ] o.a.s.c.a.s.TestSimComputePlanAction Live nodes: [127.0.0.1:10100_solr, 127.0.0.1:10101_solr], collection state: DocCollection(testNodeAdded//clusterstate.json/11)={
[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:10100_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:10100_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:10100_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:10100_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> 764105 INFO (TEST-TestSimComputePlanAction.testNodeAdded-seed#[FB1D8D6D09040CB4]) [ ] o.a.s.c.a.s.TestSimComputePlanAction -------------_ FINAL STATE --------------
[junit4] 2> 764105 INFO (TEST-TestSimComputePlanAction.testNodeAdded-seed#[FB1D8D6D09040CB4]) [ ] o.a.s.c.a.s.TestSimComputePlanAction * Node values: {
[junit4] 2> "127.0.0.1:10100_solr":{
[junit4] 2> "sysprop.java.vendor":"Oracle Corporation",
[junit4] 2> "cores":4,
[junit4] 2> "host":"127.0.0.1",
[junit4] 2> "freedisk":996,
[junit4] 2> "sysprop.java.version":"9.0.4",
[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:10100_solr",
[junit4] 2> "metrics:solr.jvm:buffers.direct.Count":0,
[junit4] 2> "port":10100,
[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:10101_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":"9.0.4",
[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:10101_solr",
[junit4] 2> "metrics:solr.jvm:buffers.direct.Count":0,
[junit4] 2> "port":10101,
[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> 764105 INFO (TEST-TestSimComputePlanAction.testNodeAdded-seed#[FB1D8D6D09040CB4]) [ ] o.a.s.c.a.s.TestSimComputePlanAction * Live nodes: [127.0.0.1:10100_solr, 127.0.0.1:10101_solr]
[junit4] 2> 764105 INFO (TEST-TestSimComputePlanAction.testNodeAdded-seed#[FB1D8D6D09040CB4]) [ ] o.a.s.c.a.s.TestSimComputePlanAction * Collection .system state: DocCollection(.system//clusterstate.json/11)={
[junit4] 2> "replicationFactor":"1",
[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":{"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:10101_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> 764105 INFO (TEST-TestSimComputePlanAction.testNodeAdded-seed#[FB1D8D6D09040CB4]) [ ] o.a.s.c.a.s.TestSimComputePlanAction * Collection testNodeAdded state: DocCollection(testNodeAdded//clusterstate.json/11)={
[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:10100_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:10100_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:10100_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:10100_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> 764105 INFO (TEST-TestSimComputePlanAction.testNodeAdded-seed#[FB1D8D6D09040CB4]) [ ] o.a.s.SolrTestCaseJ4 ###Ending testNodeAdded
[junit4] 2> 764105 DEBUG (TEST-TestSimComputePlanAction.testNodeAdded-seed#[FB1D8D6D09040CB4]) [ ] o.a.s.c.a.s.SimClusterStateProvider ** creating new collection states
[junit4] 2> 764106 DEBUG (TEST-TestSimComputePlanAction.testNodeAdded-seed#[FB1D8D6D09040CB4]) [ ] o.a.s.c.a.s.SimClusterStateProvider ** saved cluster state version 10
[junit4] 2> 764106 INFO (TEST-TestSimComputePlanAction.testNodeAdded-seed#[FB1D8D6D09040CB4]) [ ] 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 1
[junit4] 2> ## activeReplicas 1
[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: 1
[junit4] 2> ## Total replicas: 5
[junit4] 2> ## * .system 1
[junit4] 2> ## - active 1
[junit4] 2> ## * testNodeAdded 4
[junit4] 2> ## - active 4
[junit4] 2> ######### Solr op counts ##########
[junit4] 2> ## - CREATE 1
[junit4] 2> ## - autoscaling 5
[junit4] 2> ## - update 2
[junit4] 2> ######### Autoscaling event counts ###########
[junit4] 2> ## * Trigger: node_added_trigger
[junit4] 2> ## - BEFORE_ACTION 1
[junit4] 2> ## - STARTED 1
[junit4] 2>
[junit4] 2> 764125 INFO (TEST-TestSimComputePlanAction.testNodeWithMultipleReplicasLost-seed#[FB1D8D6D09040CB4]) [ ] o.a.s.SolrTestCaseJ4 ###Starting testNodeWithMultipleReplicasLost
[junit4] 2> 764125 DEBUG (TEST-TestSimComputePlanAction.testNodeWithMultipleReplicasLost-seed#[FB1D8D6D09040CB4]) [ ] o.a.s.c.a.OverseerTriggerThread Refreshing /autoscaling.json with znode version 7
[junit4] 2> 764125 DEBUG (TEST-TestSimComputePlanAction.testNodeWithMultipleReplicasLost-seed#[FB1D8D6D09040CB4]) [ ] o.a.s.c.a.s.SimNodeStateProvider --removing value for 127.0.0.1:10101_solr
[junit4] 2> 764125 INFO (TEST-TestSimComputePlanAction.testNodeWithMultipleReplicasLost-seed#[FB1D8D6D09040CB4]) [ ] o.a.s.c.a.s.SimCloudManager === Restarting OverseerTriggerThread and clearing object cache...
[junit4] 2> 764125 DEBUG (TEST-TestSimComputePlanAction.testNodeWithMultipleReplicasLost-seed#[FB1D8D6D09040CB4]) [ ] o.a.s.c.a.ScheduledTriggers Shutting down scheduled thread pool executor now
[junit4] 2> 764125 DEBUG (TEST-TestSimComputePlanAction.testNodeWithMultipleReplicasLost-seed#[FB1D8D6D09040CB4]) [ ] o.a.s.c.a.ScheduledTriggers Shutting down action executor now
[junit4] 2> 764126 DEBUG (TEST-TestSimComputePlanAction.testNodeWithMultipleReplicasLost-seed#[FB1D8D6D09040CB4]) [ ] o.a.s.c.a.ScheduledTriggers Awaiting termination for action executor
[junit4] 2> 764126 WARN (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread OverseerTriggerThread woken up but we are closed, exiting.
[junit4] 2> 764126 DEBUG (simCloudManagerPool-3167-thread-16) [ ] o.a.s.c.a.s.SimClusterStateProvider ** creating new collection states
[junit4] 2> 764126 DEBUG (simCloudManagerPool-3167-thread-16) [ ] o.a.s.c.a.s.SimClusterStateProvider ** saved cluster state version 11
[junit4] 2> 764126 DEBUG (simCloudManagerPool-3167-thread-16) [ ] o.a.s.c.o.ClusterStateMutator building a new cName: .system
[junit4] 2> 764129 WARN (AutoscalingActionExecutor-3169-thread-1) [ ] o.a.s.c.a.SystemLogListener Exception sending event to collection .system
[junit4] 2> java.io.IOException: java.lang.InterruptedException
[junit4] 2> at org.apache.solr.cloud.autoscaling.sim.SimCloudManager.request(SimCloudManager.java:653) ~[test/:?]
[junit4] 2> at org.apache.solr.cloud.autoscaling.SystemLogListener.onEvent(SystemLogListener.java:118) [java/:?]
[junit4] 2> at org.apache.solr.cloud.autoscaling.ScheduledTriggers$TriggerListeners.fireListeners(ScheduledTriggers.java:793) [java/:?]
[junit4] 2> at org.apache.solr.cloud.autoscaling.ScheduledTriggers$TriggerListeners.fireListeners(ScheduledTriggers.java:769) [java/:?]
[junit4] 2> at org.apache.solr.cloud.autoscaling.ScheduledTriggers.lambda$add$3(ScheduledTriggers.java:316) [java/:?]
[junit4] 2> at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:514) [?:?]
[junit4] 2> at java.util.concurrent.FutureTask.run(FutureTask.java:264) [?:?]
[junit4] 2> at org.apache.solr.common.util.ExecutorUtil$MDCAwareThreadPoolExecutor.lambda$execute$0(ExecutorUtil.java:209) [java/:?]
[junit4] 2> at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1167) [?:?]
[junit4] 2> at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:641) [?:?]
[junit4] 2> at java.lang.Thread.run(Thread.java:844) [?:?]
[junit4] 2> Caused by: java.lang.InterruptedException
[junit4] 2> at java.util.concurrent.FutureTask.awaitDone(FutureTask.java:418) ~[?:?]
[junit4] 2> at java.util.concurrent.FutureTask.get(FutureTask.java:190) ~[?:?]
[junit4] 2> at org.apache.solr.cloud.autoscaling.sim.SimCloudManager.request(SimCloudManager.java:651) ~[test/:?]
[junit4] 2> ... 10 more
[junit4] 2> 764133 DEBUG (simCloudManagerPool-3167-thread-17) [ ] o.a.s.c.a.s.SimClusterStateProvider ** creating new collection states
[junit4] 2> 764133 DEBUG (simCloudManagerPool-3167-thread-17) [ ] o.a.s.c.a.s.SimClusterStateProvider ** saved cluster state version 12
[junit4] 2> 764133 DEBUG (simCloudManagerPool-3167-thread-17) [ ] o.a.s.c.o.ClusterStateMutator building a new cName: .system
[junit4] 2> 764151 DEBUG (simCloudManagerPool-3167-thread-18) [ ] o.a.s.c.a.s.SimClusterStateProvider ** creating new collection states
[junit4] 2> 764151 DEBUG (simCloudManagerPool-3167-thread-18) [ ] o.a.s.c.a.s.SimClusterStateProvider ** saved cluster state version 13
[junit4] 2> 764151 DEBUG (simCloudManagerPool-3167-thread-17) [ ] o.a.s.c.a.s.SimClusterStateProvider ** creating new collection states
[junit4] 2> 764151 DEBUG (simCloudManagerPool-3167-thread-17) [ ] o.a.s.c.a.s.SimClusterStateProvider ** saved cluster state version 14
[junit4] 2> 764153 DEBUG (simCloudManagerPool-3167-thread-16) [ ] o.a.s.c.a.s.SimClusterStateProvider ** creating new collection states
[junit4] 2> 764153 DEBUG (simCloudManagerPool-3167-thread-16) [ ] o.a.s.c.a.s.SimClusterStateProvider ** saved cluster state version 15
[junit4] 2> 764154 DEBUG (simCloudManagerPool-3167-thread-19) [ ] o.a.s.c.a.s.SimClusterStateProvider -- elected new leader for .system / shard1: {"core_node2":{
[junit4] 2> "core":".system_shard1_replica_n1",
[junit4] 2> "shard":"shard1",
[junit4] 2> "collection":".system",
[junit4] 2> "node_name":"127.0.0.1:10100_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> 764156 DEBUG (simCloudManagerPool-3167-thread-16) [ ] o.a.s.c.a.s.SimClusterStateProvider ** creating new collection states
[junit4] 2> 764156 DEBUG (simCloudManagerPool-3167-thread-16) [ ] o.a.s.c.a.s.SimClusterStateProvider ** saved cluster state version 16
[junit4] 2> 765354 WARN (AutoscalingActionExecutor-3169-thread-1) [ ] o.a.s.c.a.ScheduledTriggers Unhandled exception executing actions
[junit4] 2> org.apache.lucene.store.AlreadyClosedException: ScheduledTrigger node_added_trigger has been closed.
[junit4] 2> at org.apache.solr.cloud.autoscaling.ScheduledTriggers$TriggerWrapper.dequeue(ScheduledTriggers.java:549) ~[java/:?]
[junit4] 2> at org.apache.solr.cloud.autoscaling.ScheduledTriggers.lambda$add$3(ScheduledTriggers.java:319) [java/:?]
[junit4] 2> at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:514) [?:?]
[junit4] 2> at java.util.concurrent.FutureTask.run(FutureTask.java:264) [?:?]
[junit4] 2> at org.apache.solr.common.util.ExecutorUtil$MDCAwareThreadPoolExecutor.lambda$execute$0(ExecutorUtil.java:209) [java/:?]
[junit4] 2> at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1167) [?:?]
[junit4] 2> at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:641) [?:?]
[junit4] 2> at java.lang.Thread.run(Thread.java:844) [?:?]
[junit4] 2> 765354 DEBUG (AutoscalingActionExecutor-3169-thread-1) [ ] o.a.s.c.a.ScheduledTriggers -- processing took 63014 ms for event id=5053b353b8c40Tb5ava2ta1466re7k0hezrjk52
[junit4] 2> 765354 DEBUG (TEST-TestSimComputePlanAction.testNodeWithMultipleReplicasLost-seed#[FB1D8D6D09040CB4]) [ ] o.a.s.c.a.ScheduledTriggers Awaiting termination for scheduled thread pool executor
[junit4] 2> 765355 DEBUG (TEST-TestSimComputePlanAction.testNodeWithMultipleReplicasLost-seed#[FB1D8D6D09040CB4]) [ ] o.a.s.c.a.ScheduledTriggers ScheduledTriggers closed completely
[junit4] 2> 765355 DEBUG (TEST-TestSimComputePlanAction.testNodeWithMultipleReplicasLost-seed#[FB1D8D6D09040CB4]) [ ] o.a.s.c.a.OverseerTriggerThread OverseerTriggerThread has been closed explicitly
[junit4] 2> 765358 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Adding .auto_add_replicas and .scheduled_maintenance triggers
[junit4] 2> 765359 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Refreshing /autoscaling.json with znode version 8
[junit4] 2> 765359 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Current znodeVersion 8, lastZnodeVersion -1
[junit4] 2> 765359 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Processed trigger updates upto znodeVersion 8
[junit4] 2> 765359 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.NodeLostTrigger NodeLostTrigger .auto_add_replicas - Initial livenodes: [127.0.0.1:10100_solr]
[junit4] 2> 765359 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread -- clean old nodeAdded markers
[junit4] 2> 765359 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Current znodeVersion 8, lastZnodeVersion 8
[junit4] 2> 765360 DEBUG (ScheduledTrigger-3171-thread-1) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 1
[junit4] 2> 765382 DEBUG (ScheduledTrigger-3171-thread-2) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 1
[junit4] 2> 765403 DEBUG (ScheduledTrigger-3171-thread-1) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 1
[junit4] 2> 765425 DEBUG (ScheduledTrigger-3171-thread-3) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 1
[junit4] 2> 765446 DEBUG (ScheduledTrigger-3171-thread-2) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 1
[junit4] 2> 765458 DEBUG (simCloudManagerPool-3170-thread-1) [ ] o.a.s.c.a.AutoScalingHandler Verified autoscaling configuration
[junit4] 2> 765459 DEBUG (simCloudManagerPool-3170-thread-1) [ ] o.a.s.c.a.OverseerTriggerThread Refreshing /autoscaling.json with znode version 9
[junit4] 2> 765459 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Processed trigger updates upto znodeVersion 9
[junit4] 2> 765459 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread -- clean old nodeAdded markers
[junit4] 2> 765459 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Current znodeVersion 9, lastZnodeVersion 9
[junit4] 2> 765460 DEBUG (simCloudManagerPool-3170-thread-2) [ ] o.a.s.c.a.AutoScalingHandler Verified autoscaling configuration
[junit4] 2> 765460 DEBUG (simCloudManagerPool-3170-thread-2) [ ] o.a.s.c.a.OverseerTriggerThread Refreshing /autoscaling.json with znode version 10
[junit4] 2> 765460 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Processed trigger updates upto znodeVersion 10
[junit4] 2> 765460 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread -- clean old nodeAdded markers
[junit4] 2> 765460 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Current znodeVersion 10, lastZnodeVersion 10
[junit4] 2> 765467 DEBUG (ScheduledTrigger-3171-thread-4) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 1
[junit4] 2> 765487 DEBUG (ScheduledTrigger-3171-thread-4) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 1
[junit4] 2> 765508 DEBUG (ScheduledTrigger-3171-thread-2) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 1
[junit4] 2> 765528 DEBUG (ScheduledTrigger-3171-thread-2) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 1
[junit4] 2> 765549 DEBUG (ScheduledTrigger-3171-thread-2) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 1
[junit4] 2> 765560 DEBUG (simCloudManagerPool-3170-thread-3) [ ] o.a.s.c.a.AutoScalingHandler Verified autoscaling configuration
[junit4] 2> 765560 DEBUG (simCloudManagerPool-3170-thread-3) [ ] o.a.s.c.a.OverseerTriggerThread Refreshing /autoscaling.json with znode version 11
[junit4] 2> 765560 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Processed trigger updates upto znodeVersion 11
[junit4] 2> 765560 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.NodeLostTrigger NodeLostTrigger node_lost_trigger - Initial livenodes: [127.0.0.1:10100_solr, 127.0.0.1:10104_solr, 127.0.0.1:10102_solr, 127.0.0.1:10103_solr]
[junit4] 2> 765560 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread -- clean old nodeAdded markers
[junit4] 2> 765560 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Current znodeVersion 11, lastZnodeVersion 11
[junit4] 2> 765560 DEBUG (ScheduledTrigger-3171-thread-3) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: node_lost_trigger with currently live nodes: 4
[junit4] 2> 765568 DEBUG (simCloudManagerPool-3170-thread-4) [ ] o.a.s.c.a.s.SimClusterStateProvider ** creating new collection states
[junit4] 2> 765568 DEBUG (simCloudManagerPool-3170-thread-4) [ ] o.a.s.c.a.s.SimClusterStateProvider ** saved cluster state version 17
[junit4] 2> 765568 DEBUG (simCloudManagerPool-3170-thread-4) [ ] o.a.s.c.o.ClusterStateMutator building a new cName: testNodeWithMultipleReplicasLost
[junit4] 2> 765572 DEBUG (ScheduledTrigger-3171-thread-2) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 4
[junit4] 2> 765580 DEBUG (simCloudManagerPool-3170-thread-4) [ ] o.a.s.c.s.c.a.PolicyHelper Creating a new session
[junit4] 2> 765580 DEBUG (simCloudManagerPool-3170-thread-4) [ ] o.a.s.c.s.c.a.PolicyHelper New session created
[junit4] 2> 765582 DEBUG (simCloudManagerPool-3170-thread-4) [ ] o.a.s.c.s.c.a.PolicyHelper returnSession, curr-time 1413206817 sessionWrapper.createTime 1413206731397600, this.sessionWrapper.createTime 1413206731397600
[junit4] 2> 765582 DEBUG (simCloudManagerPool-3170-thread-4) [ ] o.a.s.c.s.c.a.PolicyHelper session set to NULL
[junit4] 2> 765583 DEBUG (TEST-TestSimComputePlanAction.testNodeWithMultipleReplicasLost-seed#[FB1D8D6D09040CB4]) [ ] o.a.s.c.a.s.SimClusterStateProvider ** creating new collection states
[junit4] 2> 765583 DEBUG (TEST-TestSimComputePlanAction.testNodeWithMultipleReplicasLost-seed#[FB1D8D6D09040CB4]) [ ] o.a.s.c.a.s.SimClusterStateProvider ** saved cluster state version 18
[junit4] 2> 765593 DEBUG (ScheduledTrigger-3171-thread-3) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: node_lost_trigger with currently live nodes: 4
[junit4] 2> 765593 DEBUG (ScheduledTrigger-3171-thread-3) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 4
[junit4] 2> 765596 DEBUG (simCloudManagerPool-3170-thread-5) [ ] o.a.s.c.a.s.SimClusterStateProvider ** creating new collection states
[junit4] 2> 765596 DEBUG (simCloudManagerPool-3170-thread-5) [ ] o.a.s.c.a.s.SimClusterStateProvider ** saved cluster state version 19
[junit4] 2> 765596 DEBUG (simCloudManagerPool-3170-thread-11) [ ] o.a.s.c.a.s.SimClusterStateProvider -- elected new leader for testNodeWithMultipleReplicasLost / shard1: {"core_node1":{
[junit4] 2> "core":"testNodeWithMultipleReplicasLost_shard1_replica_n1",
[junit4] 2> "shard":"shard1",
[junit4] 2> "collection":"testNodeWithMultipleReplicasLost",
[junit4] 2> "node_name":"127.0.0.1:10103_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> 765606 DEBUG (simCloudManagerPool-3170-thread-7) [ ] o.a.s.c.a.s.SimClusterStateProvider ** creating new collection states
[junit4] 2> 765606 DEBUG (simCloudManagerPool-3170-thread-7) [ ] o.a.s.c.a.s.SimClusterStateProvider ** saved cluster state version 20
[junit4] 2> 765616 DEBUG (simCloudManagerPool-3170-thread-6) [ ] o.a.s.c.a.s.SimClusterStateProvider ** creating new collection states
[junit4] 2> 765616 DEBUG (simCloudManagerPool-3170-thread-6) [ ] o.a.s.c.a.s.SimClusterStateProvider ** saved cluster state version 21
[junit4] 2> 765617 DEBUG (ScheduledTrigger-3171-thread-4) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 4
[junit4] 2> 765617 DEBUG (ScheduledTrigger-3171-thread-3) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: node_lost_trigger with currently live nodes: 4
[junit4] 2> 765628 DEBUG (simCloudManagerPool-3170-thread-8) [ ] o.a.s.c.a.s.SimClusterStateProvider ** creating new collection states
[junit4] 2> 765628 DEBUG (simCloudManagerPool-3170-thread-8) [ ] o.a.s.c.a.s.SimClusterStateProvider ** saved cluster state version 22
[junit4] 2> 765637 DEBUG (ScheduledTrigger-3171-thread-1) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 4
[junit4] 2> 765638 DEBUG (ScheduledTrigger-3171-thread-1) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: node_lost_trigger with currently live nodes: 4
[junit4] 2> 765638 DEBUG (simCloudManagerPool-3170-thread-12) [ ] o.a.s.c.a.s.SimClusterStateProvider -- elected new leader for testNodeWithMultipleReplicasLost / shard2: {"core_node4":{
[junit4] 2> "core":"testNodeWithMultipleReplicasLost_shard2_replica_n4",
[junit4] 2> "shard":"shard2",
[junit4] 2> "collection":"testNodeWithMultipleReplicasLost",
[junit4] 2> "node_name":"127.0.0.1:10104_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> 765639 DEBUG (simCloudManagerPool-3170-thread-9) [ ] o.a.s.c.a.s.SimClusterStateProvider ** creating new collection states
[junit4] 2> 765639 DEBUG (simCloudManagerPool-3170-thread-9) [ ] o.a.s.c.a.s.SimClusterStateProvider ** saved cluster state version 23
[junit4] 2> 765649 DEBUG (simCloudManagerPool-3170-thread-10) [ ] o.a.s.c.a.s.SimClusterStateProvider ** creating new collection states
[junit4] 2> 765649 DEBUG (simCloudManagerPool-3170-thread-10) [ ] o.a.s.c.a.s.SimClusterStateProvider ** saved cluster state version 24
[junit4] 2> 765650 DEBUG (TEST-TestSimComputePlanAction.testNodeWithMultipleReplicasLost-seed#[FB1D8D6D09040CB4]) [ ] o.a.s.c.a.s.SimClusterStateProvider ** creating new collection states
[junit4] 2> 765650 DEBUG (TEST-TestSimComputePlanAction.testNodeWithMultipleReplicasLost-seed#[FB1D8D6D09040CB4]) [ ] o.a.s.c.a.s.SimClusterStateProvider ** saved cluster state version 25
[junit4] 2> 765650 DEBUG (TEST-TestSimComputePlanAction.testNodeWithMultipleReplicasLost-seed#[FB1D8D6D09040CB4]) [ ] o.a.s.c.a.s.TestSimComputePlanAction -- cluster state: znodeVersion: 27
[junit4] 2> live nodes:[127.0.0.1:10102_solr, 127.0.0.1:10100_solr, 127.0.0.1:10104_solr, 127.0.0.1:10103_solr]
[junit4] 2> collections:{.system=DocCollection(.system//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":"1",
[junit4] 2> "tlogReplicas":"0",
[junit4] 2> "autoCreated":"true",
[junit4] 2> "shards":{"shard1":{
[junit4] 2> "replicas":{"core_node2":{
[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:10100_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"}}}, testNodeWithMultipleReplicasLost=DocCollection(testNodeWithMultipleReplicasLost//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":"3",
[junit4] 2> "tlogReplicas":"0",
[junit4] 2> "autoCreated":"true",
[junit4] 2> "shards":{
[junit4] 2> "shard2":{
[junit4] 2> "replicas":{
[junit4] 2> "core_node6":{
[junit4] 2> "core":"testNodeWithMultipleReplicasLost_shard2_replica_n6",
[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:10103_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":"testNodeWithMultipleReplicasLost_shard2_replica_n4",
[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:10104_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_node5":{
[junit4] 2> "core":"testNodeWithMultipleReplicasLost_shard2_replica_n5",
[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:10102_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":"0-7fffffff",
[junit4] 2> "state":"active"},
[junit4] 2> "shard1":{
[junit4] 2> "replicas":{
[junit4] 2> "core_node1":{
[junit4] 2> "core":"testNodeWithMultipleReplicasLost_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:10103_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":"testNodeWithMultipleReplicasLost_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:10102_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":"testNodeWithMultipleReplicasLost_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:10104_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-ffffffff",
[junit4] 2> "state":"active"}}}}
[junit4] 2> 765652 DEBUG (TEST-TestSimComputePlanAction.testNodeWithMultipleReplicasLost-seed#[FB1D8D6D09040CB4]) [ ] o.a.s.c.a.s.SimClusterStateProvider ** creating new collection states
[junit4] 2> 765652 DEBUG (TEST-TestSimComputePlanAction.testNodeWithMultipleReplicasLost-seed#[FB1D8D6D09040CB4]) [ ] o.a.s.c.a.s.SimClusterStateProvider ** saved cluster state version 26
[junit4] 2> 765653 INFO (simCloudManagerPool-3170-thread-13) [ ] o.a.s.c.ActionThrottle Throttling leader attempts - waiting for 4273ms
[junit4] 2> 765661 DEBUG (ScheduledTrigger-3171-thread-2) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: node_lost_trigger with currently live nodes: 3
[junit4] 2> 765661 DEBUG (ScheduledTrigger-3171-thread-2) [ ] o.a.s.c.a.NodeLostTrigger Tracking lost node: 127.0.0.1:10104_solr
[junit4] 2> 765661 DEBUG (ScheduledTrigger-3171-thread-1) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 3
[junit4] 2> 765661 DEBUG (ScheduledTrigger-3171-thread-1) [ ] o.a.s.c.a.NodeLostTrigger Tracking lost node: 127.0.0.1:10104_solr
[junit4] 2> 765682 DEBUG (ScheduledTrigger-3171-thread-2) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: node_lost_trigger with currently live nodes: 3
[junit4] 2> 765682 DEBUG (ScheduledTrigger-3171-thread-2) [ ] o.a.s.c.a.NodeLostTrigger NodeLostTrigger firing registered processor for lost nodes: [127.0.0.1:10104_solr]
[junit4] 2> 765682 DEBUG (ScheduledTrigger-3171-thread-2) [ ] o.a.s.c.a.ScheduledTriggers ++++++++ Cooldown inactive - processing event: {
[junit4] 2> "id":"5054ec29f8d80Tb5ava2ta1466re7k0hezrjk57",
[junit4] 2> "source":"node_lost_trigger",
[junit4] 2> "eventTime":1413210714377600,
[junit4] 2> "eventType":"NODELOST",
[junit4] 2> "properties":{
[junit4] 2> "eventTimes":[1413210714377600],
[junit4] 2> "preferredOperation":"movereplica",
[junit4] 2> "nodeNames":["127.0.0.1:10104_solr"]}}
[junit4] 2> 765682 DEBUG (ScheduledTrigger-3171-thread-2) [ ] o.a.s.c.a.ScheduledTriggers Pausing all triggers: [.auto_add_replicas, .scheduled_maintenance, node_lost_trigger]
[junit4] 2> 765683 DEBUG (AutoscalingActionExecutor-3172-thread-1) [ ] o.a.s.c.a.ScheduledTriggers -- processing actions for {
[junit4] 2> "id":"5054ec29f8d80Tb5ava2ta1466re7k0hezrjk57",
[junit4] 2> "source":"node_lost_trigger",
[junit4] 2> "eventTime":1413210714377600,
[junit4] 2> "eventType":"NODELOST",
[junit4] 2> "properties":{
[junit4] 2> "eventTimes":[1413210714377600],
[junit4] 2> "preferredOperation":"movereplica",
[junit4] 2> "_enqueue_time_":1413211804052600,
[junit4] 2> "nodeNames":["127.0.0.1:10104_solr"]}}
[junit4] 2> 765683 DEBUG (AutoscalingActionExecutor-3172-thread-1) [ ] o.a.s.c.a.ComputePlanAction -- processing event: {
[junit4] 2> "id":"5054ec29f8d80Tb5ava2ta1466re7k0hezrjk57",
[junit4] 2> "source":"node_lost_trigger",
[junit4] 2> "eventTime":1413210714377600,
[junit4] 2> "eventType":"NODELOST",
[junit4] 2> "properties":{
[junit4] 2> "eventTimes":[1413210714377600],
[junit4] 2> "preferredOperation":"movereplica",
[junit4] 2> "_enqueue_time_":1413211804052600,
[junit4] 2> "nodeNames":["127.0.0.1:10104_solr"]}} with context properties: {BEFORE_ACTION=[compute_plan]}
[junit4] 2> 765684 DEBUG (AutoscalingActionExecutor-3172-thread-1) [ ] o.a.s.c.s.c.a.PolicyHelper Creating a new session
[junit4] 2> 765684 DEBUG (AutoscalingActionExecutor-3172-thread-1) [ ] o.a.s.c.s.c.a.PolicyHelper New session created
[junit4] 2> 765692 DEBUG (AutoscalingActionExecutor-3172-thread-1) [ ] o.a.s.c.a.ComputePlanAction Computed Plan: action=MOVEREPLICA&collection=testNodeWithMultipleReplicasLost&targetNode=127.0.0.1:10100_solr&inPlaceMove=true&replica=core_node4
[junit4] 2> 765693 DEBUG (AutoscalingActionExecutor-3172-thread-1) [ ] o.a.s.c.a.ComputePlanAction Computed Plan: action=MOVEREPLICA&collection=testNodeWithMultipleReplicasLost&targetNode=127.0.0.1:10100_solr&inPlaceMove=true&replica=core_node3
[junit4] 2> 765693 DEBUG (AutoscalingActionExecutor-3172-thread-1) [ ] o.a.s.c.s.c.a.PolicyHelper returnSession, curr-time 1413212352 sessionWrapper.createTime 1413211922672600, this.sessionWrapper.createTime 1413211922672600
[junit4] 2> 765693 DEBUG (AutoscalingActionExecutor-3172-thread-1) [ ] o.a.s.c.s.c.a.PolicyHelper session set to NULL
[junit4] 2> 765695 INFO (TEST-TestSimComputePlanAction.testNodeWithMultipleReplicasLost-seed#[FB1D8D6D09040CB4]) [ ] o.a.s.c.a.s.TestSimComputePlanAction action=MOVEREPLICA&collection=testNodeWithMultipleReplicasLost&targetNode=127.0.0.1:10100_solr&inPlaceMove=true&replica=core_node4
[junit4] 2> 765695 INFO (TEST-TestSimComputePlanAction.testNodeWithMultipleReplicasLost-seed#[FB1D8D6D09040CB4]) [ ] o.a.s.c.a.s.TestSimComputePlanAction action=MOVEREPLICA&collection=testNodeWithMultipleReplicasLost&targetNode=127.0.0.1:10100_solr&inPlaceMove=true&replica=core_node3
[junit4] 2> 765695 INFO (TEST-TestSimComputePlanAction.testNodeWithMultipleReplicasLost-seed#[FB1D8D6D09040CB4]) [ ] o.a.s.c.a.s.TestSimComputePlanAction -------------_ FINAL STATE --------------
[junit4] 2> 765695 INFO (TEST-TestSimComputePlanAction.testNodeWithMultipleReplicasLost-seed#[FB1D8D6D09040CB4]) [ ] o.a.s.c.a.s.TestSimComputePlanAction * Node values: {
[junit4] 2> "127.0.0.1:10100_solr":{
[junit4] 2> "sysprop.java.vendor":"Oracle Corporation",
[junit4] 2> "cores":1,
[junit4] 2> "host":"127.0.0.1",
[junit4] 2> "freedisk":999,
[junit4] 2> "sysprop.java.version":"9.0.4",
[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:10100_solr",
[junit4] 2> "metrics:solr.jvm:buffers.direct.Count":0,
[junit4] 2> "port":10100,
[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:10104_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":"9.0.4",
[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:10104_solr",
[junit4] 2> "metrics:solr.jvm:buffers.direct.Count":0,
[junit4] 2> "port":10104,
[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:10102_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":"9.0.4",
[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:10102_solr",
[junit4] 2> "metrics:solr.jvm:buffers.direct.Count":0,
[junit4] 2> "port":10102,
[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:10103_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":"9.0.4",
[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:10103_solr",
[junit4] 2> "metrics:solr.jvm:buffers.direct.Count":0,
[junit4] 2> "port":10103,
[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> 765695 INFO (TEST-TestSimComputePlanAction.testNodeWithMultipleReplicasLost-seed#[FB1D8D6D09040CB4]) [ ] o.a.s.c.a.s.TestSimComputePlanAction * Live nodes: [127.0.0.1:10100_solr, 127.0.0.1:10102_solr, 127.0.0.1:10103_solr]
[junit4] 2> 765695 INFO (TEST-TestSimComputePlanAction.testNodeWithMultipleReplicasLost-seed#[FB1D8D6D09040CB4]) [ ] o.a.s.c.a.s.TestSimComputePlanAction * Collection .system state: DocCollection(.system//clusterstate.json/28)={
[junit4] 2> "replicationFactor":"1",
[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":{"core_node2":{
[junit4] 2> "core":".system_shard1_replica_n1",
[junit4] 2> "leader":"true",
[junit4] 2> "SEARCHER.searcher.maxDoc":4,
[junit4] 2> "SEARCHER.searcher.deletedDocs":0,
[junit4] 2> "INDEX.sizeInBytes":12240,
[junit4] 2> "node_name":"127.0.0.1:10100_solr",
[junit4] 2> "state":"active",
[junit4] 2> "type":"NRT",
[junit4] 2> "INDEX.sizeInGB":1.1399388313293457E-5,
[junit4] 2> "SEARCHER.searcher.numDocs":4}},
[junit4] 2> "range":"80000000-7fffffff",
[junit4] 2> "state":"active"}}}
[junit4] 2> 765696 INFO (TEST-TestSimComputePlanAction.testNodeWithMultipleReplicasLost-seed#[FB1D8D6D09040CB4]) [ ] o.a.s.c.a.s.TestSimComputePlanAction * Collection testNodeWithMultipleReplicasLost state: DocCollection(testNodeWithMultipleReplicasLost//clusterstate.json/28)={
[junit4] 2> "replicationFactor":"1",
[junit4] 2> "pullReplicas":"0",
[junit4] 2> "router":{"name":"compositeId"},
[junit4] 2> "maxShardsPerNode":"1",
[junit4] 2> "autoAddReplicas":"false",
[junit4] 2> "nrtReplicas":"3",
[junit4] 2> "tlogReplicas":"0",
[junit4] 2> "autoCreated":"true",
[junit4] 2> "shards":{
[junit4] 2> "shard2":{
[junit4] 2> "replicas":{
[junit4] 2> "core_node6":{
[junit4] 2> "core":"testNodeWithMultipleReplicasLost_shard2_replica_n6",
[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:10103_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":"testNodeWithMultipleReplicasLost_shard2_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:10104_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_node5":{
[junit4] 2> "core":"testNodeWithMultipleReplicasLost_shard2_replica_n5",
[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:10102_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":"0-7fffffff",
[junit4] 2> "state":"active"},
[junit4] 2> "shard1":{
[junit4] 2> "replicas":{
[junit4] 2> "core_node1":{
[junit4] 2> "core":"testNodeWithMultipleReplicasLost_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:10103_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":"testNodeWithMultipleReplicasLost_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:10102_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":"testNodeWithMultipleReplicasLost_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:10104_solr",
[junit4] 2> "state":"down",
[junit4] 2> "type":"NRT",
[junit4] 2> "INDEX.sizeInGB":9.5367431640625E-6,
[junit4] 2> "SEARCHER.searcher.numDocs":0}},
[junit4] 2> "range":"80000000-ffffffff",
[junit4] 2> "state":"active"}}}
[junit4] 2> 765696 INFO (TEST-TestSimComputePlanAction.testNodeWithMultipleReplicasLost-seed#[FB1D8D6D09040CB4]) [ ] o.a.s.SolrTestCaseJ4 ###Ending testNodeWithMultipleReplicasLost
[junit4] 2> 765696 DEBUG (TEST-TestSimComputePlanAction.testNodeWithMultipleReplicasLost-seed#[FB1D8D6D09040CB4]) [ ] o.a.s.c.a.s.SimClusterStateProvider ** creating new collection states
[junit4] 2> 765697 DEBUG (TEST-TestSimComputePlanAction.testNodeWithMultipleReplicasLost-seed#[FB1D8D6D09040CB4]) [ ] o.a.s.c.a.s.SimClusterStateProvider ** saved cluster state version 27
[junit4] 2> 765698 INFO (TEST-TestSimComputePlanAction.testNodeWithMultipleReplicasLost-seed#[FB1D8D6D09040CB4]) [ ] o.a.s.c.a.s.SimSolrCloudTestCase #######################################
[junit4] 2> ############ CLUSTER STATE ############
[junit4] 2> #######################################
[junit4] 2> ## Live nodes: 3
[junit4] 2> ## Empty nodes: 0
[junit4] 2> ## Dead nodes: 1
[junit4] 2> ## 127.0.0.1:10104_solr
[junit4] 2> ## Collections:
[junit4] 2> ## * .system
[junit4] 2> ## shardsTotal 1
[junit4] 2> ## shardsState {active=1}
[junit4] 2> ## shardsWithoutLeader 0
[junit4] 2> ## totalReplicas 1
[junit4] 2> ## activeReplicas 1
[junit4] 2> ## inactiveReplicas 0
[junit4] 2> ## totalActiveDocs 4
[junit4] 2> ## bufferedDocs 0
[junit4] 2> ## maxActiveSliceDocs 4
[junit4] 2> ## minActiveSliceDocs 4
[junit4] 2> ## avgActiveSliceDocs 4
[junit4] 2> ## totalInactiveDocs 0
[junit4] 2> ## maxInactiveSliceDocs 0
[junit4] 2> ## minInactiveSliceDocs 0
[junit4] 2> ## avgInactiveSliceDocs NaN
[junit4] 2> ## totalActiveBytes 12,240
[junit4] 2> ## maxActiveSliceBytes 12,240
[junit4] 2> ## minActiveSliceBytes 12,240
[junit4] 2> ## avgActiveSliceBytes 12,240
[junit4] 2> ## totalInactiveBytes 0
[junit4] 2> ## maxInactiveSliceBytes 0
[junit4] 2> ## minInactiveSliceBytes 0
[junit4] 2> ## avgInactiveSliceBytes NaN
[junit4] 2> ## totalActiveDeletedDocs 0
[junit4] 2> ## * testNodeWithMultipleReplicasLost
[junit4] 2> ## shardsTotal 2
[junit4] 2> ## shardsState {active=2}
[junit4] 2> ## shardsWithoutLeader 1
[junit4] 2> ## totalReplicas 6
[junit4] 2> ## activeReplicas 6
[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 20,480
[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: 1
[junit4] 2> ## Total replicas: 5
[junit4] 2> ## * .system 1
[junit4] 2> ## - active 1
[junit4] 2> ## * testNodeWithMultipleReplicasLost 4
[junit4] 2> ## - active 4
[junit4] 2> ######### Solr op counts ##########
[junit4] 2> ## - CREATE 1
[junit4] 2> ## - autoscaling 3
[junit4] 2> ## - update 2
[junit4] 2> ######### Autoscaling event counts ###########
[junit4] 2> ## * Trigger: node_added_trigger
[junit4] 2> ## - AFTER_ACTION 1
[junit4] 2> ## - BEFORE_ACTION 1
[junit4] 2> ## - FAILED 1
[junit4] 2> ## - STARTED 1
[junit4] 2> ## * Trigger: node_lost_trigger
[junit4] 2> ## - BEFORE_ACTION 1
[junit4] 2> ## - STARTED 1
[junit4] 2>
[junit4] 2> 765704 DEBUG (AutoscalingActionExecutor-3172-thread-1) [ ] o.a.s.c.a.ScheduledTriggers Resuming trigger: .auto_add_replicas after 100ms
[junit4] 2> 765704 DEBUG (AutoscalingActionExecutor-3172-thread-1) [ ] o.a.s.c.a.ScheduledTriggers Resuming trigger: .scheduled_maintenance after 100ms
[junit4] 2> 765704 DEBUG (AutoscalingActionExecutor-3172-thread-1) [ ] o.a.s.c.a.ScheduledTriggers Resuming trigger: node_lost_trigger after 100ms
[junit4] 2> 765704 DEBUG (AutoscalingActionExecutor-3172-thread-1) [ ] o.a.s.c.a.ScheduledTriggers -- processing took 1048 ms for event id=5054ec29f8d80Tb5ava2ta1466re7k0hezrjk57
[junit4] 2> 765706 INFO (TEST-TestSimComputePlanAction.testNodeLost-seed#[FB1D8D6D09040CB4]) [ ] o.a.s.SolrTestCaseJ4 ###Starting testNodeLost
[junit4] 2> 765707 DEBUG (TEST-TestSimComputePlanAction.testNodeLost-seed#[FB1D8D6D09040CB4]) [ ] o.a.s.c.a.OverseerTriggerThread Refreshing /autoscaling.json with znode version 12
[junit4] 2> 765707 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Processed trigger updates upto znodeVersion 12
[junit4] 2> 765707 DEBUG (TEST-TestSimComputePlanAction.testNodeLost-seed#[FB1D8D6D09040CB4]) [ ] o.a.s.c.a.s.SimNodeStateProvider - removing dead node values: 127.0.0.1:10104_solr
[junit4] 2> 765707 DEBUG (TEST-TestSimComputePlanAction.testNodeLost-seed#[FB1D8D6D09040CB4]) [ ] o.a.s.c.a.s.SimClusterStateProvider --- new Overseer leader: 127.0.0.1:10102_solr
[junit4] 2> 765707 DEBUG (TEST-TestSimComputePlanAction.testNodeLost-seed#[FB1D8D6D09040CB4]) [ ] o.a.s.c.a.s.SimNodeStateProvider --removing value for 127.0.0.1:10100_solr
[junit4] 2> 765707 DEBUG (TEST-TestSimComputePlanAction.testNodeLost-seed#[FB1D8D6D09040CB4]) [ ] o.a.s.c.a.s.SimClusterStateProvider --- new Overseer leader: 127.0.0.1:10103_solr
[junit4] 2> 765707 DEBUG (TEST-TestSimComputePlanAction.testNodeLost-seed#[FB1D8D6D09040CB4]) [ ] o.a.s.c.a.s.SimNodeStateProvider --removing value for 127.0.0.1:10102_solr
[junit4] 2> 765707 INFO (TEST-TestSimComputePlanAction.testNodeLost-seed#[FB1D8D6D09040CB4]) [ ] o.a.s.c.a.s.SimCloudManager === Restarting OverseerTriggerThread and clearing object cache...
[junit4] 2> 765707 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread -- clean old nodeLost markers
[junit4] 2> 765707 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread -- clean old nodeAdded markers
[junit4] 2> 765707 WARN (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Interrupted
[junit4] 2> java.lang.InterruptedException: null
[junit4] 2> at java.util.concurrent.locks.AbstractQueuedSynchronizer.acquireInterruptibly(AbstractQueuedSynchronizer.java:1247) ~[?:?]
[junit4] 2> at java.util.concurrent.locks.ReentrantLock.lockInterruptibly(ReentrantLock.java:317) ~[?:?]
[junit4] 2> at org.apache.solr.cloud.autoscaling.OverseerTriggerThread.run(OverseerTriggerThread.java:177) [java/:?]
[junit4] 2> at java.lang.Thread.run(Thread.java:844) [?:?]
[junit4] 2> 765708 DEBUG (TEST-TestSimComputePlanAction.testNodeLost-seed#[FB1D8D6D09040CB4]) [ ] o.a.s.c.a.ScheduledTriggers Shutting down scheduled thread pool executor now
[junit4] 2> 765708 DEBUG (TEST-TestSimComputePlanAction.testNodeLost-seed#[FB1D8D6D09040CB4]) [ ] o.a.s.c.a.ScheduledTriggers Shutting down action executor now
[junit4] 2> 765708 DEBUG (TEST-TestSimComputePlanActio
[...truncated too long message...]
eBytes 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: 1
[junit4] 2> ## Min replicas per node: 1
[junit4] 2> ## Total replicas: 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 2
[junit4] 2> ######### Autoscaling event counts ###########
[junit4] 2> ## * Trigger: node_added_trigger
[junit4] 2> ## - AFTER_ACTION 1
[junit4] 2> ## - BEFORE_ACTION 1
[junit4] 2> ## - STARTED 1
[junit4] 2> ## - SUCCEEDED 1
[junit4] 2> ## * Trigger: node_lost_trigger
[junit4] 2> ## - AFTER_ACTION 1
[junit4] 2> ## - BEFORE_ACTION 2
[junit4] 2> ## - STARTED 2
[junit4] 2> ## - SUCCEEDED 1
[junit4] 2>
[junit4] OK 0.54s J0 | TestSimComputePlanAction.testNodeLost
[junit4] 2> 13418 DEBUG (simCloudManagerPool-13-thread-13) [ ] o.a.s.c.a.s.SimClusterStateProvider -- no leader in shard1:{
[junit4] 2> "replicas":{"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:10006_solr",
[junit4] 2> "state":"down",
[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> 13418 WARN (simCloudManagerPool-13-thread-14) [ ] o.a.s.c.a.s.SimClusterStateProvider Can't find any active replicas for .system / shard1: shard1:{
[junit4] 2> "replicas":{"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:10006_solr",
[junit4] 2> "state":"down",
[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> 13419 DEBUG (simCloudManagerPool-13-thread-14) [ ] o.a.s.c.a.s.SimClusterStateProvider -- liveNodes: [127.0.0.1:10003_solr]
[junit4] 2> 13420 DEBUG (simCloudManagerPool-13-thread-15) [ ] o.a.s.c.a.s.SimClusterStateProvider -- no leader in shard1:{
[junit4] 2> "replicas":{"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:10006_solr",
[junit4] 2> "state":"down",
[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> 13420 DEBUG (AutoscalingActionExecutor-15-thread-1) [ ] o.a.s.c.a.ScheduledTriggers Resuming trigger: .auto_add_replicas after 100ms
[junit4] 2> 13420 DEBUG (AutoscalingActionExecutor-15-thread-1) [ ] o.a.s.c.a.ScheduledTriggers Resuming trigger: .scheduled_maintenance after 100ms
[junit4] 2> 13420 DEBUG (AutoscalingActionExecutor-15-thread-1) [ ] o.a.s.c.a.ScheduledTriggers Resuming trigger: node_lost_trigger after 100ms
[junit4] 2> 13420 DEBUG (AutoscalingActionExecutor-15-thread-1) [ ] o.a.s.c.a.ScheduledTriggers -- processing took 978 ms for event id=4eb2b26ad99b8Tb5ava2ta1466re7k0hezrjhev
[junit4] 2> 13439 DEBUG (SUITE-TestSimComputePlanAction-seed#[FB1D8D6D09040CB4]-worker) [ ] o.a.s.c.a.ScheduledTriggers Shutting down scheduled thread pool executor now
[junit4] 2> 13439 DEBUG (SUITE-TestSimComputePlanAction-seed#[FB1D8D6D09040CB4]-worker) [ ] o.a.s.c.a.ScheduledTriggers Shutting down action executor now
[junit4] 2> 13439 DEBUG (SUITE-TestSimComputePlanAction-seed#[FB1D8D6D09040CB4]-worker) [ ] o.a.s.c.a.ScheduledTriggers Awaiting termination for action executor
[junit4] 2> 13439 WARN (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread OverseerTriggerThread woken up but we are closed, exiting.
[junit4] 2> 13440 DEBUG (SUITE-TestSimComputePlanAction-seed#[FB1D8D6D09040CB4]-worker) [ ] o.a.s.c.a.ScheduledTriggers Awaiting termination for scheduled thread pool executor
[junit4] 2> 13440 DEBUG (SUITE-TestSimComputePlanAction-seed#[FB1D8D6D09040CB4]-worker) [ ] o.a.s.c.a.ScheduledTriggers ScheduledTriggers closed completely
[junit4] 2> 13440 DEBUG (SUITE-TestSimComputePlanAction-seed#[FB1D8D6D09040CB4]-worker) [ ] o.a.s.c.a.OverseerTriggerThread OverseerTriggerThread has been closed explicitly
[junit4] 2> NOTE: leaving temporary files on disk at: C:\Users\jenkins\workspace\Lucene-Solr-7.x-Windows\solr\build\solr-core\test\J0\temp\solr.cloud.autoscaling.sim.TestSimComputePlanAction_FB1D8D6D09040CB4-001
[junit4] 2> NOTE: test params are: codec=Asserting(Lucene70), sim=RandomSimilarity(queryNorm=true): {}, locale=en-CK, timezone=Pacific/Palau
[junit4] 2> NOTE: Windows 10 10.0 amd64/Oracle Corporation 9.0.4 (64-bit)/cpus=3,threads=1,free=42038272,total=100663296
[junit4] 2> NOTE: All tests run in this JVM: [TestSimComputePlanAction]
[junit4] Completed [1/5 (1!)] on J0 in 12.33s, 3 tests, 1 error <<< FAILURES!
[...truncated 35 lines...]
BUILD FAILED
C:\Users\jenkins\workspace\Lucene-Solr-7.x-Windows\lucene\common-build.xml:1567: The following error occurred while executing this line:
C:\Users\jenkins\workspace\Lucene-Solr-7.x-Windows\lucene\common-build.xml:1092: There were test failures: 5 suites, 15 tests, 1 error [seed: FB1D8D6D09040CB4]
Total time: 19 seconds
[repro] Setting last failure code to 1
[repro] Failures:
[repro] 1/5 failed: org.apache.solr.cloud.autoscaling.sim.TestSimComputePlanAction
[repro] Exiting with code 1
C:\Users\jenkins\workspace\Lucene-Solr-7.x-Windows>IF EXIST lucene\build move /y lucene\build lucene\build.repro
1 dir(s) moved.
C:\Users\jenkins\workspace\Lucene-Solr-7.x-Windows>IF EXIST solr\build move /y solr\build solr\build.repro
1 dir(s) moved.
C:\Users\jenkins\workspace\Lucene-Solr-7.x-Windows>IF EXIST lucene\build.orig move /y lucene\build.orig lucene\build
1 dir(s) moved.
C:\Users\jenkins\workspace\Lucene-Solr-7.x-Windows>IF EXIST solr\build.orig move /y solr\build.orig solr\build
1 dir(s) moved.
C:\Users\jenkins\workspace\Lucene-Solr-7.x-Windows>exit 0
Archiving artifacts
Setting ANT_1_8_2_HOME=C:\Users\jenkins\tools\hudson.tasks.Ant_AntInstallation\ANT_1.8.2
[WARNINGS] Parsing warnings in console log with parser Java Compiler (javac)
Setting ANT_1_8_2_HOME=C:\Users\jenkins\tools\hudson.tasks.Ant_AntInstallation\ANT_1.8.2
Setting ANT_1_8_2_HOME=C:\Users\jenkins\tools\hudson.tasks.Ant_AntInstallation\ANT_1.8.2
<Git Blamer> Using GitBlamer to create author and commit information for all warnings.
<Git Blamer> GIT_COMMIT=6e6b00a0df7e86c8e8959788362ae3ff3d88b83f, workspace=C:\Users\jenkins\workspace\Lucene-Solr-7.x-Windows
[WARNINGS] Computing warning deltas based on reference build #812
Recording test results
Setting ANT_1_8_2_HOME=C:\Users\jenkins\tools\hudson.tasks.Ant_AntInstallation\ANT_1.8.2
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)
Setting ANT_1_8_2_HOME=C:\Users\jenkins\tools\hudson.tasks.Ant_AntInstallation\ANT_1.8.2
Setting ANT_1_8_2_HOME=C:\Users\jenkins\tools\hudson.tasks.Ant_AntInstallation\ANT_1.8.2
Setting ANT_1_8_2_HOME=C:\Users\jenkins\tools\hudson.tasks.Ant_AntInstallation\ANT_1.8.2
Setting ANT_1_8_2_HOME=C:\Users\jenkins\tools\hudson.tasks.Ant_AntInstallation\ANT_1.8.2