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/05/31 19:57:10 UTC
[JENKINS] Lucene-Solr-7.x-Linux (64bit/jdk-9.0.4) - Build # 2025 -
Unstable!
Build: https://jenkins.thetaphi.de/job/Lucene-Solr-7.x-Linux/2025/
Java: 64bit/jdk-9.0.4 -XX:+UseCompressedOops -XX:+UseG1GC
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@7a02e1e2, org.apache.solr.client.solrj.request.CollectionAdminRequest$MoveReplica@bf29883] 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@7a02e1e2, org.apache.solr.client.solrj.request.CollectionAdminRequest$MoveReplica@bf29883] expected:<1> but was:<2>
at __randomizedtesting.SeedInfo.seed([B4921AA6A77AB73B:D1514CD105D91F38]: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 java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
at java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
at java.base/java.lang.reflect.Method.invoke(Method.java:564)
at com.carrotsearch.randomizedtesting.RandomizedRunner.invoke(RandomizedRunner.java: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 org.apache.lucene.util.TestRuleAssertionsRequired$1.evaluate(TestRuleAssertionsRequired.java:53)
at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:47)
at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:64)
at org.apache.lucene.util.TestRuleIgnoreTestSuites$1.evaluate(TestRuleIgnoreTestSuites.java:54)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:368)
at java.base/java.lang.Thread.run(Thread.java:844)
Build Log:
[...truncated 12435 lines...]
[junit4] Suite: org.apache.solr.cloud.autoscaling.sim.TestComputePlanAction
[junit4] 2> 33634 INFO (SUITE-TestComputePlanAction-seed#[B4921AA6A77AB73B]-worker) [ ] o.a.s.SolrTestCaseJ4 SecureRandom sanity checks: test.solr.allowed.securerandom=null & java.security.egd=file:/dev/./urandom
[junit4] 2> Creating dataDir: /home/jenkins/workspace/Lucene-Solr-7.x-Linux/solr/build/solr-core/test/J0/temp/solr.cloud.autoscaling.sim.TestComputePlanAction_B4921AA6A77AB73B-001/init-core-data-001
[junit4] 2> 33635 WARN (SUITE-TestComputePlanAction-seed#[B4921AA6A77AB73B]-worker) [ ] o.a.s.SolrTestCaseJ4 startTrackingSearchers: numOpens=16 numCloses=16
[junit4] 2> 33635 INFO (SUITE-TestComputePlanAction-seed#[B4921AA6A77AB73B]-worker) [ ] o.a.s.SolrTestCaseJ4 Using PointFields (NUMERIC_POINTS_SYSPROP=true) w/NUMERIC_DOCVALUES_SYSPROP=false
[junit4] 2> 33636 INFO (SUITE-TestComputePlanAction-seed#[B4921AA6A77AB73B]-worker) [ ] o.a.s.SolrTestCaseJ4 Randomized ssl (false) and clientAuth (true) via: @org.apache.solr.util.RandomizeSSL(reason="", ssl=0.0/0.0, value=0.0/0.0, clientAuth=0.0/0.0)
[junit4] 2> 33652 DEBUG (SUITE-TestComputePlanAction-seed#[B4921AA6A77AB73B]-worker) [ ] o.a.s.c.a.s.SimClusterStateProvider --- new Overseer leader: 127.0.0.1:10000_solr
[junit4] 2> 33653 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Adding .auto_add_replicas and .scheduled_maintenance triggers
[junit4] 2> 33654 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Refreshing /autoscaling.json with znode version 0
[junit4] 2> 33654 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Current znodeVersion 0, lastZnodeVersion -1
[junit4] 2> 33654 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Processed trigger updates upto znodeVersion 0
[junit4] 2> 33666 WARN (SUITE-TestComputePlanAction-seed#[B4921AA6A77AB73B]-worker) [ ] o.a.s.h.a.MetricsHistoryHandler Missing .system, keeping metrics history in memory
[junit4] 2> 33670 INFO (TEST-TestComputePlanAction.testNodeAdded-seed#[B4921AA6A77AB73B]) [ ] o.a.s.SolrTestCaseJ4 ###Starting testNodeAdded
[junit4] 2> 33670 DEBUG (TEST-TestComputePlanAction.testNodeAdded-seed#[B4921AA6A77AB73B]) [ ] o.a.s.c.a.OverseerTriggerThread Refreshing /autoscaling.json with znode version 1
[junit4] 2> 33671 INFO (TEST-TestComputePlanAction.testNodeAdded-seed#[B4921AA6A77AB73B]) [ ] o.a.s.c.a.s.SimCloudManager === Restarting OverseerTriggerThread and clearing object cache...
[junit4] 2> 33681 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.NodeLostTrigger NodeLostTrigger .auto_add_replicas - Initial livenodes: [127.0.0.1:10000_solr]
[junit4] 2> 33682 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread -- clean old nodeAdded markers
[junit4] 2> 33683 WARN (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Interrupted
[junit4] 2> java.lang.InterruptedException: null
[junit4] 2> at java.util.concurrent.locks.AbstractQueuedSynchronizer.acquireInterruptibly(AbstractQueuedSynchronizer.java:1247) ~[?:?]
[junit4] 2> at java.util.concurrent.locks.ReentrantLock.lockInterruptibly(ReentrantLock.java:317) ~[?:?]
[junit4] 2> at org.apache.solr.cloud.autoscaling.OverseerTriggerThread.run(OverseerTriggerThread.java:177) [java/:?]
[junit4] 2> at java.lang.Thread.run(Thread.java:844) [?:?]
[junit4] 2> 33697 DEBUG (ScheduledTrigger-118-thread-1) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 1
[junit4] 2> 33698 DEBUG (TEST-TestComputePlanAction.testNodeAdded-seed#[B4921AA6A77AB73B]) [ ] o.a.s.c.a.ScheduledTriggers Shutting down scheduled thread pool executor now
[junit4] 2> 33698 DEBUG (TEST-TestComputePlanAction.testNodeAdded-seed#[B4921AA6A77AB73B]) [ ] o.a.s.c.a.ScheduledTriggers Shutting down action executor now
[junit4] 2> 33698 DEBUG (TEST-TestComputePlanAction.testNodeAdded-seed#[B4921AA6A77AB73B]) [ ] o.a.s.c.a.ScheduledTriggers Awaiting termination for action executor
[junit4] 2> 33698 DEBUG (TEST-TestComputePlanAction.testNodeAdded-seed#[B4921AA6A77AB73B]) [ ] o.a.s.c.a.ScheduledTriggers Awaiting termination for scheduled thread pool executor
[junit4] 2> 33699 DEBUG (TEST-TestComputePlanAction.testNodeAdded-seed#[B4921AA6A77AB73B]) [ ] o.a.s.c.a.ScheduledTriggers ScheduledTriggers closed completely
[junit4] 2> 33699 DEBUG (TEST-TestComputePlanAction.testNodeAdded-seed#[B4921AA6A77AB73B]) [ ] o.a.s.c.a.OverseerTriggerThread OverseerTriggerThread has been closed explicitly
[junit4] 2> 33701 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Adding .auto_add_replicas and .scheduled_maintenance triggers
[junit4] 2> 33701 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Refreshing /autoscaling.json with znode version 2
[junit4] 2> 33704 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Current znodeVersion 2, lastZnodeVersion -1
[junit4] 2> 33704 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Processed trigger updates upto znodeVersion 2
[junit4] 2> 33708 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.NodeLostTrigger NodeLostTrigger .auto_add_replicas - Initial livenodes: [127.0.0.1:10000_solr]
[junit4] 2> 33712 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread -- clean old nodeAdded markers
[junit4] 2> 33712 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Current znodeVersion 2, lastZnodeVersion 2
[junit4] 2> 33713 DEBUG (ScheduledTrigger-123-thread-2) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 1
[junit4] 2> 33740 DEBUG (ScheduledTrigger-123-thread-2) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 1
[junit4] 2> 33761 DEBUG (ScheduledTrigger-123-thread-2) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 1
[junit4] 2> 33781 DEBUG (ScheduledTrigger-123-thread-1) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 1
[junit4] 2> 33804 DEBUG (ScheduledTrigger-123-thread-1) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 1
[junit4] 2> 33828 DEBUG (ScheduledTrigger-123-thread-1) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 1
[junit4] 2> 33849 DEBUG (ScheduledTrigger-123-thread-1) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 1
[junit4] 2> 33864 DEBUG (simCloudManagerPool-122-thread-1) [ ] o.a.s.c.a.AutoScalingHandler Verified autoscaling configuration
[junit4] 2> 33869 DEBUG (ScheduledTrigger-123-thread-1) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 1
[junit4] 2> 33880 DEBUG (simCloudManagerPool-122-thread-1) [ ] o.a.s.c.a.OverseerTriggerThread Refreshing /autoscaling.json with znode version 3
[junit4] 2> 33882 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Processed trigger updates upto znodeVersion 3
[junit4] 2> 33882 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread -- clean old nodeAdded markers
[junit4] 2> 33882 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Current znodeVersion 3, lastZnodeVersion 3
[junit4] 2> 33889 DEBUG (ScheduledTrigger-123-thread-1) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 1
[junit4] 2> 33894 DEBUG (simCloudManagerPool-122-thread-2) [ ] o.a.s.c.a.AutoScalingHandler Verified autoscaling configuration
[junit4] 2> 33894 DEBUG (simCloudManagerPool-122-thread-2) [ ] o.a.s.c.a.OverseerTriggerThread Refreshing /autoscaling.json with znode version 4
[junit4] 2> 33894 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Processed trigger updates upto znodeVersion 4
[junit4] 2> 33895 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread -- clean old nodeAdded markers
[junit4] 2> 33895 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Current znodeVersion 4, lastZnodeVersion 4
[junit4] 2> 33910 DEBUG (ScheduledTrigger-123-thread-1) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 1
[junit4] 2> 33930 DEBUG (ScheduledTrigger-123-thread-1) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 1
[junit4] 2> 33950 DEBUG (ScheduledTrigger-123-thread-4) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 1
[junit4] 2> 33971 DEBUG (ScheduledTrigger-123-thread-4) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 1
[junit4] 2> 33991 DEBUG (ScheduledTrigger-123-thread-3) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 1
[junit4] 2> 34007 DEBUG (simCloudManagerPool-122-thread-3) [ ] o.a.s.c.a.AutoScalingHandler Verified autoscaling configuration
[junit4] 2> 34007 DEBUG (simCloudManagerPool-122-thread-3) [ ] o.a.s.c.a.OverseerTriggerThread Refreshing /autoscaling.json with znode version 5
[junit4] 2> 34008 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Processed trigger updates upto znodeVersion 5
[junit4] 2> 34008 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.NodeAddedTrigger NodeAddedTrigger node_added_trigger - Initial livenodes: [127.0.0.1:10000_solr]
[junit4] 2> 34008 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> 34009 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Current znodeVersion 5, lastZnodeVersion 5
[junit4] 2> 34012 DEBUG (ScheduledTrigger-123-thread-4) [ ] o.a.s.c.a.NodeAddedTrigger Running NodeAddedTrigger node_added_trigger
[junit4] 2> 34013 DEBUG (ScheduledTrigger-123-thread-4) [ ] o.a.s.c.a.NodeAddedTrigger Found livenodes: 1
[junit4] 2> 34013 DEBUG (simCloudManagerPool-122-thread-4) [ ] o.a.s.c.a.AutoScalingHandler Verified autoscaling configuration
[junit4] 2> 34013 DEBUG (ScheduledTrigger-123-thread-4) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 1
[junit4] 2> 34013 DEBUG (simCloudManagerPool-122-thread-4) [ ] o.a.s.c.a.OverseerTriggerThread Refreshing /autoscaling.json with znode version 6
[junit4] 2> 34014 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Processed trigger updates upto znodeVersion 6
[junit4] 2> 34014 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Current znodeVersion 6, lastZnodeVersion 6
[junit4] 2> 34021 DEBUG (simCloudManagerPool-122-thread-5) [ ] o.a.s.c.o.ClusterStateMutator building a new cName: testNodeAdded
[junit4] 2> 34032 WARN (simCloudManagerPool-122-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> 34033 DEBUG (ScheduledTrigger-123-thread-4) [ ] o.a.s.c.a.NodeAddedTrigger Running NodeAddedTrigger node_added_trigger
[junit4] 2> 34033 DEBUG (ScheduledTrigger-123-thread-4) [ ] o.a.s.c.a.NodeAddedTrigger Found livenodes: 1
[junit4] 2> 34033 DEBUG (ScheduledTrigger-123-thread-4) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 1
[junit4] 2> 34036 DEBUG (simCloudManagerPool-122-thread-5) [ ] o.a.s.c.s.c.a.PolicyHelper Creating a new session
[junit4] 2> 34037 DEBUG (simCloudManagerPool-122-thread-5) [ ] o.a.s.c.s.c.a.PolicyHelper New session created
[junit4] 2> 34046 INFO (simCloudManagerPool-122-thread-5) [ ] o.a.s.c.s.c.a.PolicyHelper returnSession, curr-time 974687755 sessionWrapper.createTime 974687273273056, this.sessionWrapper.createTime 974687273273056
[junit4] 2> 34047 DEBUG (simCloudManagerPool-122-thread-5) [ ] o.a.s.c.s.c.a.PolicyHelper session set to NULL
[junit4] 2> 34055 DEBUG (ScheduledTrigger-123-thread-2) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 1
[junit4] 2> 34069 DEBUG (ScheduledTrigger-123-thread-3) [ ] o.a.s.c.a.NodeAddedTrigger Running NodeAddedTrigger node_added_trigger
[junit4] 2> 34069 DEBUG (ScheduledTrigger-123-thread-3) [ ] o.a.s.c.a.NodeAddedTrigger Found livenodes: 1
[junit4] 2> 34075 DEBUG (ScheduledTrigger-123-thread-2) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 1
[junit4] 2> 34089 DEBUG (ScheduledTrigger-123-thread-1) [ ] o.a.s.c.a.NodeAddedTrigger Running NodeAddedTrigger node_added_trigger
[junit4] 2> 34090 DEBUG (ScheduledTrigger-123-thread-1) [ ] o.a.s.c.a.NodeAddedTrigger Found livenodes: 1
[junit4] 2> 34095 DEBUG (ScheduledTrigger-123-thread-4) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 1
[junit4] 2> 34098 DEBUG (simCloudManagerPool-122-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:10000_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> 34108 DEBUG (simCloudManagerPool-122-thread-11) [ ] o.a.s.c.a.AutoScalingHandler Verified autoscaling configuration
[junit4] 2> 34109 DEBUG (simCloudManagerPool-122-thread-11) [ ] o.a.s.c.a.OverseerTriggerThread Refreshing /autoscaling.json with znode version 7
[junit4] 2> 34110 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Processed trigger updates upto znodeVersion 7
[junit4] 2> 34110 DEBUG (ScheduledTrigger-123-thread-4) [ ] o.a.s.c.a.NodeAddedTrigger Running NodeAddedTrigger node_added_trigger
[junit4] 2> 34110 DEBUG (ScheduledTrigger-123-thread-4) [ ] o.a.s.c.a.NodeAddedTrigger Found livenodes: 2
[junit4] 2> 34110 DEBUG (ScheduledTrigger-123-thread-4) [ ] o.a.s.c.a.NodeAddedTrigger Tracking new node: 127.0.0.1:10001_solr at time 974690927489906
[junit4] 2> 34110 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Current znodeVersion 7, lastZnodeVersion 7
[junit4] 2> 34115 DEBUG (ScheduledTrigger-123-thread-4) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 2
[junit4] 2> 34130 DEBUG (ScheduledTrigger-123-thread-4) [ ] o.a.s.c.a.NodeAddedTrigger Running NodeAddedTrigger node_added_trigger
[junit4] 2> 34130 DEBUG (ScheduledTrigger-123-thread-4) [ ] o.a.s.c.a.NodeAddedTrigger Found livenodes: 2
[junit4] 2> 34130 DEBUG (ScheduledTrigger-123-thread-4) [ ] o.a.s.c.a.NodeAddedTrigger NodeAddedTrigger node_added_trigger firing registered processor for nodes: [127.0.0.1:10001_solr] added at times [974690927489906], now=974691950038406
[junit4] 2> 34132 DEBUG (ScheduledTrigger-123-thread-4) [ ] o.a.s.c.a.ScheduledTriggers ++++++++ Cooldown inactive - processing event: {
[junit4] 2> "id":"37679ea7fb372Tbhsny3b52bo9sd3wnlpk0u564",
[junit4] 2> "source":"node_added_trigger",
[junit4] 2> "eventTime":974690927489906,
[junit4] 2> "eventType":"NODEADDED",
[junit4] 2> "properties":{
[junit4] 2> "eventTimes":[974690927489906],
[junit4] 2> "nodeNames":["127.0.0.1:10001_solr"]}}
[junit4] 2> 34132 DEBUG (ScheduledTrigger-123-thread-4) [ ] o.a.s.c.a.ScheduledTriggers Pausing all triggers: [.auto_add_replicas, .scheduled_maintenance, node_added_trigger]
[junit4] 2> 34163 DEBUG (simCloudManagerPool-122-thread-12) [ ] o.a.s.c.o.ClusterStateMutator building a new cName: .system
[junit4] 2> 34175 DEBUG (simCloudManagerPool-122-thread-12) [ ] o.a.s.c.s.c.a.PolicyHelper Creating a new session
[junit4] 2> 34175 DEBUG (simCloudManagerPool-122-thread-12) [ ] o.a.s.c.s.c.a.PolicyHelper New session created
[junit4] 2> 34176 INFO (simCloudManagerPool-122-thread-12) [ ] o.a.s.c.s.c.a.PolicyHelper returnSession, curr-time 974694246 sessionWrapper.createTime 974694211451556, this.sessionWrapper.createTime 974694211451556
[junit4] 2> 34176 DEBUG (simCloudManagerPool-122-thread-12) [ ] o.a.s.c.s.c.a.PolicyHelper session set to NULL
[junit4] 2> 34197 WARN (ScheduledTrigger-123-thread-4) [ ] 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:790) [java/:?]
[junit4] 2> at org.apache.solr.cloud.autoscaling.ScheduledTriggers$TriggerListeners.fireListeners(ScheduledTriggers.java:757) [java/:?]
[junit4] 2> at org.apache.solr.cloud.autoscaling.ScheduledTriggers.lambda$add$4(ScheduledTriggers.java:283) [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:589) [java/:?]
[junit4] 2> at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:514) [?:?]
[junit4] 2> at java.util.concurrent.FutureTask.runAndReset(FutureTask.java:305) [?:?]
[junit4] 2> at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:300) [?:?]
[junit4] 2> at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1167) [?:?]
[junit4] 2> at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:641) [?:?]
[junit4] 2> at java.lang.Thread.run(Thread.java:844) [?:?]
[junit4] 2> Caused by: java.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) ~[?:?]
[junit4] 2> at java.util.concurrent.FutureTask.get(FutureTask.java:191) ~[?:?]
[junit4] 2> at org.apache.solr.cloud.autoscaling.sim.SimCloudManager.request(SimCloudManager.java:619) ~[test/:?]
[junit4] 2> ... 12 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:264) ~[?:?]
[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:264) ~[?:?]
[junit4] 2> at org.apache.solr.common.util.ExecutorUtil$MDCAwareThreadPoolExecutor.lambda$execute$0(ExecutorUtil.java:209) ~[java/:?]
[junit4] 2> ... 3 more
[junit4] 2> 34209 DEBUG (ScheduledTrigger-123-thread-4) [ ] o.a.s.c.a.NodeAddedTrigger NodeAddedTrigger node_added_trigger - removing marker path: /autoscaling/nodeAdded/127.0.0.1:10001_solr
[junit4] 2> 34210 DEBUG (AutoscalingActionExecutor-124-thread-1) [ ] o.a.s.c.a.ScheduledTriggers -- processing actions for {
[junit4] 2> "id":"37679ea7fb372Tbhsny3b52bo9sd3wnlpk0u564",
[junit4] 2> "source":"node_added_trigger",
[junit4] 2> "eventTime":974690927489906,
[junit4] 2> "eventType":"NODEADDED",
[junit4] 2> "properties":{
[junit4] 2> "eventTimes":[974690927489906],
[junit4] 2> "_enqueue_time_":974692056729156,
[junit4] 2> "nodeNames":["127.0.0.1:10001_solr"]}}
[junit4] 2> 34211 DEBUG (AutoscalingActionExecutor-124-thread-1) [ ] o.a.s.c.a.ComputePlanAction -- processing event: {
[junit4] 2> "id":"37679ea7fb372Tbhsny3b52bo9sd3wnlpk0u564",
[junit4] 2> "source":"node_added_trigger",
[junit4] 2> "eventTime":974690927489906,
[junit4] 2> "eventType":"NODEADDED",
[junit4] 2> "properties":{
[junit4] 2> "eventTimes":[974690927489906],
[junit4] 2> "_enqueue_time_":974692056729156,
[junit4] 2> "nodeNames":["127.0.0.1:10001_solr"]}} with context properties: {BEFORE_ACTION=[compute_plan]}
[junit4] 2> 34211 DEBUG (AutoscalingActionExecutor-124-thread-1) [ ] o.a.s.c.s.c.a.PolicyHelper Creating a new session
[junit4] 2> 34212 DEBUG (AutoscalingActionExecutor-124-thread-1) [ ] o.a.s.c.s.c.a.PolicyHelper New session created
[junit4] 2> 34214 INFO (AutoscalingActionExecutor-124-thread-1) [ ] o.a.s.c.a.ComputePlanAction Computed Plan: action=MOVEREPLICA&collection=testNodeAdded&targetNode=127.0.0.1:10001_solr&inPlaceMove=true&replica=core_node1
[junit4] 2> 34215 INFO (AutoscalingActionExecutor-124-thread-1) [ ] o.a.s.c.a.ComputePlanAction Computed Plan: action=MOVEREPLICA&collection=testNodeAdded&targetNode=127.0.0.1:10001_solr&inPlaceMove=true&replica=core_node2
[junit4] 2> 34215 INFO (AutoscalingActionExecutor-124-thread-1) [ ] o.a.s.c.s.c.a.PolicyHelper returnSession, curr-time 974696202 sessionWrapper.createTime 974696019895306, this.sessionWrapper.createTime 974696019895306
[junit4] 2> 34215 DEBUG (AutoscalingActionExecutor-124-thread-1) [ ] o.a.s.c.s.c.a.PolicyHelper session set to NULL
[junit4] 2> 34224 INFO (TEST-TestComputePlanAction.testNodeAdded-seed#[B4921AA6A77AB73B]) [ ] o.a.s.c.a.s.TestComputePlanAction Node values: {
[junit4] 2> "127.0.0.1:10001_solr":{
[junit4] 2> "sysprop.java.vendor":"Oracle Corporation",
[junit4] 2> "cores":1,
[junit4] 2> "host":"127.0.0.1",
[junit4] 2> "freedisk":999,
[junit4] 2> "sysprop.java.version":"9.0.4",
[junit4] 2> "ip_1":"127",
[junit4] 2> "ip_3":"0",
[junit4] 2> "ip_2":"0",
[junit4] 2> "ip_4":"1",
[junit4] 2> "node":"127.0.0.1:10001_solr",
[junit4] 2> "metrics:solr.jvm:buffers.direct.Count":0,
[junit4] 2> "port":10001,
[junit4] 2> "heapUsage":123450000,
[junit4] 2> "sysLoadAvg":1.0,
[junit4] 2> "metrics:solr.node:ADMIN./admin/authorization.clientErrors:count":0},
[junit4] 2> "127.0.0.1:10000_solr":{
[junit4] 2> "sysprop.java.vendor":"Oracle Corporation",
[junit4] 2> "cores":4,
[junit4] 2> "host":"127.0.0.1",
[junit4] 2> "freedisk":996,
[junit4] 2> "sysprop.java.version":"9.0.4",
[junit4] 2> "ip_1":"127",
[junit4] 2> "ip_3":"0",
[junit4] 2> "ip_2":"0",
[junit4] 2> "ip_4":"1",
[junit4] 2> "node":"127.0.0.1:10000_solr",
[junit4] 2> "metrics:solr.jvm:buffers.direct.Count":0,
[junit4] 2> "port":10000,
[junit4] 2> "heapUsage":123450000,
[junit4] 2> "sysLoadAvg":1.0,
[junit4] 2> "metrics:solr.node:ADMIN./admin/authorization.clientErrors:count":0}}
[junit4] 2> 34236 INFO (TEST-TestComputePlanAction.testNodeAdded-seed#[B4921AA6A77AB73B]) [ ] o.a.s.c.a.s.TestComputePlanAction Live nodes: [127.0.0.1:10001_solr, 127.0.0.1:10000_solr], collection state: DocCollection(testNodeAdded//clusterstate.json/7)={
[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:10000_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:10000_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:10000_solr",
[junit4] 2> "state":"active",
[junit4] 2> "type":"NRT",
[junit4] 2> "SEARCHER.searcher.numDocs":0},
[junit4] 2> "core_node4":{
[junit4] 2> "core":"testNodeAdded_shard1_replica_n4",
[junit4] 2> "SEARCHER.searcher.maxDoc":0,
[junit4] 2> "SEARCHER.searcher.deletedDocs":0,
[junit4] 2> "INDEX.sizeInBytes":1,
[junit4] 2> "node_name":"127.0.0.1:10000_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> 34236 INFO (TEST-TestComputePlanAction.testNodeAdded-seed#[B4921AA6A77AB73B]) [ ] o.a.s.c.a.s.TestComputePlanAction -------------_ FINAL STATE --------------
[junit4] 2> 34236 INFO (TEST-TestComputePlanAction.testNodeAdded-seed#[B4921AA6A77AB73B]) [ ] o.a.s.c.a.s.TestComputePlanAction * Node values: {
[junit4] 2> "127.0.0.1:10001_solr":{
[junit4] 2> "sysprop.java.vendor":"Oracle Corporation",
[junit4] 2> "cores":1,
[junit4] 2> "host":"127.0.0.1",
[junit4] 2> "freedisk":999,
[junit4] 2> "sysprop.java.version":"9.0.4",
[junit4] 2> "ip_1":"127",
[junit4] 2> "ip_3":"0",
[junit4] 2> "ip_2":"0",
[junit4] 2> "ip_4":"1",
[junit4] 2> "node":"127.0.0.1:10001_solr",
[junit4] 2> "metrics:solr.jvm:buffers.direct.Count":0,
[junit4] 2> "port":10001,
[junit4] 2> "heapUsage":123450000,
[junit4] 2> "sysLoadAvg":1.0,
[junit4] 2> "metrics:solr.node:ADMIN./admin/authorization.clientErrors:count":0},
[junit4] 2> "127.0.0.1:10000_solr":{
[junit4] 2> "sysprop.java.vendor":"Oracle Corporation",
[junit4] 2> "cores":4,
[junit4] 2> "host":"127.0.0.1",
[junit4] 2> "freedisk":996,
[junit4] 2> "sysprop.java.version":"9.0.4",
[junit4] 2> "ip_1":"127",
[junit4] 2> "ip_3":"0",
[junit4] 2> "ip_2":"0",
[junit4] 2> "ip_4":"1",
[junit4] 2> "node":"127.0.0.1:10000_solr",
[junit4] 2> "metrics:solr.jvm:buffers.direct.Count":0,
[junit4] 2> "port":10000,
[junit4] 2> "heapUsage":123450000,
[junit4] 2> "sysLoadAvg":1.0,
[junit4] 2> "metrics:solr.node:ADMIN./admin/authorization.clientErrors:count":0}}
[junit4] 2> 34236 INFO (TEST-TestComputePlanAction.testNodeAdded-seed#[B4921AA6A77AB73B]) [ ] o.a.s.c.a.s.TestComputePlanAction * Live nodes: [127.0.0.1:10001_solr, 127.0.0.1:10000_solr]
[junit4] 2> 34237 INFO (TEST-TestComputePlanAction.testNodeAdded-seed#[B4921AA6A77AB73B]) [ ] o.a.s.c.a.s.TestComputePlanAction * Collection .system state: DocCollection(.system//clusterstate.json/9)={
[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:10001_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> 34237 INFO (TEST-TestComputePlanAction.testNodeAdded-seed#[B4921AA6A77AB73B]) [ ] o.a.s.c.a.s.TestComputePlanAction * Collection testNodeAdded state: DocCollection(testNodeAdded//clusterstate.json/9)={
[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:10000_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:10000_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:10000_solr",
[junit4] 2> "state":"active",
[junit4] 2> "type":"NRT",
[junit4] 2> "SEARCHER.searcher.numDocs":0},
[junit4] 2> "core_node4":{
[junit4] 2> "core":"testNodeAdded_shard1_replica_n4",
[junit4] 2> "SEARCHER.searcher.maxDoc":0,
[junit4] 2> "SEARCHER.searcher.deletedDocs":0,
[junit4] 2> "INDEX.sizeInBytes":1,
[junit4] 2> "node_name":"127.0.0.1:10000_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> 34237 INFO (TEST-TestComputePlanAction.testNodeAdded-seed#[B4921AA6A77AB73B]) [ ] o.a.s.SolrTestCaseJ4 ###Ending testNodeAdded
[junit4] 2> 34241 INFO (TEST-TestComputePlanAction.testNodeAdded-seed#[B4921AA6A77AB73B]) [ ] o.a.s.c.a.s.SimSolrCloudTestCase #######################################
[junit4] 2> ############ CLUSTER STATE ############
[junit4] 2> #######################################
[junit4] 2> ## Live nodes: 2
[junit4] 2> ## Empty nodes: 0
[junit4] 2> ## Dead nodes: 0
[junit4] 2> ## Collections: [.system, testNodeAdded]
[junit4] 2> ## Max replicas per node: 4
[junit4] 2> ## Min replicas per node: 1
[junit4] 2> ## Total replicas: 5
[junit4] 2> ## * .system 1
[junit4] 2> ## - active 1
[junit4] 2> ## * testNodeAdded 4
[junit4] 2> ## - active 4
[junit4] 2> ######### Solr op counts ##########
[junit4] 2> ## - CREATE 1
[junit4] 2> ## - autoscaling 5
[junit4] 2> ## - update 4
[junit4] 2> ######### Autoscaling event counts ###########
[junit4] 2> ## * Trigger: node_added_trigger
[junit4] 2> ## - AFTER_ACTION 1
[junit4] 2> ## - BEFORE_ACTION 1
[junit4] 2>
[junit4] 2> 34241 DEBUG (AutoscalingActionExecutor-124-thread-1) [ ] o.a.s.c.a.ScheduledTriggers Resuming trigger: .auto_add_replicas after 100ms
[junit4] 2> 34241 DEBUG (AutoscalingActionExecutor-124-thread-1) [ ] o.a.s.c.a.ScheduledTriggers Resuming trigger: .scheduled_maintenance after 100ms
[junit4] 2> 34241 DEBUG (AutoscalingActionExecutor-124-thread-1) [ ] o.a.s.c.a.ScheduledTriggers Resuming trigger: node_added_trigger after 100ms
[junit4] 2> 34241 DEBUG (AutoscalingActionExecutor-124-thread-1) [ ] o.a.s.c.a.ScheduledTriggers -- processing took 1570 ms for event id=37679ea7fb372Tbhsny3b52bo9sd3wnlpk0u564
[junit4] 2> NOTE: reproduce with: ant test -Dtestcase=TestComputePlanAction -Dtests.method=testNodeAdded -Dtests.seed=B4921AA6A77AB73B -Dtests.multiplier=3 -Dtests.slow=true -Dtests.locale=fr-GP -Dtests.timezone=Antarctica/South_Pole -Dtests.asserts=true -Dtests.file.encoding=UTF-8
[junit4] FAILURE 0.58s J0 | TestComputePlanAction.testNodeAdded <<<
[junit4] > Throwable #1: java.lang.AssertionError: ComputePlanAction should have computed exactly 1 operation, but was: [org.apache.solr.client.solrj.request.CollectionAdminRequest$MoveReplica@7a02e1e2, org.apache.solr.client.solrj.request.CollectionAdminRequest$MoveReplica@bf29883] expected:<1> but was:<2>
[junit4] > at __randomizedtesting.SeedInfo.seed([B4921AA6A77AB73B:D1514CD105D91F38]:0)
[junit4] > at org.apache.solr.cloud.autoscaling.sim.TestComputePlanAction.testNodeAdded(TestComputePlanAction.java:313)
[junit4] > at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
[junit4] > at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
[junit4] > at java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
[junit4] > at java.base/java.lang.reflect.Method.invoke(Method.java:564)
[junit4] > at java.base/java.lang.Thread.run(Thread.java:844)
[junit4] 2> 34245 INFO (TEST-TestComputePlanAction.testNodeWithMultipleReplicasLost-seed#[B4921AA6A77AB73B]) [ ] o.a.s.SolrTestCaseJ4 ###Starting testNodeWithMultipleReplicasLost
[junit4] 2> 34245 DEBUG (TEST-TestComputePlanAction.testNodeWithMultipleReplicasLost-seed#[B4921AA6A77AB73B]) [ ] o.a.s.c.a.OverseerTriggerThread Refreshing /autoscaling.json with znode version 8
[junit4] 2> 34245 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Processed trigger updates upto znodeVersion 8
[junit4] 2> 34245 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread -- clean old nodeLost markers
[junit4] 2> 34245 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread -- clean old nodeAdded markers
[junit4] 2> 34245 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Current znodeVersion 8, lastZnodeVersion 8
[junit4] 2> 34246 DEBUG (TEST-TestComputePlanAction.testNodeWithMultipleReplicasLost-seed#[B4921AA6A77AB73B]) [ ] o.a.s.c.a.s.SimClusterStateProvider --- new Overseer leader: 127.0.0.1:10001_solr
[junit4] 2> 34252 INFO (TEST-TestComputePlanAction.testNodeWithMultipleReplicasLost-seed#[B4921AA6A77AB73B]) [ ] o.a.s.c.a.s.SimCloudManager === Restarting OverseerTriggerThread and clearing object cache...
[junit4] 2> 34253 WARN (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Interrupted
[junit4] 2> java.lang.InterruptedException: null
[junit4] 2> at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.reportInterruptAfterWait(AbstractQueuedSynchronizer.java:2037) ~[?:?]
[junit4] 2> at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.await(AbstractQueuedSynchronizer.java:2071) ~[?:?]
[junit4] 2> at org.apache.solr.cloud.autoscaling.OverseerTriggerThread.run(OverseerTriggerThread.java:189) [java/:?]
[junit4] 2> at java.lang.Thread.run(Thread.java:844) [?:?]
[junit4] 2> 34253 DEBUG (TEST-TestComputePlanAction.testNodeWithMultipleReplicasLost-seed#[B4921AA6A77AB73B]) [ ] o.a.s.c.a.ScheduledTriggers Shutting down scheduled thread pool executor now
[junit4] 2> 34253 DEBUG (TEST-TestComputePlanAction.testNodeWithMultipleReplicasLost-seed#[B4921AA6A77AB73B]) [ ] o.a.s.c.a.ScheduledTriggers Shutting down action executor now
[junit4] 2> 34253 DEBUG (TEST-TestComputePlanAction.testNodeWithMultipleReplicasLost-seed#[B4921AA6A77AB73B]) [ ] o.a.s.c.a.ScheduledTriggers Awaiting termination for action executor
[junit4] 2> 34253 DEBUG (TEST-TestComputePlanAction.testNodeWithMultipleReplicasLost-seed#[B4921AA6A77AB73B]) [ ] o.a.s.c.a.ScheduledTriggers Awaiting termination for scheduled thread pool executor
[junit4] 2> 34253 DEBUG (TEST-TestComputePlanAction.testNodeWithMultipleReplicasLost-seed#[B4921AA6A77AB73B]) [ ] o.a.s.c.a.ScheduledTriggers ScheduledTriggers closed completely
[junit4] 2> 34253 DEBUG (TEST-TestComputePlanAction.testNodeWithMultipleReplicasLost-seed#[B4921AA6A77AB73B]) [ ] o.a.s.c.a.OverseerTriggerThread OverseerTriggerThread has been closed explicitly
[junit4] 2> 34266 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Adding .auto_add_replicas and .scheduled_maintenance triggers
[junit4] 2> 34266 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Refreshing /autoscaling.json with znode version 9
[junit4] 2> 34266 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Current znodeVersion 9, lastZnodeVersion -1
[junit4] 2> 34266 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Processed trigger updates upto znodeVersion 9
[junit4] 2> 34280 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.NodeLostTrigger NodeLostTrigger .auto_add_replicas - Initial livenodes: [127.0.0.1:10001_solr]
[junit4] 2> 34288 DEBUG (ScheduledTrigger-126-thread-2) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 1
[junit4] 2> 34288 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread -- clean old nodeAdded markers
[junit4] 2> 34289 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Current znodeVersion 9, lastZnodeVersion 9
[junit4] 2> 34325 DEBUG (ScheduledTrigger-126-thread-1) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 1
[junit4] 2> 34345 DEBUG (ScheduledTrigger-126-thread-1) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 1
[junit4] 2> 34365 DEBUG (ScheduledTrigger-126-thread-1) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 1
[junit4] 2> 34365 DEBUG (simCloudManagerPool-125-thread-1) [ ] o.a.s.c.a.AutoScalingHandler Verified autoscaling configuration
[junit4] 2> 34365 DEBUG (simCloudManagerPool-125-thread-1) [ ] o.a.s.c.a.OverseerTriggerThread Refreshing /autoscaling.json with znode version 10
[junit4] 2> 34367 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Processed trigger updates upto znodeVersion 10
[junit4] 2> 34368 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread -- clean old nodeAdded markers
[junit4] 2> 34368 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Current znodeVersion 10, lastZnodeVersion 10
[junit4] 2> 34385 DEBUG (ScheduledTrigger-126-thread-1) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 1
[junit4] 2> 34389 DEBUG (simCloudManagerPool-125-thread-2) [ ] o.a.s.c.a.AutoScalingHandler Verified autoscaling configuration
[junit4] 2> 34389 DEBUG (simCloudManagerPool-125-thread-2) [ ] o.a.s.c.a.OverseerTriggerThread Refreshing /autoscaling.json with znode version 11
[junit4] 2> 34390 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Processed trigger updates upto znodeVersion 11
[junit4] 2> 34390 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread -- clean old nodeAdded markers
[junit4] 2> 34390 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Current znodeVersion 11, lastZnodeVersion 11
[junit4] 2> 34406 DEBUG (ScheduledTrigger-126-thread-1) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 1
[junit4] 2> 34426 DEBUG (ScheduledTrigger-126-thread-1) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 1
[junit4] 2> 34447 DEBUG (ScheduledTrigger-126-thread-1) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 1
[junit4] 2> 34467 DEBUG (ScheduledTrigger-126-thread-4) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 1
[junit4] 2> 34487 DEBUG (ScheduledTrigger-126-thread-1) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 1
[junit4] 2> 34498 DEBUG (simCloudManagerPool-125-thread-3) [ ] o.a.s.c.a.AutoScalingHandler Verified autoscaling configuration
[junit4] 2> 34498 DEBUG (simCloudManagerPool-125-thread-3) [ ] o.a.s.c.a.OverseerTriggerThread Refreshing /autoscaling.json with znode version 12
[junit4] 2> 34500 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Processed trigger updates upto znodeVersion 12
[junit4] 2> 34500 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.NodeLostTrigger NodeLostTrigger node_lost_trigger - Initial livenodes: [127.0.0.1:10001_solr, 127.0.0.1:10004_solr, 127.0.0.1:10002_solr, 127.0.0.1:10003_solr]
[junit4] 2> 34500 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread -- clean old nodeAdded markers
[junit4] 2> 34500 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Current znodeVersion 12, lastZnodeVersion 12
[junit4] 2> 34500 DEBUG (ScheduledTrigger-126-thread-3) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: node_lost_trigger with currently live nodes: 4
[junit4] 2> 34501 DEBUG (simCloudManagerPool-125-thread-4) [ ] o.a.s.c.o.ClusterStateMutator building a new cName: testNodeWithMultipleReplicasLost
[junit4] 2> 34507 DEBUG (ScheduledTrigger-126-thread-2) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 4
[junit4] 2> 34512 DEBUG (simCloudManagerPool-125-thread-4) [ ] o.a.s.c.s.c.a.PolicyHelper Creating a new session
[junit4] 2> 34514 DEBUG (simCloudManagerPool-125-thread-4) [ ] o.a.s.c.s.c.a.PolicyHelper New session created
[junit4] 2> 34521 DEBUG (ScheduledTrigger-126-thread-3) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: node_lost_trigger with currently live nodes: 4
[junit4] 2> 34524 INFO (simCloudManagerPool-125-thread-4) [ ] o.a.s.c.s.c.a.PolicyHelper returnSession, curr-time 974711639 sessionWrapper.createTime 974711138056056, this.sessionWrapper.createTime 974711138056056
[junit4] 2> 34524 DEBUG (simCloudManagerPool-125-thread-4) [ ] o.a.s.c.s.c.a.PolicyHelper session set to NULL
[junit4] 2> 34528 DEBUG (ScheduledTrigger-126-thread-2) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 4
[junit4] 2> 34541 DEBUG (ScheduledTrigger-126-thread-3) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: node_lost_trigger with currently live nodes: 4
[junit4] 2> 34548 DEBUG (ScheduledTrigger-126-thread-2) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 4
[junit4] 2> 34561 DEBUG (ScheduledTrigger-126-thread-3) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: node_lost_trigger with currently live nodes: 4
[junit4] 2> 34568 DEBUG (ScheduledTrigger-126-thread-4) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 4
[junit4] 2> 34589 DEBUG (ScheduledTrigger-126-thread-3) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 4
[junit4] 2> 34597 DEBUG (simCloudManagerPool-125-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:10001_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> 34597 DEBUG (ScheduledTrigger-126-thread-4) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: node_lost_trigger with currently live nodes: 4
[junit4] 2> 34597 DEBUG (simCloudManagerPool-125-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:10003_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> 34609 DEBUG (ScheduledTrigger-126-thread-3) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 4
[junit4] 2> 34613 DEBUG (TEST-TestComputePlanAction.testNodeWithMultipleReplicasLost-seed#[B4921AA6A77AB73B]) [ ] o.a.s.c.a.s.TestComputePlanAction -- cluster state: znodeVersion: 15
[junit4] 2> live nodes:[127.0.0.1:10001_solr, 127.0.0.1:10004_solr, 127.0.0.1:10002_solr, 127.0.0.1:10003_solr]
[junit4] 2> collections:{testNodeWithMultipleReplicasLost=DocCollection(testNodeWithMultipleReplicasLost//clusterstate.json/14)={
[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:10002_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:10001_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:10004_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:10003_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:10002_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:10004_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> 34617 DEBUG (ScheduledTrigger-126-thread-3) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: node_lost_trigger with currently live nodes: 3
[junit4] 2> 34617 DEBUG (ScheduledTrigger-126-thread-3) [ ] o.a.s.c.a.NodeLostTrigger Tracking lost node: 127.0.0.1:10004_solr
[junit4] 2> 34629 DEBUG (ScheduledTrigger-126-thread-3) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 3
[junit4] 2> 34629 DEBUG (ScheduledTrigger-126-thread-3) [ ] o.a.s.c.a.NodeLostTrigger Tracking lost node: 127.0.0.1:10004_solr
[junit4] 2> 34638 DEBUG (ScheduledTrigger-126-thread-3) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: node_lost_trigger with currently live nodes: 3
[junit4] 2> 34638 DEBUG (ScheduledTrigger-126-thread-3) [ ] o.a.s.c.a.NodeLostTrigger NodeLostTrigger firing registered processor for lost nodes: [127.0.0.1:10004_solr]
[junit4] 2> 34638 DEBUG (ScheduledTrigger-126-thread-3) [ ] o.a.s.c.a.ScheduledTriggers ++++++++ Cooldown inactive - processing event: {
[junit4] 2> "id":"3767fd2e16a20Tbhsny3b52bo9sd3wnlpk0u569",
[junit4] 2> "source":"node_lost_trigger",
[junit4] 2> "eventTime":974716301044256,
[junit4] 2> "eventType":"NODELOST",
[junit4] 2> "properties":{
[junit4] 2> "eventTimes":[974716301044256],
[junit4] 2> "nodeNames":["127.0.0.1:10004_solr"]}}
[junit4] 2> 34638 DEBUG (ScheduledTrigger-126-thread-3) [ ] o.a.s.c.a.ScheduledTriggers Pausing all triggers: [.auto_add_replicas, .scheduled_maintenance, node_lost_trigger]
[junit4] 2> 34657 DEBUG (simCloudManagerPool-125-thread-15) [ ] o.a.s.c.o.ClusterStateMutator building a new cName: .system
[junit4] 2> 34668 DEBUG (simCloudManagerPool-125-thread-15) [ ] o.a.s.c.s.c.a.PolicyHelper Creating a new session
[junit4] 2> 34668 DEBUG (simCloudManagerPool-125-thread-15) [ ] o.a.s.c.s.c.a.PolicyHelper New session created
[junit4] 2> 34669 INFO (simCloudManagerPool-125-thread-15) [ ] o.a.s.c.s.c.a.PolicyHelper returnSession, curr-time 974718886 sessionWrapper.createTime 974718857325306, this.sessionWrapper.createTime 974718857325306
[junit4] 2> 34669 DEBUG (simCloudManagerPool-125-thread-15) [ ] o.a.s.c.s.c.a.PolicyHelper session set to NULL
[junit4] 2> 34689 DEBUG (AutoscalingActionExecutor-127-thread-1) [ ] o.a.s.c.a.ScheduledTriggers -- processing actions for {
[junit4] 2> "id":"3767fd2e16a20Tbhsny3b52bo9sd3wnlpk0u569",
[junit4] 2> "source":"node_lost_trigger",
[junit4] 2> "eventTime":974716301044256,
[junit4] 2> "eventType":"NODELOST",
[junit4] 2> "properties":{
[junit4] 2> "eventTimes":[974716301044256],
[junit4] 2> "_enqueue_time_":974717346735606,
[junit4] 2> "nodeNames":["127.0.0.1:10004_solr"]}}
[junit4] 2> 34689 DEBUG (AutoscalingActionExecutor-127-thread-1) [ ] o.a.s.c.a.ComputePlanAction -- processing event: {
[junit4] 2> "id":"3767fd2e16a20Tbhsny3b52bo9sd3wnlpk0u569",
[junit4] 2> "source":"node_lost_trigger",
[junit4] 2> "eventTime":974716301044256,
[junit4] 2> "eventType":"NODELOST",
[junit4] 2> "properties":{
[junit4] 2> "eventTimes":[974716301044256],
[junit4] 2> "_enqueue_time_":974717346735606,
[junit4] 2> "nodeNames":["127.0.0.1:10004_solr"]}} with context properties: {BEFORE_ACTION=[compute_plan]}
[junit4] 2> 34691 DEBUG (AutoscalingActionExecutor-127-thread-1) [ ] o.a.s.c.s.c.a.PolicyHelper Creating a new session
[junit4] 2> 34692 DEBUG (AutoscalingActionExecutor-127-thread-1) [ ] o.a.s.c.s.c.a.PolicyHelper New session created
[junit4] 2> 34697 INFO (AutoscalingActionExecutor-127-thread-1) [ ] o.a.s.c.a.ComputePlanAction Computed Plan: action=MOVEREPLICA&collection=testNodeWithMultipleReplicasLost&targetNode=127.0.0.1:10003_solr&inPlaceMove=true&replica=core_node5
[junit4] 2> 34698 INFO (AutoscalingActionExecutor-127-thread-1) [ ] o.a.s.c.a.ComputePlanAction Computed Plan: action=MOVEREPLICA&collection=testNodeWithMultipleReplicasLost&targetNode=127.0.0.1:10001_solr&inPlaceMove=true&replica=core_node3
[junit4] 2> 34698 INFO (AutoscalingActionExecutor-127-thread-1) [ ] o.a.s.c.s.c.a.PolicyHelper returnSession, curr-time 974720339 sessionWrapper.createTime 974720044294856, this.sessionWrapper.createTime 974720044294856
[junit4] 2> 34698 DEBUG (AutoscalingActionExecutor-127-thread-1) [ ] o.a.s.c.s.c.a.PolicyHelper session set to NULL
[junit4] 2> 34702 INFO (TEST-TestComputePlanAction.testNodeWithMultipleReplicasLost-seed#[B4921AA6A77AB73B]) [ ] o.a.s.c.a.s.TestComputePlanAction action=MOVEREPLICA&collection=testNodeWithMultipleReplicasLost&targetNode=127.0.0.1:10003_solr&inPlaceMove=true&replica=core_node5
[junit4] 2> 34702 INFO (TEST-TestComputePlanAction.testNodeWithMultipleReplicasLost-seed#[B4921AA6A77AB73B]) [ ] o.a.s.c.a.s.TestComputePlanAction action=MOVEREPLICA&collection=testNodeWithMultipleReplicasLost&targetNode=127.0.0.1:10001_solr&inPlaceMove=true&replica=core_node3
[junit4] 2> 34702 INFO (TEST-TestComputePlanAction.testNodeWithMultipleReplicasLost-seed#[B4921AA6A77AB73B]) [ ] o.a.s.c.a.s.TestComputePlanAction -------------_ FINAL STATE --------------
[junit4] 2> 34702 INFO (TEST-TestComputePlanAction.testNodeWithMultipleReplicasLost-seed#[B4921AA6A77AB73B]) [ ] o.a.s.c.a.s.TestComputePlanAction * Node values: {
[junit4] 2> "127.0.0.1:10001_solr":{
[junit4] 2> "sysprop.java.vendor":"Oracle Corporation",
[junit4] 2> "cores":1,
[junit4] 2> "host":"127.0.0.1",
[junit4] 2> "freedisk":999,
[junit4] 2> "sysprop.java.version":"9.0.4",
[junit4] 2> "ip_1":"127",
[junit4] 2> "ip_3":"0",
[junit4] 2> "ip_2":"0",
[junit4] 2> "ip_4":"1",
[junit4] 2> "node":"127.0.0.1:10001_solr",
[junit4] 2> "metrics:solr.jvm:buffers.direct.Count":0,
[junit4] 2> "port":10001,
[junit4] 2> "heapUsage":123450000,
[junit4] 2> "sysLoadAvg":1.0,
[junit4] 2> "metrics:solr.node:ADMIN./admin/authorization.clientErrors:count":0},
[junit4] 2> "127.0.0.1:10004_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":"9.0.4",
[junit4] 2> "ip_1":"127",
[junit4] 2> "ip_3":"0",
[junit4] 2> "ip_2":"0",
[junit4] 2> "ip_4":"1",
[junit4] 2> "node":"127.0.0.1:10004_solr",
[junit4] 2> "metrics:solr.jvm:buffers.direct.Count":0,
[junit4] 2> "port":10004,
[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:10002_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":"9.0.4",
[junit4] 2> "ip_1":"127",
[junit4] 2> "ip_3":"0",
[junit4] 2> "ip_2":"0",
[junit4] 2> "ip_4":"1",
[junit4] 2> "node":"127.0.0.1:10002_solr",
[junit4] 2> "metrics:solr.jvm:buffers.direct.Count":0,
[junit4] 2> "port":10002,
[junit4] 2> "heapUsage":123450000,
[junit4] 2> "sysLoadAvg":1.0,
[junit4] 2> "metrics:solr.node:ADMIN./admin/authorization.clientErrors:count":0},
[junit4] 2> "127.0.0.1:10003_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":"9.0.4",
[junit4] 2> "ip_1":"127",
[junit4] 2> "ip_3":"0",
[junit4] 2> "ip_2":"0",
[junit4] 2> "ip_4":"1",
[junit4] 2> "node":"127.0.0.1:10003_solr",
[junit4] 2> "metrics:solr.jvm:buffers.direct.Count":0,
[junit4] 2> "port":10003,
[junit4] 2> "heapUsage":123450000,
[junit4] 2> "sysLoadAvg":1.0,
[junit4] 2> "metrics:solr.node:ADMIN./admin/authorization.clientErrors:count":0}}
[junit4] 2> 34702 INFO (TEST-TestComputePlanAction.testNodeWithMultipleReplicasLost-seed#[B4921AA6A77AB73B]) [ ] o.a.s.c.a.s.TestComputePlanAction * Live nodes: [127.0.0.1:10001_solr, 127.0.0.1:10002_solr, 127.0.0.1:10003_solr]
[junit4] 2> 34702 INFO (TEST-TestComputePlanAction.testNodeWithMultipleReplicasLost-seed#[B4921AA6A77AB73B]) [ ] o.a.s.c.a.s.TestComputePlanAction * Collection .system state: DocCollection(.system//clusterstate.json/21)={
[junit4] 2> "replicationFactor":"1",
[junit4] 2> "pullReplicas":"0",
[junit4] 2> "router":{"name":"compositeId"},
[junit4] 2> "maxShardsPerNode":"1",
[junit4] 2> "autoAddReplicas":"false",
[junit4] 2> "nrtReplicas":"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:10003_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> 34703 INFO (TEST-TestComputePlanAction.testNodeWithMultipleReplicasLost-seed#[B4921AA6A77AB73B]) [ ] o.a.s.c.a.s.TestComputePlanAction * Collection testNodeWithMultipleReplicasLost state: DocCollection(testNodeWithMultipleReplicasLost//clusterstate.json/21)={
[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:10002_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:10001_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:10004_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:10003_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:10002_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:10004_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> 34703 INFO (TEST-TestComputePlanAction.testNodeWithMultipleReplicasLost-seed#[B4921AA6A77AB73B]) [ ] o.a.s.SolrTestCaseJ4 ###Ending testNodeWithMultipleReplicasLost
[junit4] 2> 34703 INFO (TEST-TestComputePlanAction.testNodeWithMultipleReplicasLost-seed#[B4921AA6A77AB73B]) [ ] 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:10004_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> 34712 INFO (TEST-TestComputePlanAction.testNodeLost-seed#[B4921AA6A77AB73B]) [ ] o.a.s.SolrTestCaseJ4 ###Starting testNodeLost
[junit4] 2> 34712 DEBUG (TEST-TestComputePlanAction.testNodeLost-seed#[B4921AA6A77AB73B]) [ ] o.a.s.c.a.OverseerTriggerThread Refreshing /autoscaling.json with znode version 13
[junit4] 2> 34712 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Processed trigger updates upto znodeVersion 13
[junit4] 2> 34712 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread -- clean old nodeLost markers
[junit4] 2> 34712 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread -- clean old nodeAdded markers
[junit4] 2> 34712 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Current znodeVersion 13, lastZnodeVersion 13
[junit4] 2> 34716 WARN (simCloudManagerPool-125-thread-20) [ ] o.a.s.c.a.s.SimClusterStateProvider -- can't find any active replicas for .system / shard1
[junit4] 2> 34728 DEBUG (TEST-TestComputePlanAction.testNodeLost-seed#[B4921AA6A77AB73B]) [ ] o.a.s.c.a.s.SimClusterStateProvider --- new Overseer leader: 127.0.0.1:10002_solr
[junit4] 2> 34729 DEBUG (simCloudManagerPool-125-thread-22) [ ] 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:10002_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> 34745 DEBUG (simCloudManagerPool-125-thread-23) [ ] 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:10002_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> 34751 DEBUG (TEST-TestComputePlanAction.testNodeLost-seed#[B4921AA6A77AB73B]) [ ] o.a.s.c.a.s.SimNodeStateProvider - removing dead node values: 127.0.0.1:10004_solr
[junit4] 2> 34751 INFO (TEST-TestComputePlanAction.testNodeLost-seed#[B4921AA6A77AB73B]) [ ] o.a.s.c.a.s.SimCloudManager === Restarting OverseerTriggerThread and clearing object cache...
[junit4] 2> 34751 DEBUG (TEST-TestComputePlanAction.testNodeLost-seed#[B4921AA6A77AB73B]) [ ] o.a.s.c.a.ScheduledTriggers Shutting down scheduled thread pool executor now
[junit4] 2> 34751 WARN (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread OverseerTriggerThread woken up but we are closed, exiting.
[junit4] 2> 34750 WARN (AutoscalingActionExecutor-127-thread-1) [ ] o.a.s.c.a.ScheduledTriggers Exception executing actions
[junit4] 2> org.apache.lucene.store.AlreadyClosedException: ScheduledTrigger node_lost_trigger has been closed.
[junit4] 2> at org.apache.solr.cloud.autoscaling.ScheduledTriggers$TriggerWrapper.dequeue(ScheduledTriggers.java:546) ~[java/:?]
[junit4] 2> at org.apache.solr.cloud.autoscaling.ScheduledTriggers.lambda$add$3(ScheduledTriggers.java:319) [java/:?]
[junit4] 2> at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:514) [?:?]
[junit4] 2> at java.util.concurrent.FutureTask.run(FutureTask.java:264) [?:?]
[junit4] 2> at org.apache.solr.common.util.ExecutorUtil$MDCAwareThreadPoolExecutor.lambda$execute$0(ExecutorUtil.java:209) [java/:?]
[junit4] 2> at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1167) [?:?]
[junit4] 2> at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:641) [?:?]
[junit4] 2> at java.lang.Thread.run(Thread.java:844) [?:?]
[junit4] 2> 34751 DEBUG (AutoscalingActionExecutor-127-thread-1) [ ] o.a.s.c.a.ScheduledTriggers -- processing took 3092 ms for event id=3767fd2e16a20Tbhsny3b52bo9sd3wnlpk0u569
[junit4] 2> 34751 DEBUG (TEST-TestComputePlanAction.testNodeLost-seed#[B4921AA6A77AB73B]) [ ] o.a.s.c.a.ScheduledTriggers Shutting down action executor now
[junit4] 2> 34751 DEBUG (TEST-TestComputePlanAction.testNodeLost-seed#[B4921AA6A77AB73B]) [ ] o.a.s.c.a.ScheduledTriggers Awaiting termination for action executor
[junit4] 2> 34751 DEBUG (TEST-TestComputePlanAction.testNodeLost-seed#[B4921AA6A77AB73B]) [ ] o.a.s.c.a.ScheduledTriggers Awaiting termination for scheduled thread pool executor
[junit4] 2> 34751 DEBUG (TEST-TestComputePlanAction.testNodeLost-seed#[B4921AA6A77AB73B]) [ ] o.a.s.c.a.ScheduledTriggers ScheduledTriggers closed completely
[junit4] 2> 34751 DEBUG (TEST-TestComputePlanAction.testNodeLost-seed#[B4921AA6A77AB73B]) [ ] o.a.s.c.a.OverseerTriggerThread OverseerTriggerThread has been closed explicitly
[junit4] 2> 34757 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Adding .auto_add_replicas and .scheduled_maintenance triggers
[junit4] 2> 34757 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Refreshing /autoscaling.json with znode version 14
[junit4] 2> 34757 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Current znodeVersion 14, lastZnodeVersion -1
[junit4] 2> 34757 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Processed trigger updates upto znodeVersion 14
[junit4] 2> 34772 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.NodeLostTrigger NodeLostTrigger .auto_add_replicas - Initial livenodes: [127.0.0.1:10002_solr]
[junit4] 2> 34780 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread -- clean old nodeAdded markers
[junit4] 2> 34780 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Current znodeVersion 14, lastZnodeVersion 14
[junit4] 2> 34781 DEBUG (ScheduledTrigger-129-thread-2) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 1
[junit4] 2> 34804 DEBUG (ScheduledTrigger-129-thread-1) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 1
[junit4] 2> 34825 DEBUG (ScheduledTrigger-129-thread-3) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 1
[junit4] 2> 34845 DEBUG (ScheduledTrigger-129-thread-4) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 1
[junit4] 2> 34857 DEBUG (simCloudManagerPool-128-thread-1) [ ] o.a.s.c.a.AutoScalingHandler Verified autoscaling configuration
[junit4] 2> 34857 DEBUG (simCloudManagerPool-128-thread-1) [ ] o.a.s.c.a.OverseerTriggerThread Refreshing /autoscaling.json with znode version 15
[junit4] 2> 34858 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Processed trigger updates upto znodeVersion 15
[junit4] 2> 34858 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread -- clean old nodeAdded markers
[junit4] 2> 34858 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Current znodeVersion 15, lastZnodeVersion 15
[junit4] 2> 34859 DEBUG (simCloudManagerPool-128-thread-2) [ ] o.a.s.c.a.AutoScalingHandler Verified autoscaling configuration
[junit4] 2> 34860 DEBUG (simCloudManagerPool-128-thread-2) [ ] o.a.s.c.a.OverseerTriggerThread Refreshing /autoscaling.json with znode version 16
[junit4] 2> 34860 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Processed trigger updates upto znodeVersion 16
[junit4] 2> 34860 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread -- clean old nodeAdded markers
[junit4] 2> 34860 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Current znodeVersion 16, lastZnodeVersion 16
[junit4] 2> 34865 DEBUG (ScheduledTrigger-129-thread-3) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 1
[junit4] 2> 34885 DEBUG (ScheduledTrigger-129-thread-4) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 1
[junit4] 2> 34906 DEBUG (ScheduledTrigger-129-thread-3) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 1
[junit4] 2> 34926 DEBUG (ScheduledTrigger-129-thread-4) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 1
[junit4] 2> 34946 DEBUG (ScheduledTrigger-129-thread-3) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 1
[junit4] 2> 34963 DEBUG (simCloudManagerPool-128-thread-3) [ ] o.a.s.c.a.AutoScalingHandler Verified autoscaling configuration
[junit4] 2> 34963 DEBUG (simCloudManagerPool-128-thread-3) [ ] o.a.s.c.a.OverseerTriggerThread Refreshing /autoscaling.json with znode version 17
[junit4] 2> 34965 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Processed trigger updates upto znodeVersion 17
[junit4] 2> 34965 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.NodeLostTrigger NodeLostTrigger node_lost_trigger - Initial livenodes: [127.0.0.1:10005_solr, 127.0.0.1:10002_solr]
[junit4] 2> 34965 DEBUG (simCloudManagerPool-128-thread-4) [ ] o.a.s.c.o.ClusterStateMutator building a new cName: testNodeLost
[junit4] 2> 34965 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread -- clean old nodeAdded markers
[junit4] 2> 34965 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Current znodeVersion 17, lastZnodeVersion 17
[junit4] 2> 34965 DEBUG (ScheduledTrigger-129-thread-2) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: node_lost_trigger with currently live nodes: 2
[junit4] 2> 34967 DEBUG (ScheduledTrigger-129-thread-2) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 2
[junit4] 2> 34985 DEBUG (ScheduledTrigger-129-thread-1) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: node_lost_trigger with currently live nodes: 2
[junit4] 2> 34987 DEBUG (ScheduledTrigger-129-thread-4) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 2
[junit4] 2> 34995 DEBUG (simCloudManagerPool-128-thread-4) [ ] o.a.s.c.s.c.a.PolicyHelper Creating a new session
[junit4] 2> 34995 DEBUG (simCloudManagerPool-128-thread-4) [ ] o.a.s.c.s.c.a.PolicyHelper New session created
[junit4] 2> 34997 INFO (simCloudManagerPool-128-thread-4) [ ] o.a.s.c.s.c.a.PolicyHelper returnSession, curr-time 974735290 sessionWrapper.createTime 974735213419356, this.sessionWrapper.createTime 974735213419356
[junit4] 2> 34997 DEBUG (simCloudManagerPool-128-thread-4) [ ] o.a.s.c.s.c.a.PolicyHelper session set to NULL
[junit4] 2> 35008 DEBUG (ScheduledTrigger-129-thread-4) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: node_lost_trigger with currently live nodes: 2
[junit4] 2> 35008 DEBUG (ScheduledTrigger-129-thread-4) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 2
[junit4] 2> 35027 DEBUG (simCloudManagerPool-128-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:10002_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> 35027 DEBUG (TEST-TestComputePlanAction.testNodeLost-seed#[B4921AA6A77AB73B]) [ ] o.a.s.c.a.s.TestComputePlanAction -- cluster state: znodeVersion: 28
[junit4] 2> live nodes:[127.0.0.1:10002_solr, 127.0.0.1:10005_solr]
[junit4] 2> collections:{testNodeLost=DocCollection(testNodeLost//clusterstate.json/27)={
[junit4] 2> "replicationFactor":"2",
[junit4] 2> "pullReplicas":"0",
[junit4] 2> "router":{"name":"compositeId"},
[junit4] 2> "maxShardsPerNode":"1",
[junit4] 2> "autoAddReplicas":"false",
[junit4] 2> "nrtReplicas":"2",
[junit4] 2> "tlogReplicas":"0",
[junit4] 2> "autoCreated":"true",
[junit4] 2> "shards":{"shard1":{
[junit4] 2> "replicas":{
[junit4] 2> "core_node1":{
[junit4] 2> "core":"testNodeLost_shard1_replica_n1",
[junit4] 2> "SEARCHER.searcher.maxDoc":0,
[junit4] 2> "SEARCHER.searcher.deletedDocs":0,
[junit4] 2> "INDEX.sizeInBytes":1,
[junit4] 2> "node_name":"127.0.0.1:10002_solr",
[junit4] 2> "state":"active",
[junit4] 2> "type":"NRT",
[junit4] 2> "SEARCH
[...truncated too long message...]
"SEARCHER.searcher.numDocs":2}},
[junit4] 2> "range":"80000000-7fffffff",
[junit4] 2> "state":"active"}}}
[junit4] 2> 35265 INFO (TEST-TestComputePlanAction.testNodeLost-seed#[B4921AA6A77AB73B]) [ ] o.a.s.c.a.s.TestComputePlanAction * Collection testNodeLost state: DocCollection(testNodeLost//clusterstate.json/36)={
[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:10002_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:10005_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> 35266 INFO (TEST-TestComputePlanAction.testNodeLost-seed#[B4921AA6A77AB73B]) [ ] o.a.s.SolrTestCaseJ4 ###Ending testNodeLost
[junit4] 2> 35266 INFO (TEST-TestComputePlanAction.testNodeLost-seed#[B4921AA6A77AB73B]) [ ] 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:10005_solr
[junit4] 2> ## 127.0.0.1:10006_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 3
[junit4] 2> ######### Autoscaling event counts ###########
[junit4] 2> ## * Trigger: node_lost_trigger
[junit4] 2> ## - BEFORE_ACTION 1
[junit4] 2> ## - STARTED 1
[junit4] 2>
[junit4] 2> 35267 DEBUG (SUITE-TestComputePlanAction-seed#[B4921AA6A77AB73B]-worker) [ ] o.a.s.c.a.ScheduledTriggers Shutting down scheduled thread pool executor now
[junit4] 2> 35267 WARN (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread OverseerTriggerThread woken up but we are closed, exiting.
[junit4] 2> 35267 DEBUG (SUITE-TestComputePlanAction-seed#[B4921AA6A77AB73B]-worker) [ ] o.a.s.c.a.ScheduledTriggers Shutting down action executor now
[junit4] 2> 35275 DEBUG (SUITE-TestComputePlanAction-seed#[B4921AA6A77AB73B]-worker) [ ] o.a.s.c.a.ScheduledTriggers Awaiting termination for action executor
[junit4] 2> 35275 WARN (AutoscalingActionExecutor-130-thread-1) [ ] o.a.s.c.a.SystemLogListener Exception sending event to collection .system
[junit4] 2> java.io.IOException: java.lang.InterruptedException
[junit4] 2> at org.apache.solr.cloud.autoscaling.sim.SimCloudManager.request(SimCloudManager.java: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:790) [java/:?]
[junit4] 2> at org.apache.solr.cloud.autoscaling.ScheduledTriggers$TriggerListeners.fireListeners(ScheduledTriggers.java:766) [java/:?]
[junit4] 2> at org.apache.solr.cloud.autoscaling.ScheduledTriggers.lambda$add$3(ScheduledTriggers.java:316) [java/:?]
[junit4] 2> at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:514) [?:?]
[junit4] 2> at java.util.concurrent.FutureTask.run(FutureTask.java:264) [?:?]
[junit4] 2> at org.apache.solr.common.util.ExecutorUtil$MDCAwareThreadPoolExecutor.lambda$execute$0(ExecutorUtil.java:209) [java/:?]
[junit4] 2> at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1167) [?:?]
[junit4] 2> at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:641) [?:?]
[junit4] 2> at java.lang.Thread.run(Thread.java:844) [?:?]
[junit4] 2> Caused by: java.lang.InterruptedException
[junit4] 2> at java.util.concurrent.FutureTask.awaitDone(FutureTask.java:418) ~[?:?]
[junit4] 2> at java.util.concurrent.FutureTask.get(FutureTask.java:190) ~[?:?]
[junit4] 2> at org.apache.solr.cloud.autoscaling.sim.SimCloudManager.request(SimCloudManager.java:619) ~[test/:?]
[junit4] 2> ... 10 more
[junit4] 2> 35276 WARN (AutoscalingActionExecutor-130-thread-1) [ ] o.a.s.c.a.ScheduledTriggers Exception executing actions
[junit4] 2> org.apache.lucene.store.AlreadyClosedException: ScheduledTrigger node_lost_trigger has been closed.
[junit4] 2> at org.apache.solr.cloud.autoscaling.ScheduledTriggers$TriggerWrapper.dequeue(ScheduledTriggers.java:546) ~[java/:?]
[junit4] 2> at org.apache.solr.cloud.autoscaling.ScheduledTriggers.lambda$add$3(ScheduledTriggers.java:319) [java/:?]
[junit4] 2> at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:514) [?:?]
[junit4] 2> at java.util.concurrent.FutureTask.run(FutureTask.java:264) [?:?]
[junit4] 2> at org.apache.solr.common.util.ExecutorUtil$MDCAwareThreadPoolExecutor.lambda$execute$0(ExecutorUtil.java:209) [java/:?]
[junit4] 2> at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1167) [?:?]
[junit4] 2> at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:641) [?:?]
[junit4] 2> at java.lang.Thread.run(Thread.java:844) [?:?]
[junit4] 2> 35276 DEBUG (AutoscalingActionExecutor-130-thread-1) [ ] o.a.s.c.a.ScheduledTriggers -- processing took 2792 ms for event id=376849c80be04Tbhsny3b52bo9sd3wnlpk0u56d
[junit4] 2> 35276 DEBUG (SUITE-TestComputePlanAction-seed#[B4921AA6A77AB73B]-worker) [ ] o.a.s.c.a.ScheduledTriggers Awaiting termination for scheduled thread pool executor
[junit4] 2> 35276 DEBUG (SUITE-TestComputePlanAction-seed#[B4921AA6A77AB73B]-worker) [ ] o.a.s.c.a.ScheduledTriggers ScheduledTriggers closed completely
[junit4] 2> 35277 DEBUG (SUITE-TestComputePlanAction-seed#[B4921AA6A77AB73B]-worker) [ ] o.a.s.c.a.OverseerTriggerThread OverseerTriggerThread has been closed explicitly
[junit4] 2> NOTE: leaving temporary files on disk at: /home/jenkins/workspace/Lucene-Solr-7.x-Linux/solr/build/solr-core/test/J0/temp/solr.cloud.autoscaling.sim.TestComputePlanAction_B4921AA6A77AB73B-001
[junit4] 2> 35267 WARN (simCloudManagerPool-128-thread-14) [ ] o.a.s.c.a.s.SimClusterStateProvider -- can't find any active replicas for .system / shard1
[junit4] 2> May 31, 2018 7:05:57 PM com.carrotsearch.randomizedtesting.ThreadLeakControl checkThreadLeaks
[junit4] 2> WARNING: Will linger awaiting termination of 8 leaked thread(s).
[junit4] 2> NOTE: test params are: codec=Asserting(Lucene70): {}, docValues:{}, maxPointsInLeafNode=756, maxMBSortInHeap=7.001516038805256, sim=RandomSimilarity(queryNorm=true): {}, locale=fr-GP, timezone=Antarctica/South_Pole
[junit4] 2> NOTE: Linux 4.13.0-41-generic amd64/Oracle Corporation 9.0.4 (64-bit)/cpus=8,threads=1,free=243366312,total=536870912
[junit4] 2> NOTE: All tests run in this JVM: [TestAuthenticationFramework, TestXmlQParser, TestImplicitCoreProperties, TestJsonFacetRefinement, CurrencyRangeFacetCloudTest, SolrIndexSplitterTest, TestComputePlanAction]
[junit4] Completed [8/812 (1!)] on J0 in 1.96s, 3 tests, 1 failure <<< FAILURES!
[...truncated 46670 lines...]
[repro] Jenkins log URL: https://jenkins.thetaphi.de/job/Lucene-Solr-7.x-Linux/2025/consoleText
[repro] Revision: d65f40f3852be74bf0fc5c17d8252c669ea325d8
[repro] Ant options: "-Dargs=-XX:+UseCompressedOops -XX:+UseG1GC"
[repro] Repro line: ant test -Dtestcase=TestComputePlanAction -Dtests.method=testNodeAdded -Dtests.seed=B4921AA6A77AB73B -Dtests.multiplier=3 -Dtests.slow=true -Dtests.locale=fr-GP -Dtests.timezone=Antarctica/South_Pole -Dtests.asserts=true -Dtests.file.encoding=UTF-8
[repro] ant clean
[...truncated 6 lines...]
[repro] Test suites by module:
[repro] solr/core
[repro] TestComputePlanAction
[repro] ant compile-test
[...truncated 3322 lines...]
[repro] ant test-nocompile -Dtests.dups=5 -Dtests.maxfailures=5 -Dtests.class="*.TestComputePlanAction" -Dtests.showOutput=onerror "-Dargs=-XX:+UseCompressedOops -XX:+UseG1GC" -Dtests.seed=B4921AA6A77AB73B -Dtests.multiplier=3 -Dtests.slow=true -Dtests.locale=fr-GP -Dtests.timezone=Antarctica/South_Pole -Dtests.asserts=true -Dtests.file.encoding=UTF-8
[...truncated 86 lines...]
[repro] Failures:
[repro] 0/5 failed: org.apache.solr.cloud.autoscaling.sim.TestComputePlanAction
[repro] Exiting with code 0
[...truncated 40 lines...]
[JENKINS] Lucene-Solr-7.x-Linux (64bit/jdk-10) - Build # 2026 -
Still Unstable!
Posted by Policeman Jenkins Server <je...@thetaphi.de>.
Build: https://jenkins.thetaphi.de/job/Lucene-Solr-7.x-Linux/2026/
Java: 64bit/jdk-10 -XX:-UseCompressedOops -XX:+UseParallelGC
2 tests failed.
FAILED: org.apache.solr.cloud.autoscaling.IndexSizeTriggerTest.testSplitIntegration
Error Message:
last state: DocCollection(testSplitIntegration_collection//clusterstate.json/95)={ "replicationFactor":"2", "pullReplicas":"0", "router":{"name":"compositeId"}, "maxShardsPerNode":"2", "autoAddReplicas":"false", "nrtReplicas":"2", "tlogReplicas":"0", "autoCreated":"true", "shards":{ "shard2":{ "replicas":{ "core_node3":{ "core":"testSplitIntegration_collection_shard2_replica_n3", "leader":"true", "SEARCHER.searcher.maxDoc":11, "SEARCHER.searcher.deletedDocs":0, "INDEX.sizeInBytes":1, "node_name":"127.0.0.1:10000_solr", "state":"active", "type":"NRT", "SEARCHER.searcher.numDocs":11}, "core_node4":{ "core":"testSplitIntegration_collection_shard2_replica_n4", "SEARCHER.searcher.maxDoc":11, "SEARCHER.searcher.deletedDocs":0, "INDEX.sizeInBytes":1, "node_name":"127.0.0.1:10001_solr", "state":"active", "type":"NRT", "SEARCHER.searcher.numDocs":11}}, "range":"0-7fffffff", "state":"active"}, "shard1":{ "stateTimestamp":"1527808486270123250", "replicas":{ "core_node1":{ "core":"testSplitIntegration_collection_shard1_replica_n1", "leader":"true", "SEARCHER.searcher.maxDoc":14, "SEARCHER.searcher.deletedDocs":0, "INDEX.sizeInBytes":1, "node_name":"127.0.0.1:10000_solr", "state":"active", "type":"NRT", "SEARCHER.searcher.numDocs":14}, "core_node2":{ "core":"testSplitIntegration_collection_shard1_replica_n2", "SEARCHER.searcher.maxDoc":14, "SEARCHER.searcher.deletedDocs":0, "INDEX.sizeInBytes":1, "node_name":"127.0.0.1:10001_solr", "state":"active", "type":"NRT", "SEARCHER.searcher.numDocs":14}}, "range":"80000000-ffffffff", "state":"inactive"}, "shard1_1":{ "parent":"shard1", "stateTimestamp":"1527808486281884600", "range":"c0000000-ffffffff", "state":"active", "replicas":{ "core_node10":{ "leader":"true", "core":"testSplitIntegration_collection_shard1_1_replica1", "SEARCHER.searcher.maxDoc":7, "SEARCHER.searcher.deletedDocs":0, "INDEX.sizeInBytes":1, "node_name":"127.0.0.1:10000_solr", "base_url":"http://127.0.0.1:10000/solr", "state":"active", "type":"NRT", "SEARCHER.searcher.numDocs":7}, "core_node9":{ "core":"testSplitIntegration_collection_shard1_1_replica0", "SEARCHER.searcher.maxDoc":7, "SEARCHER.searcher.deletedDocs":0, "INDEX.sizeInBytes":1, "node_name":"127.0.0.1:10001_solr", "base_url":"http://127.0.0.1:10001/solr", "state":"active", "type":"NRT", "SEARCHER.searcher.numDocs":7}}}, "shard1_0":{ "parent":"shard1", "stateTimestamp":"1527808486281697350", "range":"80000000-bfffffff", "state":"active", "replicas":{ "core_node7":{ "leader":"true", "core":"testSplitIntegration_collection_shard1_0_replica0", "SEARCHER.searcher.maxDoc":7, "SEARCHER.searcher.deletedDocs":0, "INDEX.sizeInBytes":1, "node_name":"127.0.0.1:10001_solr", "base_url":"http://127.0.0.1:10001/solr", "state":"active", "type":"NRT", "SEARCHER.searcher.numDocs":7}, "core_node8":{ "core":"testSplitIntegration_collection_shard1_0_replica1", "SEARCHER.searcher.maxDoc":7, "SEARCHER.searcher.deletedDocs":0, "INDEX.sizeInBytes":1, "node_name":"127.0.0.1:10000_solr", "base_url":"http://127.0.0.1:10000/solr", "state":"active", "type":"NRT", "SEARCHER.searcher.numDocs":7}}}}}
Stack Trace:
java.util.concurrent.TimeoutException: last state: DocCollection(testSplitIntegration_collection//clusterstate.json/95)={
"replicationFactor":"2",
"pullReplicas":"0",
"router":{"name":"compositeId"},
"maxShardsPerNode":"2",
"autoAddReplicas":"false",
"nrtReplicas":"2",
"tlogReplicas":"0",
"autoCreated":"true",
"shards":{
"shard2":{
"replicas":{
"core_node3":{
"core":"testSplitIntegration_collection_shard2_replica_n3",
"leader":"true",
"SEARCHER.searcher.maxDoc":11,
"SEARCHER.searcher.deletedDocs":0,
"INDEX.sizeInBytes":1,
"node_name":"127.0.0.1:10000_solr",
"state":"active",
"type":"NRT",
"SEARCHER.searcher.numDocs":11},
"core_node4":{
"core":"testSplitIntegration_collection_shard2_replica_n4",
"SEARCHER.searcher.maxDoc":11,
"SEARCHER.searcher.deletedDocs":0,
"INDEX.sizeInBytes":1,
"node_name":"127.0.0.1:10001_solr",
"state":"active",
"type":"NRT",
"SEARCHER.searcher.numDocs":11}},
"range":"0-7fffffff",
"state":"active"},
"shard1":{
"stateTimestamp":"1527808486270123250",
"replicas":{
"core_node1":{
"core":"testSplitIntegration_collection_shard1_replica_n1",
"leader":"true",
"SEARCHER.searcher.maxDoc":14,
"SEARCHER.searcher.deletedDocs":0,
"INDEX.sizeInBytes":1,
"node_name":"127.0.0.1:10000_solr",
"state":"active",
"type":"NRT",
"SEARCHER.searcher.numDocs":14},
"core_node2":{
"core":"testSplitIntegration_collection_shard1_replica_n2",
"SEARCHER.searcher.maxDoc":14,
"SEARCHER.searcher.deletedDocs":0,
"INDEX.sizeInBytes":1,
"node_name":"127.0.0.1:10001_solr",
"state":"active",
"type":"NRT",
"SEARCHER.searcher.numDocs":14}},
"range":"80000000-ffffffff",
"state":"inactive"},
"shard1_1":{
"parent":"shard1",
"stateTimestamp":"1527808486281884600",
"range":"c0000000-ffffffff",
"state":"active",
"replicas":{
"core_node10":{
"leader":"true",
"core":"testSplitIntegration_collection_shard1_1_replica1",
"SEARCHER.searcher.maxDoc":7,
"SEARCHER.searcher.deletedDocs":0,
"INDEX.sizeInBytes":1,
"node_name":"127.0.0.1:10000_solr",
"base_url":"http://127.0.0.1:10000/solr",
"state":"active",
"type":"NRT",
"SEARCHER.searcher.numDocs":7},
"core_node9":{
"core":"testSplitIntegration_collection_shard1_1_replica0",
"SEARCHER.searcher.maxDoc":7,
"SEARCHER.searcher.deletedDocs":0,
"INDEX.sizeInBytes":1,
"node_name":"127.0.0.1:10001_solr",
"base_url":"http://127.0.0.1:10001/solr",
"state":"active",
"type":"NRT",
"SEARCHER.searcher.numDocs":7}}},
"shard1_0":{
"parent":"shard1",
"stateTimestamp":"1527808486281697350",
"range":"80000000-bfffffff",
"state":"active",
"replicas":{
"core_node7":{
"leader":"true",
"core":"testSplitIntegration_collection_shard1_0_replica0",
"SEARCHER.searcher.maxDoc":7,
"SEARCHER.searcher.deletedDocs":0,
"INDEX.sizeInBytes":1,
"node_name":"127.0.0.1:10001_solr",
"base_url":"http://127.0.0.1:10001/solr",
"state":"active",
"type":"NRT",
"SEARCHER.searcher.numDocs":7},
"core_node8":{
"core":"testSplitIntegration_collection_shard1_0_replica1",
"SEARCHER.searcher.maxDoc":7,
"SEARCHER.searcher.deletedDocs":0,
"INDEX.sizeInBytes":1,
"node_name":"127.0.0.1:10000_solr",
"base_url":"http://127.0.0.1:10000/solr",
"state":"active",
"type":"NRT",
"SEARCHER.searcher.numDocs":7}}}}}
at __randomizedtesting.SeedInfo.seed([908582EF0A9F048C:A90B3BAF2560CD72]:0)
at org.apache.solr.cloud.CloudTestUtils.waitForState(CloudTestUtils.java:111)
at org.apache.solr.cloud.autoscaling.IndexSizeTriggerTest.testSplitIntegration(IndexSizeTriggerTest.java:299)
at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
at java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
at java.base/java.lang.reflect.Method.invoke(Method.java:564)
at com.carrotsearch.randomizedtesting.RandomizedRunner.invoke(RandomizedRunner.java: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 org.apache.lucene.util.TestRuleAssertionsRequired$1.evaluate(TestRuleAssertionsRequired.java:53)
at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:47)
at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:64)
at org.apache.lucene.util.TestRuleIgnoreTestSuites$1.evaluate(TestRuleIgnoreTestSuites.java:54)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:368)
at java.base/java.lang.Thread.run(Thread.java:844)
FAILED: org.apache.solr.cloud.autoscaling.IndexSizeTriggerTest.testSplitIntegration
Error Message:
last state: DocCollection(testSplitIntegration_collection//clusterstate.json/99)={ "replicationFactor":"2", "pullReplicas":"0", "router":{"name":"compositeId"}, "maxShardsPerNode":"2", "autoAddReplicas":"false", "nrtReplicas":"2", "tlogReplicas":"0", "autoCreated":"true", "shards":{ "shard2":{ "replicas":{ "core_node3":{ "core":"testSplitIntegration_collection_shard2_replica_n3", "leader":"true", "SEARCHER.searcher.maxDoc":11, "SEARCHER.searcher.deletedDocs":0, "INDEX.sizeInBytes":1, "node_name":"127.0.0.1:10000_solr", "state":"active", "type":"NRT", "SEARCHER.searcher.numDocs":11}, "core_node4":{ "core":"testSplitIntegration_collection_shard2_replica_n4", "SEARCHER.searcher.maxDoc":11, "SEARCHER.searcher.deletedDocs":0, "INDEX.sizeInBytes":1, "node_name":"127.0.0.1:10001_solr", "state":"active", "type":"NRT", "SEARCHER.searcher.numDocs":11}}, "range":"0-7fffffff", "state":"active"}, "shard1":{ "stateTimestamp":"1527805688895087350", "replicas":{ "core_node1":{ "core":"testSplitIntegration_collection_shard1_replica_n1", "leader":"true", "SEARCHER.searcher.maxDoc":14, "SEARCHER.searcher.deletedDocs":0, "INDEX.sizeInBytes":1, "node_name":"127.0.0.1:10000_solr", "state":"active", "type":"NRT", "SEARCHER.searcher.numDocs":14}, "core_node2":{ "core":"testSplitIntegration_collection_shard1_replica_n2", "SEARCHER.searcher.maxDoc":14, "SEARCHER.searcher.deletedDocs":0, "INDEX.sizeInBytes":1, "node_name":"127.0.0.1:10001_solr", "state":"active", "type":"NRT", "SEARCHER.searcher.numDocs":14}}, "range":"80000000-ffffffff", "state":"inactive"}, "shard1_1":{ "parent":"shard1", "stateTimestamp":"1527805688907769700", "range":"c0000000-ffffffff", "state":"active", "replicas":{ "core_node10":{ "leader":"true", "core":"testSplitIntegration_collection_shard1_1_replica1", "SEARCHER.searcher.maxDoc":7, "SEARCHER.searcher.deletedDocs":0, "INDEX.sizeInBytes":1, "node_name":"127.0.0.1:10000_solr", "base_url":"http://127.0.0.1:10000/solr", "state":"active", "type":"NRT", "SEARCHER.searcher.numDocs":7}, "core_node9":{ "core":"testSplitIntegration_collection_shard1_1_replica0", "SEARCHER.searcher.maxDoc":7, "SEARCHER.searcher.deletedDocs":0, "INDEX.sizeInBytes":1, "node_name":"127.0.0.1:10001_solr", "base_url":"http://127.0.0.1:10001/solr", "state":"active", "type":"NRT", "SEARCHER.searcher.numDocs":7}}}, "shard1_0":{ "parent":"shard1", "stateTimestamp":"1527805688907524600", "range":"80000000-bfffffff", "state":"active", "replicas":{ "core_node7":{ "leader":"true", "core":"testSplitIntegration_collection_shard1_0_replica0", "SEARCHER.searcher.maxDoc":7, "SEARCHER.searcher.deletedDocs":0, "INDEX.sizeInBytes":1, "node_name":"127.0.0.1:10001_solr", "base_url":"http://127.0.0.1:10001/solr", "state":"active", "type":"NRT", "SEARCHER.searcher.numDocs":7}, "core_node8":{ "core":"testSplitIntegration_collection_shard1_0_replica1", "SEARCHER.searcher.maxDoc":7, "SEARCHER.searcher.deletedDocs":0, "INDEX.sizeInBytes":1, "node_name":"127.0.0.1:10000_solr", "base_url":"http://127.0.0.1:10000/solr", "state":"active", "type":"NRT", "SEARCHER.searcher.numDocs":7}}}}}
Stack Trace:
java.util.concurrent.TimeoutException: last state: DocCollection(testSplitIntegration_collection//clusterstate.json/99)={
"replicationFactor":"2",
"pullReplicas":"0",
"router":{"name":"compositeId"},
"maxShardsPerNode":"2",
"autoAddReplicas":"false",
"nrtReplicas":"2",
"tlogReplicas":"0",
"autoCreated":"true",
"shards":{
"shard2":{
"replicas":{
"core_node3":{
"core":"testSplitIntegration_collection_shard2_replica_n3",
"leader":"true",
"SEARCHER.searcher.maxDoc":11,
"SEARCHER.searcher.deletedDocs":0,
"INDEX.sizeInBytes":1,
"node_name":"127.0.0.1:10000_solr",
"state":"active",
"type":"NRT",
"SEARCHER.searcher.numDocs":11},
"core_node4":{
"core":"testSplitIntegration_collection_shard2_replica_n4",
"SEARCHER.searcher.maxDoc":11,
"SEARCHER.searcher.deletedDocs":0,
"INDEX.sizeInBytes":1,
"node_name":"127.0.0.1:10001_solr",
"state":"active",
"type":"NRT",
"SEARCHER.searcher.numDocs":11}},
"range":"0-7fffffff",
"state":"active"},
"shard1":{
"stateTimestamp":"1527805688895087350",
"replicas":{
"core_node1":{
"core":"testSplitIntegration_collection_shard1_replica_n1",
"leader":"true",
"SEARCHER.searcher.maxDoc":14,
"SEARCHER.searcher.deletedDocs":0,
"INDEX.sizeInBytes":1,
"node_name":"127.0.0.1:10000_solr",
"state":"active",
"type":"NRT",
"SEARCHER.searcher.numDocs":14},
"core_node2":{
"core":"testSplitIntegration_collection_shard1_replica_n2",
"SEARCHER.searcher.maxDoc":14,
"SEARCHER.searcher.deletedDocs":0,
"INDEX.sizeInBytes":1,
"node_name":"127.0.0.1:10001_solr",
"state":"active",
"type":"NRT",
"SEARCHER.searcher.numDocs":14}},
"range":"80000000-ffffffff",
"state":"inactive"},
"shard1_1":{
"parent":"shard1",
"stateTimestamp":"1527805688907769700",
"range":"c0000000-ffffffff",
"state":"active",
"replicas":{
"core_node10":{
"leader":"true",
"core":"testSplitIntegration_collection_shard1_1_replica1",
"SEARCHER.searcher.maxDoc":7,
"SEARCHER.searcher.deletedDocs":0,
"INDEX.sizeInBytes":1,
"node_name":"127.0.0.1:10000_solr",
"base_url":"http://127.0.0.1:10000/solr",
"state":"active",
"type":"NRT",
"SEARCHER.searcher.numDocs":7},
"core_node9":{
"core":"testSplitIntegration_collection_shard1_1_replica0",
"SEARCHER.searcher.maxDoc":7,
"SEARCHER.searcher.deletedDocs":0,
"INDEX.sizeInBytes":1,
"node_name":"127.0.0.1:10001_solr",
"base_url":"http://127.0.0.1:10001/solr",
"state":"active",
"type":"NRT",
"SEARCHER.searcher.numDocs":7}}},
"shard1_0":{
"parent":"shard1",
"stateTimestamp":"1527805688907524600",
"range":"80000000-bfffffff",
"state":"active",
"replicas":{
"core_node7":{
"leader":"true",
"core":"testSplitIntegration_collection_shard1_0_replica0",
"SEARCHER.searcher.maxDoc":7,
"SEARCHER.searcher.deletedDocs":0,
"INDEX.sizeInBytes":1,
"node_name":"127.0.0.1:10001_solr",
"base_url":"http://127.0.0.1:10001/solr",
"state":"active",
"type":"NRT",
"SEARCHER.searcher.numDocs":7},
"core_node8":{
"core":"testSplitIntegration_collection_shard1_0_replica1",
"SEARCHER.searcher.maxDoc":7,
"SEARCHER.searcher.deletedDocs":0,
"INDEX.sizeInBytes":1,
"node_name":"127.0.0.1:10000_solr",
"base_url":"http://127.0.0.1:10000/solr",
"state":"active",
"type":"NRT",
"SEARCHER.searcher.numDocs":7}}}}}
at __randomizedtesting.SeedInfo.seed([908582EF0A9F048C:A90B3BAF2560CD72]:0)
at org.apache.solr.cloud.CloudTestUtils.waitForState(CloudTestUtils.java:111)
at org.apache.solr.cloud.autoscaling.IndexSizeTriggerTest.testSplitIntegration(IndexSizeTriggerTest.java:299)
at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
at java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
at java.base/java.lang.reflect.Method.invoke(Method.java:564)
at com.carrotsearch.randomizedtesting.RandomizedRunner.invoke(RandomizedRunner.java: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 org.apache.lucene.util.TestRuleAssertionsRequired$1.evaluate(TestRuleAssertionsRequired.java:53)
at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:47)
at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:64)
at org.apache.lucene.util.TestRuleIgnoreTestSuites$1.evaluate(TestRuleIgnoreTestSuites.java:54)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:368)
at java.base/java.lang.Thread.run(Thread.java:844)
Build Log:
[...truncated 12627 lines...]
[junit4] Suite: org.apache.solr.cloud.autoscaling.IndexSizeTriggerTest
[junit4] 2> Creating dataDir: /home/jenkins/workspace/Lucene-Solr-7.x-Linux/solr/build/solr-core/test/J1/temp/solr.cloud.autoscaling.IndexSizeTriggerTest_908582EF0A9F048C-001/init-core-data-001
[junit4] 2> 86610 INFO (SUITE-IndexSizeTriggerTest-seed#[908582EF0A9F048C]-worker) [ ] o.a.s.c.MiniSolrCloudCluster Starting cluster of 2 servers in /home/jenkins/workspace/Lucene-Solr-7.x-Linux/solr/build/solr-core/test/J1/temp/solr.cloud.autoscaling.IndexSizeTriggerTest_908582EF0A9F048C-001/tempDir-001
[junit4] 2> 86610 INFO (SUITE-IndexSizeTriggerTest-seed#[908582EF0A9F048C]-worker) [ ] o.a.s.c.ZkTestServer STARTING ZK TEST SERVER
[junit4] 2> 86610 INFO (Thread-88) [ ] o.a.s.c.ZkTestServer client port:0.0.0.0/0.0.0.0:0
[junit4] 2> 86610 INFO (Thread-88) [ ] o.a.s.c.ZkTestServer Starting server
[junit4] 2> 86617 ERROR (Thread-88) [ ] 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> 86722 INFO (SUITE-IndexSizeTriggerTest-seed#[908582EF0A9F048C]-worker) [ ] o.a.s.c.ZkTestServer start zk server on port:41705
[junit4] 2> 86770 INFO (zkConnectionManagerCallback-119-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 86776 INFO (jetty-launcher-116-thread-1) [ ] o.e.j.s.Server jetty-9.4.10.v20180503; built: 2018-05-03T15:56:21.710Z; git: daa59876e6f384329b122929e70a80934569428c; jvm 10+46
[junit4] 2> 86782 INFO (jetty-launcher-116-thread-2) [ ] o.e.j.s.Server jetty-9.4.10.v20180503; built: 2018-05-03T15:56:21.710Z; git: daa59876e6f384329b122929e70a80934569428c; jvm 10+46
[junit4] 2> 86858 INFO (jetty-launcher-116-thread-2) [ ] o.e.j.s.session DefaultSessionIdManager workerName=node0
[junit4] 2> 86858 INFO (jetty-launcher-116-thread-2) [ ] o.e.j.s.session No SessionScavenger set, using defaults
[junit4] 2> 86859 INFO (jetty-launcher-116-thread-2) [ ] o.e.j.s.session node0 Scavenging every 600000ms
[junit4] 2> 86867 INFO (jetty-launcher-116-thread-2) [ ] o.e.j.s.h.ContextHandler Started o.e.j.s.ServletContextHandler@19715246{/solr,null,AVAILABLE}
[junit4] 2> 86868 INFO (jetty-launcher-116-thread-2) [ ] o.e.j.s.AbstractConnector Started ServerConnector@cd49685{HTTP/1.1,[http/1.1]}{127.0.0.1:46443}
[junit4] 2> 86868 INFO (jetty-launcher-116-thread-2) [ ] o.e.j.s.Server Started @86904ms
[junit4] 2> 86868 INFO (jetty-launcher-116-thread-2) [ ] o.a.s.c.s.e.JettySolrRunner Jetty properties: {hostContext=/solr, hostPort=46443}
[junit4] 2> 86869 ERROR (jetty-launcher-116-thread-2) [ ] o.a.s.u.StartupLoggingUtils Missing Java Option solr.log.dir. Logging may be missing or incomplete.
[junit4] 2> 86869 INFO (jetty-launcher-116-thread-2) [ ] o.a.s.s.SolrDispatchFilter Using logger factory org.apache.logging.slf4j.Log4jLoggerFactory
[junit4] 2> 86869 INFO (jetty-launcher-116-thread-2) [ ] o.a.s.s.SolrDispatchFilter ___ _ Welcome to Apache Solr? version 7.4.0
[junit4] 2> 86869 INFO (jetty-launcher-116-thread-2) [ ] o.a.s.s.SolrDispatchFilter / __| ___| |_ _ Starting in cloud mode on port null
[junit4] 2> 86869 INFO (jetty-launcher-116-thread-2) [ ] o.a.s.s.SolrDispatchFilter \__ \/ _ \ | '_| Install dir: null
[junit4] 2> 86869 INFO (jetty-launcher-116-thread-2) [ ] o.a.s.s.SolrDispatchFilter |___/\___/_|_| Start time: 2018-05-31T22:26:39.594492Z
[junit4] 2> 86887 INFO (zkConnectionManagerCallback-121-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 86890 INFO (jetty-launcher-116-thread-1) [ ] o.e.j.s.session DefaultSessionIdManager workerName=node0
[junit4] 2> 86890 INFO (jetty-launcher-116-thread-1) [ ] o.e.j.s.session No SessionScavenger set, using defaults
[junit4] 2> 86891 INFO (jetty-launcher-116-thread-1) [ ] o.e.j.s.session node0 Scavenging every 600000ms
[junit4] 2> 86903 INFO (jetty-launcher-116-thread-1) [ ] o.e.j.s.h.ContextHandler Started o.e.j.s.ServletContextHandler@3a604c{/solr,null,AVAILABLE}
[junit4] 2> 86903 INFO (jetty-launcher-116-thread-1) [ ] o.e.j.s.AbstractConnector Started ServerConnector@15926443{HTTP/1.1,[http/1.1]}{127.0.0.1:35603}
[junit4] 2> 86903 INFO (jetty-launcher-116-thread-1) [ ] o.e.j.s.Server Started @86938ms
[junit4] 2> 86903 INFO (jetty-launcher-116-thread-1) [ ] o.a.s.c.s.e.JettySolrRunner Jetty properties: {hostContext=/solr, hostPort=35603}
[junit4] 2> 86904 ERROR (jetty-launcher-116-thread-1) [ ] o.a.s.u.StartupLoggingUtils Missing Java Option solr.log.dir. Logging may be missing or incomplete.
[junit4] 2> 86904 INFO (jetty-launcher-116-thread-1) [ ] o.a.s.s.SolrDispatchFilter Using logger factory org.apache.logging.slf4j.Log4jLoggerFactory
[junit4] 2> 86904 INFO (jetty-launcher-116-thread-1) [ ] o.a.s.s.SolrDispatchFilter ___ _ Welcome to Apache Solr? version 7.4.0
[junit4] 2> 86904 INFO (jetty-launcher-116-thread-1) [ ] o.a.s.s.SolrDispatchFilter / __| ___| |_ _ Starting in cloud mode on port null
[junit4] 2> 86904 INFO (jetty-launcher-116-thread-1) [ ] o.a.s.s.SolrDispatchFilter \__ \/ _ \ | '_| Install dir: null
[junit4] 2> 86904 INFO (jetty-launcher-116-thread-1) [ ] o.a.s.s.SolrDispatchFilter |___/\___/_|_| Start time: 2018-05-31T22:26:39.629242Z
[junit4] 2> 86937 INFO (jetty-launcher-116-thread-2) [ ] o.a.s.s.SolrDispatchFilter solr.xml found in ZooKeeper. Loading...
[junit4] 2> 86954 INFO (zkConnectionManagerCallback-123-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 86962 INFO (jetty-launcher-116-thread-1) [ ] o.a.s.s.SolrDispatchFilter solr.xml found in ZooKeeper. Loading...
[junit4] 2> 86963 INFO (jetty-launcher-116-thread-2) [ ] o.a.s.c.ZkContainer Zookeeper client=127.0.0.1:41705/solr
[junit4] 2> 86991 INFO (jetty-launcher-116-thread-1) [ ] o.a.s.c.ZkContainer Zookeeper client=127.0.0.1:41705/solr
[junit4] 2> 87013 INFO (zkConnectionManagerCallback-127-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 87035 INFO (zkConnectionManagerCallback-131-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 87039 WARN (NIOServerCxn.Factory:0.0.0.0/0.0.0.0:0) [ ] o.a.z.s.NIOServerCnxn Unable to read additional data from client sessionid 0x1003ad003ed0004, likely client has closed socket
[junit4] 2> 87040 INFO (zkConnectionManagerCallback-133-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 87086 INFO (zkConnectionManagerCallback-135-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 87093 INFO (jetty-launcher-116-thread-1) [n:127.0.0.1:35603_solr ] o.a.s.c.Overseer Overseer (id=null) closing
[junit4] 2> 87094 INFO (jetty-launcher-116-thread-1) [n:127.0.0.1:35603_solr ] o.a.s.c.OverseerElectionContext I am going to be the leader 127.0.0.1:35603_solr
[junit4] 2> 87094 INFO (jetty-launcher-116-thread-1) [n:127.0.0.1:35603_solr ] o.a.s.c.Overseer Overseer (id=72122259131400198-127.0.0.1:35603_solr-n_0000000000) starting
[junit4] 2> 87179 INFO (zkConnectionManagerCallback-144-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 87180 INFO (jetty-launcher-116-thread-1) [n:127.0.0.1:35603_solr ] o.a.s.c.s.i.ZkClientClusterStateProvider Cluster at 127.0.0.1:41705/solr ready
[junit4] 2> 87194 INFO (jetty-launcher-116-thread-1) [n:127.0.0.1:35603_solr ] o.a.s.c.ZkController Register node as live in ZooKeeper:/live_nodes/127.0.0.1:35603_solr
[junit4] 2> 87195 DEBUG (OverseerAutoScalingTriggerThread-72122259131400198-127.0.0.1:35603_solr-n_0000000000) [ ] o.a.s.c.a.OverseerTriggerThread Adding .auto_add_replicas and .scheduled_maintenance triggers
[junit4] 2> 87204 DEBUG (OverseerAutoScalingTriggerThread-72122259131400198-127.0.0.1:35603_solr-n_0000000000) [ ] o.a.s.c.a.OverseerTriggerThread Refreshing /autoscaling.json with znode version 1
[junit4] 2> 87204 DEBUG (OverseerAutoScalingTriggerThread-72122259131400198-127.0.0.1:35603_solr-n_0000000000) [ ] o.a.s.c.a.OverseerTriggerThread Current znodeVersion 1, lastZnodeVersion -1
[junit4] 2> 87205 DEBUG (OverseerAutoScalingTriggerThread-72122259131400198-127.0.0.1:35603_solr-n_0000000000) [ ] o.a.s.c.a.OverseerTriggerThread Processed trigger updates upto znodeVersion 1
[junit4] 2> 87215 INFO (zkCallback-134-thread-1) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (1)
[junit4] 2> 87239 INFO (zkCallback-143-thread-1) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (1)
[junit4] 2> 87240 DEBUG (OverseerAutoScalingTriggerThread-72122259131400198-127.0.0.1:35603_solr-n_0000000000) [ ] o.a.s.c.a.NodeLostTrigger NodeLostTrigger .auto_add_replicas - Initial livenodes: [127.0.0.1:35603_solr]
[junit4] 2> 87245 DEBUG (OverseerAutoScalingTriggerThread-72122259131400198-127.0.0.1:35603_solr-n_0000000000) [ ] o.a.s.c.a.OverseerTriggerThread -- clean old nodeAdded markers
[junit4] 2> 87245 DEBUG (OverseerAutoScalingTriggerThread-72122259131400198-127.0.0.1:35603_solr-n_0000000000) [ ] o.a.s.c.a.OverseerTriggerThread Current znodeVersion 1, lastZnodeVersion 1
[junit4] 2> 87249 INFO (jetty-launcher-116-thread-2) [n:127.0.0.1:46443_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (1)
[junit4] 2> 87251 INFO (jetty-launcher-116-thread-2) [n:127.0.0.1:46443_solr ] o.a.s.c.Overseer Overseer (id=null) closing
[junit4] 2> 87252 DEBUG (ScheduledTrigger-449-thread-2) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 1
[junit4] 2> 87254 INFO (jetty-launcher-116-thread-2) [n:127.0.0.1:46443_solr ] o.a.s.c.TransientSolrCoreCacheDefault Allocating transient cache for 2147483647 transient cores
[junit4] 2> 87254 INFO (jetty-launcher-116-thread-2) [n:127.0.0.1:46443_solr ] o.a.s.c.ZkController Register node as live in ZooKeeper:/live_nodes/127.0.0.1:46443_solr
[junit4] 2> 87255 INFO (zkCallback-134-thread-1) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (1) -> (2)
[junit4] 2> 87255 INFO (zkCallback-143-thread-1) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (1) -> (2)
[junit4] 2> 87297 INFO (zkCallback-132-thread-1) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (1) -> (2)
[junit4] 2> 87505 INFO (zkConnectionManagerCallback-150-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 87506 INFO (jetty-launcher-116-thread-2) [n:127.0.0.1:46443_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (2)
[junit4] 2> 87507 INFO (jetty-launcher-116-thread-2) [n:127.0.0.1:46443_solr ] o.a.s.c.s.i.ZkClientClusterStateProvider Cluster at 127.0.0.1:41705/solr ready
[junit4] 2> 87511 WARN (jetty-launcher-116-thread-2) [n:127.0.0.1:46443_solr ] o.a.s.h.a.MetricsHistoryHandler Missing .system, keeping metrics history in memory
[junit4] 2> 87553 INFO (jetty-launcher-116-thread-2) [n:127.0.0.1:46443_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_46443.solr.node' (registry 'solr.node') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@5310d198
[junit4] 2> 87560 INFO (jetty-launcher-116-thread-2) [n:127.0.0.1:46443_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_46443.solr.jvm' (registry 'solr.jvm') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@5310d198
[junit4] 2> 87560 INFO (jetty-launcher-116-thread-2) [n:127.0.0.1:46443_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_46443.solr.jetty' (registry 'solr.jetty') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@5310d198
[junit4] 2> 87561 INFO (jetty-launcher-116-thread-2) [n:127.0.0.1:46443_solr ] o.a.s.c.CorePropertiesLocator Found 0 core definitions underneath /home/jenkins/workspace/Lucene-Solr-7.x-Linux/solr/build/solr-core/test/J1/temp/solr.cloud.autoscaling.IndexSizeTriggerTest_908582EF0A9F048C-001/tempDir-001/node2/.
[junit4] 2> 87582 WARN (jetty-launcher-116-thread-1) [n:127.0.0.1:35603_solr ] o.a.s.h.a.MetricsHistoryHandler Missing .system, keeping metrics history in memory
[junit4] 2> 87599 INFO (jetty-launcher-116-thread-1) [n:127.0.0.1:35603_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_35603.solr.node' (registry 'solr.node') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@5310d198
[junit4] 2> 87605 INFO (jetty-launcher-116-thread-1) [n:127.0.0.1:35603_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_35603.solr.jvm' (registry 'solr.jvm') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@5310d198
[junit4] 2> 87606 INFO (jetty-launcher-116-thread-1) [n:127.0.0.1:35603_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_35603.solr.jetty' (registry 'solr.jetty') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@5310d198
[junit4] 2> 87607 INFO (jetty-launcher-116-thread-1) [n:127.0.0.1:35603_solr ] o.a.s.c.CorePropertiesLocator Found 0 core definitions underneath /home/jenkins/workspace/Lucene-Solr-7.x-Linux/solr/build/solr-core/test/J1/temp/solr.cloud.autoscaling.IndexSizeTriggerTest_908582EF0A9F048C-001/tempDir-001/node1/.
[junit4] 2> 87638 INFO (zkConnectionManagerCallback-153-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 87650 INFO (zkConnectionManagerCallback-158-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 87652 INFO (SUITE-IndexSizeTriggerTest-seed#[908582EF0A9F048C]-worker) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (2)
[junit4] 2> 87652 INFO (SUITE-IndexSizeTriggerTest-seed#[908582EF0A9F048C]-worker) [ ] o.a.s.c.s.i.ZkClientClusterStateProvider Cluster at 127.0.0.1:41705/solr ready
[junit4] 2> 87684 DEBUG (SUITE-IndexSizeTriggerTest-seed#[908582EF0A9F048C]-worker) [ ] o.a.s.c.a.s.SimClusterStateProvider --- new Overseer leader: 127.0.0.1:10000_solr
[junit4] 2> 87685 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Adding .auto_add_replicas and .scheduled_maintenance triggers
[junit4] 2> 87685 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Refreshing /autoscaling.json with znode version 0
[junit4] 2> 87686 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Current znodeVersion 0, lastZnodeVersion -1
[junit4] 2> 87686 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Processed trigger updates upto znodeVersion 0
[junit4] 2> 87689 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.NodeLostTrigger NodeLostTrigger .auto_add_replicas - Initial livenodes: [127.0.0.1:10000_solr]
[junit4] 2> 87691 WARN (SUITE-IndexSizeTriggerTest-seed#[908582EF0A9F048C]-worker) [ ] o.a.s.h.a.MetricsHistoryHandler Missing .system, keeping metrics history in memory
[junit4] 2> 87694 DEBUG (ScheduledTrigger-462-thread-1) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 2
[junit4] 2> 87706 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread -- clean old nodeAdded markers
[junit4] 2> 87706 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Current znodeVersion 0, lastZnodeVersion 0
[junit4] 2> 87715 DEBUG (ScheduledTrigger-462-thread-1) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 2
[junit4] 2> 87738 DEBUG (ScheduledTrigger-462-thread-1) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 2
[junit4] 2> 87759 DEBUG (ScheduledTrigger-462-thread-1) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 2
[junit4] 2> 87779 DEBUG (ScheduledTrigger-462-thread-1) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 2
[junit4] 2> 87799 DEBUG (ScheduledTrigger-462-thread-1) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 2
[junit4] 2> 87819 DEBUG (ScheduledTrigger-462-thread-3) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 2
[junit4] 2> 87840 DEBUG (ScheduledTrigger-462-thread-2) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 2
[junit4] 2> 87860 DEBUG (ScheduledTrigger-462-thread-4) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 2
[junit4] 2> 87881 DEBUG (ScheduledTrigger-462-thread-2) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 2
[junit4] 2> 87903 DEBUG (ScheduledTrigger-462-thread-2) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 2
[junit4] 2> 87903 WARN (TEST-IndexSizeTriggerTest.testMixedBounds-seed#[908582EF0A9F048C]) [ ] o.a.s.c.a.IndexSizeTriggerTest Requires SOLR-12208
[junit4] 2> 87907 INFO (TEST-IndexSizeTriggerTest.testMixedBounds-seed#[908582EF0A9F048C]) [ ] o.a.s.c.a.IndexSizeTriggerTest #######################################
[junit4] 2> ############ CLUSTER STATE ############
[junit4] 2> #######################################
[junit4] 2> ## Live nodes: 2
[junit4] 2> ## Empty nodes: 2
[junit4] 2> ## Dead nodes: 0
[junit4] 2> ## Collections: []
[junit4] 2> ## Max replicas per node: 0
[junit4] 2> ## Min replicas per node: 0
[junit4] 2> ## Total replicas: 0
[junit4] 2> ######### Solr op counts ##########
[junit4] 2> ######### Autoscaling event counts ###########
[junit4] 2>
[junit4] 2> 87908 DEBUG (TEST-IndexSizeTriggerTest.testMixedBounds-seed#[908582EF0A9F048C]) [ ] o.a.s.c.a.OverseerTriggerThread Refreshing /autoscaling.json with znode version 1
[junit4] 2> 87908 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Processed trigger updates upto znodeVersion 1
[junit4] 2> 87908 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread -- clean old nodeLost markers
[junit4] 2> 87908 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread -- clean old nodeAdded markers
[junit4] 2> 87908 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Current znodeVersion 1, lastZnodeVersion 1
[junit4] 2> 88101 DEBUG (simCloudManagerPool-461-thread-6) [ ] o.a.s.c.a.s.SimClusterStateProvider -- elected new leader for testTrigger_collection / shard2: {"core_node3":{
[junit4] 2> "core":"testTrigger_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:10001_solr",
[junit4] 2> "state":"active",
[junit4] 2> "type":"NRT",
[junit4] 2> "SEARCHER.searcher.numDocs":0,
[junit4] 2> "shard":"shard2",
[junit4] 2> "collection":"testTrigger_collection"}}
[junit4] 2> 88101 DEBUG (simCloudManagerPool-461-thread-7) [ ] o.a.s.c.a.s.SimClusterStateProvider -- elected new leader for testTrigger_collection / shard1: {"core_node1":{
[junit4] 2> "core":"testTrigger_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:10001_solr",
[junit4] 2> "state":"active",
[junit4] 2> "type":"NRT",
[junit4] 2> "SEARCHER.searcher.numDocs":0,
[junit4] 2> "shard":"shard1",
[junit4] 2> "collection":"testTrigger_collection"}}
[junit4] 2> 88259 DEBUG (ScheduledTrigger-449-thread-1) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 2
[junit4] 2> 88378 INFO (TEST-IndexSizeTriggerTest.testTrigger-seed#[908582EF0A9F048C]) [ ] o.a.s.c.a.IndexSizeTriggerTest #######################################
[junit4] 2> ############ CLUSTER STATE ############
[junit4] 2> #######################################
[junit4] 2> ## Live nodes: 2
[junit4] 2> ## Empty nodes: 0
[junit4] 2> ## Dead nodes: 0
[junit4] 2> ## Collections: [testTrigger_collection]
[junit4] 2> DocCollection(testTrigger_collection//clusterstate.json/29)={
[junit4] 2> "replicationFactor":"2",
[junit4] 2> "pullReplicas":"0",
[junit4] 2> "router":{"name":"compositeId"},
[junit4] 2> "maxShardsPerNode":"2",
[junit4] 2> "autoAddReplicas":"false",
[junit4] 2> "nrtReplicas":"2",
[junit4] 2> "tlogReplicas":"0",
[junit4] 2> "autoCreated":"true",
[junit4] 2> "shards":{
[junit4] 2> "shard2":{
[junit4] 2> "replicas":{
[junit4] 2> "core_node3":{
[junit4] 2> "core":"testTrigger_collection_shard2_replica_n3",
[junit4] 2> "leader":"true",
[junit4] 2> "SEARCHER.searcher.maxDoc":11,
[junit4] 2> "SEARCHER.searcher.deletedDocs":0,
[junit4] 2> "INDEX.sizeInBytes":1,
[junit4] 2> "node_name":"127.0.0.1:10001_solr",
[junit4] 2> "state":"active",
[junit4] 2> "type":"NRT",
[junit4] 2> "SEARCHER.searcher.numDocs":11},
[junit4] 2> "core_node4":{
[junit4] 2> "core":"testTrigger_collection_shard2_replica_n4",
[junit4] 2> "SEARCHER.searcher.maxDoc":11,
[junit4] 2> "SEARCHER.searcher.deletedDocs":0,
[junit4] 2> "INDEX.sizeInBytes":1,
[junit4] 2> "node_name":"127.0.0.1:10000_solr",
[junit4] 2> "state":"active",
[junit4] 2> "type":"NRT",
[junit4] 2> "SEARCHER.searcher.numDocs":11}},
[junit4] 2> "range":"0-7fffffff",
[junit4] 2> "state":"active"},
[junit4] 2> "shard1":{
[junit4] 2> "replicas":{
[junit4] 2> "core_node1":{
[junit4] 2> "core":"testTrigger_collection_shard1_replica_n1",
[junit4] 2> "leader":"true",
[junit4] 2> "SEARCHER.searcher.maxDoc":14,
[junit4] 2> "SEARCHER.searcher.deletedDocs":0,
[junit4] 2> "INDEX.sizeInBytes":1,
[junit4] 2> "node_name":"127.0.0.1:10001_solr",
[junit4] 2> "state":"active",
[junit4] 2> "type":"NRT",
[junit4] 2> "SEARCHER.searcher.numDocs":14},
[junit4] 2> "core_node2":{
[junit4] 2> "core":"testTrigger_collection_shard1_replica_n2",
[junit4] 2> "SEARCHER.searcher.maxDoc":14,
[junit4] 2> "SEARCHER.searcher.deletedDocs":0,
[junit4] 2> "INDEX.sizeInBytes":1,
[junit4] 2> "node_name":"127.0.0.1:10000_solr",
[junit4] 2> "state":"active",
[junit4] 2> "type":"NRT",
[junit4] 2> "SEARCHER.searcher.numDocs":14}},
[junit4] 2> "range":"80000000-ffffffff",
[junit4] 2> "state":"active"}}}
[junit4] 2> ## Max replicas per node: 2
[junit4] 2> ## Min replicas per node: 2
[junit4] 2> ## Total replicas: 4
[junit4] 2> ## * testTrigger_collection 4
[junit4] 2> ## - active 4
[junit4] 2> ######### Solr op counts ##########
[junit4] 2> ## - CREATE 1
[junit4] 2> ## - update 26
[junit4] 2> ######### Autoscaling event counts ###########
[junit4] 2>
[junit4] 2> 88379 DEBUG (TEST-IndexSizeTriggerTest.testTrigger-seed#[908582EF0A9F048C]) [ ] o.a.s.c.a.OverseerTriggerThread Refreshing /autoscaling.json with znode version 2
[junit4] 2> 88379 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Processed trigger updates upto znodeVersion 2
[junit4] 2> 88379 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread -- clean old nodeLost markers
[junit4] 2> 88379 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread -- clean old nodeAdded markers
[junit4] 2> 88379 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Current znodeVersion 2, lastZnodeVersion 2
[junit4] 2> 88560 DEBUG (simCloudManagerPool-461-thread-39) [ ] 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:10000_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> 88560 DEBUG (simCloudManagerPool-461-thread-40) [ ] 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:10000_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> 88583 DEBUG (simCloudManagerPool-461-thread-52) [ ] o.a.s.c.a.AutoScalingHandler Verified autoscaling configuration
[junit4] 2> 88583 DEBUG (simCloudManagerPool-461-thread-52) [ ] o.a.s.c.a.OverseerTriggerThread Refreshing /autoscaling.json with znode version 3
[junit4] 2> 88583 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Processed trigger updates upto znodeVersion 3
[junit4] 2> 88583 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread -- clean old nodeLost markers
[junit4] 2> 88583 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread -- clean old nodeAdded markers
[junit4] 2> 88583 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Current znodeVersion 3, lastZnodeVersion 3
[junit4] 2> 88585 DEBUG (simCloudManagerPool-461-thread-53) [ ] o.a.s.c.a.AutoScalingHandler Verified autoscaling configuration
[junit4] 2> 88585 DEBUG (simCloudManagerPool-461-thread-53) [ ] o.a.s.c.a.OverseerTriggerThread Refreshing /autoscaling.json with znode version 4
[junit4] 2> 88586 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Processed trigger updates upto znodeVersion 4
[junit4] 2> 88586 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread -- clean old nodeLost markers
[junit4] 2> 88586 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread -- clean old nodeAdded markers
[junit4] 2> 88586 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Current znodeVersion 4, lastZnodeVersion 4
[junit4] 2> 88591 DEBUG (simCloudManagerPool-461-thread-54) [ ] o.a.s.c.a.AutoScalingHandler Verified autoscaling configuration
[junit4] 2> 88591 DEBUG (simCloudManagerPool-461-thread-54) [ ] o.a.s.c.a.OverseerTriggerThread Refreshing /autoscaling.json with znode version 5
[junit4] 2> 88592 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Processed trigger updates upto znodeVersion 5
[junit4] 2> 88592 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread -- clean old nodeLost markers
[junit4] 2> 88592 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread -- clean old nodeAdded markers
[junit4] 2> 88592 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Current znodeVersion 5, lastZnodeVersion 5
[junit4] 2> 88731 DEBUG (ScheduledTrigger-462-thread-3) [ ] o.a.s.c.a.ScheduledTriggers ++++++++ Cooldown inactive - processing event: {
[junit4] 2> "id":"381739d0d8ea8T6x9sbek923kh2a125tb6ngu7u",
[junit4] 2> "source":"index_size_trigger",
[junit4] 2> "eventTime":986758486265512,
[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:10000_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:10000_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> 88732 DEBUG (ScheduledTrigger-462-thread-3) [ ] o.a.s.c.a.ScheduledTriggers Pausing all triggers: [index_size_trigger]
[junit4] 2> 88734 INFO (ScheduledTrigger-462-thread-3) [ ] o.a.s.c.a.IndexSizeTriggerTest =======> CapturedEvent{timestamp=986765978793962, stage=STARTED, actionName='null', event={
[junit4] 2> "id":"381739d0d8ea8T6x9sbek923kh2a125tb6ngu7u",
[junit4] 2> "source":"index_size_trigger",
[junit4] 2> "eventTime":986758486265512,
[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:10000_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:10000_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_":986765908061212,
[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_trigger",
[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> 88780 DEBUG (AutoscalingActionExecutor-463-thread-1) [ ] o.a.s.c.a.ScheduledTriggers -- processing actions for {
[junit4] 2> "id":"381739d0d8ea8T6x9sbek923kh2a125tb6ngu7u",
[junit4] 2> "source":"index_size_trigger",
[junit4] 2> "eventTime":986758486265512,
[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:10000_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:10000_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_":986765908061212,
[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> 88781 INFO (AutoscalingActionExecutor-463-thread-1) [ ] o.a.s.c.a.IndexSizeTriggerTest =======> CapturedEvent{timestamp=986768363375062, stage=BEFORE_ACTION, actionName='compute_plan', event={
[junit4] 2> "id":"381739d0d8ea8T6x9sbek923kh2a125tb6ngu7u",
[junit4] 2> "source":"index_size_trigger",
[junit4] 2> "eventTime":986758486265512,
[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:10000_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:10000_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_":986765908061212,
[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_trigger}, config={
[junit4] 2> "trigger":"index_size_trigger",
[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> 88782 DEBUG (AutoscalingActionExecutor-463-thread-1) [ ] o.a.s.c.a.ComputePlanAction -- processing event: {
[junit4] 2> "id":"381739d0d8ea8T6x9sbek923kh2a125tb6ngu7u",
[junit4] 2> "source":"index_size_trigger",
[junit4] 2> "eventTime":986758486265512,
[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:10000_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:10000_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_":986765908061212,
[junit4] 2> "requestedOps":["Op{action=MERGESHARDS, hints={COLL_SHARD=[{\n \"first\":\"testMergeIntegration_collection\",\n \"second\":\"shard2\"}, {\n \"first\":\"testMergeIntegration_collection\",\n \"second\":\"shard1\"}]}}"]}} with context properties: {BEFORE_ACTION=[compute_plan]}
[junit4] 2> 88787 INFO (AutoscalingActionExecutor-463-thread-1) [ ] o.a.s.c.a.ComputePlanAction Computed plan empty, remained 0 requested ops to try.
[junit4] 2> 88787 INFO (AutoscalingActionExecutor-463-thread-1) [ ] o.a.s.c.s.c.a.PolicyHelper returnSession, curr-time 986768673 sessionWrapper.createTime 986768564928462, this.sessionWrapper.createTime 986768564928462
[junit4] 2> 88788 INFO (AutoscalingActionExecutor-463-thread-1) [ ] o.a.s.c.a.IndexSizeTriggerTest =======> CapturedEvent{timestamp=986768687149462, stage=AFTER_ACTION, actionName='compute_plan', event={
[junit4] 2> "id":"381739d0d8ea8T6x9sbek923kh2a125tb6ngu7u",
[junit4] 2> "source":"index_size_trigger",
[junit4] 2> "eventTime":986758486265512,
[junit4] 2> "eventType":"INDEXSIZE",
[junit4] 2> "properties":{
[junit4] 2> "__start__":1,
[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:10000_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:10000_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_":986765908061212,
[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.unsupportedOps=[Op{action=MERGESHARDS, hints={COLL_SHARD=[{
[junit4] 2> "first":"testMergeIntegration_collection",
[junit4] 2> "second":"shard2"}, {
[junit4] 2> "first":"testMergeIntegration_collection",
[junit4] 2> "second":"shard1"}]}}], properties.BEFORE_ACTION=[compute_plan], source=index_size_trigger, properties.AFTER_ACTION=[compute_plan]}, config={
[junit4] 2> "trigger":"index_size_trigger",
[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> 88788 INFO (AutoscalingActionExecutor-463-thread-1) [ ] o.a.s.c.a.IndexSizeTriggerTest =======> CapturedEvent{timestamp=986768708046362, stage=BEFORE_ACTION, actionName='execute_plan', event={
[junit4] 2> "id":"381739d0d8ea8T6x9sbek923kh2a125tb6ngu7u",
[junit4] 2> "source":"index_size_trigger",
[junit4] 2> "eventTime":986758486265512,
[junit4] 2> "eventType":"INDEXSIZE",
[junit4] 2> "properties":{
[junit4] 2> "__start__":1,
[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:10000_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:10000_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_":986765908061212,
[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.unsupportedOps=[Op{action=MERGESHARDS, hints={COLL_SHARD=[{
[junit4] 2> "first":"testMergeIntegration_collection",
[junit4] 2> "second":"shard2"}, {
[junit4] 2> "first":"testMergeIntegration_collection",
[junit4] 2> "second":"shard1"}]}}], properties.BEFORE_ACTION=[compute_plan, execute_plan], source=index_size_trigger, properties.AFTER_ACTION=[compute_plan]}, config={
[junit4] 2> "trigger":"index_size_trigger",
[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> 88788 DEBUG (AutoscalingActionExecutor-463-thread-1) [ ] o.a.s.c.a.ExecutePlanAction -- processing event: {
[junit4] 2> "id":"381739d0d8ea8T6x9sbek923kh2a125tb6ngu7u",
[junit4] 2> "source":"index_size_trigger",
[junit4] 2> "eventTime":986758486265512,
[junit4] 2> "eventType":"INDEXSIZE",
[junit4] 2> "properties":{
[junit4] 2> "__start__":1,
[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:10000_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:10000_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_":986765908061212,
[junit4] 2> "requestedOps":["Op{action=MERGESHARDS, hints={COLL_SHARD=[{\n \"first\":\"testMergeIntegration_collection\",\n \"second\":\"shard2\"}, {\n \"first\":\"testMergeIntegration_collection\",\n \"second\":\"shard1\"}]}}"]}} with context properties: {AFTER_ACTION=[compute_plan], unsupportedOps=[Op{action=MERGESHARDS, hints={COLL_SHARD=[{
[junit4] 2> "first":"testMergeIntegration_collection",
[junit4] 2> "second":"shard2"}, {
[junit4] 2> "first":"testMergeIntegration_collection",
[junit4] 2> "second":"shard1"}]}}], BEFORE_ACTION=[compute_plan, execute_plan]}
[junit4] 2> 88789 INFO (AutoscalingActionExecutor-463-thread-1) [ ] o.a.s.c.a.ExecutePlanAction No operations to execute for event: {
[junit4] 2> "id":"381739d0d8ea8T6x9sbek923kh2a125tb6ngu7u",
[junit4] 2> "source":"index_size_trigger",
[junit4] 2> "eventTime":986758486265512,
[junit4] 2> "eventType":"INDEXSIZE",
[junit4] 2> "properties":{
[junit4] 2> "__start__":1,
[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:10000_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:10000_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_":986765908061212,
[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> 88789 INFO (AutoscalingActionExecutor-463-thread-1) [ ] o.a.s.c.a.IndexSizeTriggerTest =======> CapturedEvent{timestamp=986768772462662, stage=AFTER_ACTION, actionName='execute_plan', event={
[junit4] 2> "id":"381739d0d8ea8T6x9sbek923kh2a125tb6ngu7u",
[junit4] 2> "source":"index_size_trigger",
[junit4] 2> "eventTime":986758486265512,
[junit4] 2> "eventType":"INDEXSIZE",
[junit4] 2> "properties":{
[junit4] 2> "__start__":1,
[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:10000_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:10000_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_":986765908061212,
[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.unsupportedOps=[Op{action=MERGESHARDS, hints={COLL_SHARD=[{
[junit4] 2> "first":"testMergeIntegration_collection",
[junit4] 2> "second":"shard2"}, {
[junit4] 2> "first":"testMergeIntegration_collection",
[junit4] 2> "second":"shard1"}]}}], properties.BEFORE_ACTION=[compute_plan, execute_plan], source=index_size_trigger, properties.AFTER_ACTION=[compute_plan, execute_plan]}, config={
[junit4] 2> "trigger":"index_size_trigger",
[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> 88790 INFO (AutoscalingActionExecutor-463-thread-1) [ ] o.a.s.c.a.IndexSizeTriggerTest =======> CapturedEvent{timestamp=986768823185462, stage=SUCCEEDED, actionName='null', event={
[junit4] 2> "id":"381739d0d8ea8T6x9sbek923kh2a125tb6ngu7u",
[junit4] 2> "source":"index_size_trigger",
[junit4] 2> "eventTime":986758486265512,
[junit4] 2> "eventType":"INDEXSIZE",
[junit4] 2> "properties":{
[junit4] 2> "__start__":1,
[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:10000_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:10000_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_":986765908061212,
[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_trigger",
[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> 88792 INFO (TEST-IndexSizeTriggerTest.testMergeIntegration-seed#[908582EF0A9F048C]) [ ] o.a.s.c.a.IndexSizeTriggerTest #######################################
[junit4] 2> ############ CLUSTER STATE ############
[junit4] 2> #######################################
[junit4] 2> ## Live nodes: 2
[junit4] 2> ## Empty nodes: 0
[junit4] 2> ## Dead nodes: 0
[junit4] 2> ## Collections: [testMergeIntegration_collection, .system]
[junit4] 2> DocCollection(testMergeIntegration_collection//clusterstate.json/52)={
[junit4] 2> "replicationFactor":"2",
[junit4] 2> "pullReplicas":"0",
[junit4] 2> "router":{"name":"compositeId"},
[junit4] 2> "maxShardsPerNode":"2",
[junit4] 2> "autoAddReplicas":"false",
[junit4] 2> "nrtReplicas":"2",
[junit4] 2> "tlogReplicas":"0",
[junit4] 2> "autoCreated":"true",
[junit4] 2> "shards":{
[junit4] 2> "shard2":{
[junit4] 2> "replicas":{
[junit4] 2> "core_node3":{
[junit4] 2> "core":"testMergeIntegration_collection_shard2_replica_n3",
[junit4] 2> "leader":"true",
[junit4] 2> "SEARCHER.searcher.maxDoc":3,
[junit4] 2> "SEARCHER.searcher.deletedDocs":0,
[junit4] 2> "INDEX.sizeInBytes":1,
[junit4] 2> "node_name":"127.0.0.1:10000_solr",
[junit4] 2> "state":"active",
[junit4] 2> "type":"NRT",
[junit4] 2> "SEARCHER.searcher.numDocs":3},
[junit4] 2> "core_node4":{
[junit4] 2> "core":"testMergeIntegration_collection_shard2_replica_n4",
[junit4] 2> "SEARCHER.searcher.maxDoc":3,
[junit4] 2> "SEARCHER.searcher.deletedDocs":0,
[junit4] 2> "INDEX.sizeInBytes":1,
[junit4] 2> "node_name":"127.0.0.1:10001_solr",
[junit4] 2> "state":"active",
[junit4] 2> "type":"NRT",
[junit4] 2> "SEARCHER.searcher.numDocs":3}},
[junit4] 2> "range":"0-7fffffff",
[junit4] 2> "state":"active"},
[junit4] 2> "shard1":{
[junit4] 2> "replicas":{
[junit4] 2> "core_node1":{
[junit4] 2> "core":"testMergeIntegration_collection_shard1_replica_n1",
[junit4] 2> "leader":"true",
[junit4] 2> "SEARCHER.searcher.maxDoc":7,
[junit4] 2> "SEARCHER.searcher.deletedDocs":5,
[junit4] 2> "INDEX.sizeInBytes":1,
[junit4] 2> "node_name":"127.0.0.1:10000_solr",
[junit4] 2> "state":"active",
[junit4] 2> "type":"NRT",
[junit4] 2> "SEARCHER.searcher.numDocs":2},
[junit4] 2> "core_node2":{
[junit4] 2> "core":"testMergeIntegration_collection_shard1_replica_n2",
[junit4] 2> "SEARCHER.searcher.maxDoc":7,
[junit4] 2> "SEARCHER.searcher.deletedDocs":5,
[junit4] 2> "INDEX.sizeInBytes":1,
[junit4] 2> "node_name":"127.0.0.1:10001_solr",
[junit4] 2> "state":"active",
[junit4] 2> "type":"NRT",
[junit4] 2> "SEARCHER.searcher.numDocs":2}},
[junit4] 2> "range":"80000000-ffffffff",
[junit4] 2> "state":"active"}}}
[junit4] 2> DocCollection(.system//clusterstate.json/52)={
[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":1,
[junit4] 2> "SEARCHER.searcher.deletedDocs":0,
[junit4] 2> "INDEX.sizeInBytes":1,
[junit4] 2> "node_name":"127.0.0.1:10000_solr",
[junit4] 2> "state":"active",
[junit4] 2> "type":"NRT",
[junit4] 2> "SEARCHER.searcher.numDocs":1}},
[junit4] 2> "range":"80000000-7fffffff",
[junit4] 2> "state":"active"}}}
[junit4] 2> ## Max replicas per node: 3
[junit4] 2> ## Min replicas per node: 2
[junit4] 2> ## Total replicas: 5
[junit4] 2> ## * .system 1
[junit4] 2> ## - active 1
[junit4] 2> ## * testMergeIntegration_collection 4
[junit4] 2> ## - active 4
[junit4] 2> ######### Solr op counts ##########
[junit4] 2> ## - CREATE 1
[junit4] 2> ## - autoscaling 3
[junit4] 2> ## - update 18
[junit4] 2> ######### Autoscaling event counts ###########
[junit4] 2> ## * Trigger: index_size_trigger
[junit4] 2> ## - STARTED 1
[junit4] 2>
[junit4] 2> 88793 DEBUG (TEST-IndexSizeTriggerTest.testMergeIntegration-seed#[908582EF0A9F048C]) [ ] o.a.s.c.a.OverseerTriggerThread Refreshing /autoscaling.json with znode version 6
[junit4] 2> 88793 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Processed trigger updates upto znodeVersion 6
[junit4] 2> 88793 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread -- clean old nodeLost markers
[junit4] 2> 88793 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread -- clean old nodeAdded markers
[junit4] 2> 88793 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Current znodeVersion 6, lastZnodeVersion 6
[junit4] 2> 88815 DEBUG (AutoscalingActionExecutor-463-thread-1) [ ] o.a.s.c.a.ScheduledTriggers -- processing took 1843 ms for event id=381739d0d8ea8T6x9sbek923kh2a125tb6ngu7u
[junit4] 2> 89063 DEBUG (simCloudManagerPool-461-thread-72) [ ] o.a.s.c.a.s.SimClusterStateProvider -- elected new leader for testSplitIntegration_collection / shard2: {"core_node3":{
[junit4] 2> "core":"testSplitIntegration_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:10000_solr",
[junit4] 2> "state":"active",
[junit4] 2> "type":"NRT",
[junit4] 2> "SEARCHER.searcher.numDocs":0,
[junit4] 2> "shard":"shard2",
[junit4] 2> "collection":"testSplitIntegration_collection"}}
[junit4] 2> 89067 DEBUG (simCloudManagerPool-461-thread-73) [ ] o.a.s.c.a.s.SimClusterStateProvider -- elected new leader for testSplitIntegration_collection / shard1: {"core_node1":{
[junit4] 2> "core":"testSplitIntegration_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:10000_solr",
[junit4] 2> "state":"active",
[junit4] 2> "type":"NRT",
[junit4] 2> "SEARCHER.searcher.numDocs":0,
[junit4] 2> "shard":"shard1",
[junit4] 2> "collection":"testSplitIntegration_collection"}}
[junit4] 2> 89068 DEBUG (simCloudManagerPool-461-thread-74) [ ] o.a.s.c.a.AutoScalingHandler Verified autoscaling configuration
[junit4] 2> 89069 DEBUG (simCloudManagerPool-461-thread-74) [ ] o.a.s.c.a.OverseerTriggerThread Refreshing /autoscaling.json with znode version 7
[junit4] 2> 89069 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Processed trigger updates upto znodeVersion 7
[junit4] 2> 89069 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread -- clean old nodeLost markers
[junit4] 2> 89069 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread -- clean old nodeAdded markers
[junit4] 2> 89069 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Current znodeVersion 7, lastZnodeVersion 7
[junit4] 2> 89083 DEBUG (simCloudManagerPool-461-thread-75) [ ] o.a.s.c.a.AutoScalingHandler Verified autoscaling configuration
[junit4] 2> 89084 DEBUG (simCloudManagerPool-461-thread-75) [ ] o.a.s.c.a.OverseerTriggerThread Refreshing /autoscaling.json with znode version 8
[junit4] 2> 89084 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTrigge
[...truncated too long message...]
[junit4] 2> 7958 INFO (jetty-closer-2-thread-1) [ ] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.node, tag=null
[junit4] 2> 7958 INFO (jetty-closer-2-thread-2) [ ] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.node, tag=null
[junit4] 2> 7959 INFO (jetty-closer-2-thread-1) [ ] o.a.s.m.r.SolrJmxReporter Closing reporter [org.apache.solr.metrics.reporters.SolrJmxReporter@5eb7d60b: rootName = solr_33259, domain = solr.node, service url = null, agent id = null] for registry solr.node / com.codahale.metrics.MetricRegistry@3af09c0d
[junit4] 2> 7959 INFO (jetty-closer-2-thread-2) [ ] o.a.s.m.r.SolrJmxReporter Closing reporter [org.apache.solr.metrics.reporters.SolrJmxReporter@aa9e44a: rootName = solr_37961, domain = solr.node, service url = null, agent id = null] for registry solr.node / com.codahale.metrics.MetricRegistry@55ac34ce
[junit4] 2> 7965 INFO (jetty-closer-2-thread-2) [ ] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.jvm, tag=null
[junit4] 2> 7965 INFO (jetty-closer-2-thread-2) [ ] o.a.s.m.r.SolrJmxReporter Closing reporter [org.apache.solr.metrics.reporters.SolrJmxReporter@52ecc7cb: rootName = solr_37961, domain = solr.jvm, service url = null, agent id = null] for registry solr.jvm / com.codahale.metrics.MetricRegistry@75f16ce4
[junit4] 2> 7965 INFO (jetty-closer-2-thread-1) [ ] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.jvm, tag=null
[junit4] 2> 7965 INFO (jetty-closer-2-thread-1) [ ] o.a.s.m.r.SolrJmxReporter Closing reporter [org.apache.solr.metrics.reporters.SolrJmxReporter@8258605: rootName = solr_33259, domain = solr.jvm, service url = null, agent id = null] for registry solr.jvm / com.codahale.metrics.MetricRegistry@75f16ce4
[junit4] 2> 7970 INFO (jetty-closer-2-thread-2) [ ] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.jetty, tag=null
[junit4] 2> 7970 INFO (jetty-closer-2-thread-2) [ ] o.a.s.m.r.SolrJmxReporter Closing reporter [org.apache.solr.metrics.reporters.SolrJmxReporter@4a83c147: rootName = solr_37961, domain = solr.jetty, service url = null, agent id = null] for registry solr.jetty / com.codahale.metrics.MetricRegistry@4ad4abb
[junit4] 2> 7970 INFO (jetty-closer-2-thread-1) [ ] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.jetty, tag=null
[junit4] 2> 7970 INFO (jetty-closer-2-thread-1) [ ] o.a.s.m.r.SolrJmxReporter Closing reporter [org.apache.solr.metrics.reporters.SolrJmxReporter@38ed4f59: rootName = solr_33259, domain = solr.jetty, service url = null, agent id = null] for registry solr.jetty / com.codahale.metrics.MetricRegistry@4ad4abb
[junit4] 2> 7972 INFO (jetty-closer-2-thread-2) [ ] o.a.s.c.ZkController Remove node as live in ZooKeeper:/live_nodes/127.0.0.1:37961_solr
[junit4] 2> 7972 INFO (jetty-closer-2-thread-1) [ ] o.a.s.c.ZkController Remove node as live in ZooKeeper:/live_nodes/127.0.0.1:33259_solr
[junit4] 2> 7980 INFO (zkCallback-28-thread-1) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (2) -> (0)
[junit4] 2> 7980 INFO (jetty-closer-2-thread-2) [ ] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.cluster, tag=null
[junit4] 2> 7980 INFO (zkCallback-17-thread-1) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (2) -> (0)
[junit4] 2> 7980 INFO (jetty-closer-2-thread-2) [ ] o.a.s.c.TransientSolrCoreCacheDefault Allocating transient cache for 2147483647 transient cores
[junit4] 2> 7980 INFO (zkCallback-19-thread-1) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (2) -> (0)
[junit4] 2> 7981 INFO (jetty-closer-2-thread-1) [ ] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.cluster, tag=null
[junit4] 2> 7986 INFO (jetty-closer-2-thread-1) [ ] o.a.s.c.Overseer Overseer (id=72122442625253381-127.0.0.1:33259_solr-n_0000000000) closing
[junit4] 2> 7986 INFO (OverseerStateUpdate-72122442625253381-127.0.0.1:33259_solr-n_0000000000) [ ] o.a.s.c.Overseer Overseer Loop exiting : 127.0.0.1:33259_solr
[junit4] 2> 7987 WARN (OverseerAutoScalingTriggerThread-72122442625253381-127.0.0.1:33259_solr-n_0000000000) [ ] o.a.s.c.a.OverseerTriggerThread OverseerTriggerThread woken up but we are closed, exiting.
[junit4] 2> 7987 DEBUG (jetty-closer-2-thread-1) [ ] o.a.s.c.a.ScheduledTriggers Shutting down scheduled thread pool executor now
[junit4] 2> 7987 DEBUG (jetty-closer-2-thread-1) [ ] o.a.s.c.a.ScheduledTriggers Shutting down action executor now
[junit4] 2> 7987 DEBUG (jetty-closer-2-thread-1) [ ] o.a.s.c.a.ScheduledTriggers Awaiting termination for action executor
[junit4] 2> 7988 DEBUG (jetty-closer-2-thread-1) [ ] o.a.s.c.a.ScheduledTriggers Awaiting termination for scheduled thread pool executor
[junit4] 2> 7988 DEBUG (jetty-closer-2-thread-1) [ ] o.a.s.c.a.ScheduledTriggers ScheduledTriggers closed completely
[junit4] 2> 7988 DEBUG (jetty-closer-2-thread-1) [ ] o.a.s.c.a.OverseerTriggerThread OverseerTriggerThread has been closed explicitly
[junit4] 2> 7990 INFO (zkCallback-19-thread-1) [ ] o.a.s.c.OverseerElectionContext I am going to be the leader 127.0.0.1:37961_solr
[junit4] 2> 7991 INFO (jetty-closer-2-thread-1) [ ] o.e.j.s.h.ContextHandler Stopped o.e.j.s.ServletContextHandler@3c14320a{/solr,null,UNAVAILABLE}
[junit4] 2> 7991 INFO (jetty-closer-2-thread-1) [ ] o.e.j.s.session node0 Stopped scavenging
[junit4] 2> 9487 WARN (zkCallback-35-thread-1) [ ] o.a.s.c.c.ZkStateReader ZooKeeper watch triggered, but Solr cannot talk to ZK: [KeeperErrorCode = Session expired for /live_nodes]
[junit4] 2> 9489 INFO (jetty-closer-2-thread-2) [ ] o.e.j.s.h.ContextHandler Stopped o.e.j.s.ServletContextHandler@549d934b{/solr,null,UNAVAILABLE}
[junit4] 2> 9489 INFO (jetty-closer-2-thread-2) [ ] o.e.j.s.session node0 Stopped scavenging
[junit4] 2> 9490 ERROR (SUITE-IndexSizeTriggerTest-seed#[908582EF0A9F048C]-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> 9491 INFO (SUITE-IndexSizeTriggerTest-seed#[908582EF0A9F048C]-worker) [ ] o.a.s.c.ZkTestServer connecting to 127.0.0.1:36695 36695
[junit4] 2> 9598 INFO (Thread-0) [ ] o.a.s.c.ZkTestServer connecting to 127.0.0.1:36695 36695
[junit4] 2> 9599 WARN (Thread-0) [ ] 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: /home/jenkins/workspace/Lucene-Solr-7.x-Linux/solr/build/solr-core/test/J1/temp/solr.cloud.autoscaling.IndexSizeTriggerTest_908582EF0A9F048C-001
[junit4] 2> May 31, 2018 11:13:26 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=Lucene70, sim=RandomSimilarity(queryNorm=true): {}, locale=bs-Latn-BA, timezone=America/Thule
[junit4] 2> NOTE: Linux 4.13.0-41-generic amd64/Oracle Corporation 10 (64-bit)/cpus=8,threads=1,free=383845664,total=495976448
[junit4] 2> NOTE: All tests run in this JVM: [IndexSizeTriggerTest]
[junit4] Completed [3/5 (3!)] on J1 in 8.93s, 4 tests, 1 error <<< FAILURES!
[...truncated 27 lines...]
BUILD FAILED
/home/jenkins/workspace/Lucene-Solr-7.x-Linux/lucene/common-build.xml:1568: The following error occurred while executing this line:
/home/jenkins/workspace/Lucene-Solr-7.x-Linux/lucene/common-build.xml:1092: There were test failures: 5 suites, 20 tests, 3 errors [seed: 908582EF0A9F048C]
Total time: 14 seconds
[repro] Setting last failure code to 256
[repro] Failures:
[repro] 3/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=/var/lib/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=/var/lib/jenkins/tools/hudson.tasks.Ant_AntInstallation/ANT_1.8.2
Setting ANT_1_8_2_HOME=/var/lib/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=61a65d5928f4563f5c8284b1100528257e5c6834, workspace=/var/lib/jenkins/workspace/Lucene-Solr-7.x-Linux
[WARNINGS] Computing warning deltas based on reference build #2025
Recording test results
Setting ANT_1_8_2_HOME=/var/lib/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=/var/lib/jenkins/tools/hudson.tasks.Ant_AntInstallation/ANT_1.8.2
Setting ANT_1_8_2_HOME=/var/lib/jenkins/tools/hudson.tasks.Ant_AntInstallation/ANT_1.8.2
Setting ANT_1_8_2_HOME=/var/lib/jenkins/tools/hudson.tasks.Ant_AntInstallation/ANT_1.8.2
Setting ANT_1_8_2_HOME=/var/lib/jenkins/tools/hudson.tasks.Ant_AntInstallation/ANT_1.8.2