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/06/01 10:31:50 UTC

[JENKINS] Lucene-Solr-master-MacOSX (64bit/jdk1.8.0) - Build # 4667 - Unstable!

Build: https://jenkins.thetaphi.de/job/Lucene-Solr-master-MacOSX/4667/
Java: 64bit/jdk1.8.0 -XX:-UseCompressedOops -XX:+UseParallelGC

1 tests failed.
FAILED:  org.apache.solr.cloud.autoscaling.sim.TestComputePlanAction.testNodeAdded

Error Message:
ComputePlanAction should have computed exactly 1 operation, but was: [org.apache.solr.client.solrj.request.CollectionAdminRequest$MoveReplica@74c517, org.apache.solr.client.solrj.request.CollectionAdminRequest$MoveReplica@2015af47] expected:<1> but was:<2>

Stack Trace:
java.lang.AssertionError: ComputePlanAction should have computed exactly 1 operation, but was: [org.apache.solr.client.solrj.request.CollectionAdminRequest$MoveReplica@74c517, org.apache.solr.client.solrj.request.CollectionAdminRequest$MoveReplica@2015af47] expected:<1> but was:<2>
	at __randomizedtesting.SeedInfo.seed([BC5D7C28E88D0D59:D99E2A5F4A2EA55A]: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.TestComputePlanAction.testNodeAdded(TestComputePlanAction.java:313)
	at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
	at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
	at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
	at java.lang.reflect.Method.invoke(Method.java:498)
	at com.carrotsearch.randomizedtesting.RandomizedRunner.invoke(RandomizedRunner.java:1737)
	at com.carrotsearch.randomizedtesting.RandomizedRunner$8.evaluate(RandomizedRunner.java:934)
	at com.carrotsearch.randomizedtesting.RandomizedRunner$9.evaluate(RandomizedRunner.java:970)
	at com.carrotsearch.randomizedtesting.RandomizedRunner$10.evaluate(RandomizedRunner.java:984)
	at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:57)
	at org.apache.lucene.util.TestRuleSetupTeardownChained$1.evaluate(TestRuleSetupTeardownChained.java:49)
	at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:45)
	at org.apache.lucene.util.TestRuleThreadAndTestName$1.evaluate(TestRuleThreadAndTestName.java:48)
	at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:64)
	at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:47)
	at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
	at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:368)
	at com.carrotsearch.randomizedtesting.ThreadLeakControl.forkTimeoutingTask(ThreadLeakControl.java:817)
	at com.carrotsearch.randomizedtesting.ThreadLeakControl$3.evaluate(ThreadLeakControl.java:468)
	at com.carrotsearch.randomizedtesting.RandomizedRunner.runSingleTest(RandomizedRunner.java:943)
	at com.carrotsearch.randomizedtesting.RandomizedRunner$5.evaluate(RandomizedRunner.java:829)
	at com.carrotsearch.randomizedtesting.RandomizedRunner$6.evaluate(RandomizedRunner.java:879)
	at com.carrotsearch.randomizedtesting.RandomizedRunner$7.evaluate(RandomizedRunner.java:890)
	at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
	at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:57)
	at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:45)
	at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
	at org.apache.lucene.util.TestRuleStoreClassName$1.evaluate(TestRuleStoreClassName.java:41)
	at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:40)
	at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:40)
	at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
	at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
	at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
	at org.apache.lucene.util.TestRuleAssertionsRequired$1.evaluate(TestRuleAssertionsRequired.java:53)
	at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:47)
	at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:64)
	at org.apache.lucene.util.TestRuleIgnoreTestSuites$1.evaluate(TestRuleIgnoreTestSuites.java:54)
	at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
	at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:368)
	at java.lang.Thread.run(Thread.java:748)




Build Log:
[...truncated 14410 lines...]
   [junit4] Suite: org.apache.solr.cloud.autoscaling.sim.TestComputePlanAction
   [junit4]   2> Creating dataDir: /Users/jenkins/workspace/Lucene-Solr-master-MacOSX/solr/build/solr-core/test/J1/temp/solr.cloud.autoscaling.sim.TestComputePlanAction_BC5D7C28E88D0D59-001/init-core-data-001
   [junit4]   2> 2619602 DEBUG (SUITE-TestComputePlanAction-seed#[BC5D7C28E88D0D59]-worker) [    ] o.a.s.c.a.s.SimClusterStateProvider --- new Overseer leader: 127.0.0.1:10009_solr
   [junit4]   2> 2619603 DEBUG (Simulated OverseerAutoScalingTriggerThread) [    ] o.a.s.c.a.OverseerTriggerThread Adding .auto_add_replicas and .scheduled_maintenance triggers
   [junit4]   2> 2619603 DEBUG (Simulated OverseerAutoScalingTriggerThread) [    ] o.a.s.c.a.OverseerTriggerThread Refreshing /autoscaling.json with znode version 0
   [junit4]   2> 2619603 DEBUG (Simulated OverseerAutoScalingTriggerThread) [    ] o.a.s.c.a.OverseerTriggerThread Current znodeVersion 0, lastZnodeVersion -1
   [junit4]   2> 2619603 DEBUG (Simulated OverseerAutoScalingTriggerThread) [    ] o.a.s.c.a.OverseerTriggerThread Processed trigger updates upto znodeVersion 0
   [junit4]   2> 2619604 WARN  (SUITE-TestComputePlanAction-seed#[BC5D7C28E88D0D59]-worker) [    ] o.a.s.h.a.MetricsHistoryHandler Missing .system, keeping metrics history in memory
   [junit4]   2> 2619605 DEBUG (Simulated OverseerAutoScalingTriggerThread) [    ] o.a.s.c.a.NodeLostTrigger NodeLostTrigger .auto_add_replicas - Initial livenodes: [127.0.0.1:10009_solr]
   [junit4]   2> 2619606 DEBUG (Simulated OverseerAutoScalingTriggerThread) [    ] o.a.s.c.a.OverseerTriggerThread -- clean old nodeAdded markers
   [junit4]   2> 2619606 DEBUG (Simulated OverseerAutoScalingTriggerThread) [    ] o.a.s.c.a.OverseerTriggerThread Current znodeVersion 0, lastZnodeVersion 0
   [junit4]   2> 2619609 DEBUG (ScheduledTrigger-9983-thread-2) [    ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 1
   [junit4]   2> 2619636 DEBUG (ScheduledTrigger-9983-thread-4) [    ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 1
   [junit4]   2> 2619641 DEBUG (TEST-TestComputePlanAction.testNodeLost-seed#[BC5D7C28E88D0D59]) [    ] o.a.s.c.a.OverseerTriggerThread Refreshing /autoscaling.json with znode version 1
   [junit4]   2> 2619641 DEBUG (Simulated OverseerAutoScalingTriggerThread) [    ] o.a.s.c.a.OverseerTriggerThread Processed trigger updates upto znodeVersion 1
   [junit4]   2> 2619641 INFO  (TEST-TestComputePlanAction.testNodeLost-seed#[BC5D7C28E88D0D59]) [    ] o.a.s.c.a.s.SimCloudManager === Restarting OverseerTriggerThread and clearing object cache...
   [junit4]   2> 2619642 DEBUG (Simulated OverseerAutoScalingTriggerThread) [    ] o.a.s.c.a.OverseerTriggerThread -- clean old nodeLost markers
   [junit4]   2> 2619646 DEBUG (Simulated OverseerAutoScalingTriggerThread) [    ] o.a.s.c.a.OverseerTriggerThread -- clean old nodeAdded markers
   [junit4]   2> 2619646 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:1220) ~[?:1.8.0_172]
   [junit4]   2> 	at java.util.concurrent.locks.ReentrantLock.lockInterruptibly(ReentrantLock.java:335) ~[?:1.8.0_172]
   [junit4]   2> 	at org.apache.solr.cloud.autoscaling.OverseerTriggerThread.run(OverseerTriggerThread.java:177) [java/:?]
   [junit4]   2> 	at java.lang.Thread.run(Thread.java:748) [?:1.8.0_172]
   [junit4]   2> 2619649 DEBUG (TEST-TestComputePlanAction.testNodeLost-seed#[BC5D7C28E88D0D59]) [    ] o.a.s.c.a.ScheduledTriggers Shutting down scheduled thread pool executor now
   [junit4]   2> 2619649 DEBUG (TEST-TestComputePlanAction.testNodeLost-seed#[BC5D7C28E88D0D59]) [    ] o.a.s.c.a.ScheduledTriggers Shutting down action executor now
   [junit4]   2> 2619649 DEBUG (TEST-TestComputePlanAction.testNodeLost-seed#[BC5D7C28E88D0D59]) [    ] o.a.s.c.a.ScheduledTriggers Awaiting termination for action executor
   [junit4]   2> 2619649 DEBUG (TEST-TestComputePlanAction.testNodeLost-seed#[BC5D7C28E88D0D59]) [    ] o.a.s.c.a.ScheduledTriggers Awaiting termination for scheduled thread pool executor
   [junit4]   2> 2619649 DEBUG (TEST-TestComputePlanAction.testNodeLost-seed#[BC5D7C28E88D0D59]) [    ] o.a.s.c.a.ScheduledTriggers ScheduledTriggers closed completely
   [junit4]   2> 2619649 DEBUG (TEST-TestComputePlanAction.testNodeLost-seed#[BC5D7C28E88D0D59]) [    ] o.a.s.c.a.OverseerTriggerThread OverseerTriggerThread has been closed explicitly
   [junit4]   2> 2619650 DEBUG (Simulated OverseerAutoScalingTriggerThread) [    ] o.a.s.c.a.OverseerTriggerThread Adding .auto_add_replicas and .scheduled_maintenance triggers
   [junit4]   2> 2619650 DEBUG (Simulated OverseerAutoScalingTriggerThread) [    ] o.a.s.c.a.OverseerTriggerThread Refreshing /autoscaling.json with znode version 2
   [junit4]   2> 2619653 DEBUG (Simulated OverseerAutoScalingTriggerThread) [    ] o.a.s.c.a.OverseerTriggerThread Current znodeVersion 2, lastZnodeVersion -1
   [junit4]   2> 2619653 DEBUG (Simulated OverseerAutoScalingTriggerThread) [    ] o.a.s.c.a.OverseerTriggerThread Processed trigger updates upto znodeVersion 2
   [junit4]   2> 2619654 DEBUG (Simulated OverseerAutoScalingTriggerThread) [    ] o.a.s.c.a.NodeLostTrigger NodeLostTrigger .auto_add_replicas - Initial livenodes: [127.0.0.1:10009_solr]
   [junit4]   2> 2619654 DEBUG (Simulated OverseerAutoScalingTriggerThread) [    ] o.a.s.c.a.OverseerTriggerThread -- clean old nodeAdded markers
   [junit4]   2> 2619654 DEBUG (Simulated OverseerAutoScalingTriggerThread) [    ] o.a.s.c.a.OverseerTriggerThread Current znodeVersion 2, lastZnodeVersion 2
   [junit4]   2> 2619655 DEBUG (ScheduledTrigger-9988-thread-2) [    ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 1
   [junit4]   2> 2619677 DEBUG (ScheduledTrigger-9988-thread-2) [    ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 1
   [junit4]   2> 2619716 DEBUG (ScheduledTrigger-9988-thread-3) [    ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 1
   [junit4]   2> 2619737 DEBUG (ScheduledTrigger-9988-thread-4) [    ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 1
   [junit4]   2> 2619760 DEBUG (ScheduledTrigger-9988-thread-1) [    ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 1
   [junit4]   2> 2619773 DEBUG (simCloudManagerPool-9987-thread-1) [    ] o.a.s.c.a.AutoScalingHandler Verified autoscaling configuration
   [junit4]   2> 2619773 DEBUG (simCloudManagerPool-9987-thread-1) [    ] o.a.s.c.a.OverseerTriggerThread Refreshing /autoscaling.json with znode version 3
   [junit4]   2> 2619779 DEBUG (Simulated OverseerAutoScalingTriggerThread) [    ] o.a.s.c.a.OverseerTriggerThread Processed trigger updates upto znodeVersion 3
   [junit4]   2> 2619779 DEBUG (Simulated OverseerAutoScalingTriggerThread) [    ] o.a.s.c.a.OverseerTriggerThread -- clean old nodeAdded markers
   [junit4]   2> 2619779 DEBUG (Simulated OverseerAutoScalingTriggerThread) [    ] o.a.s.c.a.OverseerTriggerThread Current znodeVersion 3, lastZnodeVersion 3
   [junit4]   2> 2619780 DEBUG (simCloudManagerPool-9987-thread-2) [    ] o.a.s.c.a.AutoScalingHandler Verified autoscaling configuration
   [junit4]   2> 2619781 DEBUG (simCloudManagerPool-9987-thread-2) [    ] o.a.s.c.a.OverseerTriggerThread Refreshing /autoscaling.json with znode version 4
   [junit4]   2> 2619781 DEBUG (Simulated OverseerAutoScalingTriggerThread) [    ] o.a.s.c.a.OverseerTriggerThread Processed trigger updates upto znodeVersion 4
   [junit4]   2> 2619781 DEBUG (Simulated OverseerAutoScalingTriggerThread) [    ] o.a.s.c.a.OverseerTriggerThread -- clean old nodeAdded markers
   [junit4]   2> 2619781 DEBUG (Simulated OverseerAutoScalingTriggerThread) [    ] o.a.s.c.a.OverseerTriggerThread Current znodeVersion 4, lastZnodeVersion 4
   [junit4]   2> 2619781 DEBUG (ScheduledTrigger-9988-thread-1) [    ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 1
   [junit4]   2> 2619815 DEBUG (ScheduledTrigger-9988-thread-1) [    ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 1
   [junit4]   2> 2619841 DEBUG (ScheduledTrigger-9988-thread-1) [    ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 1
   [junit4]   2> 2619871 DEBUG (ScheduledTrigger-9988-thread-4) [    ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 1
   [junit4]   2> 2619887 DEBUG (simCloudManagerPool-9987-thread-3) [    ] o.a.s.c.a.AutoScalingHandler Verified autoscaling configuration
   [junit4]   2> 2619887 DEBUG (simCloudManagerPool-9987-thread-3) [    ] o.a.s.c.a.OverseerTriggerThread Refreshing /autoscaling.json with znode version 5
   [junit4]   2> 2619888 DEBUG (Simulated OverseerAutoScalingTriggerThread) [    ] o.a.s.c.a.OverseerTriggerThread Processed trigger updates upto znodeVersion 5
   [junit4]   2> 2619888 DEBUG (Simulated OverseerAutoScalingTriggerThread) [    ] o.a.s.c.a.NodeLostTrigger NodeLostTrigger node_lost_trigger - Initial livenodes: [127.0.0.1:10010_solr, 127.0.0.1:10009_solr]
   [junit4]   2> 2619888 DEBUG (Simulated OverseerAutoScalingTriggerThread) [    ] o.a.s.c.a.OverseerTriggerThread -- clean old nodeAdded markers
   [junit4]   2> 2619888 DEBUG (Simulated OverseerAutoScalingTriggerThread) [    ] o.a.s.c.a.OverseerTriggerThread Current znodeVersion 5, lastZnodeVersion 5
   [junit4]   2> 2619888 DEBUG (ScheduledTrigger-9988-thread-1) [    ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: node_lost_trigger with currently live nodes: 2
   [junit4]   2> 2619892 DEBUG (ScheduledTrigger-9988-thread-3) [    ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 2
   [junit4]   2> 2619893 DEBUG (simCloudManagerPool-9987-thread-4) [    ] o.a.s.c.o.ClusterStateMutator building a new cName: testNodeLost
   [junit4]   2> 2619916 INFO  (simCloudManagerPool-9987-thread-4) [    ] o.a.s.c.s.c.a.PolicyHelper returnSession, curr-time 1131052319 sessionWrapper.createTime 1131052289821447, this.sessionWrapper.createTime 1131052289821447 
   [junit4]   2> 2619935 DEBUG (ScheduledTrigger-9988-thread-1) [    ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: node_lost_trigger with currently live nodes: 2
   [junit4]   2> 2619935 DEBUG (ScheduledTrigger-9988-thread-1) [    ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 2
   [junit4]   2> 2619953 DEBUG (simCloudManagerPool-9987-thread-7) [    ] o.a.s.c.a.s.SimClusterStateProvider -- elected new leader for testNodeLost / shard1: {"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":1,
   [junit4]   2>     "node_name":"127.0.0.1:10009_solr",
   [junit4]   2>     "state":"active",
   [junit4]   2>     "type":"NRT",
   [junit4]   2>     "SEARCHER.searcher.numDocs":0,
   [junit4]   2>     "shard":"shard1",
   [junit4]   2>     "collection":"testNodeLost"}}
   [junit4]   2> 2619966 DEBUG (ScheduledTrigger-9988-thread-1) [    ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: node_lost_trigger with currently live nodes: 2
   [junit4]   2> 2619966 DEBUG (ScheduledTrigger-9988-thread-1) [    ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 2
   [junit4]   2> 2619966 DEBUG (TEST-TestComputePlanAction.testNodeLost-seed#[BC5D7C28E88D0D59]) [    ] o.a.s.c.a.s.TestComputePlanAction -- cluster state: znodeVersion: 4
   [junit4]   2> live nodes:[127.0.0.1:10010_solr, 127.0.0.1:10009_solr]
   [junit4]   2> collections:{testNodeLost=DocCollection(testNodeLost//clusterstate.json/3)={
   [junit4]   2>   "replicationFactor":"2",
   [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":1,
   [junit4]   2>           "node_name":"127.0.0.1:10009_solr",
   [junit4]   2>           "state":"active",
   [junit4]   2>           "type":"NRT",
   [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":1,
   [junit4]   2>           "node_name":"127.0.0.1:10010_solr",
   [junit4]   2>           "state":"active",
   [junit4]   2>           "type":"NRT",
   [junit4]   2>           "SEARCHER.searcher.numDocs":0}},
   [junit4]   2>       "range":"80000000-7fffffff",
   [junit4]   2>       "state":"active"}}}}
   [junit4]   2> 2619966 INFO  (TEST-TestComputePlanAction.testNodeLost-seed#[BC5D7C28E88D0D59]) [    ] o.a.s.c.a.s.TestComputePlanAction Stopped_node : 127.0.0.1:10010_solr
   [junit4]   2> 2619999 DEBUG (ScheduledTrigger-9988-thread-2) [    ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 2
   [junit4]   2> 2619999 DEBUG (ScheduledTrigger-9988-thread-2) [    ] o.a.s.c.a.NodeLostTrigger Tracking lost node: 127.0.0.1:10010_solr
   [junit4]   2> 2619999 DEBUG (ScheduledTrigger-9988-thread-1) [    ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: node_lost_trigger with currently live nodes: 2
   [junit4]   2> 2619999 DEBUG (ScheduledTrigger-9988-thread-1) [    ] o.a.s.c.a.NodeLostTrigger Tracking lost node: 127.0.0.1:10010_solr
   [junit4]   2> 2620045 DEBUG (ScheduledTrigger-9988-thread-4) [    ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 2
   [junit4]   2> 2620049 DEBUG (ScheduledTrigger-9988-thread-2) [    ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: node_lost_trigger with currently live nodes: 2
   [junit4]   2> 2620069 DEBUG (ScheduledTrigger-9988-thread-3) [    ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 2
   [junit4]   2> 2620069 DEBUG (ScheduledTrigger-9988-thread-3) [    ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: node_lost_trigger with currently live nodes: 2
   [junit4]   2> 2620091 DEBUG (ScheduledTrigger-9988-thread-2) [    ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 2
   [junit4]   2> 2620091 DEBUG (ScheduledTrigger-9988-thread-2) [    ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: node_lost_trigger with currently live nodes: 2
   [junit4]   2> 2620113 DEBUG (ScheduledTrigger-9988-thread-2) [    ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 2
   [junit4]   2> 2620113 DEBUG (ScheduledTrigger-9988-thread-2) [    ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: node_lost_trigger with currently live nodes: 2
   [junit4]   2> 2620143 DEBUG (ScheduledTrigger-9988-thread-2) [    ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 2
   [junit4]   2> 2620143 DEBUG (ScheduledTrigger-9988-thread-2) [    ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: node_lost_trigger with currently live nodes: 2
   [junit4]   2> 2620143 DEBUG (ScheduledTrigger-9988-thread-2) [    ] o.a.s.c.a.NodeLostTrigger NodeLostTrigger firing registered processor for lost nodes: [127.0.0.1:10010_solr]
   [junit4]   2> 2620144 DEBUG (ScheduledTrigger-9988-thread-2) [    ] o.a.s.c.a.ScheduledTriggers ++++++++ Cooldown inactive - processing event: {
   [junit4]   2>   "id":"404b09d48a4ebTdug1z3j4zni0e51ptoz0qo5pe",
   [junit4]   2>   "source":"node_lost_trigger",
   [junit4]   2>   "eventTime":1131056506381547,
   [junit4]   2>   "eventType":"NODELOST",
   [junit4]   2>   "properties":{
   [junit4]   2>     "eventTimes":[1131056506381547],
   [junit4]   2>     "nodeNames":["127.0.0.1:10010_solr"]}}
   [junit4]   2> 2620157 DEBUG (ScheduledTrigger-9988-thread-2) [    ] o.a.s.c.a.ScheduledTriggers Pausing all triggers: [.auto_add_replicas, .scheduled_maintenance, node_lost_trigger]
   [junit4]   2> 2620165 DEBUG (simCloudManagerPool-9987-thread-9) [    ] o.a.s.c.o.ClusterStateMutator building a new cName: .system
   [junit4]   2> 2620184 INFO  (simCloudManagerPool-9987-thread-9) [    ] o.a.s.c.s.c.a.PolicyHelper returnSession, curr-time 1131065713 sessionWrapper.createTime 1131065700073197, this.sessionWrapper.createTime 1131065700073197 
   [junit4]   2> 2620205 DEBUG (AutoscalingActionExecutor-9989-thread-1) [    ] o.a.s.c.a.ScheduledTriggers -- processing actions for {
   [junit4]   2>   "id":"404b09d48a4ebTdug1z3j4zni0e51ptoz0qo5pe",
   [junit4]   2>   "source":"node_lost_trigger",
   [junit4]   2>   "eventTime":1131056506381547,
   [junit4]   2>   "eventType":"NODELOST",
   [junit4]   2>   "properties":{
   [junit4]   2>     "eventTimes":[1131056506381547],
   [junit4]   2>     "_enqueue_time_":1131064368319647,
   [junit4]   2>     "nodeNames":["127.0.0.1:10010_solr"]}}
   [junit4]   2> 2620205 DEBUG (AutoscalingActionExecutor-9989-thread-1) [    ] o.a.s.c.a.ComputePlanAction -- processing event: {
   [junit4]   2>   "id":"404b09d48a4ebTdug1z3j4zni0e51ptoz0qo5pe",
   [junit4]   2>   "source":"node_lost_trigger",
   [junit4]   2>   "eventTime":1131056506381547,
   [junit4]   2>   "eventType":"NODELOST",
   [junit4]   2>   "properties":{
   [junit4]   2>     "eventTimes":[1131056506381547],
   [junit4]   2>     "_enqueue_time_":1131064368319647,
   [junit4]   2>     "nodeNames":["127.0.0.1:10010_solr"]}} with context properties: {BEFORE_ACTION=[compute_plan]}
   [junit4]   2> 2620224 INFO  (AutoscalingActionExecutor-9989-thread-1) [    ] o.a.s.c.a.ComputePlanAction Computed Plan: action=MOVEREPLICA&collection=testNodeLost&targetNode=127.0.0.1:10011_solr&inPlaceMove=true&replica=core_node2
   [junit4]   2> 2620224 INFO  (AutoscalingActionExecutor-9989-thread-1) [    ] o.a.s.c.s.c.a.PolicyHelper returnSession, curr-time 1131067762 sessionWrapper.createTime 1131067734431797, this.sessionWrapper.createTime 1131067734431797 
   [junit4]   2> 2620237 INFO  (TEST-TestComputePlanAction.testNodeLost-seed#[BC5D7C28E88D0D59]) [    ] o.a.s.c.a.s.TestComputePlanAction -------------_ FINAL STATE --------------
   [junit4]   2> 2620237 INFO  (TEST-TestComputePlanAction.testNodeLost-seed#[BC5D7C28E88D0D59]) [    ] o.a.s.c.a.s.TestComputePlanAction * Node values: {
   [junit4]   2>   "127.0.0.1:10010_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":"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:10010_solr",
   [junit4]   2>     "metrics:solr.jvm:buffers.direct.Count":0,
   [junit4]   2>     "port":10010,
   [junit4]   2>     "heapUsage":123450000,
   [junit4]   2>     "sysLoadAvg":1.0,
   [junit4]   2>     "metrics:solr.node:ADMIN./admin/authorization.clientErrors:count":0},
   [junit4]   2>   "127.0.0.1:10009_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":"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:10009_solr",
   [junit4]   2>     "metrics:solr.jvm:buffers.direct.Count":0,
   [junit4]   2>     "port":10009,
   [junit4]   2>     "heapUsage":123450000,
   [junit4]   2>     "sysLoadAvg":1.0,
   [junit4]   2>     "metrics:solr.node:ADMIN./admin/authorization.clientErrors:count":0},
   [junit4]   2>   "127.0.0.1:10011_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":"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:10011_solr",
   [junit4]   2>     "metrics:solr.jvm:buffers.direct.Count":0,
   [junit4]   2>     "port":10011,
   [junit4]   2>     "heapUsage":123450000,
   [junit4]   2>     "sysLoadAvg":1.0,
   [junit4]   2>     "metrics:solr.node:ADMIN./admin/authorization.clientErrors:count":0}}
   [junit4]   2> 2620237 INFO  (TEST-TestComputePlanAction.testNodeLost-seed#[BC5D7C28E88D0D59]) [    ] o.a.s.c.a.s.TestComputePlanAction * Live nodes: [127.0.0.1:10009_solr]
   [junit4]   2> 2620237 INFO  (TEST-TestComputePlanAction.testNodeLost-seed#[BC5D7C28E88D0D59]) [    ] o.a.s.c.a.s.TestComputePlanAction * 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>           "SEARCHER.searcher.maxDoc":2,
   [junit4]   2>           "SEARCHER.searcher.deletedDocs":0,
   [junit4]   2>           "INDEX.sizeInBytes":1,
   [junit4]   2>           "node_name":"127.0.0.1:10011_solr",
   [junit4]   2>           "state":"down",
   [junit4]   2>           "type":"NRT",
   [junit4]   2>           "SEARCHER.searcher.numDocs":2}},
   [junit4]   2>       "range":"80000000-7fffffff",
   [junit4]   2>       "state":"active"}}}
   [junit4]   2> 2620237 INFO  (TEST-TestComputePlanAction.testNodeLost-seed#[BC5D7C28E88D0D59]) [    ] o.a.s.c.a.s.TestComputePlanAction * Collection testNodeLost state: DocCollection(testNodeLost//clusterstate.json/11)={
   [junit4]   2>   "replicationFactor":"2",
   [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":1,
   [junit4]   2>           "node_name":"127.0.0.1:10009_solr",
   [junit4]   2>           "state":"active",
   [junit4]   2>           "type":"NRT",
   [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":1,
   [junit4]   2>           "node_name":"127.0.0.1:10010_solr",
   [junit4]   2>           "state":"down",
   [junit4]   2>           "type":"NRT",
   [junit4]   2>           "SEARCHER.searcher.numDocs":0}},
   [junit4]   2>       "range":"80000000-7fffffff",
   [junit4]   2>       "state":"active"}}}
   [junit4]   2> 2620238 INFO  (TEST-TestComputePlanAction.testNodeLost-seed#[BC5D7C28E88D0D59]) [    ] 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:10010_solr
   [junit4]   2> ##		127.0.0.1:10011_solr
   [junit4]   2> ## Collections:	[.system, testNodeLost]
   [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_lost_trigger
   [junit4]   2> ##		- BEFORE_ACTION     1
   [junit4]   2> ##		- STARTED         1
   [junit4]   2> 
   [junit4]   2> 2620239 WARN  (simCloudManagerPool-9987-thread-14) [    ] o.a.s.c.a.s.SimClusterStateProvider -- can't find any active replicas for .system / shard1
   [junit4]   2> 2620309 DEBUG (AutoscalingActionExecutor-9989-thread-1) [    ] o.a.s.c.a.ScheduledTriggers Resuming trigger: .auto_add_replicas after 100ms
   [junit4]   2> 2620311 DEBUG (AutoscalingActionExecutor-9989-thread-1) [    ] o.a.s.c.a.ScheduledTriggers Resuming trigger: .scheduled_maintenance after 100ms
   [junit4]   2> 2620311 DEBUG (AutoscalingActionExecutor-9989-thread-1) [    ] o.a.s.c.a.ScheduledTriggers Resuming trigger: node_lost_trigger after 100ms
   [junit4]   2> 2620311 DEBUG (AutoscalingActionExecutor-9989-thread-1) [    ] o.a.s.c.a.ScheduledTriggers -- processing took 5315 ms for event id=404b09d48a4ebTdug1z3j4zni0e51ptoz0qo5pe
   [junit4]   2> 2620384 DEBUG (TEST-TestComputePlanAction.testNodeWithMultipleReplicasLost-seed#[BC5D7C28E88D0D59]) [    ] o.a.s.c.a.OverseerTriggerThread Refreshing /autoscaling.json with znode version 6
   [junit4]   2> 2620384 DEBUG (Simulated OverseerAutoScalingTriggerThread) [    ] o.a.s.c.a.OverseerTriggerThread Processed trigger updates upto znodeVersion 6
   [junit4]   2> 2620384 DEBUG (TEST-TestComputePlanAction.testNodeWithMultipleReplicasLost-seed#[BC5D7C28E88D0D59]) [    ] o.a.s.c.a.s.SimNodeStateProvider - removing dead node values: 127.0.0.1:10010_solr
   [junit4]   2> 2620384 DEBUG (TEST-TestComputePlanAction.testNodeWithMultipleReplicasLost-seed#[BC5D7C28E88D0D59]) [    ] o.a.s.c.a.s.SimNodeStateProvider - removing dead node values: 127.0.0.1:10011_solr
   [junit4]   2> 2620384 DEBUG (Simulated OverseerAutoScalingTriggerThread) [    ] o.a.s.c.a.OverseerTriggerThread -- clean old nodeLost markers
   [junit4]   2> 2620384 INFO  (TEST-TestComputePlanAction.testNodeWithMultipleReplicasLost-seed#[BC5D7C28E88D0D59]) [    ] o.a.s.c.a.s.SimCloudManager === Restarting OverseerTriggerThread and clearing object cache...
   [junit4]   2> 2620384 DEBUG (Simulated OverseerAutoScalingTriggerThread) [    ] o.a.s.c.a.OverseerTriggerThread -- clean old nodeAdded markers
   [junit4]   2> 2620384 DEBUG (TEST-TestComputePlanAction.testNodeWithMultipleReplicasLost-seed#[BC5D7C28E88D0D59]) [    ] o.a.s.c.a.ScheduledTriggers Shutting down scheduled thread pool executor now
   [junit4]   2> 2620384 DEBUG (TEST-TestComputePlanAction.testNodeWithMultipleReplicasLost-seed#[BC5D7C28E88D0D59]) [    ] o.a.s.c.a.ScheduledTriggers Shutting down action executor now
   [junit4]   2> 2620384 DEBUG (TEST-TestComputePlanAction.testNodeWithMultipleReplicasLost-seed#[BC5D7C28E88D0D59]) [    ] o.a.s.c.a.ScheduledTriggers Awaiting termination for action executor
   [junit4]   2> 2620384 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:1220) ~[?:1.8.0_172]
   [junit4]   2> 	at java.util.concurrent.locks.ReentrantLock.lockInterruptibly(ReentrantLock.java:335) ~[?:1.8.0_172]
   [junit4]   2> 	at org.apache.solr.cloud.autoscaling.OverseerTriggerThread.run(OverseerTriggerThread.java:177) [java/:?]
   [junit4]   2> 	at java.lang.Thread.run(Thread.java:748) [?:1.8.0_172]
   [junit4]   2> 2620385 DEBUG (TEST-TestComputePlanAction.testNodeWithMultipleReplicasLost-seed#[BC5D7C28E88D0D59]) [    ] o.a.s.c.a.ScheduledTriggers Awaiting termination for scheduled thread pool executor
   [junit4]   2> 2620385 DEBUG (TEST-TestComputePlanAction.testNodeWithMultipleReplicasLost-seed#[BC5D7C28E88D0D59]) [    ] o.a.s.c.a.ScheduledTriggers ScheduledTriggers closed completely
   [junit4]   2> 2620385 DEBUG (TEST-TestComputePlanAction.testNodeWithMultipleReplicasLost-seed#[BC5D7C28E88D0D59]) [    ] o.a.s.c.a.OverseerTriggerThread OverseerTriggerThread has been closed explicitly
   [junit4]   2> 2620388 DEBUG (Simulated OverseerAutoScalingTriggerThread) [    ] o.a.s.c.a.OverseerTriggerThread Adding .auto_add_replicas and .scheduled_maintenance triggers
   [junit4]   2> 2620388 DEBUG (Simulated OverseerAutoScalingTriggerThread) [    ] o.a.s.c.a.OverseerTriggerThread Refreshing /autoscaling.json with znode version 7
   [junit4]   2> 2620388 DEBUG (Simulated OverseerAutoScalingTriggerThread) [    ] o.a.s.c.a.OverseerTriggerThread Current znodeVersion 7, lastZnodeVersion -1
   [junit4]   2> 2620388 DEBUG (Simulated OverseerAutoScalingTriggerThread) [    ] o.a.s.c.a.OverseerTriggerThread Processed trigger updates upto znodeVersion 7
   [junit4]   2> 2620388 DEBUG (Simulated OverseerAutoScalingTriggerThread) [    ] o.a.s.c.a.NodeLostTrigger NodeLostTrigger .auto_add_replicas - Initial livenodes: [127.0.0.1:10009_solr]
   [junit4]   2> 2620389 DEBUG (Simulated OverseerAutoScalingTriggerThread) [    ] o.a.s.c.a.OverseerTriggerThread -- clean old nodeAdded markers
   [junit4]   2> 2620389 DEBUG (Simulated OverseerAutoScalingTriggerThread) [    ] o.a.s.c.a.OverseerTriggerThread Current znodeVersion 7, lastZnodeVersion 7
   [junit4]   2> 2620389 DEBUG (ScheduledTrigger-9991-thread-2) [    ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 1
   [junit4]   2> 2620432 DEBUG (ScheduledTrigger-9991-thread-1) [    ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 1
   [junit4]   2> 2620479 DEBUG (ScheduledTrigger-9991-thread-3) [    ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 1
   [junit4]   2> 2620500 DEBUG (simCloudManagerPool-9990-thread-1) [    ] o.a.s.c.a.AutoScalingHandler Verified autoscaling configuration
   [junit4]   2> 2620500 DEBUG (ScheduledTrigger-9991-thread-1) [    ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 1
   [junit4]   2> 2620503 DEBUG (simCloudManagerPool-9990-thread-1) [    ] o.a.s.c.a.OverseerTriggerThread Refreshing /autoscaling.json with znode version 8
   [junit4]   2> 2620508 DEBUG (Simulated OverseerAutoScalingTriggerThread) [    ] o.a.s.c.a.OverseerTriggerThread Processed trigger updates upto znodeVersion 8
   [junit4]   2> 2620508 DEBUG (Simulated OverseerAutoScalingTriggerThread) [    ] o.a.s.c.a.OverseerTriggerThread -- clean old nodeAdded markers
   [junit4]   2> 2620508 DEBUG (Simulated OverseerAutoScalingTriggerThread) [    ] o.a.s.c.a.OverseerTriggerThread Current znodeVersion 8, lastZnodeVersion 8
   [junit4]   2> 2620508 DEBUG (simCloudManagerPool-9990-thread-2) [    ] o.a.s.c.a.AutoScalingHandler Verified autoscaling configuration
   [junit4]   2> 2620509 DEBUG (simCloudManagerPool-9990-thread-2) [    ] o.a.s.c.a.OverseerTriggerThread Refreshing /autoscaling.json with znode version 9
   [junit4]   2> 2620509 DEBUG (Simulated OverseerAutoScalingTriggerThread) [    ] o.a.s.c.a.OverseerTriggerThread Processed trigger updates upto znodeVersion 9
   [junit4]   2> 2620509 DEBUG (Simulated OverseerAutoScalingTriggerThread) [    ] o.a.s.c.a.OverseerTriggerThread -- clean old nodeAdded markers
   [junit4]   2> 2620509 DEBUG (Simulated OverseerAutoScalingTriggerThread) [    ] o.a.s.c.a.OverseerTriggerThread Current znodeVersion 9, lastZnodeVersion 9
   [junit4]   2> 2620546 DEBUG (ScheduledTrigger-9991-thread-3) [    ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 1
   [junit4]   2> 2620567 DEBUG (ScheduledTrigger-9991-thread-2) [    ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 1
   [junit4]   2> 2620594 DEBUG (ScheduledTrigger-9991-thread-3) [    ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 1
   [junit4]   2> 2620616 DEBUG (ScheduledTrigger-9991-thread-3) [    ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 4
   [junit4]   2> 2620619 DEBUG (simCloudManagerPool-9990-thread-3) [    ] o.a.s.c.a.AutoScalingHandler Verified autoscaling configuration
   [junit4]   2> 2620619 DEBUG (simCloudManagerPool-9990-thread-3) [    ] o.a.s.c.a.OverseerTriggerThread Refreshing /autoscaling.json with znode version 10
   [junit4]   2> 2620620 DEBUG (Simulated OverseerAutoScalingTriggerThread) [    ] o.a.s.c.a.OverseerTriggerThread Processed trigger updates upto znodeVersion 10
   [junit4]   2> 2620620 DEBUG (Simulated OverseerAutoScalingTriggerThread) [    ] o.a.s.c.a.NodeLostTrigger NodeLostTrigger node_lost_trigger - Initial livenodes: [127.0.0.1:10009_solr, 127.0.0.1:10013_solr, 127.0.0.1:10012_solr, 127.0.0.1:10014_solr]
   [junit4]   2> 2620620 DEBUG (Simulated OverseerAutoScalingTriggerThread) [    ] o.a.s.c.a.OverseerTriggerThread -- clean old nodeAdded markers
   [junit4]   2> 2620620 DEBUG (Simulated OverseerAutoScalingTriggerThread) [    ] o.a.s.c.a.OverseerTriggerThread Current znodeVersion 10, lastZnodeVersion 10
   [junit4]   2> 2620620 DEBUG (ScheduledTrigger-9991-thread-1) [    ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: node_lost_trigger with currently live nodes: 4
   [junit4]   2> 2620620 DEBUG (simCloudManagerPool-9990-thread-4) [    ] o.a.s.c.o.ClusterStateMutator building a new cName: testNodeWithMultipleReplicasLost
   [junit4]   2> 2620637 INFO  (simCloudManagerPool-9990-thread-4) [    ] o.a.s.c.s.c.a.PolicyHelper returnSession, curr-time 1131088391 sessionWrapper.createTime 1131088338239197, this.sessionWrapper.createTime 1131088338239197 
   [junit4]   2> 2620638 DEBUG (ScheduledTrigger-9991-thread-2) [    ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 4
   [junit4]   2> 2620645 DEBUG (ScheduledTrigger-9991-thread-3) [    ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: node_lost_trigger with currently live nodes: 4
   [junit4]   2> 2620665 DEBUG (ScheduledTrigger-9991-thread-4) [    ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 4
   [junit4]   2> 2620666 DEBUG (ScheduledTrigger-9991-thread-2) [    ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: node_lost_trigger with currently live nodes: 4
   [junit4]   2> 2620690 DEBUG (ScheduledTrigger-9991-thread-1) [    ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 4
   [junit4]   2> 2620690 DEBUG (ScheduledTrigger-9991-thread-3) [    ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: node_lost_trigger with currently live nodes: 4
   [junit4]   2> 2620699 DEBUG (simCloudManagerPool-9990-thread-11) [    ] o.a.s.c.a.s.SimClusterStateProvider -- elected new leader for testNodeWithMultipleReplicasLost / shard2: {"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":1,
   [junit4]   2>     "node_name":"127.0.0.1:10009_solr",
   [junit4]   2>     "state":"active",
   [junit4]   2>     "type":"NRT",
   [junit4]   2>     "SEARCHER.searcher.numDocs":0,
   [junit4]   2>     "shard":"shard2",
   [junit4]   2>     "collection":"testNodeWithMultipleReplicasLost"}}
   [junit4]   2> 2620699 DEBUG (simCloudManagerPool-9990-thread-12) [    ] o.a.s.c.a.s.SimClusterStateProvider -- elected new leader for testNodeWithMultipleReplicasLost / shard1: {"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":1,
   [junit4]   2>     "node_name":"127.0.0.1:10014_solr",
   [junit4]   2>     "state":"active",
   [junit4]   2>     "type":"NRT",
   [junit4]   2>     "SEARCHER.searcher.numDocs":0,
   [junit4]   2>     "shard":"shard1",
   [junit4]   2>     "collection":"testNodeWithMultipleReplicasLost"}}
   [junit4]   2> 2620716 DEBUG (ScheduledTrigger-9991-thread-2) [    ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: node_lost_trigger with currently live nodes: 4
   [junit4]   2> 2620717 DEBUG (ScheduledTrigger-9991-thread-2) [    ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 4
   [junit4]   2> 2620717 DEBUG (TEST-TestComputePlanAction.testNodeWithMultipleReplicasLost-seed#[BC5D7C28E88D0D59]) [    ] o.a.s.c.a.s.TestComputePlanAction -- cluster state: znodeVersion: 17
   [junit4]   2> live nodes:[127.0.0.1:10012_solr, 127.0.0.1:10014_solr, 127.0.0.1:10009_solr, 127.0.0.1:10013_solr]
   [junit4]   2> collections:{testNodeWithMultipleReplicasLost=DocCollection(testNodeWithMultipleReplicasLost//clusterstate.json/16)={
   [junit4]   2>   "replicationFactor":"3",
   [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":1,
   [junit4]   2>           "node_name":"127.0.0.1:10012_solr",
   [junit4]   2>           "state":"active",
   [junit4]   2>           "type":"NRT",
   [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":1,
   [junit4]   2>           "node_name":"127.0.0.1:10009_solr",
   [junit4]   2>           "state":"active",
   [junit4]   2>           "type":"NRT",
   [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":1,
   [junit4]   2>           "node_name":"127.0.0.1:10013_solr",
   [junit4]   2>           "state":"active",
   [junit4]   2>           "type":"NRT",
   [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":1,
   [junit4]   2>           "node_name":"127.0.0.1:10014_solr",
   [junit4]   2>           "state":"active",
   [junit4]   2>           "type":"NRT",
   [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":1,
   [junit4]   2>           "node_name":"127.0.0.1:10012_solr",
   [junit4]   2>           "state":"active",
   [junit4]   2>           "type":"NRT",
   [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":1,
   [junit4]   2>           "node_name":"127.0.0.1:10013_solr",
   [junit4]   2>           "state":"active",
   [junit4]   2>           "type":"NRT",
   [junit4]   2>           "SEARCHER.searcher.numDocs":0}},
   [junit4]   2>       "range":"80000000-ffffffff",
   [junit4]   2>       "state":"active"}}}}
   [junit4]   2> 2620740 DEBUG (ScheduledTrigger-9991-thread-3) [    ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: node_lost_trigger with currently live nodes: 3
   [junit4]   2> 2620740 DEBUG (ScheduledTrigger-9991-thread-3) [    ] o.a.s.c.a.NodeLostTrigger Tracking lost node: 127.0.0.1:10013_solr
   [junit4]   2> 2620740 DEBUG (ScheduledTrigger-9991-thread-3) [    ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 3
   [junit4]   2> 2620740 DEBUG (ScheduledTrigger-9991-thread-3) [    ] o.a.s.c.a.NodeLostTrigger Tracking lost node: 127.0.0.1:10013_solr
   [junit4]   2> 2620764 DEBUG (ScheduledTrigger-9991-thread-3) [    ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: node_lost_trigger with currently live nodes: 3
   [junit4]   2> 2620764 DEBUG (ScheduledTrigger-9991-thread-2) [    ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 3
   [junit4]   2> 2620764 DEBUG (ScheduledTrigger-9991-thread-3) [    ] o.a.s.c.a.NodeLostTrigger NodeLostTrigger firing registered processor for lost nodes: [127.0.0.1:10013_solr]
   [junit4]   2> 2620764 DEBUG (ScheduledTrigger-9991-thread-3) [    ] o.a.s.c.a.ScheduledTriggers ++++++++ Cooldown inactive - processing event: {
   [junit4]   2>   "id":"404b93c9b9645Tdug1z3j4zni0e51ptoz0qo5pj",
   [junit4]   2>   "source":"node_lost_trigger",
   [junit4]   2>   "eventTime":1131093539132997,
   [junit4]   2>   "eventType":"NODELOST",
   [junit4]   2>   "properties":{
   [junit4]   2>     "eventTimes":[1131093539132997],
   [junit4]   2>     "nodeNames":["127.0.0.1:10013_solr"]}}
   [junit4]   2> 2620767 DEBUG (ScheduledTrigger-9991-thread-3) [    ] o.a.s.c.a.ScheduledTriggers Pausing all triggers: [.auto_add_replicas, .scheduled_maintenance, node_lost_trigger]
   [junit4]   2> 2620781 DEBUG (simCloudManagerPool-9990-thread-15) [    ] o.a.s.c.o.ClusterStateMutator building a new cName: .system
   [junit4]   2> 2620797 INFO  (simCloudManagerPool-9990-thread-15) [    ] o.a.s.c.s.c.a.PolicyHelper returnSession, curr-time 1131096386 sessionWrapper.createTime 1131096375136947, this.sessionWrapper.createTime 1131096375136947 
   [junit4]   2> 2620819 DEBUG (AutoscalingActionExecutor-9992-thread-1) [    ] o.a.s.c.a.ScheduledTriggers -- processing actions for {
   [junit4]   2>   "id":"404b93c9b9645Tdug1z3j4zni0e51ptoz0qo5pj",
   [junit4]   2>   "source":"node_lost_trigger",
   [junit4]   2>   "eventTime":1131093539132997,
   [junit4]   2>   "eventType":"NODELOST",
   [junit4]   2>   "properties":{
   [junit4]   2>     "eventTimes":[1131093539132997],
   [junit4]   2>     "_enqueue_time_":1131094904455547,
   [junit4]   2>     "nodeNames":["127.0.0.1:10013_solr"]}}
   [junit4]   2> 2620819 DEBUG (AutoscalingActionExecutor-9992-thread-1) [    ] o.a.s.c.a.ComputePlanAction -- processing event: {
   [junit4]   2>   "id":"404b93c9b9645Tdug1z3j4zni0e51ptoz0qo5pj",
   [junit4]   2>   "source":"node_lost_trigger",
   [junit4]   2>   "eventTime":1131093539132997,
   [junit4]   2>   "eventType":"NODELOST",
   [junit4]   2>   "properties":{
   [junit4]   2>     "eventTimes":[1131093539132997],
   [junit4]   2>     "_enqueue_time_":1131094904455547,
   [junit4]   2>     "nodeNames":["127.0.0.1:10013_solr"]}} with context properties: {BEFORE_ACTION=[compute_plan]}
   [junit4]   2> 2620820 INFO  (AutoscalingActionExecutor-9992-thread-1) [    ] o.a.s.c.a.ComputePlanAction Computed Plan: action=MOVEREPLICA&collection=testNodeWithMultipleReplicasLost&targetNode=127.0.0.1:10014_solr&inPlaceMove=true&replica=core_node5
   [junit4]   2> 2620820 INFO  (AutoscalingActionExecutor-9992-thread-1) [    ] o.a.s.c.a.ComputePlanAction Computed Plan: action=MOVEREPLICA&collection=testNodeWithMultipleReplicasLost&targetNode=127.0.0.1:10009_solr&inPlaceMove=true&replica=core_node3
   [junit4]   2> 2620820 INFO  (AutoscalingActionExecutor-9992-thread-1) [    ] o.a.s.c.s.c.a.PolicyHelper returnSession, curr-time 1131097560 sessionWrapper.createTime 1131097513086047, this.sessionWrapper.createTime 1131097513086047 
   [junit4]   2> 2620822 INFO  (TEST-TestComputePlanAction.testNodeWithMultipleReplicasLost-seed#[BC5D7C28E88D0D59]) [    ] o.a.s.c.a.s.TestComputePlanAction action=MOVEREPLICA&collection=testNodeWithMultipleReplicasLost&targetNode=127.0.0.1:10014_solr&inPlaceMove=true&replica=core_node5
   [junit4]   2> 2620822 INFO  (TEST-TestComputePlanAction.testNodeWithMultipleReplicasLost-seed#[BC5D7C28E88D0D59]) [    ] o.a.s.c.a.s.TestComputePlanAction action=MOVEREPLICA&collection=testNodeWithMultipleReplicasLost&targetNode=127.0.0.1:10009_solr&inPlaceMove=true&replica=core_node3
   [junit4]   2> 2620823 INFO  (TEST-TestComputePlanAction.testNodeWithMultipleReplicasLost-seed#[BC5D7C28E88D0D59]) [    ] o.a.s.c.a.s.TestComputePlanAction -------------_ FINAL STATE --------------
   [junit4]   2> 2620823 INFO  (TEST-TestComputePlanAction.testNodeWithMultipleReplicasLost-seed#[BC5D7C28E88D0D59]) [    ] o.a.s.c.a.s.TestComputePlanAction * Node values: {
   [junit4]   2>   "127.0.0.1:10009_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":"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:10009_solr",
   [junit4]   2>     "metrics:solr.jvm:buffers.direct.Count":0,
   [junit4]   2>     "port":10009,
   [junit4]   2>     "heapUsage":123450000,
   [junit4]   2>     "sysLoadAvg":1.0,
   [junit4]   2>     "metrics:solr.node:ADMIN./admin/authorization.clientErrors:count":0},
   [junit4]   2>   "127.0.0.1:10013_solr":{
   [junit4]   2>     "sysprop.java.vendor":"Oracle Corporation",
   [junit4]   2>     "cores":2,
   [junit4]   2>     "host":"127.0.0.1",
   [junit4]   2>     "freedisk":998,
   [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:10013_solr",
   [junit4]   2>     "metrics:solr.jvm:buffers.direct.Count":0,
   [junit4]   2>     "port":10013,
   [junit4]   2>     "heapUsage":123450000,
   [junit4]   2>     "sysLoadAvg":1.0,
   [junit4]   2>     "metrics:solr.node:ADMIN./admin/authorization.clientErrors:count":0},
   [junit4]   2>   "127.0.0.1:10012_solr":{
   [junit4]   2>     "sysprop.java.vendor":"Oracle Corporation",
   [junit4]   2>     "cores":2,
   [junit4]   2>     "host":"127.0.0.1",
   [junit4]   2>     "freedisk":998,
   [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:10012_solr",
   [junit4]   2>     "metrics:solr.jvm:buffers.direct.Count":0,
   [junit4]   2>     "port":10012,
   [junit4]   2>     "heapUsage":123450000,
   [junit4]   2>     "sysLoadAvg":1.0,
   [junit4]   2>     "metrics:solr.node:ADMIN./admin/authorization.clientErrors:count":0},
   [junit4]   2>   "127.0.0.1:10014_solr":{
   [junit4]   2>     "sysprop.java.vendor":"Oracle Corporation",
   [junit4]   2>     "cores":2,
   [junit4]   2>     "host":"127.0.0.1",
   [junit4]   2>     "freedisk":998,
   [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:10014_solr",
   [junit4]   2>     "metrics:solr.jvm:buffers.direct.Count":0,
   [junit4]   2>     "port":10014,
   [junit4]   2>     "heapUsage":123450000,
   [junit4]   2>     "sysLoadAvg":1.0,
   [junit4]   2>     "metrics:solr.node:ADMIN./admin/authorization.clientErrors:count":0}}
   [junit4]   2> 2620823 INFO  (TEST-TestComputePlanAction.testNodeWithMultipleReplicasLost-seed#[BC5D7C28E88D0D59]) [    ] o.a.s.c.a.s.TestComputePlanAction * Live nodes: [127.0.0.1:10009_solr, 127.0.0.1:10012_solr, 127.0.0.1:10014_solr]
   [junit4]   2> 2620823 INFO  (TEST-TestComputePlanAction.testNodeWithMultipleReplicasLost-seed#[BC5D7C28E88D0D59]) [    ] o.a.s.c.a.s.TestComputePlanAction * Collection .system state: DocCollection(.system//clusterstate.json/24)={
   [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>           "SEARCHER.searcher.maxDoc":2,
   [junit4]   2>           "SEARCHER.searcher.deletedDocs":0,
   [junit4]   2>           "INDEX.sizeInBytes":1,
   [junit4]   2>           "node_name":"127.0.0.1:10014_solr",
   [junit4]   2>           "state":"active",
   [junit4]   2>           "type":"NRT",
   [junit4]   2>           "SEARCHER.searcher.numDocs":2}},
   [junit4]   2>       "range":"80000000-7fffffff",
   [junit4]   2>       "state":"active"}}}
   [junit4]   2> 2620823 INFO  (TEST-TestComputePlanAction.testNodeWithMultipleReplicasLost-seed#[BC5D7C28E88D0D59]) [    ] o.a.s.c.a.s.TestComputePlanAction * Collection testNodeWithMultipleReplicasLost state: DocCollection(testNodeWithMultipleReplicasLost//clusterstate.json/24)={
   [junit4]   2>   "replicationFactor":"3",
   [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":1,
   [junit4]   2>           "node_name":"127.0.0.1:10012_solr",
   [junit4]   2>           "state":"active",
   [junit4]   2>           "type":"NRT",
   [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":1,
   [junit4]   2>           "node_name":"127.0.0.1:10009_solr",
   [junit4]   2>           "state":"active",
   [junit4]   2>           "type":"NRT",
   [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":1,
   [junit4]   2>           "node_name":"127.0.0.1:10013_solr",
   [junit4]   2>           "state":"down",
   [junit4]   2>           "type":"NRT",
   [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":1,
   [junit4]   2>           "node_name":"127.0.0.1:10014_solr",
   [junit4]   2>           "state":"active",
   [junit4]   2>           "type":"NRT",
   [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":1,
   [junit4]   2>           "node_name":"127.0.0.1:10012_solr",
   [junit4]   2>           "state":"active",
   [junit4]   2>           "type":"NRT",
   [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":1,
   [junit4]   2>           "node_name":"127.0.0.1:10013_solr",
   [junit4]   2>           "state":"down",
   [junit4]   2>           "type":"NRT",
   [junit4]   2>           "SEARCHER.searcher.numDocs":0}},
   [junit4]   2>       "range":"80000000-ffffffff",
   [junit4]   2>       "state":"active"}}}
   [junit4]   2> 2620824 INFO  (TEST-TestComputePlanAction.testNodeWithMultipleReplicasLost-seed#[BC5D7C28E88D0D59]) [    ] 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:10013_solr
   [junit4]   2> ## Collections:	[.system, testNodeWithMultipleReplicasLost]
   [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_lost_trigger
   [junit4]   2> ##		- BEFORE_ACTION     1
   [junit4]   2> ##		- STARTED         1
   [junit4]   2> 
   [junit4]   2> 2620840 DEBUG (AutoscalingActionExecutor-9992-thread-1) [    ] o.a.s.c.a.ScheduledTriggers Resuming trigger: .auto_add_replicas after 100ms
   [junit4]   2> 2620844 DEBUG (AutoscalingActionExecutor-9992-thread-1) [    ] o.a.s.c.a.ScheduledTriggers Resuming trigger: .scheduled_maintenance after 100ms
   [junit4]   2> 2620844 DEBUG (AutoscalingActionExecutor-9992-thread-1) [    ] o.a.s.c.a.ScheduledTriggers Resuming trigger: node_lost_trigger after 100ms
   [junit4]   2> 2620844 DEBUG (AutoscalingActionExecutor-9992-thread-1) [    ] o.a.s.c.a.ScheduledTriggers -- processing took 1278 ms for event id=404b93c9b9645Tdug1z3j4zni0e51ptoz0qo5pj
   [junit4]   2> 2620951 DEBUG (ScheduledTrigger-9991-thread-4) [    ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 3
   [junit4]   2> 2620951 DEBUG (ScheduledTrigger-9991-thread-4) [    ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: node_lost_trigger with currently live nodes: 3
   [junit4]   2> 2620976 DEBUG (ScheduledTrigger-9991-thread-4) [    ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 3
   [junit4]   2> 2620976 DEBUG (ScheduledTrigger-9991-thread-4) [    ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: node_lost_trigger with currently live nodes: 3
   [junit4]   2> 2621006 DEBUG (TEST-TestComputePlanAction.testNodeAdded-seed#[BC5D7C28E88D0D59]) [    ] o.a.s.c.a.OverseerTriggerThread Refreshing /autoscaling.json with znode version 11
   [junit4]   2> 2621006 DEBUG (ScheduledTrigger-9991-thread-4) [    ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 3
   [junit4]   2> 2621006 DEBUG (ScheduledTrigger-9991-thread-4) [    ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: node_lost_trigger with currently live nodes: 2
   [junit4]   2> 2621006 DEBUG (ScheduledTrigger-9991-thread-4) [    ] o.a.s.c.a.NodeLostTrigger Tracking lost node: 127.0.0.1:10014_solr
   [junit4]   2> 2621006 DEBUG (Simulated OverseerAutoScalingTriggerThread) [    ] o.a.s.c.a.OverseerTriggerThread Processed trigger updates upto znodeVersion 11
   [junit4]   2> 2621006 DEBUG (Simulated OverseerAutoScalingTriggerThread) [    ] o.a.s.c.a.OverseerTriggerThread -- clean old nodeLost markers
   [junit4]   2> 2621006 DEBUG (Simulated OverseerAutoScalingTriggerThread) [    ] o.a.s.c.a.OverseerTriggerThread -- clean old nodeAdded markers
   [junit4]   2> 2621006 DEBUG (Simulated OverseerAutoScalingTriggerThread) [    ] o.a.s.c.a.OverseerTriggerThread Current znodeVersion 11, lastZnodeVersion 11
   [junit4]   2> 2621007 WARN  (simCloudManagerPool-9990-thread-21) [    ] o.a.s.c.a.s.SimClusterStateProvider -- can't find any active replicas for .system / shard1
   [junit4]   2> 2621007 DEBUG (TEST-TestComputePlanAction.testNodeAdded-seed#[BC5D7C28E88D0D59]) [    ] o.a.s.c.a.s.SimClusterStateProvider --- new Overseer leader: 127.0.0.1:10012_solr
   [junit4]   2> 2621007 DEBUG (simCloudManagerPool-9990-thread-22) [    ] o.a.s.c.a.s.SimClusterStateProvider -- elected new leader for testNodeWithMultipleReplicasLost / shard2: {"core_node6":{
   [junit4]   2>     "core":"testNodeWithMultipleReplicasLost_shard2_replica_n6",
   [junit4]   2>     "leader":"true",
   [junit4]   2>     "SEARCHER.searcher.maxDoc":0,
   [junit4]   2>     "SEARCHER.searcher.deletedDocs":0,
   [junit4]   2>     "INDEX.sizeInBytes":1,
   [junit4]   2>     "node_name":"127.0.0.1:10012_solr",
   [junit4]   2>     "state":"active",
   [junit4]   2>     "type":"NRT",
   [junit4]   2>     "SEARCHER.searcher.numDocs":0,
   [junit4]   2>     "shard":"shard2",
   [junit4]   2>     "collection":"testNodeWithMultipleReplicasLost"}}
   [junit4]   2> 2621007 DEBUG (simCloudManagerPool-9990-thread-23) [    ] o.a.s.c.a.s.SimClusterStateProvider -- elected new leader for testNodeWithMultipleReplicasLost / shard1: {"core_node2":{
   [junit4]   2>     "core":"testNodeWithMultipleReplicasLost_shard1_replica_n2",
   [junit4]   2>     "leader":"true",
   [junit4]   2>     "SEARCHER.searcher.maxDoc":0,
   [junit4]   2>     "SEARCHER.searcher.deletedDocs":0,
   [junit4]   2>     "INDEX.sizeInBytes":1,
   [junit4]   2>     "node_name":"127.0.0.1:10012_solr",
   [junit4]   2>     "state":"active",
   [junit4]   2>     "type":"NRT",
   [junit4]   2>     "SEARCHER.searcher.numDocs":0,
   [junit4]   2>     "shard":"shard1",
   [junit4]   2>     "collection":"testNodeWithMultipleReplicasLost"}}
   [junit4]   2> 2621008 DEBUG (TEST-TestComputePlanAction.testNodeAdded-seed#[BC5D7C28E88D0D59]) [    ] o.a.s.c.a.s.SimNodeStateProvider - removing dead node values: 127.0.0.1:10013_solr
   [junit4]   2> 2621008 INFO  (TEST-TestComputePlanAction.testNodeAdded-seed#[BC5D7C28E88D0D59]) [    ] o.a.s.c.a.s.SimCloudManager === Restarting OverseerTriggerThread and clearing object cache...
   [junit4]   2> 2621008 DEBUG (TEST-TestComputePlanAction.testNodeAdded-seed#[BC5D7C28E88D0D59]) [    ] o.a.s.c.a.ScheduledTriggers Shutting down scheduled thread pool executor now
   [junit4]   2> 2621008 DEBUG (TEST-TestComputePlanAction.testNodeAdded-seed#[BC5D7C28E88D0D59]) [    ] o.a.s.c.a.ScheduledTriggers Shutting down action executor now
   [junit4]   2> 2621008 WARN  (Simulated OverseerAutoScalingTriggerThread) [    ] o.a.s.c.a.OverseerTriggerThread OverseerTriggerThread woken up but we are closed, exiting.
   [junit4]   2> 2621008 DEBUG (TEST-TestComputePlanAction.testNodeAdded-seed#[BC5D7C28E88D0D59]) [    ] o.a.s.c.a.ScheduledTriggers Awaiting termination for action executor
   [junit4]   2> 2621008 DEBUG (TEST-TestComputePlanAction.testNodeAdded-seed#[BC5D7C28E88D0D59]) [    ] o.a.s.c.a.ScheduledTriggers Awaiting termination for scheduled thread pool executor
   [junit4]   2> 2621008 DEBUG (TEST-TestComputePlanAction.testNodeAdded-seed#[BC5D7C28E88D0D59]) [    ] o.a.s.c.a.ScheduledTriggers ScheduledTriggers closed completely
   [junit4]   2> 2621008 DEBUG (TEST-TestComputePlanAction.testNodeAdded-seed#[BC5D7C28E88D0D59]) [    ] o.a.s.c.a.OverseerTriggerThread OverseerTriggerThread has been closed explicitly
   [junit4]   2> 2621012 DEBUG (Simulated OverseerAutoScalingTriggerThread) [    ] o.a.s.c.a.OverseerTriggerThread Adding .auto_add_replicas and .scheduled_maintenance triggers
   [junit4]   2> 2621013 DEBUG (Simulated OverseerAutoScalingTriggerThread) [    ] o.a.s.c.a.OverseerTriggerThread Refreshing /autoscaling.json with znode version 12
   [junit4]   2> 2621013 DEBUG (Simulated OverseerAutoScalingTriggerThread) [    ] o.a.s.c.a.OverseerTriggerThread Current znodeVersion 12, lastZnodeVersion -1
   [junit4]   2> 2621013 DEBUG (Simulated OverseerAutoScalingTriggerThread) [    ] o.a.s.c.a.OverseerTriggerThread Processed trigger updates upto znodeVersion 12
   [junit4]   2> 2621013 DEBUG (Simulated OverseerAutoScalingTriggerThread) [    ] o.a.s.c.a.NodeLostTrigger NodeLostTrigger .auto_add_replicas - Initial livenodes: [127.0.0.1:10012_solr]
   [junit4]   2> 2621013 DEBUG (Simulated OverseerAutoScalingTriggerThread) [    ] o.a.s.c.a.OverseerTriggerThread -- clean old nodeAdded markers
   [junit4]   2> 2621013 DEBUG (Simulated OverseerAutoScalingTriggerThread) [    ] o.a.s.c.a.OverseerTriggerThread Current znodeVersion 12, lastZnodeVersion 12
   [junit4]   2> 2621014 DEBUG (ScheduledTrigger-9994-thread-2) [    ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 1
   [junit4]   2> 2621048 DEBUG (ScheduledTrigger-9994-thread-1) [    ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 1
   [junit4]   2> 2621068 DEBUG (ScheduledTrigger-9994-thread-4) [    ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 1
   [junit4]   2> 2621100 DEBUG (ScheduledTrigger-9994-thread-4) [    ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 1
   [junit4]   2> 2621116 DEBUG (simCloudManagerPool-9993-thread-1) [    ] o.a.s.c.a.AutoScalingHandler Verified autoscaling configuration
   [junit4]   2> 2621116 DEBUG (simCloudManagerPool-9993-thread-1) [    ] o.a.s.c.a.OverseerTriggerThread Refreshing /autoscaling.json with znode version 13
   [junit4]   2> 2621121 DEBUG (Simulated OverseerAutoScalingTriggerThread) [    ] o.a.s.c.a.OverseerTriggerThread Processed trigger updates upto znodeVersion 13
   [junit4]   2> 2621121 DEBUG (Simulated OverseerAutoScalingTriggerThread) [    ] o.a.s.c.a.OverseerTriggerThread -- clean old nodeAdded markers
   [junit4]   2> 2621121 DEBUG (Simulated OverseerAutoScalingTriggerThread) [    ] o.a.s.c.a.OverseerTriggerThread Current znodeVersion 13, lastZnodeVersion 13
   [junit4]   2> 2621122 DEBUG (simCloudManagerPool-9993-thread-2) [    ] o.a.s.c.a.AutoScalingHandler Verified autoscaling configuration
   [junit4]   2> 2621122 DEBUG (simCloudManagerPool-9993-thread-2) [    ] o.a.s.c.a.OverseerTriggerThread Refreshing /autoscaling.json with znode version 14
   [junit4]   2> 2621123 DEBUG (Simulated OverseerAutoScalingTriggerThread) [    ] o.a.s.c.a.OverseerTriggerThread Processed trigger updates upto znodeVersion 14
   [junit4]   2> 2621123 DEBUG (Simulated OverseerAutoScalingTriggerThread) [    ] o.a.s.c.a.OverseerTriggerThread -- clean old nodeAdded markers
   [junit4]   2> 2621123 DEBUG (Simulated OverseerAutoScalingTriggerThread) [    ] o.a.s.c.a.OverseerTriggerThread Current znodeVersion 14, lastZnodeVersion 14
   [junit4]   2> 2621127 DEBUG (ScheduledTrigger-9994-thread-1) [    ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 1
   [junit4]   2> 2621157 DEBUG (ScheduledTrigger-9994-thread-1) [    ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 1
   [junit4]   2> 2621205 DEBUG (ScheduledTrigger-9994-thread-2) [    ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 1
   [junit4]   2> 2621233 DEBUG (ScheduledTrigger-9994-thread-2) [    ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 1
   [junit4]   2> 2621234 DEBUG (simCloudManagerPool-9993-thread-3) [    ] o.a.s.c.a.AutoScalingHandler Verified autoscaling configuration
   [junit4]   2> 2621234 DEBUG (simCloudManagerPool-9993-thread-3) [    ] o.a.s.c.a.OverseerTriggerThread Refreshing /autoscaling.json with znode version 15
   [junit4]   2> 2621234 DEBUG (Simulated OverseerAutoScalingTriggerThread) [    ] o.a.s.c.a.OverseerTriggerThread Processed trigger updates upto znodeVersion 15
   [junit4]   2> 2621235 DEBUG (Simulated OverseerAutoScalingTriggerThread) [    ] o.a.s.c.a.NodeAddedTrigger NodeAddedTrigger node_added_trigger - Initial livenodes: [127.0.0.1:10012_solr]
   [junit4]   2> 2621235 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.TestComputePlanAction$AssertingTriggerAction}], enabled=true}
   [junit4]   2> 2621235 DEBUG (Simulated OverseerAutoScalingTriggerThread) [    ] o.a.s.c.a.OverseerTriggerThread Current znodeVersion 15, lastZnodeVersion 15
   [junit4]   2> 2621235 DEBUG (ScheduledTrigger-9994-thread-1) [    ] o.a.s.c.a.NodeAddedTrigger Running NodeAddedTrigger node_added_trigger
   [junit4]   2> 2621235 DEBUG (ScheduledTrigger-9994-thread-1) [    ] o.a.s.c.a.NodeAddedTrigger Found livenodes: 1
   [junit4]   2> 2621235 DEBUG (simCloudManagerPool-9993-thread-4) [    ] o.a.s.c.a.AutoScalingHandler Verified autoscaling configuration
   [junit4]   2> 2621235 DEBUG (simCloudManagerPool-9993-thread-4) [    ] o.a.s.c.a.OverseerTriggerThread Refreshing /autoscaling.json with znode version 16
   [junit4]   2> 2621235 DEBUG (Simulated OverseerAutoScalingTriggerThread) [    ] o.a.s.c.a.OverseerTriggerThread Processed trigger updates upto znodeVersion 16
   [junit4]   2> 2621235 DEBUG (Simulated OverseerAutoScalingTriggerThread) [    ] o.a.s.c.a.OverseerTriggerThread Current znodeVersion 16, lastZnodeVersion 16
   [junit4]   2> 2621236 DEBUG (simCloudManagerPool-9993-thread-5) [    ] o.a.s.c.o.ClusterStateMutator building a new cName: testNodeAdded
   [junit4]   2> 2621251 WARN  (simCloudManagerPool-9993-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> 2621252 INFO  (simCloudManagerPool-9993-thread-5) [    ] o.a.s.c.s.c.a.PolicyHelper returnSession, curr-time 1131119124 sessionWrapper.createTime 1131119110686547, this.sessionWrapper.createTime 1131119110686547 
   [junit4]   2> 2621262 DEBUG (ScheduledTrigger-9994-thread-2) [    ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 1
   [junit4]   2> 2621266 DEBUG (ScheduledTrigger-9994-thread-3) [    ] o.a.s.c.a.NodeAddedTrigger Running NodeAddedTrigger node_added_trigger
   [junit4]   2> 2621266 DEBUG (ScheduledTrigger-9994-thread-3) [    ] o.a.s.c.a.NodeAddedTrigger Found livenodes: 1
   [junit4]   2> 2621293 DEBUG (ScheduledTrigger-9994-thread-2) [    ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 1
   [junit4]   2> 2621293 DEBUG (ScheduledTrigger-9994-thread-4) [    ] o.a.s.c.a.NodeAddedTrigger Running NodeAddedTrigger node_added_trigger
   [junit4]   2> 2621293 DEBUG (ScheduledTrigger-9994-thread-4) [    ] o.a.s.c.a.NodeAddedTrigger Found livenodes: 1
   [junit4]   2> 2621299 DEBUG (simCloudManagerPool-9993-thread-10) [    ] o.a.s.c.a.s.SimClusterStateProvider -- elected new leader for testNodeAdded / shard1: {"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":1,
   [junit4]   2>     "node_name":"127.0.0.1:10012_solr",
   [junit4]   2>     "state":"active",
   [junit4]   2>     "type":"NRT",
   [junit4]   2>     "SEARCHER.searcher.numDocs":0,
   [junit4]   2>     "shard":"shard1",
   [junit4]   2>     "collection":"testNodeAdded"}}
   [junit4]   2> 2621310 DEBUG (simCloudManagerPool-9993-thread-11) [    ] o.a.s.c.a.AutoScalingHandler Verified autoscaling configuration
   [junit4]   2> 2621310 DEBUG (simCloudManagerPool-9993-thread-11) [    ] o.a.s.c.a.OverseerTriggerThread Refreshing /autoscaling.json with znode version 17
   [junit4]   2> 2621310 DEBUG (Simulated OverseerAutoScalingTriggerThread) [    ] o.a.s.c.a.OverseerTriggerThread Processed trigger updates upto znodeVersion 17
   [junit4]   2> 2621310 DEBUG (Simulated OverseerAutoScalingTriggerThread) [    ] o.a.s.c.a.OverseerTriggerThread Current znodeVersion 17, lastZnodeVersion 17
   [junit4]   2> 2621323 DEBUG (ScheduledTrigger-9994-thread-4) [    ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 2
   [junit4]   2> 2621323 DEBUG (ScheduledTrigger-9994-thread-2) [    ] o.a.s.c.a.NodeAddedTrigger Running NodeAddedTrigger node_added_trigger
   [junit4]   2> 2621323 DEBUG (ScheduledTrigger-9994-thread-2) [    ] o.a.s.c.a.NodeAddedTrigger Found livenodes: 2
   [junit4]   2> 2621323 DEBUG (ScheduledTrigger-9994-thread-2) [    ] o.a.s.c.a.NodeAddedTrigger Tracking new node: 127.0.0.1:10015_solr at time 1131122702266697
   [junit4]   2> 2621349 DEBUG (ScheduledTrigger-9994-thread-1) [    ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 2
   [junit4]   2> 2621350 DEBUG (ScheduledTrigger-9994-thread-1) [    ] o.a.s.c.a.NodeAddedTrigger Running NodeAddedTrigger node_added_trigger
   [junit4]   2> 2621350 DEBUG (ScheduledTrigger-9994-thread-1) [    ] o.a.s.c.a.NodeAddedTrigger Found livenodes: 2
   [junit4]   2> 2621350 DEBUG (ScheduledTrigger-9994-thread-1) [    ] o.a.s.c.a.NodeAddedTrigger NodeAddedTrigger node_added_trigger firing registered processor for nodes: [127.0.0.1:10015_solr] added at times [1131122702266697], now=1131124016810097
   [junit4]   2> 2621350 DEBUG (ScheduledTrigger-9994-thread-1) [    ] o.a.s.c.a.ScheduledTriggers ++++++++ Cooldown inactive - processing event: {
   [junit4]   2>   "id":"404c006ddb149Tdug1z3j4zni0e51ptoz0qo5po",
   [junit4]   2>   "source":"node_added_trigger",
   [junit4]   2>   "eventTime":1131122702266697,
   [junit4]   2>   "eventType":"NODEADDED",
   [junit4]   2>   "properties":{
   [junit4]   2>     "eventTimes":[1131122702266697],
   [junit4]   2>     "nodeNames":["127.0.0.1:10015_solr"]}}
   [junit4]   2> 2621352 DEBUG (ScheduledTrigger-9994-thread-1) [    ] o.a.s.c.a.ScheduledTriggers Pausing all triggers: [.auto_add_replicas, .scheduled_maintenance, node_added_trigger]
   [junit4]   2> 2621352 DEBUG (simCloudManagerPool-9993-thread-12) [    ] o.a.s.c.o.ClusterStateMutator building a new cName: .system
   [junit4]   2> 2621368 INFO  (simCloudManagerPool-9993-thread-12) [    ] o.a.s.c.s.c.a.PolicyHelper returnSession, curr-time 1131124959 sessionWrapper.createTime 1131124943847447, this.sessionWrapper.createTime 1131124943847447 
   [junit4]   2> 2621370 WARN  (ScheduledTrigger-9994-thread-1) [    ] o.a.s.c.a.SystemLogListener Exception sending event to collection .system
   [junit4]   2> java.io.IOException: java.util.concurrent.ExecutionException: java.io.IOException: org.apache.solr.common.SolrException: Collection .system doesn't exist.
   [junit4]   2> 	at org.apache.solr.cloud.autoscaling.sim.SimCloudManager.request(SimCloudManager.java:621) ~[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:789) ~[java/:?]
   [junit4]   2> 	at org.apache.solr.cloud.autoscaling.ScheduledTriggers$TriggerListeners.fireListeners(ScheduledTriggers.java:756) ~[java/:?]
   [junit4]   2> 	at org.apache.solr.cloud.autoscaling.ScheduledTriggers.lambda$add$4(ScheduledTriggers.java:282) ~[java/:?]
   [junit4]   2> 	at org.apache.solr.cloud.autoscaling.NodeAddedTrigger.run(NodeAddedTrigger.java:161) [java/:?]
   [junit4]   2> 	at org.apache.solr.cloud.autoscaling.ScheduledTriggers$TriggerWrapper.run(ScheduledTriggers.java:588) [java/:?]
   [junit4]   2> 	at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511) [?:1.8.0_172]
   [junit4]   2> 	at java.util.concurrent.FutureTask.runAndReset(FutureTask.java:308) [?:1.8.0_172]
   [junit4]   2> 	at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$301(ScheduledThreadPoolExecutor.java:180) [?:1.8.0_172]
   [junit4]   2> 	at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:294) [?:1.8.0_172]
   [junit4]   2> 	at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149) [?:1.8.0_172]
   [junit4]   2> 	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624) [?:1.8.0_172]
   [junit4]   2> 	at java.lang.Thread.run(Thread.java:748) [?:1.8.0_172]
   [junit4]   2> Caused by: java.util.concurrent.ExecutionException: java.io.IOException: org.apache.solr.common.SolrException: Collection .system doesn't exist.
   [junit4]   2> 	at java.util.concurrent.FutureTask.report(FutureTask.java:122) ~[?:1.8.0_172]
   [junit4]   2> 	at java.util.concurrent.FutureTask.get(FutureTask.java:192) ~[?:1.8.0_172]
   [junit4]   2> 	at org.apache.solr.cloud.autoscaling.sim.SimCloudManager.request(SimCloudManager.java:619) ~[test/:?]
   [junit4]   2> 	... 13 more
   [junit4]   2> Caused by: java.io.IOException: org.apache.solr.common.SolrException: Collection .system doesn't exist.
   [junit4]   2> 	at org.apache.solr.cloud.autoscaling.sim.SimClusterStateProvider.simUpdate(SimClusterStateProvider.java:1201) ~[test/:?]
   [junit4]   2> 	at org.apache.solr.cloud.autoscaling.sim.SimCloudManager.simHandleSolrRequest(SimCloudManager.java:691) ~[test/:?]
   [junit4]   2> 	at org.apache.solr.cloud.autoscaling.sim.SimCloudManager.lambda$request$15(SimCloudManager.java:618) ~[test/:?]
   [junit4]   2> 	at java.util.concurrent.FutureTask.run(FutureTask.java:266) ~[?:1.8.0_172]
   [junit4]   2> 	at org.apache.solr.common.util.ExecutorUtil$MDCAwareThreadPoolExecutor.lambda$execute$0(ExecutorUtil.java:209) ~[java/:?]
   [junit4]   2> 	... 3 more
   [junit4]   2> Caused by: org.apache.solr.common.SolrException: Collection .system doesn't exist.
   [junit4]   2> 	at org.apache.solr.cloud.autoscaling.sim.SimClusterStateProvider.simSetShardValue(SimClusterStateProvider.java:1392) ~[test/:?]
   [junit4]   2> 	at org.apache.solr.cloud.autoscaling.sim.SimClusterStateProvider.simUpdate(SimClusterStateProvider.java:1195) ~[test/:?]
   [junit4]   2> 	at org.apache.solr.cloud.autoscaling.sim.SimCloudManager.simHandleSolrRequest(SimCloudManager.java:691) ~[test/:?]
   [junit4]   2> 	at org.apache.solr.cloud.autoscaling.sim.SimCloudManager.lambda$request$15(SimCloudManager.java:618) ~[test/:?]
   [junit4]   2> 	at java.util.concurrent.FutureTask.run(FutureTask.java:266) ~[?:1.8.0_172]
   [junit4]   2> 	at org.apache.solr.common.util.ExecutorUtil$MDCAwareThreadPoolExecutor.lambda$execute$0(ExecutorUtil.java:209) ~[java/:?]
   [junit4]   2> 	... 3 more
   [junit4]   2> 2621376 DEBUG (ScheduledTrigger-9994-thread-1) [    ] o.a.s.c.a.NodeAddedTrigger NodeAddedTrigger node_added_trigger - removing marker path: /autoscaling/nodeAdded/127.0.0.1:10015_solr
   [junit4]   2> 2621376 DEBUG (AutoscalingActionExecutor-9995-thread-1) [    ] o.a.s.c.a.ScheduledTriggers -- processing actions for {
   [junit4]   2>   "id":"404c006ddb149Tdug1z3j4zni0e51ptoz0qo5po",
   [junit4]   2>   "source":"node_added_trigger",
   [junit4]   2>   "eventTime":1131122702266697,
   [junit4]   2>   "eventType":"NODEADDED",
   [junit4]   2>   "properties":{
   [junit4]   2>     "eventTimes":[1131122702266697],
   [junit4]   2>     "_enqueue_time_":1131124128709597,
   [junit4]   2>     "nodeNames":["127.0.0.1:10015_solr"]}}
   [junit4]   2> 2621376 DEBUG (AutoscalingActionExecutor-9995-thread-1) [    ] o.a.s.c.a.ComputePlanAction -- processing event: {
   [junit4]   2>   "id":"404c006ddb149Tdug1z3j4zni0e51ptoz0qo5po",
   [junit4]   2>   "source":"node_added_trigger",
   [junit4]   2>   "eventTime":1131122702266697,
   [junit4]   2>   "eventType":"NODEADDED",
   [junit4]   2>   "properties":{
   [junit4]   2>     "eventTimes":[1131122702266697],
   [junit4]   2>     "_enqueue_time_":1131124128709597,
   [junit4]   2>     "nodeNames":["127.0.0.1:10015_solr"]}} with context properties: {BEFORE_ACTION=[compute_plan]}
   [junit4]   2> 2621377 INFO  (AutoscalingActionExecutor-9995-thread-1) [    ] o.a.s.c.a.ComputePlanAction Computed Plan: action=MOVEREPLICA&collection=testNodeAdded&targetNode=127.0.0.1:10015_solr&inPlaceMove=true&replica=core_node1
   [junit4]   2> 2621377 INFO  (AutoscalingActionExecutor-9995-thread-1) [    ] o.a.s.c.a.ComputePlanAction Computed Plan: action=MOVEREPLICA&collection=testNodeAdded&targetNode=127.0.0.1:10015_solr&inPlaceMove=true&replica=core_node2
   [junit4]   2> 2621377 INFO  (AutoscalingActionExecutor-9995-thread-1) [    ] o.a.s.c.s.c.a.PolicyHelper returnSession, curr-time 1131125395 sessionWrapper.createTime 1131125379351897, this.sessionWrapper.createTime 1131125379351897 
   [junit4]   2> 2621386 INFO  (TEST-TestComputePlanAction.testNodeAdded-seed#[BC5D7C28E88D0D59]) [    ] o.a.s.c.a.s.TestComputePlanAction Node values: {
   [junit4]   2>   "127.0.0.1:10012_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":"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:10012_solr",
   [junit4]   2>     "metrics:solr.jvm:buffers.direct.Count":0,
   [junit4]   2>     "port":10012,
   [junit4]   2>     "heapUsage":123450000,
   [junit4]   2>     "sysLoadAvg":1.0,
   [junit4]   2>     "metrics:solr.node:ADMIN./admin/authorization.clientErrors:count":0},
   [junit4]   2>   "127.0.0.1:10015_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":"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:10015_solr",
   [junit4]   2>     "metrics:solr.jvm:buffers.direct.Count":0,
   [junit4]   2>     "port":10015,
   [junit4]   2>     "heapUsage":123450000,
   [junit4]   2>     "sysLoadAvg":1.0,
   [junit4]   2>     "metrics:solr.node:ADMIN./admin/authorization.clientErrors:count":0}}
   [junit4]   2> 2621389 INFO  (TEST-TestComputePlanAction.testNodeAdded-seed#[BC5D7C28E88D0D59]) [    ] o.a.s.c.a.s.TestComputePlanAction Live nodes: [127.0.0.1:10012_solr, 127.0.0.1:10015_solr], collection state: DocCollection(testNodeAdded//clusterstate.json/35)={
   [junit4]   2>   "replicationFactor":"4",
   [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":1,
   [junit4]   2>           "node_name":"127.0.0.1:10012_solr",
   [junit4]   2>           "state":"active",
   [junit4]   2>           "type":"NRT",
   [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":1,
   [junit4]   2>           "node_name":"127.0.0.1:10012_solr",
   [junit4]   2>           "state":"active",
   [junit4]   2>           "type":"NRT",
   [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":1,
   [junit4]   2>           "node_name":"127.0.0.1:10012_solr",
   [junit4]   2>           "state":"active",
   [junit4]   2>           "type":"NRT",
   [junit4]   2>           "SEARCHER.searcher.numDocs":0},
   [junit4]   2>         "core_node4":{
   [junit4]   2>           "core":"testNodeAdded_shard1

[...truncated too long message...]

Dtests.slow=true -Dtests.locale=es-GT -Dtests.timezone=Asia/Chita -Dtests.asserts=true -Dtests.file.encoding=UTF-8
Buildfile: /Users/jenkins/workspace/Lucene-Solr-master-MacOSX/solr/core/build.xml

-clover.disable:

ivy-configure:
[ivy:configure] :: Apache Ivy 2.4.0 - 20141213170938 :: http://ant.apache.org/ivy/ ::
[ivy:configure] :: loading settings :: file = /Users/jenkins/workspace/Lucene-Solr-master-MacOSX/lucene/top-level-ivy-settings.xml

install-junit4-taskdef:

ivy-availability-check:
[loadresource] Do not set property disallowed.ivy.jars.list as its length is 0.

-ivy-fail-disallowed-ivy-version:

ivy-fail:

resolve-groovy:
[ivy:cachepath] :: resolving dependencies :: org.codehaus.groovy#groovy-all-caller;working
[ivy:cachepath] 	confs: [default]
[ivy:cachepath] 	found org.codehaus.groovy#groovy-all;2.4.15 in public
[ivy:cachepath] :: resolution report :: resolve 37ms :: artifacts dl 1ms
	---------------------------------------------------------------------
	|                  |            modules            ||   artifacts   |
	|       conf       | number| search|dwnlded|evicted|| number|dwnlded|
	---------------------------------------------------------------------
	|      default     |   1   |   0   |   0   |   0   ||   1   |   0   |
	---------------------------------------------------------------------

-init-totals:

-test:
    [mkdir] Created dir: /Users/jenkins/workspace/Lucene-Solr-master-MacOSX/solr/build/solr-core/test
[junit4:pickseed] Seed property 'tests.seed' already defined: BC5D7C28E88D0D59
    [mkdir] Created dir: /Users/jenkins/workspace/Lucene-Solr-master-MacOSX/solr/build/solr-core/test/temp
   [junit4] <JUnit4> says jolly good day! Master seed: BC5D7C28E88D0D59
   [junit4] Executing 5 suites with 2 JVMs.
   [junit4] 
   [junit4] Started J1 PID(38348@serv1-vm2.sd-datasolutions.de).
   [junit4] Started J0 PID(38347@serv1-vm2.sd-datasolutions.de).
   [junit4] Suite: org.apache.solr.cloud.autoscaling.sim.TestComputePlanAction
   [junit4] OK      1.90s J1 | TestComputePlanAction.testNodeLost
   [junit4] OK      0.39s J1 | TestComputePlanAction.testNodeWithMultipleReplicasLost
   [junit4] OK      0.41s J1 | TestComputePlanAction.testNodeAdded
   [junit4] Completed [1/5] on J1 in 10.07s, 3 tests
   [junit4] 
   [junit4] Suite: org.apache.solr.cloud.autoscaling.sim.TestComputePlanAction
   [junit4] OK      2.03s J0 | TestComputePlanAction.testNodeLost
   [junit4] OK      0.43s J0 | TestComputePlanAction.testNodeWithMultipleReplicasLost
   [junit4] OK      0.43s J0 | TestComputePlanAction.testNodeAdded
   [junit4] Completed [2/5] on J0 in 10.22s, 3 tests
   [junit4] 
   [junit4] Duplicate suite name used with XML reports: org.apache.solr.cloud.autoscaling.sim.TestComputePlanAction. This may confuse tools that process XML reports. Set 'ignoreDuplicateSuites' to true to skip this message.
   [junit4] Suite: org.apache.solr.cloud.autoscaling.sim.TestComputePlanAction
   [junit4] OK      0.46s J1 | TestComputePlanAction.testNodeLost
   [junit4] OK      0.38s J1 | TestComputePlanAction.testNodeWithMultipleReplicasLost
   [junit4] OK      0.39s J1 | TestComputePlanAction.testNodeAdded
   [junit4] Completed [3/5] on J1 in 1.29s, 3 tests
   [junit4] 
   [junit4] Suite: org.apache.solr.cloud.autoscaling.sim.TestComputePlanAction
   [junit4] OK      0.51s J0 | TestComputePlanAction.testNodeLost
   [junit4] OK      0.39s J0 | TestComputePlanAction.testNodeWithMultipleReplicasLost
   [junit4] OK      0.39s J0 | TestComputePlanAction.testNodeAdded
   [junit4] Completed [4/5] on J0 in 1.34s, 3 tests
   [junit4] 
   [junit4] Suite: org.apache.solr.cloud.autoscaling.sim.TestComputePlanAction
   [junit4] OK      0.49s J1 | TestComputePlanAction.testNodeLost
   [junit4] OK      0.42s J1 | TestComputePlanAction.testNodeWithMultipleReplicasLost
   [junit4] OK      0.41s J1 | TestComputePlanAction.testNodeAdded
   [junit4] Completed [5/5] on J1 in 1.35s, 3 tests
   [junit4] 
   [junit4] JVM J0:     0.99 ..    14.60 =    13.61s
   [junit4] JVM J1:     0.99 ..    16.39 =    15.40s
   [junit4] Execution time total: 16 seconds
   [junit4] Tests summary: 5 suites, 15 tests
   [junit4] Could not remove temporary path: /Users/jenkins/workspace/Lucene-Solr-master-MacOSX/solr/build/solr-core/test/J1 (java.nio.file.DirectoryNotEmptyException: Remaining files: [/Users/jenkins/workspace/Lucene-Solr-master-MacOSX/solr/build/solr-core/test/J1/temp])
   [junit4] Could not remove temporary path: /Users/jenkins/workspace/Lucene-Solr-master-MacOSX/solr/build/solr-core/test/J0 (java.nio.file.DirectoryNotEmptyException: Remaining files: [/Users/jenkins/workspace/Lucene-Solr-master-MacOSX/solr/build/solr-core/test/J0/temp])
     [echo] 5 slowest tests:
[junit4:tophints] 117.15s | org.apache.solr.update.SoftAutoCommitTest
[junit4:tophints] 115.31s | org.apache.solr.cloud.TestTlogReplica
[junit4:tophints] 115.17s | org.apache.solr.cloud.api.collections.AssignTest
[junit4:tophints] 113.17s | org.apache.solr.cloud.ZkFailoverTest
[junit4:tophints] 101.84s | org.apache.solr.cloud.TestPullReplicaErrorHandling

-check-totals:

test-nocompile:

BUILD SUCCESSFUL
Total time: 20 seconds
[repro] Failures:
[repro]   0/5 failed: org.apache.solr.cloud.autoscaling.sim.TestComputePlanAction
[repro] Exiting with code 0
+ mv lucene/build lucene/build.repro
+ mv solr/build solr/build.repro
+ mv lucene/build.orig lucene/build
+ mv solr/build.orig solr/build
Archiving artifacts
Setting ANT_1_8_2_HOME=/Users/jenkins/tools/hudson.tasks.Ant_AntInstallation/ANT_1.8.2
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 MacOSX VBOX
		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:1149)
	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
	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/**,**/*_pid*.log". Configuration error?
[WARNINGS] Parsing warnings in console log with parser Java Compiler (javac)
Setting ANT_1_8_2_HOME=/Users/jenkins/tools/hudson.tasks.Ant_AntInstallation/ANT_1.8.2
Setting ANT_1_8_2_HOME=/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=1d33130fcba48c7a59ef0518c741b647d5826873, workspace=/Users/jenkins/workspace/Lucene-Solr-master-MacOSX
[WARNINGS] Computing warning deltas based on reference build #4666
Recording test results
Setting ANT_1_8_2_HOME=/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=/Users/jenkins/tools/hudson.tasks.Ant_AntInstallation/ANT_1.8.2
Setting ANT_1_8_2_HOME=/Users/jenkins/tools/hudson.tasks.Ant_AntInstallation/ANT_1.8.2
Setting ANT_1_8_2_HOME=/Users/jenkins/tools/hudson.tasks.Ant_AntInstallation/ANT_1.8.2
Setting ANT_1_8_2_HOME=/Users/jenkins/tools/hudson.tasks.Ant_AntInstallation/ANT_1.8.2

[JENKINS] Lucene-Solr-master-MacOSX (64bit/jdk1.8.0) - Build # 4668 - Still Unstable!

Posted by Policeman Jenkins Server <je...@thetaphi.de>.
Build: https://jenkins.thetaphi.de/job/Lucene-Solr-master-MacOSX/4668/
Java: 64bit/jdk1.8.0 -XX:+UseCompressedOops -XX:+UseSerialGC

2 tests failed.
FAILED:  org.apache.solr.cloud.autoscaling.IndexSizeTriggerTest.testMergeIntegration

Error Message:
did not finish processing in time

Stack Trace:
java.lang.AssertionError: did not finish processing in time
	at __randomizedtesting.SeedInfo.seed([9DBE2A9E8D1321C3:CE07682E6F02B439]:0)
	at org.junit.Assert.fail(Assert.java:93)
	at org.junit.Assert.assertTrue(Assert.java:43)
	at org.apache.solr.cloud.autoscaling.IndexSizeTriggerTest.testMergeIntegration(IndexSizeTriggerTest.java:425)
	at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
	at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
	at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
	at java.lang.reflect.Method.invoke(Method.java:498)
	at com.carrotsearch.randomizedtesting.RandomizedRunner.invoke(RandomizedRunner.java:1737)
	at com.carrotsearch.randomizedtesting.RandomizedRunner$8.evaluate(RandomizedRunner.java:934)
	at com.carrotsearch.randomizedtesting.RandomizedRunner$9.evaluate(RandomizedRunner.java:970)
	at com.carrotsearch.randomizedtesting.RandomizedRunner$10.evaluate(RandomizedRunner.java:984)
	at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:57)
	at org.apache.lucene.util.TestRuleSetupTeardownChained$1.evaluate(TestRuleSetupTeardownChained.java:49)
	at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:45)
	at org.apache.lucene.util.TestRuleThreadAndTestName$1.evaluate(TestRuleThreadAndTestName.java:48)
	at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:64)
	at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:47)
	at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
	at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:368)
	at com.carrotsearch.randomizedtesting.ThreadLeakControl.forkTimeoutingTask(ThreadLeakControl.java:817)
	at com.carrotsearch.randomizedtesting.ThreadLeakControl$3.evaluate(ThreadLeakControl.java:468)
	at com.carrotsearch.randomizedtesting.RandomizedRunner.runSingleTest(RandomizedRunner.java:943)
	at com.carrotsearch.randomizedtesting.RandomizedRunner$5.evaluate(RandomizedRunner.java:829)
	at com.carrotsearch.randomizedtesting.RandomizedRunner$6.evaluate(RandomizedRunner.java:879)
	at com.carrotsearch.randomizedtesting.RandomizedRunner$7.evaluate(RandomizedRunner.java:890)
	at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
	at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:57)
	at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:45)
	at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
	at org.apache.lucene.util.TestRuleStoreClassName$1.evaluate(TestRuleStoreClassName.java:41)
	at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:40)
	at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:40)
	at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
	at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
	at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
	at org.apache.lucene.util.TestRuleAssertionsRequired$1.evaluate(TestRuleAssertionsRequired.java:53)
	at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:47)
	at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:64)
	at org.apache.lucene.util.TestRuleIgnoreTestSuites$1.evaluate(TestRuleIgnoreTestSuites.java:54)
	at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
	at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:368)
	at java.lang.Thread.run(Thread.java:748)


FAILED:  org.apache.solr.cloud.autoscaling.IndexSizeTriggerTest.testSplitIntegration

Error Message:
events: [CapturedEvent{timestamp=1174571025136992, stage=STARTED, actionName='null', event={   "id":"42c42f4f36456T2s5c2m9k8qv5plwwzj5yjz9y",   "source":"index_size_trigger2",   "eventTime":1174565995897942,   "eventType":"INDEXSIZE",   "properties":{     "__start__":1,     "aboveSize":{"testSplitIntegration_collection":["{\"core_node1\":{\n    \"core\":\"testSplitIntegration_collection_shard1_replica_n1\",\n    \"leader\":\"true\",\n    \"SEARCHER.searcher.maxDoc\":25,\n    \"SEARCHER.searcher.deletedDocs\":0,\n    \"INDEX.sizeInBytes\":1,\n    \"__docs__\":25,\n    \"violationType\":\"aboveDocs\",\n    \"node_name\":\"127.0.0.1:10005_solr\",\n    \"state\":\"active\",\n    \"type\":\"NRT\",\n    \"SEARCHER.searcher.numDocs\":25,\n    \"__bytes__\":1,\n    \"shard\":\"shard1\",\n    \"collection\":\"testSplitIntegration_collection\"}}"]},     "belowSize":{},     "_enqueue_time_":1174571020990592,     "requestedOps":["Op{action=SPLITSHARD, hints={COLL_SHARD=[{\n  \"first\":\"testSplitIntegration_collection\",\n  \"second\":\"shard1\"}]}}"]}}, context={}, config={   "trigger":"index_size_trigger2",   "stage":[     "STARTED",     "ABORTED",     "SUCCEEDED",     "FAILED"],   "afterAction":[     "compute_plan",     "execute_plan"],   "class":"org.apache.solr.cloud.autoscaling.IndexSizeTriggerTest$CapturingTriggerListener",   "beforeAction":[     "compute_plan",     "execute_plan"]}, message='null'}, CapturedEvent{timestamp=1174572537565592, stage=BEFORE_ACTION, actionName='compute_plan', event={   "id":"42c42f4f36456T2s5c2m9k8qv5plwwzj5yjz9y",   "source":"index_size_trigger2",   "eventTime":1174565995897942,   "eventType":"INDEXSIZE",   "properties":{     "__start__":1,     "aboveSize":{"testSplitIntegration_collection":["{\"core_node1\":{\n    \"core\":\"testSplitIntegration_collection_shard1_replica_n1\",\n    \"leader\":\"true\",\n    \"SEARCHER.searcher.maxDoc\":25,\n    \"SEARCHER.searcher.deletedDocs\":0,\n    \"INDEX.sizeInBytes\":1,\n    \"__docs__\":25,\n    \"violationType\":\"aboveDocs\",\n    \"node_name\":\"127.0.0.1:10005_solr\",\n    \"state\":\"active\",\n    \"type\":\"NRT\",\n    \"SEARCHER.searcher.numDocs\":25,\n    \"__bytes__\":1,\n    \"shard\":\"shard1\",\n    \"collection\":\"testSplitIntegration_collection\"}}"]},     "belowSize":{},     "_enqueue_time_":1174571020990592,     "requestedOps":["Op{action=SPLITSHARD, hints={COLL_SHARD=[{\n  \"first\":\"testSplitIntegration_collection\",\n  \"second\":\"shard1\"}]}}"]}}, context={properties.BEFORE_ACTION=[compute_plan], source=index_size_trigger2}, config={   "trigger":"index_size_trigger2",   "stage":[     "STARTED",     "ABORTED",     "SUCCEEDED",     "FAILED"],   "afterAction":[     "compute_plan",     "execute_plan"],   "class":"org.apache.solr.cloud.autoscaling.IndexSizeTriggerTest$CapturingTriggerListener",   "beforeAction":[     "compute_plan",     "execute_plan"]}, message='null'}, CapturedEvent{timestamp=1174572629165792, stage=AFTER_ACTION, actionName='compute_plan', event={   "id":"42c42f4f36456T2s5c2m9k8qv5plwwzj5yjz9y",   "source":"index_size_trigger2",   "eventTime":1174565995897942,   "eventType":"INDEXSIZE",   "properties":{     "__start__":1,     "aboveSize":{"testSplitIntegration_collection":["{\"core_node1\":{\n    \"core\":\"testSplitIntegration_collection_shard1_replica_n1\",\n    \"leader\":\"true\",\n    \"SEARCHER.searcher.maxDoc\":25,\n    \"SEARCHER.searcher.deletedDocs\":0,\n    \"INDEX.sizeInBytes\":1,\n    \"__docs__\":25,\n    \"violationType\":\"aboveDocs\",\n    \"node_name\":\"127.0.0.1:10005_solr\",\n    \"state\":\"active\",\n    \"type\":\"NRT\",\n    \"SEARCHER.searcher.numDocs\":25,\n    \"__bytes__\":1,\n    \"shard\":\"shard1\",\n    \"collection\":\"testSplitIntegration_collection\"}}"]},     "belowSize":{},     "_enqueue_time_":1174571020990592,     "requestedOps":["Op{action=SPLITSHARD, hints={COLL_SHARD=[{\n  \"first\":\"testSplitIntegration_collection\",\n  \"second\":\"shard1\"}]}}"]}}, context={properties.operations=[{class=org.apache.solr.client.solrj.request.CollectionAdminRequest$SplitShard, method=GET, params.action=SPLITSHARD, params.collection=testSplitIntegration_collection, params.shard=shard1}], properties.BEFORE_ACTION=[compute_plan], source=index_size_trigger2, properties.AFTER_ACTION=[compute_plan]}, config={   "trigger":"index_size_trigger2",   "stage":[     "STARTED",     "ABORTED",     "SUCCEEDED",     "FAILED"],   "afterAction":[     "compute_plan",     "execute_plan"],   "class":"org.apache.solr.cloud.autoscaling.IndexSizeTriggerTest$CapturingTriggerListener",   "beforeAction":[     "compute_plan",     "execute_plan"]}, message='null'}, CapturedEvent{timestamp=1174572641783542, stage=BEFORE_ACTION, actionName='execute_plan', event={   "id":"42c42f4f36456T2s5c2m9k8qv5plwwzj5yjz9y",   "source":"index_size_trigger2",   "eventTime":1174565995897942,   "eventType":"INDEXSIZE",   "properties":{     "__start__":1,     "aboveSize":{"testSplitIntegration_collection":["{\"core_node1\":{\n    \"core\":\"testSplitIntegration_collection_shard1_replica_n1\",\n    \"leader\":\"true\",\n    \"SEARCHER.searcher.maxDoc\":25,\n    \"SEARCHER.searcher.deletedDocs\":0,\n    \"INDEX.sizeInBytes\":1,\n    \"__docs__\":25,\n    \"violationType\":\"aboveDocs\",\n    \"node_name\":\"127.0.0.1:10005_solr\",\n    \"state\":\"active\",\n    \"type\":\"NRT\",\n    \"SEARCHER.searcher.numDocs\":25,\n    \"__bytes__\":1,\n    \"shard\":\"shard1\",\n    \"collection\":\"testSplitIntegration_collection\"}}"]},     "belowSize":{},     "_enqueue_time_":1174571020990592,     "requestedOps":["Op{action=SPLITSHARD, hints={COLL_SHARD=[{\n  \"first\":\"testSplitIntegration_collection\",\n  \"second\":\"shard1\"}]}}"]}}, context={properties.operations=[{class=org.apache.solr.client.solrj.request.CollectionAdminRequest$SplitShard, method=GET, params.action=SPLITSHARD, params.collection=testSplitIntegration_collection, params.shard=shard1}], properties.BEFORE_ACTION=[compute_plan, execute_plan], source=index_size_trigger2, properties.AFTER_ACTION=[compute_plan]}, config={   "trigger":"index_size_trigger2",   "stage":[     "STARTED",     "ABORTED",     "SUCCEEDED",     "FAILED"],   "afterAction":[     "compute_plan",     "execute_plan"],   "class":"org.apache.solr.cloud.autoscaling.IndexSizeTriggerTest$CapturingTriggerListener",   "beforeAction":[     "compute_plan",     "execute_plan"]}, message='null'}, CapturedEvent{timestamp=1174580695109692, stage=AFTER_ACTION, actionName='execute_plan', event={   "id":"42c42f4f36456T2s5c2m9k8qv5plwwzj5yjz9y",   "source":"index_size_trigger2",   "eventTime":1174565995897942,   "eventType":"INDEXSIZE",   "properties":{     "__start__":1,     "aboveSize":{"testSplitIntegration_collection":["{\"core_node1\":{\n    \"core\":\"testSplitIntegration_collection_shard1_replica_n1\",\n    \"leader\":\"true\",\n    \"SEARCHER.searcher.maxDoc\":25,\n    \"SEARCHER.searcher.deletedDocs\":0,\n    \"INDEX.sizeInBytes\":1,\n    \"__docs__\":25,\n    \"violationType\":\"aboveDocs\",\n    \"node_name\":\"127.0.0.1:10005_solr\",\n    \"state\":\"active\",\n    \"type\":\"NRT\",\n    \"SEARCHER.searcher.numDocs\":25,\n    \"__bytes__\":1,\n    \"shard\":\"shard1\",\n    \"collection\":\"testSplitIntegration_collection\"}}"]},     "belowSize":{},     "_enqueue_time_":1174571020990592,     "requestedOps":["Op{action=SPLITSHARD, hints={COLL_SHARD=[{\n  \"first\":\"testSplitIntegration_collection\",\n  \"second\":\"shard1\"}]}}"]}}, context={properties.operations=[{class=org.apache.solr.client.solrj.request.CollectionAdminRequest$SplitShard, method=GET, params.action=SPLITSHARD, params.async=index_size_trigger2/42c42f4f36456T2s5c2m9k8qv5plwwzj5yjz9y/0, params.waitForFinalState=true, params.collection=testSplitIntegration_collection, params.shard=shard1}], properties.BEFORE_ACTION=[compute_plan, execute_plan], properties.responses=[{status={state=completed,msg=found [index_size_trigger2/42c42f4f36456T2s5c2m9k8qv5plwwzj5yjz9y/0] in completed tasks},success=}], source=index_size_trigger2, properties.AFTER_ACTION=[compute_plan, execute_plan]}, config={   "trigger":"index_size_trigger2",   "stage":[     "STARTED",     "ABORTED",     "SUCCEEDED",     "FAILED"],   "afterAction":[     "compute_plan",     "execute_plan"],   "class":"org.apache.solr.cloud.autoscaling.IndexSizeTriggerTest$CapturingTriggerListener",   "beforeAction":[     "compute_plan",     "execute_plan"]}, message='null'}, CapturedEvent{timestamp=1174580713192392, stage=SUCCEEDED, actionName='null', event={   "id":"42c42f4f36456T2s5c2m9k8qv5plwwzj5yjz9y",   "source":"index_size_trigger2",   "eventTime":1174565995897942,   "eventType":"INDEXSIZE",   "properties":{     "__start__":1,     "aboveSize":{"testSplitIntegration_collection":["{\"core_node1\":{\n    \"core\":\"testSplitIntegration_collection_shard1_replica_n1\",\n    \"leader\":\"true\",\n    \"SEARCHER.searcher.maxDoc\":25,\n    \"SEARCHER.searcher.deletedDocs\":0,\n    \"INDEX.sizeInBytes\":1,\n    \"__docs__\":25,\n    \"violationType\":\"aboveDocs\",\n    \"node_name\":\"127.0.0.1:10005_solr\",\n    \"state\":\"active\",\n    \"type\":\"NRT\",\n    \"SEARCHER.searcher.numDocs\":25,\n    \"__bytes__\":1,\n    \"shard\":\"shard1\",\n    \"collection\":\"testSplitIntegration_collection\"}}"]},     "belowSize":{},     "_enqueue_time_":1174571020990592,     "requestedOps":["Op{action=SPLITSHARD, hints={COLL_SHARD=[{\n  \"first\":\"testSplitIntegration_collection\",\n  \"second\":\"shard1\"}]}}"]}}, context={}, config={   "trigger":"index_size_trigger2",   "stage":[     "STARTED",     "ABORTED",     "SUCCEEDED",     "FAILED"],   "afterAction":[     "compute_plan",     "execute_plan"],   "class":"org.apache.solr.cloud.autoscaling.IndexSizeTriggerTest$CapturingTriggerListener",   "beforeAction":[     "compute_plan",     "execute_plan"]}, message='null'}, CapturedEvent{timestamp=1174590839178392, stage=STARTED, actionName='null', event={   "id":"42c479b8b3056T2s5c2m9k8qv5plwwzj5yjza1",   "source":"index_size_trigger2",   "eventTime":1174585970733142,   "eventType":"INDEXSIZE",   "properties":{     "__start__":3,     "aboveSize":{"testSplitIntegration_collection":[         "{\"core_node10\":{\n    \"leader\":\"true\",\n    \"SEARCHER.searcher.maxDoc\":12,\n    \"SEARCHER.searcher.deletedDocs\":0,\n    \"INDEX.sizeInBytes\":1,\n    \"__docs__\":12,\n    \"violationType\":\"aboveDocs\",\n    \"node_name\":\"127.0.0.1:10005_solr\",\n    \"base_url\":\"http://127.0.0.1:10005/solr\",\n    \"state\":\"active\",\n    \"type\":\"NRT\",\n    \"SEARCHER.searcher.numDocs\":12,\n    \"__bytes__\":1,\n    \"core\":\"testSplitIntegration_collection_shard1_1_replica1\",\n    \"shard\":\"shard1_1\",\n    \"collection\":\"testSplitIntegration_collection\"}}",         "{\"core_node3\":{\n    \"core\":\"testSplitIntegration_collection_shard2_replica_n3\",\n    \"leader\":\"true\",\n    \"SEARCHER.searcher.maxDoc\":25,\n    \"SEARCHER.searcher.deletedDocs\":0,\n    \"INDEX.sizeInBytes\":1,\n    \"__docs__\":25,\n    \"violationType\":\"aboveDocs\",\n    \"node_name\":\"127.0.0.1:10005_solr\",\n    \"state\":\"active\",\n    \"type\":\"NRT\",\n    \"SEARCHER.searcher.numDocs\":25,\n    \"__bytes__\":1,\n    \"shard\":\"shard2\",\n    \"collection\":\"testSplitIntegration_collection\"}}",         "{\"core_node7\":{\n    \"leader\":\"true\",\n    \"SEARCHER.searcher.maxDoc\":13,\n    \"SEARCHER.searcher.deletedDocs\":0,\n    \"INDEX.sizeInBytes\":1,\n    \"__docs__\":13,\n    \"violationType\":\"aboveDocs\",\n    \"node_name\":\"127.0.0.1:10004_solr\",\n    \"base_url\":\"http://127.0.0.1:10004/solr\",\n    \"state\":\"active\",\n    \"type\":\"NRT\",\n    \"SEARCHER.searcher.numDocs\":13,\n    \"__bytes__\":1,\n    \"core\":\"testSplitIntegration_collection_shard1_0_replica0\",\n    \"shard\":\"shard1_0\",\n    \"collection\":\"testSplitIntegration_collection\"}}"]},     "belowSize":{},     "_enqueue_time_":1174590833404842,     "requestedOps":[       "Op{action=SPLITSHARD, hints={COLL_SHARD=[{\n  \"first\":\"testSplitIntegration_collection\",\n  \"second\":\"shard1_1\"}]}}",       "Op{action=SPLITSHARD, hints={COLL_SHARD=[{\n  \"first\":\"testSplitIntegration_collection\",\n  \"second\":\"shard2\"}]}}",       "Op{action=SPLITSHARD, hints={COLL_SHARD=[{\n  \"first\":\"testSplitIntegration_collection\",\n  \"second\":\"shard1_0\"}]}}"]}}, context={}, config={   "trigger":"index_size_trigger2",   "stage":[     "STARTED",     "ABORTED",     "SUCCEEDED",     "FAILED"],   "afterAction":[     "compute_plan",     "execute_plan"],   "class":"org.apache.solr.cloud.autoscaling.IndexSizeTriggerTest$CapturingTriggerListener",   "beforeAction":[     "compute_plan",     "execute_plan"]}, message='null'}, CapturedEvent{timestamp=1174590915734092, stage=BEFORE_ACTION, actionName='compute_plan', event={   "id":"42c479b8b3056T2s5c2m9k8qv5plwwzj5yjza1",   "source":"index_size_trigger2",   "eventTime":1174585970733142,   "eventType":"INDEXSIZE",   "properties":{     "__start__":3,     "aboveSize":{"testSplitIntegration_collection":[         "{\"core_node10\":{\n    \"leader\":\"true\",\n    \"SEARCHER.searcher.maxDoc\":12,\n    \"SEARCHER.searcher.deletedDocs\":0,\n    \"INDEX.sizeInBytes\":1,\n    \"__docs__\":12,\n    \"violationType\":\"aboveDocs\",\n    \"node_name\":\"127.0.0.1:10005_solr\",\n    \"base_url\":\"http://127.0.0.1:10005/solr\",\n    \"state\":\"active\",\n    \"type\":\"NRT\",\n    \"SEARCHER.searcher.numDocs\":12,\n    \"__bytes__\":1,\n    \"core\":\"testSplitIntegration_collection_shard1_1_replica1\",\n    \"shard\":\"shard1_1\",\n    \"collection\":\"testSplitIntegration_collection\"}}",         "{\"core_node3\":{\n    \"core\":\"testSplitIntegration_collection_shard2_replica_n3\",\n    \"leader\":\"true\",\n    \"SEARCHER.searcher.maxDoc\":25,\n    \"SEARCHER.searcher.deletedDocs\":0,\n    \"INDEX.sizeInBytes\":1,\n    \"__docs__\":25,\n    \"violationType\":\"aboveDocs\",\n    \"node_name\":\"127.0.0.1:10005_solr\",\n    \"state\":\"active\",\n    \"type\":\"NRT\",\n    \"SEARCHER.searcher.numDocs\":25,\n    \"__bytes__\":1,\n    \"shard\":\"shard2\",\n    \"collection\":\"testSplitIntegration_collection\"}}",         "{\"core_node7\":{\n    \"leader\":\"true\",\n    \"SEARCHER.searcher.maxDoc\":13,\n    \"SEARCHER.searcher.deletedDocs\":0,\n    \"INDEX.sizeInBytes\":1,\n    \"__docs__\":13,\n    \"violationType\":\"aboveDocs\",\n    \"node_name\":\"127.0.0.1:10004_solr\",\n    \"base_url\":\"http://127.0.0.1:10004/solr\",\n    \"state\":\"active\",\n    \"type\":\"NRT\",\n    \"SEARCHER.searcher.numDocs\":13,\n    \"__bytes__\":1,\n    \"core\":\"testSplitIntegration_collection_shard1_0_replica0\",\n    \"shard\":\"shard1_0\",\n    \"collection\":\"testSplitIntegration_collection\"}}"]},     "belowSize":{},     "_enqueue_time_":1174590833404842,     "requestedOps":[       "Op{action=SPLITSHARD, hints={COLL_SHARD=[{\n  \"first\":\"testSplitIntegration_collection\",\n  \"second\":\"shard1_1\"}]}}",       "Op{action=SPLITSHARD, hints={COLL_SHARD=[{\n  \"first\":\"testSplitIntegration_collection\",\n  \"second\":\"shard2\"}]}}",       "Op{action=SPLITSHARD, hints={COLL_SHARD=[{\n  \"first\":\"testSplitIntegration_collection\",\n  \"second\":\"shard1_0\"}]}}"]}}, context={properties.BEFORE_ACTION=[compute_plan], source=index_size_trigger2}, config={   "trigger":"index_size_trigger2",   "stage":[     "STARTED",     "ABORTED",     "SUCCEEDED",     "FAILED"],   "afterAction":[     "compute_plan",     "execute_plan"],   "class":"org.apache.solr.cloud.autoscaling.IndexSizeTriggerTest$CapturingTriggerListener",   "beforeAction":[     "compute_plan",     "execute_plan"]}, message='null'}, CapturedEvent{timestamp=1174590974161892, stage=AFTER_ACTION, actionName='compute_plan', event={   "id":"42c479b8b3056T2s5c2m9k8qv5plwwzj5yjza1",   "source":"index_size_trigger2",   "eventTime":1174585970733142,   "eventType":"INDEXSIZE",   "properties":{     "__start__":3,     "aboveSize":{"testSplitIntegration_collection":[         "{\"core_node10\":{\n    \"leader\":\"true\",\n    \"SEARCHER.searcher.maxDoc\":12,\n    \"SEARCHER.searcher.deletedDocs\":0,\n    \"INDEX.sizeInBytes\":1,\n    \"__docs__\":12,\n    \"violationType\":\"aboveDocs\",\n    \"node_name\":\"127.0.0.1:10005_solr\",\n    \"base_url\":\"http://127.0.0.1:10005/solr\",\n    \"state\":\"active\",\n    \"type\":\"NRT\",\n    \"SEARCHER.searcher.numDocs\":12,\n    \"__bytes__\":1,\n    \"core\":\"testSplitIntegration_collection_shard1_1_replica1\",\n    \"shard\":\"shard1_1\",\n    \"collection\":\"testSplitIntegration_collection\"}}",         "{\"core_node3\":{\n    \"core\":\"testSplitIntegration_collection_shard2_replica_n3\",\n    \"leader\":\"true\",\n    \"SEARCHER.searcher.maxDoc\":25,\n    \"SEARCHER.searcher.deletedDocs\":0,\n    \"INDEX.sizeInBytes\":1,\n    \"__docs__\":25,\n    \"violationType\":\"aboveDocs\",\n    \"node_name\":\"127.0.0.1:10005_solr\",\n    \"state\":\"active\",\n    \"type\":\"NRT\",\n    \"SEARCHER.searcher.numDocs\":25,\n    \"__bytes__\":1,\n    \"shard\":\"shard2\",\n    \"collection\":\"testSplitIntegration_collection\"}}",         "{\"core_node7\":{\n    \"leader\":\"true\",\n    \"SEARCHER.searcher.maxDoc\":13,\n    \"SEARCHER.searcher.deletedDocs\":0,\n    \"INDEX.sizeInBytes\":1,\n    \"__docs__\":13,\n    \"violationType\":\"aboveDocs\",\n    \"node_name\":\"127.0.0.1:10004_solr\",\n    \"base_url\":\"http://127.0.0.1:10004/solr\",\n    \"state\":\"active\",\n    \"type\":\"NRT\",\n    \"SEARCHER.searcher.numDocs\":13,\n    \"__bytes__\":1,\n    \"core\":\"testSplitIntegration_collection_shard1_0_replica0\",\n    \"shard\":\"shard1_0\",\n    \"collection\":\"testSplitIntegration_collection\"}}"]},     "belowSize":{},     "_enqueue_time_":1174590833404842,     "requestedOps":[       "Op{action=SPLITSHARD, hints={COLL_SHARD=[{\n  \"first\":\"testSplitIntegration_collection\",\n  \"second\":\"shard1_1\"}]}}",       "Op{action=SPLITSHARD, hints={COLL_SHARD=[{\n  \"first\":\"testSplitIntegration_collection\",\n  \"second\":\"shard2\"}]}}",       "Op{action=SPLITSHARD, hints={COLL_SHARD=[{\n  \"first\":\"testSplitIntegration_collection\",\n  \"second\":\"shard1_0\"}]}}"]}}, context={properties.operations=[{class=org.apache.solr.client.solrj.request.CollectionAdminRequest$SplitShard, method=GET, params.action=SPLITSHARD, params.collection=testSplitIntegration_collection, params.shard=shard1_1}, {class=org.apache.solr.client.solrj.request.CollectionAdminRequest$SplitShard, method=GET, params.action=SPLITSHARD, params.collection=testSplitIntegration_collection, params.shard=shard2}, {class=org.apache.solr.client.solrj.request.CollectionAdminRequest$SplitShard, method=GET, params.action=SPLITSHARD, params.collection=testSplitIntegration_collection, params.shard=shard1_0}], properties.BEFORE_ACTION=[compute_plan], source=index_size_trigger2, properties.AFTER_ACTION=[compute_plan]}, config={   "trigger":"index_size_trigger2",   "stage":[     "STARTED",     "ABORTED",     "SUCCEEDED",     "FAILED"],   "afterAction":[     "compute_plan",     "execute_plan"],   "class":"org.apache.solr.cloud.autoscaling.IndexSizeTriggerTest$CapturingTriggerListener",   "beforeAction":[     "compute_plan",     "execute_plan"]}, message='null'}, CapturedEvent{timestamp=1174590989510042, stage=BEFORE_ACTION, actionName='execute_plan', event={   "id":"42c479b8b3056T2s5c2m9k8qv5plwwzj5yjza1",   "source":"index_size_trigger2",   "eventTime":1174585970733142,   "eventType":"INDEXSIZE",   "properties":{     "__start__":3,     "aboveSize":{"testSplitIntegration_collection":[         "{\"core_node10\":{\n    \"leader\":\"true\",\n    \"SEARCHER.searcher.maxDoc\":12,\n    \"SEARCHER.searcher.deletedDocs\":0,\n    \"INDEX.sizeInBytes\":1,\n    \"__docs__\":12,\n    \"violationType\":\"aboveDocs\",\n    \"node_name\":\"127.0.0.1:10005_solr\",\n    \"base_url\":\"http://127.0.0.1:10005/solr\",\n    \"state\":\"active\",\n    \"type\":\"NRT\",\n    \"SEARCHER.searcher.numDocs\":12,\n    \"__bytes__\":1,\n    \"core\":\"testSplitIntegration_collection_shard1_1_replica1\",\n    \"shard\":\"shard1_1\",\n    \"collection\":\"testSplitIntegration_collection\"}}",         "{\"core_node3\":{\n    \"core\":\"testSplitIntegration_collection_shard2_replica_n3\",\n    \"leader\":\"true\",\n    \"SEARCHER.searcher.maxDoc\":25,\n    \"SEARCHER.searcher.deletedDocs\":0,\n    \"INDEX.sizeInBytes\":1,\n    \"__docs__\":25,\n    \"violationType\":\"aboveDocs\",\n    \"node_name\":\"127.0.0.1:10005_solr\",\n    \"state\":\"active\",\n    \"type\":\"NRT\",\n    \"SEARCHER.searcher.numDocs\":25,\n    \"__bytes__\":1,\n    \"shard\":\"shard2\",\n    \"collection\":\"testSplitIntegration_collection\"}}",         "{\"core_node7\":{\n    \"leader\":\"true\",\n    \"SEARCHER.searcher.maxDoc\":13,\n    \"SEARCHER.searcher.deletedDocs\":0,\n    \"INDEX.sizeInBytes\":1,\n    \"__docs__\":13,\n    \"violationType\":\"aboveDocs\",\n    \"node_name\":\"127.0.0.1:10004_solr\",\n    \"base_url\":\"http://127.0.0.1:10004/solr\",\n    \"state\":\"active\",\n    \"type\":\"NRT\",\n    \"SEARCHER.searcher.numDocs\":13,\n    \"__bytes__\":1,\n    \"core\":\"testSplitIntegration_collection_shard1_0_replica0\",\n    \"shard\":\"shard1_0\",\n    \"collection\":\"testSplitIntegration_collection\"}}"]},     "belowSize":{},     "_enqueue_time_":1174590833404842,     "requestedOps":[       "Op{action=SPLITSHARD, hints={COLL_SHARD=[{\n  \"first\":\"testSplitIntegration_collection\",\n  \"second\":\"shard1_1\"}]}}",       "Op{action=SPLITSHARD, hints={COLL_SHARD=[{\n  \"first\":\"testSplitIntegration_collection\",\n  \"second\":\"shard2\"}]}}",       "Op{action=SPLITSHARD, hints={COLL_SHARD=[{\n  \"first\":\"testSplitIntegration_collection\",\n  \"second\":\"shard1_0\"}]}}"]}}, context={properties.operations=[{class=org.apache.solr.client.solrj.request.CollectionAdminRequest$SplitShard, method=GET, params.action=SPLITSHARD, params.collection=testSplitIntegration_collection, params.shard=shard1_1}, {class=org.apache.solr.client.solrj.request.CollectionAdminRequest$SplitShard, method=GET, params.action=SPLITSHARD, params.collection=testSplitIntegration_collection, params.shard=shard2}, {class=org.apache.solr.client.solrj.request.CollectionAdminRequest$SplitShard, method=GET, params.action=SPLITSHARD, params.collection=testSplitIntegration_collection, params.shard=shard1_0}], properties.BEFORE_ACTION=[compute_plan, execute_plan], source=index_size_trigger2, properties.AFTER_ACTION=[compute_plan]}, config={   "trigger":"index_size_trigger2",   "stage":[     "STARTED",     "ABORTED",     "SUCCEEDED",     "FAILED"],   "afterAction":[     "compute_plan",     "execute_plan"],   "class":"org.apache.solr.cloud.autoscaling.IndexSizeTriggerTest$CapturingTriggerListener",   "beforeAction":[     "compute_plan",     "execute_plan"]}, message='null'}] expected:<6> but was:<10>

Stack Trace:
java.lang.AssertionError: events: [CapturedEvent{timestamp=1174571025136992, stage=STARTED, actionName='null', event={
  "id":"42c42f4f36456T2s5c2m9k8qv5plwwzj5yjz9y",
  "source":"index_size_trigger2",
  "eventTime":1174565995897942,
  "eventType":"INDEXSIZE",
  "properties":{
    "__start__":1,
    "aboveSize":{"testSplitIntegration_collection":["{\"core_node1\":{\n    \"core\":\"testSplitIntegration_collection_shard1_replica_n1\",\n    \"leader\":\"true\",\n    \"SEARCHER.searcher.maxDoc\":25,\n    \"SEARCHER.searcher.deletedDocs\":0,\n    \"INDEX.sizeInBytes\":1,\n    \"__docs__\":25,\n    \"violationType\":\"aboveDocs\",\n    \"node_name\":\"127.0.0.1:10005_solr\",\n    \"state\":\"active\",\n    \"type\":\"NRT\",\n    \"SEARCHER.searcher.numDocs\":25,\n    \"__bytes__\":1,\n    \"shard\":\"shard1\",\n    \"collection\":\"testSplitIntegration_collection\"}}"]},
    "belowSize":{},
    "_enqueue_time_":1174571020990592,
    "requestedOps":["Op{action=SPLITSHARD, hints={COLL_SHARD=[{\n  \"first\":\"testSplitIntegration_collection\",\n  \"second\":\"shard1\"}]}}"]}}, context={}, config={
  "trigger":"index_size_trigger2",
  "stage":[
    "STARTED",
    "ABORTED",
    "SUCCEEDED",
    "FAILED"],
  "afterAction":[
    "compute_plan",
    "execute_plan"],
  "class":"org.apache.solr.cloud.autoscaling.IndexSizeTriggerTest$CapturingTriggerListener",
  "beforeAction":[
    "compute_plan",
    "execute_plan"]}, message='null'}, CapturedEvent{timestamp=1174572537565592, stage=BEFORE_ACTION, actionName='compute_plan', event={
  "id":"42c42f4f36456T2s5c2m9k8qv5plwwzj5yjz9y",
  "source":"index_size_trigger2",
  "eventTime":1174565995897942,
  "eventType":"INDEXSIZE",
  "properties":{
    "__start__":1,
    "aboveSize":{"testSplitIntegration_collection":["{\"core_node1\":{\n    \"core\":\"testSplitIntegration_collection_shard1_replica_n1\",\n    \"leader\":\"true\",\n    \"SEARCHER.searcher.maxDoc\":25,\n    \"SEARCHER.searcher.deletedDocs\":0,\n    \"INDEX.sizeInBytes\":1,\n    \"__docs__\":25,\n    \"violationType\":\"aboveDocs\",\n    \"node_name\":\"127.0.0.1:10005_solr\",\n    \"state\":\"active\",\n    \"type\":\"NRT\",\n    \"SEARCHER.searcher.numDocs\":25,\n    \"__bytes__\":1,\n    \"shard\":\"shard1\",\n    \"collection\":\"testSplitIntegration_collection\"}}"]},
    "belowSize":{},
    "_enqueue_time_":1174571020990592,
    "requestedOps":["Op{action=SPLITSHARD, hints={COLL_SHARD=[{\n  \"first\":\"testSplitIntegration_collection\",\n  \"second\":\"shard1\"}]}}"]}}, context={properties.BEFORE_ACTION=[compute_plan], source=index_size_trigger2}, config={
  "trigger":"index_size_trigger2",
  "stage":[
    "STARTED",
    "ABORTED",
    "SUCCEEDED",
    "FAILED"],
  "afterAction":[
    "compute_plan",
    "execute_plan"],
  "class":"org.apache.solr.cloud.autoscaling.IndexSizeTriggerTest$CapturingTriggerListener",
  "beforeAction":[
    "compute_plan",
    "execute_plan"]}, message='null'}, CapturedEvent{timestamp=1174572629165792, stage=AFTER_ACTION, actionName='compute_plan', event={
  "id":"42c42f4f36456T2s5c2m9k8qv5plwwzj5yjz9y",
  "source":"index_size_trigger2",
  "eventTime":1174565995897942,
  "eventType":"INDEXSIZE",
  "properties":{
    "__start__":1,
    "aboveSize":{"testSplitIntegration_collection":["{\"core_node1\":{\n    \"core\":\"testSplitIntegration_collection_shard1_replica_n1\",\n    \"leader\":\"true\",\n    \"SEARCHER.searcher.maxDoc\":25,\n    \"SEARCHER.searcher.deletedDocs\":0,\n    \"INDEX.sizeInBytes\":1,\n    \"__docs__\":25,\n    \"violationType\":\"aboveDocs\",\n    \"node_name\":\"127.0.0.1:10005_solr\",\n    \"state\":\"active\",\n    \"type\":\"NRT\",\n    \"SEARCHER.searcher.numDocs\":25,\n    \"__bytes__\":1,\n    \"shard\":\"shard1\",\n    \"collection\":\"testSplitIntegration_collection\"}}"]},
    "belowSize":{},
    "_enqueue_time_":1174571020990592,
    "requestedOps":["Op{action=SPLITSHARD, hints={COLL_SHARD=[{\n  \"first\":\"testSplitIntegration_collection\",\n  \"second\":\"shard1\"}]}}"]}}, context={properties.operations=[{class=org.apache.solr.client.solrj.request.CollectionAdminRequest$SplitShard, method=GET, params.action=SPLITSHARD, params.collection=testSplitIntegration_collection, params.shard=shard1}], properties.BEFORE_ACTION=[compute_plan], source=index_size_trigger2, properties.AFTER_ACTION=[compute_plan]}, config={
  "trigger":"index_size_trigger2",
  "stage":[
    "STARTED",
    "ABORTED",
    "SUCCEEDED",
    "FAILED"],
  "afterAction":[
    "compute_plan",
    "execute_plan"],
  "class":"org.apache.solr.cloud.autoscaling.IndexSizeTriggerTest$CapturingTriggerListener",
  "beforeAction":[
    "compute_plan",
    "execute_plan"]}, message='null'}, CapturedEvent{timestamp=1174572641783542, stage=BEFORE_ACTION, actionName='execute_plan', event={
  "id":"42c42f4f36456T2s5c2m9k8qv5plwwzj5yjz9y",
  "source":"index_size_trigger2",
  "eventTime":1174565995897942,
  "eventType":"INDEXSIZE",
  "properties":{
    "__start__":1,
    "aboveSize":{"testSplitIntegration_collection":["{\"core_node1\":{\n    \"core\":\"testSplitIntegration_collection_shard1_replica_n1\",\n    \"leader\":\"true\",\n    \"SEARCHER.searcher.maxDoc\":25,\n    \"SEARCHER.searcher.deletedDocs\":0,\n    \"INDEX.sizeInBytes\":1,\n    \"__docs__\":25,\n    \"violationType\":\"aboveDocs\",\n    \"node_name\":\"127.0.0.1:10005_solr\",\n    \"state\":\"active\",\n    \"type\":\"NRT\",\n    \"SEARCHER.searcher.numDocs\":25,\n    \"__bytes__\":1,\n    \"shard\":\"shard1\",\n    \"collection\":\"testSplitIntegration_collection\"}}"]},
    "belowSize":{},
    "_enqueue_time_":1174571020990592,
    "requestedOps":["Op{action=SPLITSHARD, hints={COLL_SHARD=[{\n  \"first\":\"testSplitIntegration_collection\",\n  \"second\":\"shard1\"}]}}"]}}, context={properties.operations=[{class=org.apache.solr.client.solrj.request.CollectionAdminRequest$SplitShard, method=GET, params.action=SPLITSHARD, params.collection=testSplitIntegration_collection, params.shard=shard1}], properties.BEFORE_ACTION=[compute_plan, execute_plan], source=index_size_trigger2, properties.AFTER_ACTION=[compute_plan]}, config={
  "trigger":"index_size_trigger2",
  "stage":[
    "STARTED",
    "ABORTED",
    "SUCCEEDED",
    "FAILED"],
  "afterAction":[
    "compute_plan",
    "execute_plan"],
  "class":"org.apache.solr.cloud.autoscaling.IndexSizeTriggerTest$CapturingTriggerListener",
  "beforeAction":[
    "compute_plan",
    "execute_plan"]}, message='null'}, CapturedEvent{timestamp=1174580695109692, stage=AFTER_ACTION, actionName='execute_plan', event={
  "id":"42c42f4f36456T2s5c2m9k8qv5plwwzj5yjz9y",
  "source":"index_size_trigger2",
  "eventTime":1174565995897942,
  "eventType":"INDEXSIZE",
  "properties":{
    "__start__":1,
    "aboveSize":{"testSplitIntegration_collection":["{\"core_node1\":{\n    \"core\":\"testSplitIntegration_collection_shard1_replica_n1\",\n    \"leader\":\"true\",\n    \"SEARCHER.searcher.maxDoc\":25,\n    \"SEARCHER.searcher.deletedDocs\":0,\n    \"INDEX.sizeInBytes\":1,\n    \"__docs__\":25,\n    \"violationType\":\"aboveDocs\",\n    \"node_name\":\"127.0.0.1:10005_solr\",\n    \"state\":\"active\",\n    \"type\":\"NRT\",\n    \"SEARCHER.searcher.numDocs\":25,\n    \"__bytes__\":1,\n    \"shard\":\"shard1\",\n    \"collection\":\"testSplitIntegration_collection\"}}"]},
    "belowSize":{},
    "_enqueue_time_":1174571020990592,
    "requestedOps":["Op{action=SPLITSHARD, hints={COLL_SHARD=[{\n  \"first\":\"testSplitIntegration_collection\",\n  \"second\":\"shard1\"}]}}"]}}, context={properties.operations=[{class=org.apache.solr.client.solrj.request.CollectionAdminRequest$SplitShard, method=GET, params.action=SPLITSHARD, params.async=index_size_trigger2/42c42f4f36456T2s5c2m9k8qv5plwwzj5yjz9y/0, params.waitForFinalState=true, params.collection=testSplitIntegration_collection, params.shard=shard1}], properties.BEFORE_ACTION=[compute_plan, execute_plan], properties.responses=[{status={state=completed,msg=found [index_size_trigger2/42c42f4f36456T2s5c2m9k8qv5plwwzj5yjz9y/0] in completed tasks},success=}], source=index_size_trigger2, properties.AFTER_ACTION=[compute_plan, execute_plan]}, config={
  "trigger":"index_size_trigger2",
  "stage":[
    "STARTED",
    "ABORTED",
    "SUCCEEDED",
    "FAILED"],
  "afterAction":[
    "compute_plan",
    "execute_plan"],
  "class":"org.apache.solr.cloud.autoscaling.IndexSizeTriggerTest$CapturingTriggerListener",
  "beforeAction":[
    "compute_plan",
    "execute_plan"]}, message='null'}, CapturedEvent{timestamp=1174580713192392, stage=SUCCEEDED, actionName='null', event={
  "id":"42c42f4f36456T2s5c2m9k8qv5plwwzj5yjz9y",
  "source":"index_size_trigger2",
  "eventTime":1174565995897942,
  "eventType":"INDEXSIZE",
  "properties":{
    "__start__":1,
    "aboveSize":{"testSplitIntegration_collection":["{\"core_node1\":{\n    \"core\":\"testSplitIntegration_collection_shard1_replica_n1\",\n    \"leader\":\"true\",\n    \"SEARCHER.searcher.maxDoc\":25,\n    \"SEARCHER.searcher.deletedDocs\":0,\n    \"INDEX.sizeInBytes\":1,\n    \"__docs__\":25,\n    \"violationType\":\"aboveDocs\",\n    \"node_name\":\"127.0.0.1:10005_solr\",\n    \"state\":\"active\",\n    \"type\":\"NRT\",\n    \"SEARCHER.searcher.numDocs\":25,\n    \"__bytes__\":1,\n    \"shard\":\"shard1\",\n    \"collection\":\"testSplitIntegration_collection\"}}"]},
    "belowSize":{},
    "_enqueue_time_":1174571020990592,
    "requestedOps":["Op{action=SPLITSHARD, hints={COLL_SHARD=[{\n  \"first\":\"testSplitIntegration_collection\",\n  \"second\":\"shard1\"}]}}"]}}, context={}, config={
  "trigger":"index_size_trigger2",
  "stage":[
    "STARTED",
    "ABORTED",
    "SUCCEEDED",
    "FAILED"],
  "afterAction":[
    "compute_plan",
    "execute_plan"],
  "class":"org.apache.solr.cloud.autoscaling.IndexSizeTriggerTest$CapturingTriggerListener",
  "beforeAction":[
    "compute_plan",
    "execute_plan"]}, message='null'}, CapturedEvent{timestamp=1174590839178392, stage=STARTED, actionName='null', event={
  "id":"42c479b8b3056T2s5c2m9k8qv5plwwzj5yjza1",
  "source":"index_size_trigger2",
  "eventTime":1174585970733142,
  "eventType":"INDEXSIZE",
  "properties":{
    "__start__":3,
    "aboveSize":{"testSplitIntegration_collection":[
        "{\"core_node10\":{\n    \"leader\":\"true\",\n    \"SEARCHER.searcher.maxDoc\":12,\n    \"SEARCHER.searcher.deletedDocs\":0,\n    \"INDEX.sizeInBytes\":1,\n    \"__docs__\":12,\n    \"violationType\":\"aboveDocs\",\n    \"node_name\":\"127.0.0.1:10005_solr\",\n    \"base_url\":\"http://127.0.0.1:10005/solr\",\n    \"state\":\"active\",\n    \"type\":\"NRT\",\n    \"SEARCHER.searcher.numDocs\":12,\n    \"__bytes__\":1,\n    \"core\":\"testSplitIntegration_collection_shard1_1_replica1\",\n    \"shard\":\"shard1_1\",\n    \"collection\":\"testSplitIntegration_collection\"}}",
        "{\"core_node3\":{\n    \"core\":\"testSplitIntegration_collection_shard2_replica_n3\",\n    \"leader\":\"true\",\n    \"SEARCHER.searcher.maxDoc\":25,\n    \"SEARCHER.searcher.deletedDocs\":0,\n    \"INDEX.sizeInBytes\":1,\n    \"__docs__\":25,\n    \"violationType\":\"aboveDocs\",\n    \"node_name\":\"127.0.0.1:10005_solr\",\n    \"state\":\"active\",\n    \"type\":\"NRT\",\n    \"SEARCHER.searcher.numDocs\":25,\n    \"__bytes__\":1,\n    \"shard\":\"shard2\",\n    \"collection\":\"testSplitIntegration_collection\"}}",
        "{\"core_node7\":{\n    \"leader\":\"true\",\n    \"SEARCHER.searcher.maxDoc\":13,\n    \"SEARCHER.searcher.deletedDocs\":0,\n    \"INDEX.sizeInBytes\":1,\n    \"__docs__\":13,\n    \"violationType\":\"aboveDocs\",\n    \"node_name\":\"127.0.0.1:10004_solr\",\n    \"base_url\":\"http://127.0.0.1:10004/solr\",\n    \"state\":\"active\",\n    \"type\":\"NRT\",\n    \"SEARCHER.searcher.numDocs\":13,\n    \"__bytes__\":1,\n    \"core\":\"testSplitIntegration_collection_shard1_0_replica0\",\n    \"shard\":\"shard1_0\",\n    \"collection\":\"testSplitIntegration_collection\"}}"]},
    "belowSize":{},
    "_enqueue_time_":1174590833404842,
    "requestedOps":[
      "Op{action=SPLITSHARD, hints={COLL_SHARD=[{\n  \"first\":\"testSplitIntegration_collection\",\n  \"second\":\"shard1_1\"}]}}",
      "Op{action=SPLITSHARD, hints={COLL_SHARD=[{\n  \"first\":\"testSplitIntegration_collection\",\n  \"second\":\"shard2\"}]}}",
      "Op{action=SPLITSHARD, hints={COLL_SHARD=[{\n  \"first\":\"testSplitIntegration_collection\",\n  \"second\":\"shard1_0\"}]}}"]}}, context={}, config={
  "trigger":"index_size_trigger2",
  "stage":[
    "STARTED",
    "ABORTED",
    "SUCCEEDED",
    "FAILED"],
  "afterAction":[
    "compute_plan",
    "execute_plan"],
  "class":"org.apache.solr.cloud.autoscaling.IndexSizeTriggerTest$CapturingTriggerListener",
  "beforeAction":[
    "compute_plan",
    "execute_plan"]}, message='null'}, CapturedEvent{timestamp=1174590915734092, stage=BEFORE_ACTION, actionName='compute_plan', event={
  "id":"42c479b8b3056T2s5c2m9k8qv5plwwzj5yjza1",
  "source":"index_size_trigger2",
  "eventTime":1174585970733142,
  "eventType":"INDEXSIZE",
  "properties":{
    "__start__":3,
    "aboveSize":{"testSplitIntegration_collection":[
        "{\"core_node10\":{\n    \"leader\":\"true\",\n    \"SEARCHER.searcher.maxDoc\":12,\n    \"SEARCHER.searcher.deletedDocs\":0,\n    \"INDEX.sizeInBytes\":1,\n    \"__docs__\":12,\n    \"violationType\":\"aboveDocs\",\n    \"node_name\":\"127.0.0.1:10005_solr\",\n    \"base_url\":\"http://127.0.0.1:10005/solr\",\n    \"state\":\"active\",\n    \"type\":\"NRT\",\n    \"SEARCHER.searcher.numDocs\":12,\n    \"__bytes__\":1,\n    \"core\":\"testSplitIntegration_collection_shard1_1_replica1\",\n    \"shard\":\"shard1_1\",\n    \"collection\":\"testSplitIntegration_collection\"}}",
        "{\"core_node3\":{\n    \"core\":\"testSplitIntegration_collection_shard2_replica_n3\",\n    \"leader\":\"true\",\n    \"SEARCHER.searcher.maxDoc\":25,\n    \"SEARCHER.searcher.deletedDocs\":0,\n    \"INDEX.sizeInBytes\":1,\n    \"__docs__\":25,\n    \"violationType\":\"aboveDocs\",\n    \"node_name\":\"127.0.0.1:10005_solr\",\n    \"state\":\"active\",\n    \"type\":\"NRT\",\n    \"SEARCHER.searcher.numDocs\":25,\n    \"__bytes__\":1,\n    \"shard\":\"shard2\",\n    \"collection\":\"testSplitIntegration_collection\"}}",
        "{\"core_node7\":{\n    \"leader\":\"true\",\n    \"SEARCHER.searcher.maxDoc\":13,\n    \"SEARCHER.searcher.deletedDocs\":0,\n    \"INDEX.sizeInBytes\":1,\n    \"__docs__\":13,\n    \"violationType\":\"aboveDocs\",\n    \"node_name\":\"127.0.0.1:10004_solr\",\n    \"base_url\":\"http://127.0.0.1:10004/solr\",\n    \"state\":\"active\",\n    \"type\":\"NRT\",\n    \"SEARCHER.searcher.numDocs\":13,\n    \"__bytes__\":1,\n    \"core\":\"testSplitIntegration_collection_shard1_0_replica0\",\n    \"shard\":\"shard1_0\",\n    \"collection\":\"testSplitIntegration_collection\"}}"]},
    "belowSize":{},
    "_enqueue_time_":1174590833404842,
    "requestedOps":[
      "Op{action=SPLITSHARD, hints={COLL_SHARD=[{\n  \"first\":\"testSplitIntegration_collection\",\n  \"second\":\"shard1_1\"}]}}",
      "Op{action=SPLITSHARD, hints={COLL_SHARD=[{\n  \"first\":\"testSplitIntegration_collection\",\n  \"second\":\"shard2\"}]}}",
      "Op{action=SPLITSHARD, hints={COLL_SHARD=[{\n  \"first\":\"testSplitIntegration_collection\",\n  \"second\":\"shard1_0\"}]}}"]}}, context={properties.BEFORE_ACTION=[compute_plan], source=index_size_trigger2}, config={
  "trigger":"index_size_trigger2",
  "stage":[
    "STARTED",
    "ABORTED",
    "SUCCEEDED",
    "FAILED"],
  "afterAction":[
    "compute_plan",
    "execute_plan"],
  "class":"org.apache.solr.cloud.autoscaling.IndexSizeTriggerTest$CapturingTriggerListener",
  "beforeAction":[
    "compute_plan",
    "execute_plan"]}, message='null'}, CapturedEvent{timestamp=1174590974161892, stage=AFTER_ACTION, actionName='compute_plan', event={
  "id":"42c479b8b3056T2s5c2m9k8qv5plwwzj5yjza1",
  "source":"index_size_trigger2",
  "eventTime":1174585970733142,
  "eventType":"INDEXSIZE",
  "properties":{
    "__start__":3,
    "aboveSize":{"testSplitIntegration_collection":[
        "{\"core_node10\":{\n    \"leader\":\"true\",\n    \"SEARCHER.searcher.maxDoc\":12,\n    \"SEARCHER.searcher.deletedDocs\":0,\n    \"INDEX.sizeInBytes\":1,\n    \"__docs__\":12,\n    \"violationType\":\"aboveDocs\",\n    \"node_name\":\"127.0.0.1:10005_solr\",\n    \"base_url\":\"http://127.0.0.1:10005/solr\",\n    \"state\":\"active\",\n    \"type\":\"NRT\",\n    \"SEARCHER.searcher.numDocs\":12,\n    \"__bytes__\":1,\n    \"core\":\"testSplitIntegration_collection_shard1_1_replica1\",\n    \"shard\":\"shard1_1\",\n    \"collection\":\"testSplitIntegration_collection\"}}",
        "{\"core_node3\":{\n    \"core\":\"testSplitIntegration_collection_shard2_replica_n3\",\n    \"leader\":\"true\",\n    \"SEARCHER.searcher.maxDoc\":25,\n    \"SEARCHER.searcher.deletedDocs\":0,\n    \"INDEX.sizeInBytes\":1,\n    \"__docs__\":25,\n    \"violationType\":\"aboveDocs\",\n    \"node_name\":\"127.0.0.1:10005_solr\",\n    \"state\":\"active\",\n    \"type\":\"NRT\",\n    \"SEARCHER.searcher.numDocs\":25,\n    \"__bytes__\":1,\n    \"shard\":\"shard2\",\n    \"collection\":\"testSplitIntegration_collection\"}}",
        "{\"core_node7\":{\n    \"leader\":\"true\",\n    \"SEARCHER.searcher.maxDoc\":13,\n    \"SEARCHER.searcher.deletedDocs\":0,\n    \"INDEX.sizeInBytes\":1,\n    \"__docs__\":13,\n    \"violationType\":\"aboveDocs\",\n    \"node_name\":\"127.0.0.1:10004_solr\",\n    \"base_url\":\"http://127.0.0.1:10004/solr\",\n    \"state\":\"active\",\n    \"type\":\"NRT\",\n    \"SEARCHER.searcher.numDocs\":13,\n    \"__bytes__\":1,\n    \"core\":\"testSplitIntegration_collection_shard1_0_replica0\",\n    \"shard\":\"shard1_0\",\n    \"collection\":\"testSplitIntegration_collection\"}}"]},
    "belowSize":{},
    "_enqueue_time_":1174590833404842,
    "requestedOps":[
      "Op{action=SPLITSHARD, hints={COLL_SHARD=[{\n  \"first\":\"testSplitIntegration_collection\",\n  \"second\":\"shard1_1\"}]}}",
      "Op{action=SPLITSHARD, hints={COLL_SHARD=[{\n  \"first\":\"testSplitIntegration_collection\",\n  \"second\":\"shard2\"}]}}",
      "Op{action=SPLITSHARD, hints={COLL_SHARD=[{\n  \"first\":\"testSplitIntegration_collection\",\n  \"second\":\"shard1_0\"}]}}"]}}, context={properties.operations=[{class=org.apache.solr.client.solrj.request.CollectionAdminRequest$SplitShard, method=GET, params.action=SPLITSHARD, params.collection=testSplitIntegration_collection, params.shard=shard1_1}, {class=org.apache.solr.client.solrj.request.CollectionAdminRequest$SplitShard, method=GET, params.action=SPLITSHARD, params.collection=testSplitIntegration_collection, params.shard=shard2}, {class=org.apache.solr.client.solrj.request.CollectionAdminRequest$SplitShard, method=GET, params.action=SPLITSHARD, params.collection=testSplitIntegration_collection, params.shard=shard1_0}], properties.BEFORE_ACTION=[compute_plan], source=index_size_trigger2, properties.AFTER_ACTION=[compute_plan]}, config={
  "trigger":"index_size_trigger2",
  "stage":[
    "STARTED",
    "ABORTED",
    "SUCCEEDED",
    "FAILED"],
  "afterAction":[
    "compute_plan",
    "execute_plan"],
  "class":"org.apache.solr.cloud.autoscaling.IndexSizeTriggerTest$CapturingTriggerListener",
  "beforeAction":[
    "compute_plan",
    "execute_plan"]}, message='null'}, CapturedEvent{timestamp=1174590989510042, stage=BEFORE_ACTION, actionName='execute_plan', event={
  "id":"42c479b8b3056T2s5c2m9k8qv5plwwzj5yjza1",
  "source":"index_size_trigger2",
  "eventTime":1174585970733142,
  "eventType":"INDEXSIZE",
  "properties":{
    "__start__":3,
    "aboveSize":{"testSplitIntegration_collection":[
        "{\"core_node10\":{\n    \"leader\":\"true\",\n    \"SEARCHER.searcher.maxDoc\":12,\n    \"SEARCHER.searcher.deletedDocs\":0,\n    \"INDEX.sizeInBytes\":1,\n    \"__docs__\":12,\n    \"violationType\":\"aboveDocs\",\n    \"node_name\":\"127.0.0.1:10005_solr\",\n    \"base_url\":\"http://127.0.0.1:10005/solr\",\n    \"state\":\"active\",\n    \"type\":\"NRT\",\n    \"SEARCHER.searcher.numDocs\":12,\n    \"__bytes__\":1,\n    \"core\":\"testSplitIntegration_collection_shard1_1_replica1\",\n    \"shard\":\"shard1_1\",\n    \"collection\":\"testSplitIntegration_collection\"}}",
        "{\"core_node3\":{\n    \"core\":\"testSplitIntegration_collection_shard2_replica_n3\",\n    \"leader\":\"true\",\n    \"SEARCHER.searcher.maxDoc\":25,\n    \"SEARCHER.searcher.deletedDocs\":0,\n    \"INDEX.sizeInBytes\":1,\n    \"__docs__\":25,\n    \"violationType\":\"aboveDocs\",\n    \"node_name\":\"127.0.0.1:10005_solr\",\n    \"state\":\"active\",\n    \"type\":\"NRT\",\n    \"SEARCHER.searcher.numDocs\":25,\n    \"__bytes__\":1,\n    \"shard\":\"shard2\",\n    \"collection\":\"testSplitIntegration_collection\"}}",
        "{\"core_node7\":{\n    \"leader\":\"true\",\n    \"SEARCHER.searcher.maxDoc\":13,\n    \"SEARCHER.searcher.deletedDocs\":0,\n    \"INDEX.sizeInBytes\":1,\n    \"__docs__\":13,\n    \"violationType\":\"aboveDocs\",\n    \"node_name\":\"127.0.0.1:10004_solr\",\n    \"base_url\":\"http://127.0.0.1:10004/solr\",\n    \"state\":\"active\",\n    \"type\":\"NRT\",\n    \"SEARCHER.searcher.numDocs\":13,\n    \"__bytes__\":1,\n    \"core\":\"testSplitIntegration_collection_shard1_0_replica0\",\n    \"shard\":\"shard1_0\",\n    \"collection\":\"testSplitIntegration_collection\"}}"]},
    "belowSize":{},
    "_enqueue_time_":1174590833404842,
    "requestedOps":[
      "Op{action=SPLITSHARD, hints={COLL_SHARD=[{\n  \"first\":\"testSplitIntegration_collection\",\n  \"second\":\"shard1_1\"}]}}",
      "Op{action=SPLITSHARD, hints={COLL_SHARD=[{\n  \"first\":\"testSplitIntegration_collection\",\n  \"second\":\"shard2\"}]}}",
      "Op{action=SPLITSHARD, hints={COLL_SHARD=[{\n  \"first\":\"testSplitIntegration_collection\",\n  \"second\":\"shard1_0\"}]}}"]}}, context={properties.operations=[{class=org.apache.solr.client.solrj.request.CollectionAdminRequest$SplitShard, method=GET, params.action=SPLITSHARD, params.collection=testSplitIntegration_collection, params.shard=shard1_1}, {class=org.apache.solr.client.solrj.request.CollectionAdminRequest$SplitShard, method=GET, params.action=SPLITSHARD, params.collection=testSplitIntegration_collection, params.shard=shard2}, {class=org.apache.solr.client.solrj.request.CollectionAdminRequest$SplitShard, method=GET, params.action=SPLITSHARD, params.collection=testSplitIntegration_collection, params.shard=shard1_0}], properties.BEFORE_ACTION=[compute_plan, execute_plan], source=index_size_trigger2, properties.AFTER_ACTION=[compute_plan]}, config={
  "trigger":"index_size_trigger2",
  "stage":[
    "STARTED",
    "ABORTED",
    "SUCCEEDED",
    "FAILED"],
  "afterAction":[
    "compute_plan",
    "execute_plan"],
  "class":"org.apache.solr.cloud.autoscaling.IndexSizeTriggerTest$CapturingTriggerListener",
  "beforeAction":[
    "compute_plan",
    "execute_plan"]}, message='null'}] expected:<6> but was:<10>
	at __randomizedtesting.SeedInfo.seed([9DBE2A9E8D1321C3:A43093DEA2ECE83D]: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.IndexSizeTriggerTest.testSplitIntegration(IndexSizeTriggerTest.java:314)
	at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
	at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
	at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
	at java.lang.reflect.Method.invoke(Method.java:498)
	at com.carrotsearch.randomizedtesting.RandomizedRunner.invoke(RandomizedRunner.java:1737)
	at com.carrotsearch.randomizedtesting.RandomizedRunner$8.evaluate(RandomizedRunner.java:934)
	at com.carrotsearch.randomizedtesting.RandomizedRunner$9.evaluate(RandomizedRunner.java:970)
	at com.carrotsearch.randomizedtesting.RandomizedRunner$10.evaluate(RandomizedRunner.java:984)
	at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:57)
	at org.apache.lucene.util.TestRuleSetupTeardownChained$1.evaluate(TestRuleSetupTeardownChained.java:49)
	at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:45)
	at org.apache.lucene.util.TestRuleThreadAndTestName$1.evaluate(TestRuleThreadAndTestName.java:48)
	at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:64)
	at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:47)
	at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
	at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:368)
	at com.carrotsearch.randomizedtesting.ThreadLeakControl.forkTimeoutingTask(ThreadLeakControl.java:817)
	at com.carrotsearch.randomizedtesting.ThreadLeakControl$3.evaluate(ThreadLeakControl.java:468)
	at com.carrotsearch.randomizedtesting.RandomizedRunner.runSingleTest(RandomizedRunner.java:943)
	at com.carrotsearch.randomizedtesting.RandomizedRunner$5.evaluate(RandomizedRunner.java:829)
	at com.carrotsearch.randomizedtesting.RandomizedRunner$6.evaluate(RandomizedRunner.java:879)
	at com.carrotsearch.randomizedtesting.RandomizedRunner$7.evaluate(RandomizedRunner.java:890)
	at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
	at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:57)
	at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:45)
	at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
	at org.apache.lucene.util.TestRuleStoreClassName$1.evaluate(TestRuleStoreClassName.java:41)
	at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:40)
	at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:40)
	at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
	at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
	at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
	at org.apache.lucene.util.TestRuleAssertionsRequired$1.evaluate(TestRuleAssertionsRequired.java:53)
	at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:47)
	at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:64)
	at org.apache.lucene.util.TestRuleIgnoreTestSuites$1.evaluate(TestRuleIgnoreTestSuites.java:54)
	at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
	at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:368)
	at java.lang.Thread.run(Thread.java:748)




Build Log:
[...truncated 14414 lines...]
   [junit4] Suite: org.apache.solr.cloud.autoscaling.IndexSizeTriggerTest
   [junit4]   2> Creating dataDir: /Users/jenkins/workspace/Lucene-Solr-master-MacOSX/solr/build/solr-core/test/J0/temp/solr.cloud.autoscaling.IndexSizeTriggerTest_9DBE2A9E8D1321C3-001/init-core-data-001
   [junit4]   2> 2780092 WARN  (SUITE-IndexSizeTriggerTest-seed#[9DBE2A9E8D1321C3]-worker) [    ] o.a.s.SolrTestCaseJ4 startTrackingSearchers: numOpens=17 numCloses=17
   [junit4]   2> 2780092 INFO  (SUITE-IndexSizeTriggerTest-seed#[9DBE2A9E8D1321C3]-worker) [    ] o.a.s.SolrTestCaseJ4 Using PointFields (NUMERIC_POINTS_SYSPROP=true) w/NUMERIC_DOCVALUES_SYSPROP=false
   [junit4]   2> 2780096 INFO  (SUITE-IndexSizeTriggerTest-seed#[9DBE2A9E8D1321C3]-worker) [    ] o.a.s.SolrTestCaseJ4 Randomized ssl (false) and clientAuth (false) via: @org.apache.solr.util.RandomizeSSL(reason=, value=NaN, ssl=NaN, clientAuth=NaN) w/ MAC_OS_X supressed clientAuth
   [junit4]   2> 2780097 INFO  (SUITE-IndexSizeTriggerTest-seed#[9DBE2A9E8D1321C3]-worker) [    ] o.a.s.SolrTestCaseJ4 SecureRandom sanity checks: test.solr.allowed.securerandom=null & java.security.egd=file:/dev/./urandom
   [junit4]   2> 2780097 INFO  (SUITE-IndexSizeTriggerTest-seed#[9DBE2A9E8D1321C3]-worker) [    ] o.a.s.c.MiniSolrCloudCluster Starting cluster of 2 servers in /Users/jenkins/workspace/Lucene-Solr-master-MacOSX/solr/build/solr-core/test/J0/temp/solr.cloud.autoscaling.IndexSizeTriggerTest_9DBE2A9E8D1321C3-001/tempDir-001
   [junit4]   2> 2780097 INFO  (SUITE-IndexSizeTriggerTest-seed#[9DBE2A9E8D1321C3]-worker) [    ] o.a.s.c.ZkTestServer STARTING ZK TEST SERVER
   [junit4]   2> 2780098 INFO  (Thread-4395) [    ] o.a.s.c.ZkTestServer client port:0.0.0.0/0.0.0.0:0
   [junit4]   2> 2780098 INFO  (Thread-4395) [    ] o.a.s.c.ZkTestServer Starting server
   [junit4]   2> 2780101 ERROR (Thread-4395) [    ] o.a.z.s.ZooKeeperServer ZKShutdownHandler is not registered, so ZooKeeper server won't take any action on ERROR or SHUTDOWN server state changes
   [junit4]   2> 2780206 INFO  (SUITE-IndexSizeTriggerTest-seed#[9DBE2A9E8D1321C3]-worker) [    ] o.a.s.c.ZkTestServer start zk server on port:54611
   [junit4]   2> 2780215 INFO  (zkConnectionManagerCallback-7155-thread-1) [    ] o.a.s.c.c.ConnectionManager zkClient has connected
   [junit4]   2> 2780219 INFO  (jetty-launcher-7152-thread-1) [    ] o.e.j.s.Server jetty-9.4.10.v20180503; built: 2018-05-03T15:56:21.710Z; git: daa59876e6f384329b122929e70a80934569428c; jvm 1.8.0_172-b11
   [junit4]   2> 2780219 INFO  (jetty-launcher-7152-thread-2) [    ] o.e.j.s.Server jetty-9.4.10.v20180503; built: 2018-05-03T15:56:21.710Z; git: daa59876e6f384329b122929e70a80934569428c; jvm 1.8.0_172-b11
   [junit4]   2> 2780220 INFO  (jetty-launcher-7152-thread-1) [    ] o.e.j.s.session DefaultSessionIdManager workerName=node0
   [junit4]   2> 2780220 INFO  (jetty-launcher-7152-thread-1) [    ] o.e.j.s.session No SessionScavenger set, using defaults
   [junit4]   2> 2780220 INFO  (jetty-launcher-7152-thread-1) [    ] o.e.j.s.session node0 Scavenging every 660000ms
   [junit4]   2> 2780221 INFO  (jetty-launcher-7152-thread-2) [    ] o.e.j.s.session DefaultSessionIdManager workerName=node0
   [junit4]   2> 2780221 INFO  (jetty-launcher-7152-thread-2) [    ] o.e.j.s.session No SessionScavenger set, using defaults
   [junit4]   2> 2780221 INFO  (jetty-launcher-7152-thread-2) [    ] o.e.j.s.session node0 Scavenging every 600000ms
   [junit4]   2> 2780222 INFO  (jetty-launcher-7152-thread-1) [    ] o.e.j.s.h.ContextHandler Started o.e.j.s.ServletContextHandler@3f2abf00{/solr,null,AVAILABLE}
   [junit4]   2> 2780222 INFO  (jetty-launcher-7152-thread-2) [    ] o.e.j.s.h.ContextHandler Started o.e.j.s.ServletContextHandler@60a68a4a{/solr,null,AVAILABLE}
   [junit4]   2> 2780222 INFO  (jetty-launcher-7152-thread-1) [    ] o.e.j.s.AbstractConnector Started ServerConnector@a62c8b{HTTP/1.1,[http/1.1]}{127.0.0.1:54613}
   [junit4]   2> 2780222 INFO  (jetty-launcher-7152-thread-2) [    ] o.e.j.s.AbstractConnector Started ServerConnector@281a9db7{HTTP/1.1,[http/1.1]}{127.0.0.1:54614}
   [junit4]   2> 2780222 INFO  (jetty-launcher-7152-thread-1) [    ] o.e.j.s.Server Started @2780295ms
   [junit4]   2> 2780222 INFO  (jetty-launcher-7152-thread-2) [    ] o.e.j.s.Server Started @2780295ms
   [junit4]   2> 2780222 INFO  (jetty-launcher-7152-thread-1) [    ] o.a.s.c.s.e.JettySolrRunner Jetty properties: {hostContext=/solr, hostPort=54613}
   [junit4]   2> 2780222 INFO  (jetty-launcher-7152-thread-2) [    ] o.a.s.c.s.e.JettySolrRunner Jetty properties: {hostContext=/solr, hostPort=54614}
   [junit4]   2> 2780222 ERROR (jetty-launcher-7152-thread-1) [    ] o.a.s.u.StartupLoggingUtils Missing Java Option solr.log.dir. Logging may be missing or incomplete.
   [junit4]   2> 2780222 ERROR (jetty-launcher-7152-thread-2) [    ] o.a.s.u.StartupLoggingUtils Missing Java Option solr.log.dir. Logging may be missing or incomplete.
   [junit4]   2> 2780222 INFO  (jetty-launcher-7152-thread-1) [    ] o.a.s.s.SolrDispatchFilter Using logger factory org.apache.logging.slf4j.Log4jLoggerFactory
   [junit4]   2> 2780222 INFO  (jetty-launcher-7152-thread-2) [    ] o.a.s.s.SolrDispatchFilter Using logger factory org.apache.logging.slf4j.Log4jLoggerFactory
   [junit4]   2> 2780222 INFO  (jetty-launcher-7152-thread-1) [    ] o.a.s.s.SolrDispatchFilter  ___      _       Welcome to Apache Solr™ version 8.0.0
   [junit4]   2> 2780222 INFO  (jetty-launcher-7152-thread-1) [    ] o.a.s.s.SolrDispatchFilter / __| ___| |_ _   Starting in cloud mode on port null
   [junit4]   2> 2780222 INFO  (jetty-launcher-7152-thread-2) [    ] o.a.s.s.SolrDispatchFilter  ___      _       Welcome to Apache Solr™ version 8.0.0
   [junit4]   2> 2780222 INFO  (jetty-launcher-7152-thread-1) [    ] o.a.s.s.SolrDispatchFilter \__ \/ _ \ | '_|  Install dir: null
   [junit4]   2> 2780222 INFO  (jetty-launcher-7152-thread-1) [    ] o.a.s.s.SolrDispatchFilter |___/\___/_|_|    Start time: 2018-06-01T20:13:12.128Z
   [junit4]   2> 2780222 INFO  (jetty-launcher-7152-thread-2) [    ] o.a.s.s.SolrDispatchFilter / __| ___| |_ _   Starting in cloud mode on port null
   [junit4]   2> 2780222 INFO  (jetty-launcher-7152-thread-2) [    ] o.a.s.s.SolrDispatchFilter \__ \/ _ \ | '_|  Install dir: null
   [junit4]   2> 2780222 INFO  (jetty-launcher-7152-thread-2) [    ] o.a.s.s.SolrDispatchFilter |___/\___/_|_|    Start time: 2018-06-01T20:13:12.128Z
   [junit4]   2> 2780224 INFO  (zkConnectionManagerCallback-7158-thread-1) [    ] o.a.s.c.c.ConnectionManager zkClient has connected
   [junit4]   2> 2780224 INFO  (zkConnectionManagerCallback-7159-thread-1) [    ] o.a.s.c.c.ConnectionManager zkClient has connected
   [junit4]   2> 2780225 INFO  (jetty-launcher-7152-thread-2) [    ] o.a.s.s.SolrDispatchFilter solr.xml found in ZooKeeper. Loading...
   [junit4]   2> 2780225 INFO  (jetty-launcher-7152-thread-1) [    ] o.a.s.s.SolrDispatchFilter solr.xml found in ZooKeeper. Loading...
   [junit4]   2> 2780238 INFO  (jetty-launcher-7152-thread-2) [    ] o.a.s.c.ZkContainer Zookeeper client=127.0.0.1:54611/solr
   [junit4]   2> 2780238 INFO  (jetty-launcher-7152-thread-1) [    ] o.a.s.c.ZkContainer Zookeeper client=127.0.0.1:54611/solr
   [junit4]   2> 2780239 INFO  (zkConnectionManagerCallback-7166-thread-1) [    ] o.a.s.c.c.ConnectionManager zkClient has connected
   [junit4]   2> 2780239 INFO  (zkConnectionManagerCallback-7167-thread-1) [    ] o.a.s.c.c.ConnectionManager zkClient has connected
   [junit4]   2> 2780242 INFO  (zkConnectionManagerCallback-7171-thread-1) [    ] o.a.s.c.c.ConnectionManager zkClient has connected
   [junit4]   2> 2780242 INFO  (zkConnectionManagerCallback-7170-thread-1) [    ] o.a.s.c.c.ConnectionManager zkClient has connected
   [junit4]   2> 2780394 INFO  (jetty-launcher-7152-thread-1) [n:127.0.0.1:54613_solr    ] o.a.s.c.Overseer Overseer (id=null) closing
   [junit4]   2> 2780395 INFO  (jetty-launcher-7152-thread-2) [n:127.0.0.1:54614_solr    ] o.a.s.c.Overseer Overseer (id=null) closing
   [junit4]   2> 2780395 INFO  (jetty-launcher-7152-thread-1) [n:127.0.0.1:54613_solr    ] o.a.s.c.OverseerElectionContext I am going to be the leader 127.0.0.1:54613_solr
   [junit4]   2> 2780396 INFO  (jetty-launcher-7152-thread-2) [n:127.0.0.1:54614_solr    ] o.a.s.c.ZkController Register node as live in ZooKeeper:/live_nodes/127.0.0.1:54614_solr
   [junit4]   2> 2780397 INFO  (jetty-launcher-7152-thread-1) [n:127.0.0.1:54613_solr    ] o.a.s.c.Overseer Overseer (id=72127123974193157-127.0.0.1:54613_solr-n_0000000000) starting
   [junit4]   2> 2780398 INFO  (zkCallback-7169-thread-1) [    ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (1)
   [junit4]   2> 2780398 INFO  (zkCallback-7168-thread-1) [    ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (1)
   [junit4]   2> 2780408 INFO  (zkConnectionManagerCallback-7180-thread-1) [    ] o.a.s.c.c.ConnectionManager zkClient has connected
   [junit4]   2> 2780410 INFO  (jetty-launcher-7152-thread-1) [n:127.0.0.1:54613_solr    ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (1)
   [junit4]   2> 2780411 INFO  (jetty-launcher-7152-thread-1) [n:127.0.0.1:54613_solr    ] o.a.s.c.s.i.ZkClientClusterStateProvider Cluster at 127.0.0.1:54611/solr ready
   [junit4]   2> 2780413 DEBUG (OverseerAutoScalingTriggerThread-72127123974193157-127.0.0.1:54613_solr-n_0000000000) [    ] o.a.s.c.a.OverseerTriggerThread Adding .auto_add_replicas and .scheduled_maintenance triggers
   [junit4]   2> 2780414 DEBUG (OverseerAutoScalingTriggerThread-72127123974193157-127.0.0.1:54613_solr-n_0000000000) [    ] o.a.s.c.a.OverseerTriggerThread Refreshing /autoscaling.json with znode version 1
   [junit4]   2> 2780414 DEBUG (OverseerAutoScalingTriggerThread-72127123974193157-127.0.0.1:54613_solr-n_0000000000) [    ] o.a.s.c.a.OverseerTriggerThread Current znodeVersion 1, lastZnodeVersion -1
   [junit4]   2> 2780414 DEBUG (OverseerAutoScalingTriggerThread-72127123974193157-127.0.0.1:54613_solr-n_0000000000) [    ] o.a.s.c.a.OverseerTriggerThread Processed trigger updates upto znodeVersion 1
   [junit4]   2> 2780415 INFO  (jetty-launcher-7152-thread-1) [n:127.0.0.1:54613_solr    ] o.a.s.c.TransientSolrCoreCacheDefault Allocating transient cache for 2147483647 transient cores
   [junit4]   2> 2780415 INFO  (jetty-launcher-7152-thread-1) [n:127.0.0.1:54613_solr    ] o.a.s.c.ZkController Register node as live in ZooKeeper:/live_nodes/127.0.0.1:54613_solr
   [junit4]   2> 2780421 INFO  (zkCallback-7169-thread-1) [    ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (1) -> (2)
   [junit4]   2> 2780421 INFO  (zkCallback-7168-thread-1) [    ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (1) -> (2)
   [junit4]   2> 2780422 INFO  (zkCallback-7179-thread-1) [    ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (1) -> (2)
   [junit4]   2> 2780426 DEBUG (OverseerAutoScalingTriggerThread-72127123974193157-127.0.0.1:54613_solr-n_0000000000) [    ] o.a.s.c.a.NodeLostTrigger NodeLostTrigger .auto_add_replicas - Initial livenodes: [127.0.0.1:54614_solr, 127.0.0.1:54613_solr]
   [junit4]   2> 2780427 DEBUG (OverseerAutoScalingTriggerThread-72127123974193157-127.0.0.1:54613_solr-n_0000000000) [    ] o.a.s.c.a.OverseerTriggerThread -- clean old nodeAdded markers
   [junit4]   2> 2780427 DEBUG (OverseerAutoScalingTriggerThread-72127123974193157-127.0.0.1:54613_solr-n_0000000000) [    ] o.a.s.c.a.OverseerTriggerThread Current znodeVersion 1, lastZnodeVersion 1
   [junit4]   2> 2780427 DEBUG (ScheduledTrigger-11162-thread-1) [    ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 2
   [junit4]   2> 2780588 WARN  (jetty-launcher-7152-thread-1) [n:127.0.0.1:54613_solr    ] o.a.s.h.a.MetricsHistoryHandler Missing .system, keeping metrics history in memory
   [junit4]   2> 2780592 INFO  (zkConnectionManagerCallback-7187-thread-1) [    ] o.a.s.c.c.ConnectionManager zkClient has connected
   [junit4]   2> 2780594 INFO  (jetty-launcher-7152-thread-2) [n:127.0.0.1:54614_solr    ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (2)
   [junit4]   2> 2780596 INFO  (jetty-launcher-7152-thread-2) [n:127.0.0.1:54614_solr    ] o.a.s.c.s.i.ZkClientClusterStateProvider Cluster at 127.0.0.1:54611/solr ready
   [junit4]   2> 2780597 WARN  (jetty-launcher-7152-thread-2) [n:127.0.0.1:54614_solr    ] o.a.s.h.a.MetricsHistoryHandler Missing .system, keeping metrics history in memory
   [junit4]   2> 2780645 INFO  (jetty-launcher-7152-thread-2) [n:127.0.0.1:54614_solr    ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_54614.solr.node' (registry 'solr.node') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@af4fa56
   [junit4]   2> 2780646 INFO  (jetty-launcher-7152-thread-1) [n:127.0.0.1:54613_solr    ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_54613.solr.node' (registry 'solr.node') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@af4fa56
   [junit4]   2> 2780654 INFO  (jetty-launcher-7152-thread-2) [n:127.0.0.1:54614_solr    ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_54614.solr.jvm' (registry 'solr.jvm') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@af4fa56
   [junit4]   2> 2780654 INFO  (jetty-launcher-7152-thread-2) [n:127.0.0.1:54614_solr    ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_54614.solr.jetty' (registry 'solr.jetty') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@af4fa56
   [junit4]   2> 2780655 INFO  (jetty-launcher-7152-thread-1) [n:127.0.0.1:54613_solr    ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_54613.solr.jvm' (registry 'solr.jvm') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@af4fa56
   [junit4]   2> 2780655 INFO  (jetty-launcher-7152-thread-1) [n:127.0.0.1:54613_solr    ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_54613.solr.jetty' (registry 'solr.jetty') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@af4fa56
   [junit4]   2> 2780655 INFO  (jetty-launcher-7152-thread-2) [n:127.0.0.1:54614_solr    ] o.a.s.c.CorePropertiesLocator Found 0 core definitions underneath /Users/jenkins/workspace/Lucene-Solr-master-MacOSX/solr/build/solr-core/test/J0/temp/solr.cloud.autoscaling.IndexSizeTriggerTest_9DBE2A9E8D1321C3-001/tempDir-001/node2/.
   [junit4]   2> 2780656 INFO  (jetty-launcher-7152-thread-1) [n:127.0.0.1:54613_solr    ] o.a.s.c.CorePropertiesLocator Found 0 core definitions underneath /Users/jenkins/workspace/Lucene-Solr-master-MacOSX/solr/build/solr-core/test/J0/temp/solr.cloud.autoscaling.IndexSizeTriggerTest_9DBE2A9E8D1321C3-001/tempDir-001/node1/.
   [junit4]   2> 2780695 INFO  (zkConnectionManagerCallback-7189-thread-1) [    ] o.a.s.c.c.ConnectionManager zkClient has connected
   [junit4]   2> 2780700 INFO  (zkConnectionManagerCallback-7194-thread-1) [    ] o.a.s.c.c.ConnectionManager zkClient has connected
   [junit4]   2> 2780702 INFO  (SUITE-IndexSizeTriggerTest-seed#[9DBE2A9E8D1321C3]-worker) [    ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (2)
   [junit4]   2> 2780704 INFO  (SUITE-IndexSizeTriggerTest-seed#[9DBE2A9E8D1321C3]-worker) [    ] o.a.s.c.s.i.ZkClientClusterStateProvider Cluster at 127.0.0.1:54611/solr ready
   [junit4]   2> 2780727 DEBUG (SUITE-IndexSizeTriggerTest-seed#[9DBE2A9E8D1321C3]-worker) [    ] o.a.s.c.a.s.SimClusterStateProvider --- new Overseer leader: 127.0.0.1:10004_solr
   [junit4]   2> 2780728 DEBUG (Simulated OverseerAutoScalingTriggerThread) [    ] o.a.s.c.a.OverseerTriggerThread Adding .auto_add_replicas and .scheduled_maintenance triggers
   [junit4]   2> 2780728 DEBUG (Simulated OverseerAutoScalingTriggerThread) [    ] o.a.s.c.a.OverseerTriggerThread Refreshing /autoscaling.json with znode version 0
   [junit4]   2> 2780728 WARN  (SUITE-IndexSizeTriggerTest-seed#[9DBE2A9E8D1321C3]-worker) [    ] o.a.s.h.a.MetricsHistoryHandler Missing .system, keeping metrics history in memory
   [junit4]   2> 2780728 DEBUG (Simulated OverseerAutoScalingTriggerThread) [    ] o.a.s.c.a.OverseerTriggerThread Current znodeVersion 0, lastZnodeVersion -1
   [junit4]   2> 2780728 DEBUG (Simulated OverseerAutoScalingTriggerThread) [    ] o.a.s.c.a.OverseerTriggerThread Processed trigger updates upto znodeVersion 0
   [junit4]   2> 2780729 DEBUG (Simulated OverseerAutoScalingTriggerThread) [    ] o.a.s.c.a.NodeLostTrigger NodeLostTrigger .auto_add_replicas - Initial livenodes: [127.0.0.1:10004_solr, 127.0.0.1:10005_solr]
   [junit4]   2> 2780729 DEBUG (Simulated OverseerAutoScalingTriggerThread) [    ] o.a.s.c.a.OverseerTriggerThread -- clean old nodeAdded markers
   [junit4]   2> 2780729 DEBUG (Simulated OverseerAutoScalingTriggerThread) [    ] o.a.s.c.a.OverseerTriggerThread Current znodeVersion 0, lastZnodeVersion 0
   [junit4]   2> 2780730 DEBUG (ScheduledTrigger-11175-thread-2) [    ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 2
   [junit4]   2> 2780753 DEBUG (ScheduledTrigger-11175-thread-3) [    ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 2
   [junit4]   2> 2780777 DEBUG (ScheduledTrigger-11175-thread-4) [    ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 2
   [junit4]   2> 2780799 DEBUG (ScheduledTrigger-11175-thread-1) [    ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 2
   [junit4]   2> 2780820 DEBUG (ScheduledTrigger-11175-thread-4) [    ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 2
   [junit4]   2> 2780843 DEBUG (ScheduledTrigger-11175-thread-2) [    ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 2
   [junit4]   2> 2780863 DEBUG (ScheduledTrigger-11175-thread-4) [    ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 2
   [junit4]   2> 2780885 DEBUG (ScheduledTrigger-11175-thread-1) [    ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 2
   [junit4]   2> 2780915 DEBUG (ScheduledTrigger-11175-thread-3) [    ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 2
   [junit4]   2> 2780937 DEBUG (ScheduledTrigger-11175-thread-3) [    ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 2
   [junit4]   2> 2780956 INFO  (TEST-IndexSizeTriggerTest.testMergeIntegration-seed#[9DBE2A9E8D1321C3]) [    ] o.a.s.SolrTestCaseJ4 ###Starting testMergeIntegration
   [junit4]   2> 2780962 DEBUG (ScheduledTrigger-11175-thread-1) [    ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 2
   [junit4]   2> 2780983 DEBUG (ScheduledTrigger-11175-thread-1) [    ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 2
   [junit4]   2> 2781003 DEBUG (ScheduledTrigger-11175-thread-3) [    ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 2
   [junit4]   2> 2781006 DEBUG (simCloudManagerPool-11174-thread-7) [    ] o.a.s.c.a.s.SimClusterStateProvider -- elected new leader for testMergeIntegration_collection / shard1: {"core_node1":{
   [junit4]   2>     "core":"testMergeIntegration_collection_shard1_replica_n1",
   [junit4]   2>     "leader":"true",
   [junit4]   2>     "SEARCHER.searcher.maxDoc":0,
   [junit4]   2>     "SEARCHER.searcher.deletedDocs":0,
   [junit4]   2>     "INDEX.sizeInBytes":1,
   [junit4]   2>     "node_name":"127.0.0.1:10004_solr",
   [junit4]   2>     "state":"active",
   [junit4]   2>     "type":"NRT",
   [junit4]   2>     "SEARCHER.searcher.numDocs":0,
   [junit4]   2>     "shard":"shard1",
   [junit4]   2>     "collection":"testMergeIntegration_collection"}}
   [junit4]   2> 2781006 DEBUG (simCloudManagerPool-11174-thread-6) [    ] o.a.s.c.a.s.SimClusterStateProvider -- elected new leader for testMergeIntegration_collection / shard2: {"core_node3":{
   [junit4]   2>     "core":"testMergeIntegration_collection_shard2_replica_n3",
   [junit4]   2>     "leader":"true",
   [junit4]   2>     "SEARCHER.searcher.maxDoc":0,
   [junit4]   2>     "SEARCHER.searcher.deletedDocs":0,
   [junit4]   2>     "INDEX.sizeInBytes":1,
   [junit4]   2>     "node_name":"127.0.0.1:10004_solr",
   [junit4]   2>     "state":"active",
   [junit4]   2>     "type":"NRT",
   [junit4]   2>     "SEARCHER.searcher.numDocs":0,
   [junit4]   2>     "shard":"shard2",
   [junit4]   2>     "collection":"testMergeIntegration_collection"}}
   [junit4]   2> 2781025 DEBUG (ScheduledTrigger-11175-thread-4) [    ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 2
   [junit4]   2> 2781033 DEBUG (simCloudManagerPool-11174-thread-19) [    ] o.a.s.c.a.AutoScalingHandler Verified autoscaling configuration
   [junit4]   2> 2781033 DEBUG (simCloudManagerPool-11174-thread-19) [    ] o.a.s.c.a.OverseerTriggerThread Refreshing /autoscaling.json with znode version 1
   [junit4]   2> 2781034 DEBUG (Simulated OverseerAutoScalingTriggerThread) [    ] o.a.s.c.a.OverseerTriggerThread Processed trigger updates upto znodeVersion 1
   [junit4]   2> 2781034 DEBUG (Simulated OverseerAutoScalingTriggerThread) [    ] o.a.s.c.a.OverseerTriggerThread -- clean old nodeAdded markers
   [junit4]   2> 2781034 DEBUG (Simulated OverseerAutoScalingTriggerThread) [    ] o.a.s.c.a.OverseerTriggerThread Current znodeVersion 1, lastZnodeVersion 1
   [junit4]   2> 2781036 DEBUG (simCloudManagerPool-11174-thread-20) [    ] o.a.s.c.a.AutoScalingHandler Verified autoscaling configuration
   [junit4]   2> 2781037 DEBUG (simCloudManagerPool-11174-thread-20) [    ] o.a.s.c.a.OverseerTriggerThread Refreshing /autoscaling.json with znode version 2
   [junit4]   2> 2781037 DEBUG (Simulated OverseerAutoScalingTriggerThread) [    ] o.a.s.c.a.OverseerTriggerThread Processed trigger updates upto znodeVersion 2
   [junit4]   2> 2781037 DEBUG (Simulated OverseerAutoScalingTriggerThread) [    ] o.a.s.c.a.OverseerTriggerThread -- clean old nodeAdded markers
   [junit4]   2> 2781037 DEBUG (Simulated OverseerAutoScalingTriggerThread) [    ] o.a.s.c.a.OverseerTriggerThread Current znodeVersion 2, lastZnodeVersion 2
   [junit4]   2> 2781038 DEBUG (simCloudManagerPool-11174-thread-21) [    ] o.a.s.c.a.AutoScalingHandler Verified autoscaling configuration
   [junit4]   2> 2781038 DEBUG (simCloudManagerPool-11174-thread-21) [    ] o.a.s.c.a.OverseerTriggerThread Refreshing /autoscaling.json with znode version 3
   [junit4]   2> 2781039 DEBUG (Simulated OverseerAutoScalingTriggerThread) [    ] o.a.s.c.a.OverseerTriggerThread Processed trigger updates upto znodeVersion 3
   [junit4]   2> 2781039 DEBUG (Simulated OverseerAutoScalingTriggerThread) [    ] o.a.s.c.a.OverseerTriggerThread -- clean old nodeAdded markers
   [junit4]   2> 2781039 DEBUG (Simulated OverseerAutoScalingTriggerThread) [    ] o.a.s.c.a.OverseerTriggerThread Current znodeVersion 3, lastZnodeVersion 3
   [junit4]   2> 2781042 DEBUG (simCloudManagerPool-11174-thread-28) [    ] o.a.s.c.a.AutoScalingHandler Verified autoscaling configuration
   [junit4]   2> 2781043 DEBUG (simCloudManagerPool-11174-thread-28) [    ] o.a.s.c.a.OverseerTriggerThread Refreshing /autoscaling.json with znode version 4
   [junit4]   2> 2781043 DEBUG (Simulated OverseerAutoScalingTriggerThread) [    ] o.a.s.c.a.OverseerTriggerThread Processed trigger updates upto znodeVersion 4
   [junit4]   2> 2781043 DEBUG (Simulated OverseerAutoScalingTriggerThread) [    ] o.a.s.c.a.OverseerTriggerThread -- clean old nodeAdded markers
   [junit4]   2> 2781043 DEBUG (Simulated OverseerAutoScalingTriggerThread) [    ] o.a.s.c.a.OverseerTriggerThread Current znodeVersion 4, lastZnodeVersion 4
   [junit4]   2> 2781045 DEBUG (ScheduledTrigger-11175-thread-2) [    ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 2
   [junit4]   2> 2781071 DEBUG (ScheduledTrigger-11175-thread-4) [    ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 2
   [junit4]   2> 2781098 DEBUG (ScheduledTrigger-11175-thread-4) [    ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 2
   [junit4]   2> 2781125 DEBUG (ScheduledTrigger-11175-thread-3) [    ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 2
   [junit4]   2> 2781146 DEBUG (ScheduledTrigger-11175-thread-4) [    ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 2
   [junit4]   2> 2781168 DEBUG (ScheduledTrigger-11175-thread-4) [    ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 2
   [junit4]   2> 2781170 DEBUG (ScheduledTrigger-11175-thread-3) [    ] o.a.s.c.a.ScheduledTriggers ++++++++ Cooldown inactive - processing event: {
   [junit4]   2>   "id":"42c3e4c24c742T2s5c2m9k8qv5plwwzj5yjz9v",
   [junit4]   2>   "source":"index_size_trigger3",
   [junit4]   2>   "eventTime":1174545983915842,
   [junit4]   2>   "eventType":"INDEXSIZE",
   [junit4]   2>   "properties":{
   [junit4]   2>     "aboveSize":{},
   [junit4]   2>     "belowSize":{"testMergeIntegration_collection":[
   [junit4]   2>         "{\"core_node1\":{\n    \"core\":\"testMergeIntegration_collection_shard1_replica_n1\",\n    \"leader\":\"true\",\n    \"SEARCHER.searcher.maxDoc\":7,\n    \"SEARCHER.searcher.deletedDocs\":5,\n    \"INDEX.sizeInBytes\":1,\n    \"__docs__\":2,\n    \"violationType\":\"belowDocs\",\n    \"node_name\":\"127.0.0.1:10004_solr\",\n    \"state\":\"active\",\n    \"type\":\"NRT\",\n    \"SEARCHER.searcher.numDocs\":2,\n    \"__bytes__\":1,\n    \"shard\":\"shard1\",\n    \"collection\":\"testMergeIntegration_collection\"}}",
   [junit4]   2>         "{\"core_node3\":{\n    \"core\":\"testMergeIntegration_collection_shard2_replica_n3\",\n    \"leader\":\"true\",\n    \"SEARCHER.searcher.maxDoc\":3,\n    \"SEARCHER.searcher.deletedDocs\":0,\n    \"INDEX.sizeInBytes\":1,\n    \"__docs__\":3,\n    \"violationType\":\"belowDocs\",\n    \"node_name\":\"127.0.0.1:10004_solr\",\n    \"state\":\"active\",\n    \"type\":\"NRT\",\n    \"SEARCHER.searcher.numDocs\":3,\n    \"__bytes__\":1,\n    \"shard\":\"shard2\",\n    \"collection\":\"testMergeIntegration_collection\"}}"]},
   [junit4]   2>     "requestedOps":["Op{action=MERGESHARDS, hints={COLL_SHARD=[{\n  \"first\":\"testMergeIntegration_collection\",\n  \"second\":\"shard2\"}, {\n  \"first\":\"testMergeIntegration_collection\",\n  \"second\":\"shard1\"}]}}"]}}
   [junit4]   2> 2781171 DEBUG (ScheduledTrigger-11175-thread-3) [    ] o.a.s.c.a.ScheduledTriggers Pausing all triggers: [index_size_trigger3, .auto_add_replicas, .scheduled_maintenance]
   [junit4]   2> 2781172 INFO  (ScheduledTrigger-11175-thread-3) [    ] o.a.s.c.a.IndexSizeTriggerTest =======> CapturedEvent{timestamp=1174552222336842, stage=STARTED, actionName='null', event={
   [junit4]   2>   "id":"42c3e4c24c742T2s5c2m9k8qv5plwwzj5yjz9v",
   [junit4]   2>   "source":"index_size_trigger3",
   [junit4]   2>   "eventTime":1174545983915842,
   [junit4]   2>   "eventType":"INDEXSIZE",
   [junit4]   2>   "properties":{
   [junit4]   2>     "aboveSize":{},
   [junit4]   2>     "belowSize":{"testMergeIntegration_collection":[
   [junit4]   2>         "{\"core_node1\":{\n    \"core\":\"testMergeIntegration_collection_shard1_replica_n1\",\n    \"leader\":\"true\",\n    \"SEARCHER.searcher.maxDoc\":7,\n    \"SEARCHER.searcher.deletedDocs\":5,\n    \"INDEX.sizeInBytes\":1,\n    \"__docs__\":2,\n    \"violationType\":\"belowDocs\",\n    \"node_name\":\"127.0.0.1:10004_solr\",\n    \"state\":\"active\",\n    \"type\":\"NRT\",\n    \"SEARCHER.searcher.numDocs\":2,\n    \"__bytes__\":1,\n    \"shard\":\"shard1\",\n    \"collection\":\"testMergeIntegration_collection\"}}",
   [junit4]   2>         "{\"core_node3\":{\n    \"core\":\"testMergeIntegration_collection_shard2_replica_n3\",\n    \"leader\":\"true\",\n    \"SEARCHER.searcher.maxDoc\":3,\n    \"SEARCHER.searcher.deletedDocs\":0,\n    \"INDEX.sizeInBytes\":1,\n    \"__docs__\":3,\n    \"violationType\":\"belowDocs\",\n    \"node_name\":\"127.0.0.1:10004_solr\",\n    \"state\":\"active\",\n    \"type\":\"NRT\",\n    \"SEARCHER.searcher.numDocs\":3,\n    \"__bytes__\":1,\n    \"shard\":\"shard2\",\n    \"collection\":\"testMergeIntegration_collection\"}}"]},
   [junit4]   2>     "_enqueue_time_":1174552184373742,
   [junit4]   2>     "requestedOps":["Op{action=MERGESHARDS, hints={COLL_SHARD=[{\n  \"first\":\"testMergeIntegration_collection\",\n  \"second\":\"shard2\"}, {\n  \"first\":\"testMergeIntegration_collection\",\n  \"second\":\"shard1\"}]}}"]}}, context={}, config={
   [junit4]   2>   "trigger":"index_size_trigger3",
   [junit4]   2>   "stage":[
   [junit4]   2>     "STARTED",
   [junit4]   2>     "ABORTED",
   [junit4]   2>     "SUCCEEDED",
   [junit4]   2>     "FAILED"],
   [junit4]   2>   "afterAction":[
   [junit4]   2>     "compute_plan",
   [junit4]   2>     "execute_plan"],
   [junit4]   2>   "class":"org.apache.solr.cloud.autoscaling.IndexSizeTriggerTest$CapturingTriggerListener",
   [junit4]   2>   "beforeAction":[
   [junit4]   2>     "compute_plan",
   [junit4]   2>     "execute_plan"]}, message='null'}
   [junit4]   2> 2781204 DEBUG (AutoscalingActionExecutor-11176-thread-1) [    ] o.a.s.c.a.ScheduledTriggers -- processing actions for {
   [junit4]   2>   "id":"42c3e4c24c742T2s5c2m9k8qv5plwwzj5yjz9v",
   [junit4]   2>   "source":"index_size_trigger3",
   [junit4]   2>   "eventTime":1174545983915842,
   [junit4]   2>   "eventType":"INDEXSIZE",
   [junit4]   2>   "properties":{
   [junit4]   2>     "aboveSize":{},
   [junit4]   2>     "belowSize":{"testMergeIntegration_collection":[
   [junit4]   2>         "{\"core_node1\":{\n    \"core\":\"testMergeIntegration_collection_shard1_replica_n1\",\n    \"leader\":\"true\",\n    \"SEARCHER.searcher.maxDoc\":7,\n    \"SEARCHER.searcher.deletedDocs\":5,\n    \"INDEX.sizeInBytes\":1,\n    \"__docs__\":2,\n    \"violationType\":\"belowDocs\",\n    \"node_name\":\"127.0.0.1:10004_solr\",\n    \"state\":\"active\",\n    \"type\":\"NRT\",\n    \"SEARCHER.searcher.numDocs\":2,\n    \"__bytes__\":1,\n    \"shard\":\"shard1\",\n    \"collection\":\"testMergeIntegration_collection\"}}",
   [junit4]   2>         "{\"core_node3\":{\n    \"core\":\"testMergeIntegration_collection_shard2_replica_n3\",\n    \"leader\":\"true\",\n    \"SEARCHER.searcher.maxDoc\":3,\n    \"SEARCHER.searcher.deletedDocs\":0,\n    \"INDEX.sizeInBytes\":1,\n    \"__docs__\":3,\n    \"violationType\":\"belowDocs\",\n    \"node_name\":\"127.0.0.1:10004_solr\",\n    \"state\":\"active\",\n    \"type\":\"NRT\",\n    \"SEARCHER.searcher.numDocs\":3,\n    \"__bytes__\":1,\n    \"shard\":\"shard2\",\n    \"collection\":\"testMergeIntegration_collection\"}}"]},
   [junit4]   2>     "_enqueue_time_":1174552184373742,
   [junit4]   2>     "requestedOps":["Op{action=MERGESHARDS, hints={COLL_SHARD=[{\n  \"first\":\"testMergeIntegration_collection\",\n  \"second\":\"shard2\"}, {\n  \"first\":\"testMergeIntegration_collection\",\n  \"second\":\"shard1\"}]}}"]}}
   [junit4]   2> 2781205 INFO  (AutoscalingActionExecutor-11176-thread-1) [    ] o.a.s.c.a.IndexSizeTriggerTest =======> CapturedEvent{timestamp=1174553871827292, stage=BEFORE_ACTION, actionName='compute_plan', event={
   [junit4]   2>   "id":"42c3e4c24c742T2s5c2m9k8qv5plwwzj5yjz9v",
   [junit4]   2>   "source":"index_size_trigger3",
   [junit4]   2>   "eventTime":1174545983915842,
   [junit4]   2>   "eventType":"INDEXSIZE",
   [junit4]   2>   "properties":{
   [junit4]   2>     "aboveSize":{},
   [junit4]   2>     "belowSize":{"testMergeIntegration_collection":[
   [junit4]   2>         "{\"core_node1\":{\n    \"core\":\"testMergeIntegration_collection_shard1_replica_n1\",\n    \"leader\":\"true\",\n    \"SEARCHER.searcher.maxDoc\":7,\n    \"SEARCHER.searcher.deletedDocs\":5,\n    \"INDEX.sizeInBytes\":1,\n    \"__docs__\":2,\n    \"violationType\":\"belowDocs\",\n    \"node_name\":\"127.0.0.1:10004_solr\",\n    \"state\":\"active\",\n    \"type\":\"NRT\",\n    \"SEARCHER.searcher.numDocs\":2,\n    \"__bytes__\":1,\n    \"shard\":\"shard1\",\n    \"collection\":\"testMergeIntegration_collection\"}}",
   [junit4]   2>         "{\"core_node3\":{\n    \"core\":\"testMergeIntegration_collection_shard2_replica_n3\",\n    \"leader\":\"true\",\n    \"SEARCHER.searcher.maxDoc\":3,\n    \"SEARCHER.searcher.deletedDocs\":0,\n    \"INDEX.sizeInBytes\":1,\n    \"__docs__\":3,\n    \"violationType\":\"belowDocs\",\n    \"node_name\":\"127.0.0.1:10004_solr\",\n    \"state\":\"active\",\n    \"type\":\"NRT\",\n    \"SEARCHER.searcher.numDocs\":3,\n    \"__bytes__\":1,\n    \"shard\":\"shard2\",\n    \"collection\":\"testMergeIntegration_collection\"}}"]},
   [junit4]   2>     "_enqueue_time_":1174552184373742,
   [junit4]   2>     "requestedOps":["Op{action=MERGESHARDS, hints={COLL_SHARD=[{\n  \"first\":\"testMergeIntegration_collection\",\n  \"second\":\"shard2\"}, {\n  \"first\":\"testMergeIntegration_collection\",\n  \"second\":\"shard1\"}]}}"]}}, context={properties.BEFORE_ACTION=[compute_plan], source=index_size_trigger3}, config={
   [junit4]   2>   "trigger":"index_size_trigger3",
   [junit4]   2>   "stage":[
   [junit4]   2>     "STARTED",
   [junit4]   2>     "ABORTED",
   [junit4]   2>     "SUCCEEDED",
   [junit4]   2>     "FAILED"],
   [junit4]   2>   "afterAction":[
   [junit4]   2>     "compute_plan",
   [junit4]   2>     "execute_plan"],
   [junit4]   2>   "class":"org.apache.solr.cloud.autoscaling.IndexSizeTriggerTest$CapturingTriggerListener",
   [junit4]   2>   "beforeAction":[
   [junit4]   2>     "compute_plan",
   [junit4]   2>     "execute_plan"]}, message='null'}
   [junit4]   2> 2781205 DEBUG (AutoscalingActionExecutor-11176-thread-1) [    ] o.a.s.c.a.ComputePlanAction -- processing event: {
   [junit4]   2>   "id":"42c3e4c24c742T2s5c2m9k8qv5plwwzj5yjz9v",
   [junit4]   2>   "source":"index_size_trigger3",
   [junit4]   2>   "eventTime":1174545983915842,
   [junit4]   2>   "eventType":"INDEXSIZE",
   [junit4]   2>   "properties":{
   [junit4]   2>     "aboveSize":{},
   [junit4]   2>     "belowSize":{"testMergeIntegration_collection":[
   [junit4]   2>         "{\"core_node1\":{\n    \"core\":\"testMergeIntegration_collection_shard1_replica_n1\",\n    \"leader\":\"true\",\n    \"SEARCHER.searcher.maxDoc\":7,\n    \"SEARCHER.searcher.deletedDocs\":5,\n    \"INDEX.sizeInBytes\":1,\n    \"__docs__\":2,\n    \"violationType\":\"belowDocs\",\n    \"node_name\":\"127.0.0.1:10004_solr\",\n    \"state\":\"active\",\n    \"type\":\"NRT\",\n    \"SEARCHER.searcher.numDocs\":2,\n    \"__bytes__\":1,\n    \"shard\":\"shard1\",\n    \"collection\":\"testMergeIntegration_collection\"}}",
   [junit4]   2>         "{\"core_node3\":{\n    \"core\":\"testMergeIntegration_collection_shard2_replica_n3\",\n    \"leader\":\"true\",\n    \"SEARCHER.searcher.maxDoc\":3,\n    \"SEARCHER.searcher.deletedDocs\":0,\n    \"INDEX.sizeInBytes\":1,\n    \"__docs__\":3,\n    \"violationType\":\"belowDocs\",\n    \"node_name\":\"127.0.0.1:10004_solr\",\n    \"state\":\"active\",\n    \"type\":\"NRT\",\

[...truncated too long message...]

lr.metrics.reporters.SolrJmxReporter@81e7ca7: rootName = solr_61533, domain = solr.node, service url = null, agent id = null] for registry solr.node / com.codahale.metrics.MetricRegistry@30db2abf
   [junit4]   2> 28037 INFO  (jetty-closer-88-thread-2) [    ] o.a.s.m.r.SolrJmxReporter Closing reporter [org.apache.solr.metrics.reporters.SolrJmxReporter@1175c9e2: rootName = solr_61534, domain = solr.node, service url = null, agent id = null] for registry solr.node / com.codahale.metrics.MetricRegistry@41916780
   [junit4]   2> 28053 INFO  (jetty-closer-88-thread-1) [    ] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.jvm, tag=null
   [junit4]   2> 28053 INFO  (jetty-closer-88-thread-1) [    ] o.a.s.m.r.SolrJmxReporter Closing reporter [org.apache.solr.metrics.reporters.SolrJmxReporter@79a84ff7: rootName = solr_61533, domain = solr.jvm, service url = null, agent id = null] for registry solr.jvm / com.codahale.metrics.MetricRegistry@31defd0
   [junit4]   2> 28053 INFO  (jetty-closer-88-thread-2) [    ] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.jvm, tag=null
   [junit4]   2> 28053 INFO  (jetty-closer-88-thread-2) [    ] o.a.s.m.r.SolrJmxReporter Closing reporter [org.apache.solr.metrics.reporters.SolrJmxReporter@3f91e1fb: rootName = solr_61534, domain = solr.jvm, service url = null, agent id = null] for registry solr.jvm / com.codahale.metrics.MetricRegistry@31defd0
   [junit4]   2> 28056 INFO  (jetty-closer-88-thread-1) [    ] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.jetty, tag=null
   [junit4]   2> 28056 INFO  (jetty-closer-88-thread-1) [    ] o.a.s.m.r.SolrJmxReporter Closing reporter [org.apache.solr.metrics.reporters.SolrJmxReporter@3be7041c: rootName = solr_61533, domain = solr.jetty, service url = null, agent id = null] for registry solr.jetty / com.codahale.metrics.MetricRegistry@4a9e62b6
   [junit4]   2> 28057 INFO  (jetty-closer-88-thread-2) [    ] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.jetty, tag=null
   [junit4]   2> 28057 INFO  (jetty-closer-88-thread-2) [    ] o.a.s.m.r.SolrJmxReporter Closing reporter [org.apache.solr.metrics.reporters.SolrJmxReporter@6cc7a373: rootName = solr_61534, domain = solr.jetty, service url = null, agent id = null] for registry solr.jetty / com.codahale.metrics.MetricRegistry@4a9e62b6
   [junit4]   2> 28059 INFO  (jetty-closer-88-thread-1) [    ] o.a.s.c.ZkController Remove node as live in ZooKeeper:/live_nodes/127.0.0.1:61533_solr
   [junit4]   2> 28060 INFO  (jetty-closer-88-thread-2) [    ] o.a.s.c.ZkController Remove node as live in ZooKeeper:/live_nodes/127.0.0.1:61534_solr
   [junit4]   2> 28062 INFO  (jetty-closer-88-thread-1) [    ] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.cluster, tag=null
   [junit4]   2> 28062 INFO  (jetty-closer-88-thread-2) [    ] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.cluster, tag=null
   [junit4]   2> 28063 INFO  (jetty-closer-88-thread-2) [    ] o.a.s.c.TransientSolrCoreCacheDefault Allocating transient cache for 2147483647 transient cores
   [junit4]   2> 28063 INFO  (jetty-closer-88-thread-1) [    ] o.a.s.c.Overseer Overseer (id=72127279076016134-127.0.0.1:61533_solr-n_0000000000) closing
   [junit4]   2> 28063 DEBUG (jetty-closer-88-thread-1) [    ] o.a.s.c.a.ScheduledTriggers Shutting down scheduled thread pool executor now
   [junit4]   2> 28063 DEBUG (jetty-closer-88-thread-1) [    ] o.a.s.c.a.ScheduledTriggers Shutting down action executor now
   [junit4]   2> 28063 DEBUG (jetty-closer-88-thread-1) [    ] o.a.s.c.a.ScheduledTriggers Awaiting termination for action executor
   [junit4]   2> 28064 DEBUG (jetty-closer-88-thread-1) [    ] o.a.s.c.a.ScheduledTriggers Awaiting termination for scheduled thread pool executor
   [junit4]   2> 28064 INFO  (zkCallback-104-thread-1) [    ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (2) -> (0)
   [junit4]   2> 28064 INFO  (OverseerStateUpdate-72127279076016134-127.0.0.1:61533_solr-n_0000000000) [    ] o.a.s.c.Overseer Overseer Loop exiting : 127.0.0.1:61533_solr
   [junit4]   2> 28064 WARN  (OverseerAutoScalingTriggerThread-72127279076016134-127.0.0.1:61533_solr-n_0000000000) [    ] o.a.s.c.a.OverseerTriggerThread OverseerTriggerThread woken up but we are closed, exiting.
   [junit4]   2> 28064 INFO  (zkCallback-103-thread-1) [    ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (2) -> (0)
   [junit4]   2> 28065 INFO  (zkCallback-121-thread-1) [    ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (2) -> (0)
   [junit4]   2> 28065 INFO  (zkCallback-114-thread-1) [    ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (2) -> (0)
   [junit4]   2> 28066 DEBUG (jetty-closer-88-thread-1) [    ] o.a.s.c.a.ScheduledTriggers ScheduledTriggers closed completely
   [junit4]   2> 28066 DEBUG (jetty-closer-88-thread-1) [    ] o.a.s.c.a.OverseerTriggerThread OverseerTriggerThread has been closed explicitly
   [junit4]   2> 28069 INFO  (jetty-closer-88-thread-2) [    ] o.e.j.s.h.ContextHandler Stopped o.e.j.s.ServletContextHandler@7b37b77b{/solr,null,UNAVAILABLE}
   [junit4]   2> 28069 INFO  (jetty-closer-88-thread-2) [    ] o.e.j.s.session node0 Stopped scavenging
   [junit4]   2> 28070 INFO  (jetty-closer-88-thread-1) [    ] o.e.j.s.h.ContextHandler Stopped o.e.j.s.ServletContextHandler@144978e3{/solr,null,UNAVAILABLE}
   [junit4]   2> 28070 INFO  (jetty-closer-88-thread-1) [    ] o.e.j.s.session node0 Stopped scavenging
   [junit4]   2> 28072 ERROR (SUITE-IndexSizeTriggerTest-seed#[9DBE2A9E8D1321C3]-worker) [    ] o.a.z.s.ZooKeeperServer ZKShutdownHandler is not registered, so ZooKeeper server won't take any action on ERROR or SHUTDOWN server state changes
   [junit4]   2> 28072 INFO  (SUITE-IndexSizeTriggerTest-seed#[9DBE2A9E8D1321C3]-worker) [    ] o.a.s.c.ZkTestServer connecting to 127.0.0.1:61531 61531
   [junit4]   2> 28087 INFO  (Thread-42) [    ] o.a.s.c.ZkTestServer connecting to 127.0.0.1:61531 61531
   [junit4]   2> 28256 WARN  (Thread-42) [    ] o.a.s.c.ZkTestServer Watch limit violations: 
   [junit4]   2> Maximum concurrent create/delete watches above limit:
   [junit4]   2> 
   [junit4]   2> 	5	/solr/aliases.json
   [junit4]   2> 	5	/solr/clusterprops.json
   [junit4]   2> 	2	/solr/security.json
   [junit4]   2> 
   [junit4]   2> Maximum concurrent data watches above limit:
   [junit4]   2> 
   [junit4]   2> 	5	/solr/clusterstate.json
   [junit4]   2> 
   [junit4]   2> Maximum concurrent children watches above limit:
   [junit4]   2> 
   [junit4]   2> 	5	/solr/live_nodes
   [junit4]   2> 	5	/solr/collections
   [junit4]   2> 
   [junit4]   2> NOTE: leaving temporary files on disk at: /Users/jenkins/workspace/Lucene-Solr-master-MacOSX/solr/build/solr-core/test/J1/temp/solr.cloud.autoscaling.IndexSizeTriggerTest_9DBE2A9E8D1321C3-001
   [junit4]   2> Jun 01, 2018 8:52:43 PM com.carrotsearch.randomizedtesting.ThreadLeakControl checkThreadLeaks
   [junit4]   2> WARNING: Will linger awaiting termination of 1 leaked thread(s).
   [junit4]   2> NOTE: test params are: codec=Asserting(Lucene70): {}, docValues:{}, maxPointsInLeafNode=1854, maxMBSortInHeap=7.613226637735725, sim=Asserting(org.apache.lucene.search.similarities.AssertingSimilarity@12d49788), locale=hi, timezone=CAT
   [junit4]   2> NOTE: Mac OS X 10.11.6 x86_64/Oracle Corporation 1.8.0_172 (64-bit)/cpus=3,threads=1,free=28478680,total=55181312
   [junit4]   2> NOTE: All tests run in this JVM: [IndexSizeTriggerTest, IndexSizeTriggerTest, IndexSizeTriggerTest]
   [junit4] Completed [5/5 (1!)] on J1 in 4.99s, 4 tests, 1 failure <<< FAILURES!
   [junit4] 
   [junit4] 
   [junit4] Tests with failures [seed: 9DBE2A9E8D1321C3]:
   [junit4]   - org.apache.solr.cloud.autoscaling.IndexSizeTriggerTest.testMergeIntegration
   [junit4] 
   [junit4] 
   [junit4] JVM J0:     0.69 ..    24.08 =    23.39s
   [junit4] JVM J1:     0.69 ..    31.11 =    30.42s
   [junit4] Execution time total: 31 seconds
   [junit4] Tests summary: 5 suites, 20 tests, 1 failure

BUILD FAILED
/Users/jenkins/workspace/Lucene-Solr-master-MacOSX/lucene/common-build.xml:1568: The following error occurred while executing this line:
/Users/jenkins/workspace/Lucene-Solr-master-MacOSX/lucene/common-build.xml:1092: There were test failures: 5 suites, 20 tests, 1 failure [seed: 9DBE2A9E8D1321C3]

Total time: 33 seconds

[repro] Setting last failure code to 256

[repro] Failures:
[repro]   1/5 failed: org.apache.solr.cloud.autoscaling.IndexSizeTriggerTest
[repro] Exiting with code 256
+ mv lucene/build lucene/build.repro
+ mv solr/build solr/build.repro
+ mv lucene/build.orig lucene/build
+ mv solr/build.orig solr/build
Archiving artifacts
Setting ANT_1_8_2_HOME=/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=/Users/jenkins/tools/hudson.tasks.Ant_AntInstallation/ANT_1.8.2
Setting ANT_1_8_2_HOME=/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=1d33130fcba48c7a59ef0518c741b647d5826873, workspace=/Users/jenkins/workspace/Lucene-Solr-master-MacOSX
[WARNINGS] Computing warning deltas based on reference build #4667
Recording test results
Setting ANT_1_8_2_HOME=/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=/Users/jenkins/tools/hudson.tasks.Ant_AntInstallation/ANT_1.8.2
Setting ANT_1_8_2_HOME=/Users/jenkins/tools/hudson.tasks.Ant_AntInstallation/ANT_1.8.2
Setting ANT_1_8_2_HOME=/Users/jenkins/tools/hudson.tasks.Ant_AntInstallation/ANT_1.8.2
Setting ANT_1_8_2_HOME=/Users/jenkins/tools/hudson.tasks.Ant_AntInstallation/ANT_1.8.2