You are viewing a plain text version of this content. The canonical link for it is here.
Posted to builds@lucene.apache.org by Policeman Jenkins Server <je...@thetaphi.de> on 2020/09/10 17:00:47 UTC

[JENKINS] Lucene-Solr-8.x-Linux (64bit/jdk-12.0.2) - Build # 4351 - Still Unstable!

Build: https://jenkins.thetaphi.de/job/Lucene-Solr-8.x-Linux/4351/
Java: 64bit/jdk-12.0.2 -XX:+UseCompressedOops -XX:+UseG1GC

1 tests failed.
FAILED:  org.apache.solr.cloud.autoscaling.ComputePlanActionTest.testNodeWithMultipleReplicasLost

Error Message:


Stack Trace:
java.util.ConcurrentModificationException
	at __randomizedtesting.SeedInfo.seed([D6BE127202370C75:E67EF3F08A45ED29]:0)
	at java.base/java.util.ArrayList$Itr.checkForComodification(ArrayList.java:1042)
	at java.base/java.util.ArrayList$Itr.next(ArrayList.java:996)
	at java.base/java.util.AbstractCollection.toString(AbstractCollection.java:472)
	at java.base/java.lang.String.valueOf(String.java:3042)
	at java.base/java.lang.StringBuilder.append(StringBuilder.java:168)
	at java.base/java.util.AbstractMap.toString(AbstractMap.java:556)
	at java.base/java.lang.String.valueOf(String.java:3042)
	at java.base/java.lang.StringBuilder.append(StringBuilder.java:168)
	at org.apache.solr.cloud.autoscaling.ComputePlanActionTest.testNodeWithMultipleReplicasLost(ComputePlanActionTest.java:330)
	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:567)
	at com.carrotsearch.randomizedtesting.RandomizedRunner.invoke(RandomizedRunner.java:1750)
	at com.carrotsearch.randomizedtesting.RandomizedRunner$8.evaluate(RandomizedRunner.java:938)
	at com.carrotsearch.randomizedtesting.RandomizedRunner$9.evaluate(RandomizedRunner.java:974)
	at com.carrotsearch.randomizedtesting.RandomizedRunner$10.evaluate(RandomizedRunner.java:988)
	at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:57)
	at org.apache.lucene.util.TestRuleSetupTeardownChained$1.evaluate(TestRuleSetupTeardownChained.java:49)
	at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:45)
	at org.apache.lucene.util.TestRuleThreadAndTestName$1.evaluate(TestRuleThreadAndTestName.java:48)
	at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:64)
	at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:47)
	at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
	at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:368)
	at com.carrotsearch.randomizedtesting.ThreadLeakControl.forkTimeoutingTask(ThreadLeakControl.java:817)
	at com.carrotsearch.randomizedtesting.ThreadLeakControl$3.evaluate(ThreadLeakControl.java:468)
	at com.carrotsearch.randomizedtesting.RandomizedRunner.runSingleTest(RandomizedRunner.java:947)
	at com.carrotsearch.randomizedtesting.RandomizedRunner$5.evaluate(RandomizedRunner.java:832)
	at com.carrotsearch.randomizedtesting.RandomizedRunner$6.evaluate(RandomizedRunner.java:883)
	at com.carrotsearch.randomizedtesting.RandomizedRunner$7.evaluate(RandomizedRunner.java:894)
	at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
	at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:57)
	at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:45)
	at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
	at org.apache.lucene.util.TestRuleStoreClassName$1.evaluate(TestRuleStoreClassName.java:41)
	at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:40)
	at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:40)
	at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
	at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
	at 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:835)




Build Log:
[...truncated 14435 lines...]
   [junit4] Suite: org.apache.solr.cloud.autoscaling.ComputePlanActionTest
   [junit4]   2> 371388 INFO  (SUITE-ComputePlanActionTest-seed#[D6BE127202370C75]-worker) [     ] o.a.s.SolrTestCase Setting 'solr.default.confdir' system property to test-framework derived value of '/home/jenkins/workspace/Lucene-Solr-8.x-Linux/solr/server/solr/configsets/_default/conf'
   [junit4]   2> 371388 INFO  (SUITE-ComputePlanActionTest-seed#[D6BE127202370C75]-worker) [     ] o.a.s.SolrTestCaseJ4 SecureRandom sanity checks: test.solr.allowed.securerandom=null & java.security.egd=file:/dev/./urandom
   [junit4]   2> 371389 INFO  (SUITE-ComputePlanActionTest-seed#[D6BE127202370C75]-worker) [     ] o.a.s.SolrTestCaseJ4 Created dataDir: /home/jenkins/workspace/Lucene-Solr-8.x-Linux/solr/build/solr-core/test/J4/temp/solr.cloud.autoscaling.ComputePlanActionTest_D6BE127202370C75-001/data-dir-63-001
   [junit4]   2> 371389 WARN  (SUITE-ComputePlanActionTest-seed#[D6BE127202370C75]-worker) [     ] o.a.s.SolrTestCaseJ4 startTrackingSearchers: numOpens=1 numCloses=1
   [junit4]   2> 371389 INFO  (SUITE-ComputePlanActionTest-seed#[D6BE127202370C75]-worker) [     ] o.a.s.SolrTestCaseJ4 Using TrieFields (NUMERIC_POINTS_SYSPROP=false) w/NUMERIC_DOCVALUES_SYSPROP=true
   [junit4]   2> 371390 INFO  (SUITE-ComputePlanActionTest-seed#[D6BE127202370C75]-worker) [     ] o.a.s.SolrTestCaseJ4 Randomized ssl (true) and clientAuth (false) via: @org.apache.solr.util.RandomizeSSL(reason="", value=0.0/0.0, ssl=0.0/0.0, clientAuth=0.0/0.0)
   [junit4]   2> 371390 INFO  (SUITE-ComputePlanActionTest-seed#[D6BE127202370C75]-worker) [     ] o.a.s.c.MiniSolrCloudCluster Starting cluster of 1 servers in /home/jenkins/workspace/Lucene-Solr-8.x-Linux/solr/build/solr-core/test/J4/temp/solr.cloud.autoscaling.ComputePlanActionTest_D6BE127202370C75-001/tempDir-001
   [junit4]   2> 371390 INFO  (SUITE-ComputePlanActionTest-seed#[D6BE127202370C75]-worker) [     ] o.a.s.c.ZkTestServer STARTING ZK TEST SERVER
   [junit4]   2> 371390 INFO  (ZkTestServer Run Thread) [     ] o.a.s.c.ZkTestServer client port: 0.0.0.0/0.0.0.0:0
   [junit4]   2> 371390 INFO  (ZkTestServer Run Thread) [     ] o.a.s.c.ZkTestServer Starting server
   [junit4]   2> 371391 WARN  (ZkTestServer Run Thread) [     ] o.a.z.s.ServerCnxnFactory maxCnxns is not configured, using default value 0.
   [junit4]   2> 371490 INFO  (SUITE-ComputePlanActionTest-seed#[D6BE127202370C75]-worker) [     ] o.a.s.c.ZkTestServer start zk server on port: 32911
   [junit4]   2> 371490 INFO  (SUITE-ComputePlanActionTest-seed#[D6BE127202370C75]-worker) [     ] o.a.s.c.ZkTestServer waitForServerUp: 127.0.0.1:32911
   [junit4]   2> 371490 INFO  (SUITE-ComputePlanActionTest-seed#[D6BE127202370C75]-worker) [     ] o.a.s.c.ZkTestServer parse host and port list: 127.0.0.1:32911
   [junit4]   2> 371490 INFO  (SUITE-ComputePlanActionTest-seed#[D6BE127202370C75]-worker) [     ] o.a.s.c.ZkTestServer connecting to 127.0.0.1 32911
   [junit4]   2> 371492 INFO  (SUITE-ComputePlanActionTest-seed#[D6BE127202370C75]-worker) [     ] o.a.s.c.c.ConnectionManager Waiting for client to connect to ZooKeeper
   [junit4]   2> 371499 INFO  (zkConnectionManagerCallback-4239-thread-1) [     ] o.a.s.c.c.ConnectionManager zkClient has connected
   [junit4]   2> 371500 INFO  (SUITE-ComputePlanActionTest-seed#[D6BE127202370C75]-worker) [     ] o.a.s.c.c.ConnectionManager Client is connected to ZooKeeper
   [junit4]   2> 371505 INFO  (SUITE-ComputePlanActionTest-seed#[D6BE127202370C75]-worker) [     ] o.a.s.c.c.ConnectionManager Waiting for client to connect to ZooKeeper
   [junit4]   2> 371509 INFO  (zkConnectionManagerCallback-4241-thread-1) [     ] o.a.s.c.c.ConnectionManager zkClient has connected
   [junit4]   2> 371509 INFO  (SUITE-ComputePlanActionTest-seed#[D6BE127202370C75]-worker) [     ] o.a.s.c.c.ConnectionManager Client is connected to ZooKeeper
   [junit4]   2> 371509 INFO  (SUITE-ComputePlanActionTest-seed#[D6BE127202370C75]-worker) [     ] o.a.s.c.c.ConnectionManager Waiting for client to connect to ZooKeeper
   [junit4]   2> 371512 INFO  (zkConnectionManagerCallback-4243-thread-1) [     ] o.a.s.c.c.ConnectionManager zkClient has connected
   [junit4]   2> 371512 INFO  (SUITE-ComputePlanActionTest-seed#[D6BE127202370C75]-worker) [     ] o.a.s.c.c.ConnectionManager Client is connected to ZooKeeper
   [junit4]   2> 371618 WARN  (jetty-launcher-4244-thread-1) [     ] o.e.j.s.h.g.GzipHandler minGzipSize of 0 is inefficient for short content, break even is size 23
   [junit4]   2> 371618 INFO  (jetty-launcher-4244-thread-1) [     ] o.a.s.c.s.e.JettySolrRunner Start Jetty (configured port=0, binding port=0)
   [junit4]   2> 371618 INFO  (jetty-launcher-4244-thread-1) [     ] o.a.s.c.s.e.JettySolrRunner Trying to start Jetty on port 0 try number 2 ...
   [junit4]   2> 371618 INFO  (jetty-launcher-4244-thread-1) [     ] o.e.j.s.Server jetty-9.4.27.v20200227; built: 2020-02-27T18:37:21.340Z; git: a304fd9f351f337e7c0e2a7c28878dd536149c6c; jvm 12.0.2+10
   [junit4]   2> 371621 INFO  (jetty-launcher-4244-thread-1) [     ] o.e.j.s.session DefaultSessionIdManager workerName=node0
   [junit4]   2> 371621 INFO  (jetty-launcher-4244-thread-1) [     ] o.e.j.s.session No SessionScavenger set, using defaults
   [junit4]   2> 371621 INFO  (jetty-launcher-4244-thread-1) [     ] o.e.j.s.session node0 Scavenging every 600000ms
   [junit4]   2> 371622 INFO  (jetty-launcher-4244-thread-1) [     ] o.e.j.s.h.ContextHandler Started o.e.j.s.ServletContextHandler@e976322{/solr,null,AVAILABLE}
   [junit4]   2> 371623 INFO  (jetty-launcher-4244-thread-1) [     ] o.e.j.s.AbstractConnector Started ServerConnector@700b6950{ssl, (ssl, alpn, http/1.1, h2)}{127.0.0.1:38585}
   [junit4]   2> 371623 INFO  (jetty-launcher-4244-thread-1) [     ] o.e.j.s.Server Started @371643ms
   [junit4]   2> 371623 INFO  (jetty-launcher-4244-thread-1) [     ] o.a.s.c.s.e.JettySolrRunner Jetty properties: {hostContext=/solr, hostPort=38585}
   [junit4]   2> 371623 ERROR (jetty-launcher-4244-thread-1) [     ] o.a.s.u.StartupLoggingUtils Missing Java Option solr.log.dir. Logging may be missing or incomplete.
   [junit4]   2> 371623 INFO  (jetty-launcher-4244-thread-1) [     ] o.a.s.s.SolrDispatchFilter Using logger factory org.apache.logging.slf4j.Log4jLoggerFactory
   [junit4]   2> 371623 INFO  (jetty-launcher-4244-thread-1) [     ] o.a.s.s.SolrDispatchFilter  ___      _       Welcome to Apache Solr™ version 8.7.0
   [junit4]   2> 371623 INFO  (jetty-launcher-4244-thread-1) [     ] o.a.s.s.SolrDispatchFilter / __| ___| |_ _   Starting in cloud mode on port null
   [junit4]   2> 371623 INFO  (jetty-launcher-4244-thread-1) [     ] o.a.s.s.SolrDispatchFilter \__ \/ _ \ | '_|  Install dir: /home/jenkins/workspace/Lucene-Solr-8.x-Linux/solr
   [junit4]   2> 371623 INFO  (jetty-launcher-4244-thread-1) [     ] o.a.s.s.SolrDispatchFilter |___/\___/_|_|    Start time: 2020-09-10T16:34:41.977459Z
   [junit4]   2> 371624 INFO  (jetty-launcher-4244-thread-1) [     ] o.a.s.c.c.ConnectionManager Waiting for client to connect to ZooKeeper
   [junit4]   2> 371626 INFO  (zkConnectionManagerCallback-4246-thread-1) [     ] o.a.s.c.c.ConnectionManager zkClient has connected
   [junit4]   2> 371627 INFO  (jetty-launcher-4244-thread-1) [     ] o.a.s.c.c.ConnectionManager Client is connected to ZooKeeper
   [junit4]   2> 371628 INFO  (jetty-launcher-4244-thread-1) [     ] o.a.s.s.SolrDispatchFilter solr.xml found in ZooKeeper. Loading...
   [junit4]   2> 371778 INFO  (jetty-launcher-4244-thread-1) [     ] o.a.s.h.c.HttpShardHandlerFactory Host whitelist initialized: WhitelistHostChecker [whitelistHosts=null, whitelistHostCheckingEnabled=true]
   [junit4]   2> 371779 WARN  (jetty-launcher-4244-thread-1) [     ] o.e.j.u.s.S.config Trusting all certificates configured for Client@73a2d91[provider=null,keyStore=null,trustStore=null]
   [junit4]   2> 371779 WARN  (jetty-launcher-4244-thread-1) [     ] o.e.j.u.s.S.config No Client EndPointIdentificationAlgorithm configured for Client@73a2d91[provider=null,keyStore=null,trustStore=null]
   [junit4]   2> 371781 WARN  (jetty-launcher-4244-thread-1) [     ] o.e.j.u.s.S.config Trusting all certificates configured for Client@5bbdf86[provider=null,keyStore=null,trustStore=null]
   [junit4]   2> 371781 WARN  (jetty-launcher-4244-thread-1) [     ] o.e.j.u.s.S.config No Client EndPointIdentificationAlgorithm configured for Client@5bbdf86[provider=null,keyStore=null,trustStore=null]
   [junit4]   2> 371782 INFO  (jetty-launcher-4244-thread-1) [     ] o.a.s.c.ZkContainer Zookeeper client=127.0.0.1:32911/solr
   [junit4]   2> 371782 INFO  (jetty-launcher-4244-thread-1) [     ] o.a.s.c.c.ConnectionManager Waiting for client to connect to ZooKeeper
   [junit4]   2> 371783 INFO  (zkConnectionManagerCallback-4256-thread-1) [     ] o.a.s.c.c.ConnectionManager zkClient has connected
   [junit4]   2> 371783 INFO  (jetty-launcher-4244-thread-1) [     ] o.a.s.c.c.ConnectionManager Client is connected to ZooKeeper
   [junit4]   2> 371885 INFO  (jetty-launcher-4244-thread-1) [n:127.0.0.1:38585_solr     ] o.a.s.c.c.ConnectionManager Waiting for client to connect to ZooKeeper
   [junit4]   2> 371886 INFO  (zkConnectionManagerCallback-4258-thread-1) [     ] o.a.s.c.c.ConnectionManager zkClient has connected
   [junit4]   2> 371886 INFO  (jetty-launcher-4244-thread-1) [n:127.0.0.1:38585_solr     ] o.a.s.c.c.ConnectionManager Client is connected to ZooKeeper
   [junit4]   2> 371928 INFO  (jetty-launcher-4244-thread-1) [n:127.0.0.1:38585_solr     ] o.a.s.c.OverseerElectionContext I am going to be the leader 127.0.0.1:38585_solr
   [junit4]   2> 371928 INFO  (jetty-launcher-4244-thread-1) [n:127.0.0.1:38585_solr     ] o.a.s.c.Overseer Overseer (id=72110040925732869-127.0.0.1:38585_solr-n_0000000000) starting
   [junit4]   2> 371930 INFO  (OverseerStateUpdate-72110040925732869-127.0.0.1:38585_solr-n_0000000000) [n:127.0.0.1:38585_solr     ] o.a.s.c.Overseer Starting to work on the main queue : 127.0.0.1:38585_solr
   [junit4]   2> 371930 INFO  (jetty-launcher-4244-thread-1) [n:127.0.0.1:38585_solr     ] o.a.s.c.ZkController Register node as live in ZooKeeper:/live_nodes/127.0.0.1:38585_solr
   [junit4]   2> 371930 DEBUG (OverseerAutoScalingTriggerThread-72110040925732869-127.0.0.1:38585_solr-n_0000000000) [     ] o.a.s.c.a.OverseerTriggerThread Adding .auto_add_replicas and .scheduled_maintenance triggers
   [junit4]   2> 371931 DEBUG (OverseerAutoScalingTriggerThread-72110040925732869-127.0.0.1:38585_solr-n_0000000000) [     ] o.a.s.c.a.OverseerTriggerThread Refreshing /autoscaling.json with znode version 1
   [junit4]   2> 371931 DEBUG (OverseerAutoScalingTriggerThread-72110040925732869-127.0.0.1:38585_solr-n_0000000000) [     ] o.a.s.c.a.OverseerTriggerThread Current znodeVersion 1, lastZnodeVersion 0
   [junit4]   2> 371931 DEBUG (OverseerAutoScalingTriggerThread-72110040925732869-127.0.0.1:38585_solr-n_0000000000) [     ] o.a.s.c.a.OverseerTriggerThread Processed trigger updates upto znodeVersion 1
   [junit4]   2> 371931 INFO  (jetty-launcher-4244-thread-1) [n:127.0.0.1:38585_solr     ] o.a.s.p.PackageLoader /packages.json updated to version -1
   [junit4]   2> 371932 INFO  (zkCallback-4257-thread-1) [     ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (1)
   [junit4]   2> 371932 WARN  (jetty-launcher-4244-thread-1) [n:127.0.0.1:38585_solr     ] o.a.s.c.CoreContainer Not all security plugins configured!  authentication=disabled authorization=disabled.  Solr is only as secure as you make it. Consider configuring authentication/authorization before exposing Solr to users internal or external.  See https://s.apache.org/solrsecurity for more info
   [junit4]   2> 371933 DEBUG (OverseerAutoScalingTriggerThread-72110040925732869-127.0.0.1:38585_solr-n_0000000000) [     ] o.a.s.c.a.NodeLostTrigger NodeLostTrigger .auto_add_replicas - Initial livenodes: [127.0.0.1:38585_solr]
   [junit4]   2> 371933 DEBUG (ScheduledTrigger-4263-thread-1) [     ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 1 and last live nodes: 1
   [junit4]   2> 371936 DEBUG (OverseerAutoScalingTriggerThread-72110040925732869-127.0.0.1:38585_solr-n_0000000000) [     ] o.a.s.c.a.OverseerTriggerThread -- deactivating old nodeLost / nodeAdded markers
   [junit4]   2> 371936 DEBUG (OverseerAutoScalingTriggerThread-72110040925732869-127.0.0.1:38585_solr-n_0000000000) [     ] o.a.s.c.a.OverseerTriggerThread Current znodeVersion 1, lastZnodeVersion 1
   [junit4]   2> 371942 INFO  (jetty-launcher-4244-thread-1) [n:127.0.0.1:38585_solr     ] o.a.s.h.a.MetricsHistoryHandler No .system collection, keeping metrics history in memory.
   [junit4]   2> 371955 INFO  (jetty-launcher-4244-thread-1) [n:127.0.0.1:38585_solr     ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_38585.solr.node' (registry 'solr.node') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@1dfb013
   [junit4]   2> 371960 INFO  (jetty-launcher-4244-thread-1) [n:127.0.0.1:38585_solr     ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_38585.solr.jvm' (registry 'solr.jvm') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@1dfb013
   [junit4]   2> 371960 INFO  (jetty-launcher-4244-thread-1) [n:127.0.0.1:38585_solr     ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_38585.solr.jetty' (registry 'solr.jetty') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@1dfb013
   [junit4]   2> 371961 INFO  (jetty-launcher-4244-thread-1) [n:127.0.0.1:38585_solr     ] o.a.s.c.CorePropertiesLocator Found 0 core definitions underneath /home/jenkins/workspace/Lucene-Solr-8.x-Linux/solr/build/solr-core/test/J4/temp/solr.cloud.autoscaling.ComputePlanActionTest_D6BE127202370C75-001/tempDir-001/node1
   [junit4]   2> 371967 INFO  (SUITE-ComputePlanActionTest-seed#[D6BE127202370C75]-worker) [     ] o.a.s.c.MiniSolrCloudCluster waitForAllNodes: numServers=1
   [junit4]   2> 371968 INFO  (SUITE-ComputePlanActionTest-seed#[D6BE127202370C75]-worker) [     ] o.a.s.c.c.ConnectionManager Waiting for client to connect to ZooKeeper
   [junit4]   2> 371969 INFO  (zkConnectionManagerCallback-4275-thread-1) [     ] o.a.s.c.c.ConnectionManager zkClient has connected
   [junit4]   2> 371969 INFO  (SUITE-ComputePlanActionTest-seed#[D6BE127202370C75]-worker) [     ] o.a.s.c.c.ConnectionManager Client is connected to ZooKeeper
   [junit4]   2> 371969 INFO  (SUITE-ComputePlanActionTest-seed#[D6BE127202370C75]-worker) [     ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (1)
   [junit4]   2> 371970 INFO  (SUITE-ComputePlanActionTest-seed#[D6BE127202370C75]-worker) [     ] o.a.s.c.s.i.ZkClientClusterStateProvider Cluster at 127.0.0.1:32911/solr ready
   [junit4]   2> 371985 INFO  (TEST-ComputePlanActionTest.testNodeAdded-seed#[D6BE127202370C75]) [     ] o.a.s.SolrTestCaseJ4 ###Starting testNodeAdded
   [junit4]   2> 371985 DEBUG (zkCallback-4257-thread-1) [     ] o.a.s.c.a.OverseerTriggerThread Refreshing /autoscaling.json with znode version 2
   [junit4]   2> 371985 DEBUG (OverseerAutoScalingTriggerThread-72110040925732869-127.0.0.1:38585_solr-n_0000000000) [     ] o.a.s.c.a.OverseerTriggerThread Processed trigger updates upto znodeVersion 2
   [junit4]   2> 371986 INFO  (TEST-ComputePlanActionTest.testNodeAdded-seed#[D6BE127202370C75]) [     ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (1)
   [junit4]   2> 371987 DEBUG (OverseerAutoScalingTriggerThread-72110040925732869-127.0.0.1:38585_solr-n_0000000000) [     ] o.a.s.c.a.OverseerTriggerThread -- deactivating old nodeLost / nodeAdded markers
   [junit4]   2> 371987 DEBUG (OverseerAutoScalingTriggerThread-72110040925732869-127.0.0.1:38585_solr-n_0000000000) [     ] o.a.s.c.a.OverseerTriggerThread Current znodeVersion 2, lastZnodeVersion 2
   [junit4]   2> 372005 INFO  (qtp2062746144-9913) [n:127.0.0.1:38585_solr     ] o.a.s.c.TransientSolrCoreCacheDefault Allocating transient cache for 2147483647 transient cores
   [junit4]   2> 372005 INFO  (qtp2062746144-9913) [n:127.0.0.1:38585_solr     ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/metrics params={prefix=CONTAINER.fs.usableSpace,CONTAINER.cores&wt=javabin&version=2&group=solr.node} status=0 QTime=0
   [junit4]   2> 372005 DEBUG (qtp2062746144-9911) [n:127.0.0.1:38585_solr     ] o.a.s.c.a.AutoScalingHandler Verified autoscaling configuration
   [junit4]   2> 372006 INFO  (qtp2062746144-9911) [n:127.0.0.1:38585_solr     ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/autoscaling params={wt=javabin&version=2} status=0 QTime=8
   [junit4]   2> 372006 DEBUG (zkCallback-4257-thread-2) [     ] o.a.s.c.a.OverseerTriggerThread Refreshing /autoscaling.json with znode version 3
   [junit4]   2> 372006 DEBUG (OverseerAutoScalingTriggerThread-72110040925732869-127.0.0.1:38585_solr-n_0000000000) [     ] o.a.s.c.a.OverseerTriggerThread Processed trigger updates upto znodeVersion 3
   [junit4]   2> 372006 DEBUG (OverseerAutoScalingTriggerThread-72110040925732869-127.0.0.1:38585_solr-n_0000000000) [     ] o.a.s.c.a.OverseerTriggerThread -- deactivating old nodeLost / nodeAdded markers
   [junit4]   2> 372006 DEBUG (OverseerAutoScalingTriggerThread-72110040925732869-127.0.0.1:38585_solr-n_0000000000) [     ] o.a.s.c.a.OverseerTriggerThread Current znodeVersion 3, lastZnodeVersion 3
   [junit4]   2> 372009 INFO  (qtp2062746144-9913) [n:127.0.0.1:38585_solr     ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/metrics params={prefix=CONTAINER.fs.usableSpace,CONTAINER.cores&wt=javabin&version=2&group=solr.node} status=0 QTime=0
   [junit4]   2> 372009 DEBUG (qtp2062746144-9914) [n:127.0.0.1:38585_solr     ] o.a.s.c.a.AutoScalingHandler Verified autoscaling configuration
   [junit4]   2> 372009 INFO  (qtp2062746144-9914) [n:127.0.0.1:38585_solr     ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/autoscaling params={wt=javabin&version=2} status=0 QTime=2
   [junit4]   2> 372009 DEBUG (zkCallback-4257-thread-2) [     ] o.a.s.c.a.OverseerTriggerThread Refreshing /autoscaling.json with znode version 4
   [junit4]   2> 372009 DEBUG (OverseerAutoScalingTriggerThread-72110040925732869-127.0.0.1:38585_solr-n_0000000000) [     ] o.a.s.c.a.OverseerTriggerThread Processed trigger updates upto znodeVersion 4
   [junit4]   2> 372009 DEBUG (OverseerAutoScalingTriggerThread-72110040925732869-127.0.0.1:38585_solr-n_0000000000) [     ] o.a.s.c.a.OverseerTriggerThread -- deactivating old nodeLost / nodeAdded markers
   [junit4]   2> 372009 DEBUG (OverseerAutoScalingTriggerThread-72110040925732869-127.0.0.1:38585_solr-n_0000000000) [     ] o.a.s.c.a.OverseerTriggerThread Current znodeVersion 4, lastZnodeVersion 4
   [junit4]   2> 372015 INFO  (qtp2062746144-9913) [n:127.0.0.1:38585_solr     ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/metrics params={prefix=CONTAINER.fs.usableSpace,CONTAINER.fs.totalSpace,CONTAINER.cores&wt=javabin&version=2&group=solr.node} status=0 QTime=0
   [junit4]   2> 372015 DEBUG (qtp2062746144-9911) [n:127.0.0.1:38585_solr     ] o.a.s.c.a.AutoScalingHandler Verified autoscaling configuration
   [junit4]   2> 372015 INFO  (qtp2062746144-9911) [n:127.0.0.1:38585_solr     ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/cluster/autoscaling params={wt=javabin&version=2} status=0 QTime=3
   [junit4]   2> 372015 DEBUG (zkCallback-4257-thread-2) [     ] o.a.s.c.a.OverseerTriggerThread Refreshing /autoscaling.json with znode version 5
   [junit4]   2> 372016 DEBUG (OverseerAutoScalingTriggerThread-72110040925732869-127.0.0.1:38585_solr-n_0000000000) [     ] o.a.s.c.a.OverseerTriggerThread Processed trigger updates upto znodeVersion 5
   [junit4]   2> 372017 DEBUG (OverseerAutoScalingTriggerThread-72110040925732869-127.0.0.1:38585_solr-n_0000000000) [     ] o.a.s.c.a.NodeAddedTrigger NodeAddedTrigger node_added_trigger - Initial livenodes: [127.0.0.1:38585_solr]
   [junit4]   2> 372017 DEBUG (OverseerAutoScalingTriggerThread-72110040925732869-127.0.0.1:38585_solr-n_0000000000) [     ] 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.ComputePlanActionTest$AssertingTriggerAction}], enabled=true}
   [junit4]   2> 372017 DEBUG (OverseerAutoScalingTriggerThread-72110040925732869-127.0.0.1:38585_solr-n_0000000000) [     ] o.a.s.c.a.OverseerTriggerThread -- deactivating old nodeLost / nodeAdded markers
   [junit4]   2> 372017 INFO  (qtp2062746144-9913) [n:127.0.0.1:38585_solr     ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/metrics params={prefix=CONTAINER.fs.usableSpace,CONTAINER.cores&wt=javabin&version=2&group=solr.node} status=0 QTime=0
   [junit4]   2> 372017 DEBUG (OverseerAutoScalingTriggerThread-72110040925732869-127.0.0.1:38585_solr-n_0000000000) [     ] o.a.s.c.a.OverseerTriggerThread Current znodeVersion 5, lastZnodeVersion 5
   [junit4]   2> 372018 DEBUG (ScheduledTrigger-4263-thread-2) [     ] o.a.s.c.a.NodeAddedTrigger Running NodeAddedTrigger node_added_trigger
   [junit4]   2> 372018 DEBUG (ScheduledTrigger-4263-thread-2) [     ] o.a.s.c.a.NodeAddedTrigger Found livenodes: 1
   [junit4]   2> 372018 DEBUG (qtp2062746144-9914) [n:127.0.0.1:38585_solr     ] o.a.s.c.a.AutoScalingHandler Verified autoscaling configuration
   [junit4]   2> 372018 INFO  (qtp2062746144-9914) [n:127.0.0.1:38585_solr     ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/cluster/autoscaling params={wt=javabin&version=2} status=0 QTime=2
   [junit4]   2> 372018 DEBUG (zkCallback-4257-thread-2) [     ] o.a.s.c.a.OverseerTriggerThread Refreshing /autoscaling.json with znode version 6
   [junit4]   2> 372019 DEBUG (OverseerAutoScalingTriggerThread-72110040925732869-127.0.0.1:38585_solr-n_0000000000) [     ] o.a.s.c.a.OverseerTriggerThread Processed trigger updates upto znodeVersion 6
   [junit4]   2> 372019 DEBUG (OverseerAutoScalingTriggerThread-72110040925732869-127.0.0.1:38585_solr-n_0000000000) [     ] o.a.s.c.a.OverseerTriggerThread -- deactivating old nodeLost / nodeAdded markers
   [junit4]   2> 372019 DEBUG (OverseerAutoScalingTriggerThread-72110040925732869-127.0.0.1:38585_solr-n_0000000000) [     ] o.a.s.c.a.OverseerTriggerThread Current znodeVersion 6, lastZnodeVersion 6
   [junit4]   2> 372019 INFO  (qtp2062746144-9911) [n:127.0.0.1:38585_solr     ] o.a.s.h.a.CollectionsHandler Invoked Collection Action :create with params collection.configName=conf&maxShardsPerNode=2&name=testNodeAdded&nrtReplicas=2&action=CREATE&numShards=1&wt=javabin&version=2 and sendToOCPQueue=true
   [junit4]   2> 372024 INFO  (OverseerThreadFactory-4265-thread-1-processing-n:127.0.0.1:38585_solr) [n:127.0.0.1:38585_solr     ] o.a.s.c.a.c.CreateCollectionCmd Create collection testNodeAdded
   [junit4]   2> 372025 DEBUG (OverseerStateUpdate-72110040925732869-127.0.0.1:38585_solr-n_0000000000) [n:127.0.0.1:38585_solr     ] o.a.s.c.Overseer processMessage: queueSize: 1, message = {
   [junit4]   2>   "name":"testNodeAdded",
   [junit4]   2>   "fromApi":"true",
   [junit4]   2>   "collection.configName":"conf",
   [junit4]   2>   "numShards":"1",
   [junit4]   2>   "maxShardsPerNode":"2",
   [junit4]   2>   "nrtReplicas":"2",
   [junit4]   2>   "stateFormat":"2",
   [junit4]   2>   "replicationFactor":"2",
   [junit4]   2>   "operation":"create"} current state version: 0
   [junit4]   2> 372025 DEBUG (OverseerStateUpdate-72110040925732869-127.0.0.1:38585_solr-n_0000000000) [n:127.0.0.1:38585_solr     ] o.a.s.c.o.ClusterStateMutator building a new cName: testNodeAdded
   [junit4]   2> 372025 DEBUG (OverseerStateUpdate-72110040925732869-127.0.0.1:38585_solr-n_0000000000) [n:127.0.0.1:38585_solr     ] o.a.s.c.o.ZkStateWriter going to create_collection /collections/testNodeAdded/state.json
   [junit4]   2> 372125 WARN  (OverseerThreadFactory-4265-thread-1-processing-n:127.0.0.1:38585_solr) [n:127.0.0.1:38585_solr     ] o.a.s.c.a.c.CreateCollectionCmd Specified number of replicas of 2 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> 372127 INFO  (qtp2062746144-9913) [n:127.0.0.1:38585_solr     ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/metrics params={prefix=CONTAINER.fs.usableSpace,CONTAINER.fs.totalSpace,CONTAINER.cores&wt=javabin&version=2&group=solr.node} status=0 QTime=0
   [junit4]   2> 372130 DEBUG (OverseerStateUpdate-72110040925732869-127.0.0.1:38585_solr-n_0000000000) [n:127.0.0.1:38585_solr     ] o.a.s.c.Overseer processMessage: queueSize: 1, message = {
   [junit4]   2>   "operation":"ADDREPLICA",
   [junit4]   2>   "collection":"testNodeAdded",
   [junit4]   2>   "shard":"shard1",
   [junit4]   2>   "core":"testNodeAdded_shard1_replica_n1",
   [junit4]   2>   "state":"down",
   [junit4]   2>   "base_url":"https://127.0.0.1:38585/solr",
   [junit4]   2>   "node_name":"127.0.0.1:38585_solr",
   [junit4]   2>   "type":"NRT",
   [junit4]   2>   "waitForFinalState":"false"} current state version: 0
   [junit4]   2> 372130 INFO  (OverseerStateUpdate-72110040925732869-127.0.0.1:38585_solr-n_0000000000) [n:127.0.0.1:38585_solr     ] o.a.s.c.o.SliceMutator createReplica() {
   [junit4]   2>   "operation":"ADDREPLICA",
   [junit4]   2>   "collection":"testNodeAdded",
   [junit4]   2>   "shard":"shard1",
   [junit4]   2>   "core":"testNodeAdded_shard1_replica_n1",
   [junit4]   2>   "state":"down",
   [junit4]   2>   "base_url":"https://127.0.0.1:38585/solr",
   [junit4]   2>   "node_name":"127.0.0.1:38585_solr",
   [junit4]   2>   "type":"NRT",
   [junit4]   2>   "waitForFinalState":"false"} 
   [junit4]   2> 372130 DEBUG (OverseerStateUpdate-72110040925732869-127.0.0.1:38585_solr-n_0000000000) [n:127.0.0.1:38585_solr     ] o.a.s.c.o.SliceMutator Old Slice: shard1:{
   [junit4]   2>   "range":"80000000-7fffffff",
   [junit4]   2>   "state":"active",
   [junit4]   2>   "replicas":{}}
   [junit4]   2> 372130 DEBUG (OverseerStateUpdate-72110040925732869-127.0.0.1:38585_solr-n_0000000000) [n:127.0.0.1:38585_solr     ] o.a.s.c.o.SliceMutator New Slice: shard1:{
   [junit4]   2>   "range":"80000000-7fffffff",
   [junit4]   2>   "state":"active",
   [junit4]   2>   "replicas":{"core_node3":{
   [junit4]   2>       "core":"testNodeAdded_shard1_replica_n1",
   [junit4]   2>       "base_url":"https://127.0.0.1:38585/solr",
   [junit4]   2>       "state":"down",
   [junit4]   2>       "node_name":"127.0.0.1:38585_solr",
   [junit4]   2>       "type":"NRT"}}}
   [junit4]   2> 372130 DEBUG (OverseerStateUpdate-72110040925732869-127.0.0.1:38585_solr-n_0000000000) [n:127.0.0.1:38585_solr     ] o.a.s.c.Overseer processMessage: queueSize: 2, message = {
   [junit4]   2>   "operation":"ADDREPLICA",
   [junit4]   2>   "collection":"testNodeAdded",
   [junit4]   2>   "shard":"shard1",
   [junit4]   2>   "core":"testNodeAdded_shard1_replica_n2",
   [junit4]   2>   "state":"down",
   [junit4]   2>   "base_url":"https://127.0.0.1:38585/solr",
   [junit4]   2>   "node_name":"127.0.0.1:38585_solr",
   [junit4]   2>   "type":"NRT",
   [junit4]   2>   "waitForFinalState":"false"} current state version: 0
   [junit4]   2> 372130 INFO  (OverseerStateUpdate-72110040925732869-127.0.0.1:38585_solr-n_0000000000) [n:127.0.0.1:38585_solr     ] o.a.s.c.o.SliceMutator createReplica() {
   [junit4]   2>   "operation":"ADDREPLICA",
   [junit4]   2>   "collection":"testNodeAdded",
   [junit4]   2>   "shard":"shard1",
   [junit4]   2>   "core":"testNodeAdded_shard1_replica_n2",
   [junit4]   2>   "state":"down",
   [junit4]   2>   "base_url":"https://127.0.0.1:38585/solr",
   [junit4]   2>   "node_name":"127.0.0.1:38585_solr",
   [junit4]   2>   "type":"NRT",
   [junit4]   2>   "waitForFinalState":"false"} 
   [junit4]   2> 372131 DEBUG (OverseerStateUpdate-72110040925732869-127.0.0.1:38585_solr-n_0000000000) [n:127.0.0.1:38585_solr     ] o.a.s.c.o.SliceMutator Old Slice: shard1:{
   [junit4]   2>   "range":"80000000-7fffffff",
   [junit4]   2>   "state":"active",
   [junit4]   2>   "replicas":{"core_node3":{
   [junit4]   2>       "core":"testNodeAdded_shard1_replica_n1",
   [junit4]   2>       "base_url":"https://127.0.0.1:38585/solr",
   [junit4]   2>       "state":"down",
   [junit4]   2>       "node_name":"127.0.0.1:38585_solr",
   [junit4]   2>       "type":"NRT"}}}
   [junit4]   2> 372131 DEBUG (OverseerStateUpdate-72110040925732869-127.0.0.1:38585_solr-n_0000000000) [n:127.0.0.1:38585_solr     ] o.a.s.c.o.SliceMutator New Slice: shard1:{
   [junit4]   2>   "range":"80000000-7fffffff",
   [junit4]   2>   "state":"active",
   [junit4]   2>   "replicas":{
   [junit4]   2>     "core_node3":{
   [junit4]   2>       "core":"testNodeAdded_shard1_replica_n1",
   [junit4]   2>       "base_url":"https://127.0.0.1:38585/solr",
   [junit4]   2>       "state":"down",
   [junit4]   2>       "node_name":"127.0.0.1:38585_solr",
   [junit4]   2>       "type":"NRT"},
   [junit4]   2>     "core_node4":{
   [junit4]   2>       "core":"testNodeAdded_shard1_replica_n2",
   [junit4]   2>       "base_url":"https://127.0.0.1:38585/solr",
   [junit4]   2>       "state":"down",
   [junit4]   2>       "node_name":"127.0.0.1:38585_solr",
   [junit4]   2>       "type":"NRT"}}}
   [junit4]   2> 372231 DEBUG (OverseerStateUpdate-72110040925732869-127.0.0.1:38585_solr-n_0000000000) [n:127.0.0.1:38585_solr     ] o.a.s.c.o.ZkStateWriter going to update_collection /collections/testNodeAdded/state.json version: 0
   [junit4]   2> 372344 INFO  (qtp2062746144-9914) [n:127.0.0.1:38585_solr    x:testNodeAdded_shard1_replica_n2 ] o.a.s.h.a.CoreAdminOperation core create command qt=/admin/cores&coreNodeName=core_node4&collection.configName=conf&newCollection=true&name=testNodeAdded_shard1_replica_n2&action=CREATE&numShards=1&collection=testNodeAdded&shard=shard1&wt=javabin&version=2&replicaType=NRT
   [junit4]   2> 372344 INFO  (qtp2062746144-9913) [n:127.0.0.1:38585_solr    x:testNodeAdded_shard1_replica_n1 ] o.a.s.h.a.CoreAdminOperation core create command qt=/admin/cores&coreNodeName=core_node3&collection.configName=conf&newCollection=true&name=testNodeAdded_shard1_replica_n1&action=CREATE&numShards=1&collection=testNodeAdded&shard=shard1&wt=javabin&version=2&replicaType=NRT
   [junit4]   2> 372346 DEBUG (OverseerStateUpdate-72110040925732869-127.0.0.1:38585_solr-n_0000000000) [n:127.0.0.1:38585_solr     ] o.a.s.c.Overseer processMessage: queueSize: 1, message = {
   [junit4]   2>   "core":"testNodeAdded_shard1_replica_n1",
   [junit4]   2>   "core_node_name":"core_node3",
   [junit4]   2>   "roles":null,
   [junit4]   2>   "base_url":"https://127.0.0.1:38585/solr",
   [junit4]   2>   "node_name":"127.0.0.1:38585_solr",
   [junit4]   2>   "numShards":"1",
   [junit4]   2>   "state":"down",
   [junit4]   2>   "shard":"shard1",
   [junit4]   2>   "collection":"testNodeAdded",
   [junit4]   2>   "type":"NRT",
   [junit4]   2>   "force_set_state":"false",
   [junit4]   2>   "operation":"state"} current state version: 0
   [junit4]   2> 372346 DEBUG (OverseerStateUpdate-72110040925732869-127.0.0.1:38585_solr-n_0000000000) [n:127.0.0.1:38585_solr     ] o.a.s.c.o.ReplicaMutator Update state numShards=1 message={
   [junit4]   2>   "core":"testNodeAdded_shard1_replica_n1",
   [junit4]   2>   "core_node_name":"core_node3",
   [junit4]   2>   "roles":null,
   [junit4]   2>   "base_url":"https://127.0.0.1:38585/solr",
   [junit4]   2>   "node_name":"127.0.0.1:38585_solr",
   [junit4]   2>   "numShards":"1",
   [junit4]   2>   "state":"down",
   [junit4]   2>   "shard":"shard1",
   [junit4]   2>   "collection":"testNodeAdded",
   [junit4]   2>   "type":"NRT",
   [junit4]   2>   "force_set_state":"false",
   [junit4]   2>   "operation":"state"}
   [junit4]   2> 372346 DEBUG (OverseerStateUpdate-72110040925732869-127.0.0.1:38585_solr-n_0000000000) [n:127.0.0.1:38585_solr     ] o.a.s.c.o.ReplicaMutator Will update state for replica: core_node3:{
   [junit4]   2>   "core":"testNodeAdded_shard1_replica_n1",
   [junit4]   2>   "base_url":"https://127.0.0.1:38585/solr",
   [junit4]   2>   "node_name":"127.0.0.1:38585_solr",
   [junit4]   2>   "state":"down",
   [junit4]   2>   "type":"NRT",
   [junit4]   2>   "force_set_state":"false"}
   [junit4]   2> 372346 DEBUG (OverseerStateUpdate-72110040925732869-127.0.0.1:38585_solr-n_0000000000) [n:127.0.0.1:38585_solr     ] o.a.s.c.o.ReplicaMutator Collection is now: DocCollection(testNodeAdded//collections/testNodeAdded/state.json/1)={
   [junit4]   2>   "pullReplicas":"0",
   [junit4]   2>   "replicationFactor":"2",
   [junit4]   2>   "router":{"name":"compositeId"},
   [junit4]   2>   "maxShardsPerNode":"2",
   [junit4]   2>   "autoAddReplicas":"false",
   [junit4]   2>   "nrtReplicas":"2",
   [junit4]   2>   "tlogReplicas":"0",
   [junit4]   2>   "shards":{"shard1":{
   [junit4]   2>       "range":"80000000-7fffffff",
   [junit4]   2>       "state":"active",
   [junit4]   2>       "replicas":{
   [junit4]   2>         "core_node3":{
   [junit4]   2>           "core":"testNodeAdded_shard1_replica_n1",
   [junit4]   2>           "base_url":"https://127.0.0.1:38585/solr",
   [junit4]   2>           "node_name":"127.0.0.1:38585_solr",
   [junit4]   2>           "state":"down",
   [junit4]   2>           "type":"NRT",
   [junit4]   2>           "force_set_state":"false"},
   [junit4]   2>         "core_node4":{
   [junit4]   2>           "core":"testNodeAdded_shard1_replica_n2",
   [junit4]   2>           "base_url":"https://127.0.0.1:38585/solr",
   [junit4]   2>           "state":"down",
   [junit4]   2>           "node_name":"127.0.0.1:38585_solr",
   [junit4]   2>           "type":"NRT"}}}}}
   [junit4]   2> 372348 DEBUG (OverseerStateUpdate-72110040925732869-127.0.0.1:38585_solr-n_0000000000) [n:127.0.0.1:38585_solr     ] o.a.s.c.Overseer processMessage: queueSize: 2, message = {
   [junit4]   2>   "core":"testNodeAdded_shard1_replica_n2",
   [junit4]   2>   "core_node_name":"core_node4",
   [junit4]   2>   "roles":null,
   [junit4]   2>   "base_url":"https://127.0.0.1:38585/solr",
   [junit4]   2>   "node_name":"127.0.0.1:38585_solr",
   [junit4]   2>   "numShards":"1",
   [junit4]   2>   "state":"down",
   [junit4]   2>   "shard":"shard1",
   [junit4]   2>   "collection":"testNodeAdded",
   [junit4]   2>   "type":"NRT",
   [junit4]   2>   "force_set_state":"false",
   [junit4]   2>   "operation":"state"} current state version: 0
   [junit4]   2> 372348 DEBUG (OverseerStateUpdate-72110040925732869-127.0.0.1:38585_solr-n_0000000000) [n:127.0.0.1:38585_solr     ] o.a.s.c.o.ReplicaMutator Update state numShards=1 message={
   [junit4]   2>   "core":"testNodeAdded_shard1_replica_n2",
   [junit4]   2>   "core_node_name":"core_node4",
   [junit4]   2>   "roles":null,
   [junit4]   2>   "base_url":"https://127.0.0.1:38585/solr",
   [junit4]   2>   "node_name":"127.0.0.1:38585_solr",
   [junit4]   2>   "numShards":"1",
   [junit4]   2>   "state":"down",
   [junit4]   2>   "shard":"shard1",
   [junit4]   2>   "collection":"testNodeAdded",
   [junit4]   2>   "type":"NRT",
   [junit4]   2>   "force_set_state":"false",
   [junit4]   2>   "operation":"state"}
   [junit4]   2> 372348 DEBUG (OverseerStateUpdate-72110040925732869-127.0.0.1:38585_solr-n_0000000000) [n:127.0.0.1:38585_solr     ] o.a.s.c.o.ReplicaMutator Will update state for replica: core_node4:{
   [junit4]   2>   "core":"testNodeAdded_shard1_replica_n2",
   [junit4]   2>   "base_url":"https://127.0.0.1:38585/solr",
   [junit4]   2>   "node_name":"127.0.0.1:38585_solr",
   [junit4]   2>   "state":"down",
   [junit4]   2>   "type":"NRT",
   [junit4]   2>   "force_set_state":"false"}
   [junit4]   2> 372348 INFO  (qtp2062746144-9913) [n:127.0.0.1:38585_solr c:testNodeAdded s:shard1 r:core_node3 x:testNodeAdded_shard1_replica_n1 ] o.a.s.c.SolrConfig Using Lucene MatchVersion: 8.7.0
   [junit4]   2> 372348 DEBUG (OverseerStateUpdate-72110040925732869-127.0.0.1:38585_solr-n_0000000000) [n:127.0.0.1:38585_solr     ] o.a.s.c.o.ReplicaMutator Collection is now: DocCollection(testNodeAdded//collections/testNodeAdded/state.json/1)={
   [junit4]   2>   "pullReplicas":"0",
   [junit4]   2>   "replicationFactor":"2",
   [junit4]   2>   "router":{"name":"compositeId"},
   [junit4]   2>   "maxShardsPerNode":"2",
   [junit4]   2>   "autoAddReplicas":"false",
   [junit4]   2>   "nrtReplicas":"2",
   [junit4]   2>   "tlogReplicas":"0",
   [junit4]   2>   "shards":{"shard1":{
   [junit4]   2>       "range":"80000000-7fffffff",
   [junit4]   2>       "state":"active",
   [junit4]   2>       "replicas":{
   [junit4]   2>         "core_node3":{
   [junit4]   2>           "core":"testNodeAdded_shard1_replica_n1",
   [junit4]   2>           "base_url":"https://127.0.0.1:38585/solr",
   [junit4]   2>           "node_name":"127.0.0.1:38585_solr",
   [junit4]   2>           "state":"down",
   [junit4]   2>           "type":"NRT",
   [junit4]   2>           "force_set_state":"false"},
   [junit4]   2>         "core_node4":{
   [junit4]   2>           "core":"testNodeAdded_shard1_replica_n2",
   [junit4]   2>           "base_url":"https://127.0.0.1:38585/solr",
   [junit4]   2>           "node_name":"127.0.0.1:38585_solr",
   [junit4]   2>           "state":"down",
   [junit4]   2>           "type":"NRT",
   [junit4]   2>           "force_set_state":"false"}}}}}
   [junit4]   2> 372351 INFO  (qtp2062746144-9914) [n:127.0.0.1:38585_solr c:testNodeAdded s:shard1 r:core_node4 x:testNodeAdded_shard1_replica_n2 ] o.a.s.c.SolrConfig Using Lucene MatchVersion: 8.7.0
   [junit4]   2> 372351 INFO  (qtp2062746144-9913) [n:127.0.0.1:38585_solr c:testNodeAdded s:shard1 r:core_node3 x:testNodeAdded_shard1_replica_n1 ] o.a.s.c.CoreContainer Creating SolrCore 'testNodeAdded_shard1_replica_n1' using configuration from configset conf, trusted=true
   [junit4]   2> 372353 INFO  (qtp2062746144-9913) [n:127.0.0.1:38585_solr c:testNodeAdded s:shard1 r:core_node3 x:testNodeAdded_shard1_replica_n1 ] o.a.s.s.IndexSchema Schema name=minimal
   [junit4]   2> 372354 INFO  (qtp2062746144-9914) [n:127.0.0.1:38585_solr c:testNodeAdded s:shard1 r:core_node4 x:testNodeAdded_shard1_replica_n2 ] o.a.s.c.CoreContainer Creating SolrCore 'testNodeAdded_shard1_replica_n2' using configuration from configset conf, trusted=true
   [junit4]   2> 372355 INFO  (qtp2062746144-9913) [n:127.0.0.1:38585_solr c:testNodeAdded s:shard1 r:core_node3 x:testNodeAdded_shard1_replica_n1 ] o.a.s.s.IndexSchema Loaded schema minimal/1.1 with uniqueid field id
   [junit4]   2> 372355 INFO  (qtp2062746144-9913) [n:127.0.0.1:38585_solr c:testNodeAdded s:shard1 r:core_node3 x:testNodeAdded_shard1_replica_n1 ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_38585.solr.core.testNodeAdded.shard1.replica_n1' (registry 'solr.core.testNodeAdded.shard1.replica_n1') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@1dfb013
   [junit4]   2> 372355 INFO  (qtp2062746144-9913) [n:127.0.0.1:38585_solr c:testNodeAdded s:shard1 r:core_node3 x:testNodeAdded_shard1_replica_n1 ] o.a.s.c.SolrCore [[testNodeAdded_shard1_replica_n1] ] Opening new SolrCore at [/home/jenkins/workspace/Lucene-Solr-8.x-Linux/solr/build/solr-core/test/J4/temp/solr.cloud.autoscaling.ComputePlanActionTest_D6BE127202370C75-001/tempDir-001/node1/testNodeAdded_shard1_replica_n1], dataDir=[/home/jenkins/workspace/Lucene-Solr-8.x-Linux/solr/build/solr-core/test/J4/temp/solr.cloud.autoscaling.ComputePlanActionTest_D6BE127202370C75-001/tempDir-001/node1/testNodeAdded_shard1_replica_n1/data/]
   [junit4]   2> 372356 INFO  (qtp2062746144-9914) [n:127.0.0.1:38585_solr c:testNodeAdded s:shard1 r:core_node4 x:testNodeAdded_shard1_replica_n2 ] o.a.s.s.IndexSchema Schema name=minimal
   [junit4]   2> 372357 INFO  (qtp2062746144-9914) [n:127.0.0.1:38585_solr c:testNodeAdded s:shard1 r:core_node4 x:testNodeAdded_shard1_replica_n2 ] o.a.s.s.IndexSchema Loaded schema minimal/1.1 with uniqueid field id
   [junit4]   2> 372357 INFO  (qtp2062746144-9914) [n:127.0.0.1:38585_solr c:testNodeAdded s:shard1 r:core_node4 x:testNodeAdded_shard1_replica_n2 ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_38585.solr.core.testNodeAdded.shard1.replica_n2' (registry 'solr.core.testNodeAdded.shard1.replica_n2') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@1dfb013
   [junit4]   2> 372357 INFO  (qtp2062746144-9914) [n:127.0.0.1:38585_solr c:testNodeAdded s:shard1 r:core_node4 x:testNodeAdded_shard1_replica_n2 ] o.a.s.c.SolrCore [[testNodeAdded_shard1_replica_n2] ] Opening new SolrCore at [/home/jenkins/workspace/Lucene-Solr-8.x-Linux/solr/build/solr-core/test/J4/temp/solr.cloud.autoscaling.ComputePlanActionTest_D6BE127202370C75-001/tempDir-001/node1/testNodeAdded_shard1_replica_n2], dataDir=[/home/jenkins/workspace/Lucene-Solr-8.x-Linux/solr/build/solr-core/test/J4/temp/solr.cloud.autoscaling.ComputePlanActionTest_D6BE127202370C75-001/tempDir-001/node1/testNodeAdded_shard1_replica_n2/data/]
   [junit4]   2> 372391 INFO  (qtp2062746144-9913) [n:127.0.0.1:38585_solr c:testNodeAdded s:shard1 r:core_node3 x:testNodeAdded_shard1_replica_n1 ] o.a.s.u.UpdateHandler Using UpdateLog implementation: org.apache.solr.update.UpdateLog
   [junit4]   2> 372391 INFO  (qtp2062746144-9913) [n:127.0.0.1:38585_solr c:testNodeAdded s:shard1 r:core_node3 x:testNodeAdded_shard1_replica_n1 ] o.a.s.u.UpdateLog Initializing UpdateLog: dataDir=null defaultSyncLevel=FLUSH numRecordsToKeep=100 maxNumLogsToKeep=10 numVersionBuckets=65536
   [junit4]   2> 372392 INFO  (qtp2062746144-9913) [n:127.0.0.1:38585_solr c:testNodeAdded s:shard1 r:core_node3 x:testNodeAdded_shard1_replica_n1 ] o.a.s.u.CommitTracker Hard AutoCommit: disabled
   [junit4]   2> 372392 INFO  (qtp2062746144-9913) [n:127.0.0.1:38585_solr c:testNodeAdded s:shard1 r:core_node3 x:testNodeAdded_shard1_replica_n1 ] o.a.s.u.CommitTracker Soft AutoCommit: disabled
   [junit4]   2> 372395 INFO  (qtp2062746144-9913) [n:127.0.0.1:38585_solr c:testNodeAdded s:shard1 r:core_node3 x:testNodeAdded_shard1_replica_n1 ] o.a.s.r.ManagedResourceStorage Configured ZooKeeperStorageIO with znodeBase: /configs/conf
   [junit4]   2> 372395 INFO  (qtp2062746144-9913) [n:127.0.0.1:38585_solr c:testNodeAdded s:shard1 r:core_node3 x:testNodeAdded_shard1_replica_n1 ] o.a.s.r.ManagedResourceStorage Loaded null at path _rest_managed.json using ZooKeeperStorageIO:path=/configs/conf
   [junit4]   2> 372395 INFO  (qtp2062746144-9913) [n:127.0.0.1:38585_solr c:testNodeAdded s:shard1 r:core_node3 x:testNodeAdded_shard1_replica_n1 ] o.a.s.h.ReplicationHandler Commits will be reserved for 10000 ms
   [junit4]   2> 372395 INFO  (qtp2062746144-9913) [n:127.0.0.1:38585_solr c:testNodeAdded s:shard1 r:core_node3 x:testNodeAdded_shard1_replica_n1 ] o.a.s.u.UpdateLog Could not find max version in index or recent updates, using new clock 1677465414794215424
   [junit4]   2> 372397 INFO  (searcherExecutor-4279-thread-1-processing-n:127.0.0.1:38585_solr x:testNodeAdded_shard1_replica_n1 c:testNodeAdded s:shard1 r:core_node3) [n:127.0.0.1:38585_solr c:testNodeAdded s:shard1 r:core_node3 x:testNodeAdded_shard1_replica_n1 ] o.a.s.c.SolrCore [testNodeAdded_shard1_replica_n1]  Registered new searcher autowarm time: 0 ms
   [junit4]   2> 372398 INFO  (qtp2062746144-9913) [n:127.0.0.1:38585_solr c:testNodeAdded s:shard1 r:core_node3 x:testNodeAdded_shard1_replica_n1 ] o.a.s.c.ZkShardTerms Successful update of terms at /collections/testNodeAdded/terms/shard1 to Terms{values={core_node3=0}, version=0}
   [junit4]   2> 372398 INFO  (qtp2062746144-9913) [n:127.0.0.1:38585_solr c:testNodeAdded s:shard1 r:core_node3 x:testNodeAdded_shard1_replica_n1 ] o.a.s.c.ShardLeaderElectionContextBase make sure parent is created /collections/testNodeAdded/leaders/shard1
   [junit4]   2> 372399 INFO  (qtp2062746144-9913) [n:127.0.0.1:38585_solr c:testNodeAdded s:shard1 r:core_node3 x:testNodeAdded_shard1_replica_n1 ] o.a.s.c.ShardLeaderElectionContext Waiting until we see more replicas up for shard shard1: total=2 found=1 timeoute in=9999ms
   [junit4]   2> 372399 DEBUG (OverseerStateUpdate-72110040925732869-127.0.0.1:38585_solr-n_0000000000) [n:127.0.0.1:38585_solr     ] o.a.s.c.Overseer processMessage: queueSize: 3, message = {
   [junit4]   2>   "operation":"leader",
   [junit4]   2>   "shard":"shard1",
   [junit4]   2>   "collection":"testNodeAdded"} current state version: 0
   [junit4]   2> 372401 INFO  (qtp2062746144-9914) [n:127.0.0.1:38585_solr c:testNodeAdded s:shard1 r:core_node4 x:testNodeAdded_shard1_replica_n2 ] o.a.s.u.UpdateHandler Using UpdateLog implementation: org.apache.solr.update.UpdateLog
   [junit4]   2> 372401 INFO  (qtp2062746144-9914) [n:127.0.0.1:38585_solr c:testNodeAdded s:shard1 r:core_node4 x:testNodeAdded_shard1_replica_n2 ] o.a.s.u.UpdateLog Initializing UpdateLog: dataDir=null defaultSyncLevel=FLUSH numRecordsToKeep=100 maxNumLogsToKeep=10 numVersionBuckets=65536
   [junit4]   2> 372401 INFO  (qtp2062746144-9914) [n:127.0.0.1:38585_solr c:testNodeAdded s:shard1 r:core_node4 x:testNodeAdded_shard1_replica_n2 ] o.a.s.u.CommitTracker Hard AutoCommit: disabled
   [junit4]   2> 372402 INFO  (qtp2062746144-9914) [n:127.0.0.1:38585_solr c:testNodeAdded s:shard1 r:core_node4 x:testNodeAdded_shard1_replica_n2 ] o.a.s.u.CommitTracker Soft AutoCommit: disabled
   [junit4]   2> 372404 INFO  (qtp2062746144-9914) [n:127.0.0.1:38585_solr c:testNodeAdded s:shard1 r:core_node4 x:testNodeAdded_shard1_replica_n2 ] o.a.s.r.ManagedResourceStorage Configured ZooKeeperStorageIO with znodeBase: /configs/conf
   [junit4]   2> 372404 INFO  (qtp2062746144-9914) [n:127.0.0.1:38585_solr c:testNodeAdded s:shard1 r:core_node4 x:testNodeAdded_shard1_replica_n2 ] o.a.s.r.ManagedResourceStorage Loaded null at path _rest_managed.json using ZooKeeperStorageIO:path=/configs/conf
   [junit4]   2> 372404 INFO  (qtp2062746144-9914) [n:127.0.0.1:38585_solr c:testNodeAdded s:shard1 r:core_node4 x:testNodeAdded_shard1_replica_n2 ] o.a.s.h.ReplicationHandler Commits will be reserved for 10000 ms
   [junit4]   2> 372405 INFO  (qtp2062746144-9914) [n:127.0.0.1:38585_solr c:testNodeAdded s:shard1 r:core_node4 x:testNodeAdded_shard1_replica_n2 ] o.a.s.u.UpdateLog Could not find max version in index or recent updates, using new clock 1677465414804701184
   [junit4]   2> 372406 INFO  (searcherExecutor-4281-thread-1-processing-n:127.0.0.1:38585_solr x:testNodeAdded_shard1_replica_n2 c:testNodeAdded s:shard1 r:core_node4) [n:127.0.0.1:38585_solr c:testNodeAdded s:shard1 r:core_node4 x:testNodeAdded_shard1_replica_n2 ] o.a.s.c.SolrCore [testNodeAdded_shard1_replica_n2]  Registered new searcher autowarm time: 0 ms
   [junit4]   2> 372406 INFO  (qtp2062746144-9914) [n:127.0.0.1:38585_solr c:testNodeAdded s:shard1 r:core_node4 x:testNodeAdded_shard1_replica_n2 ] o.a.s.c.ZkShardTerms Successful update of terms at /collections/testNodeAdded/terms/shard1 to Terms{values={core_node3=0, core_node4=0}, version=1}
   [junit4]   2> 372406 INFO  (qtp2062746144-9914) [n:127.0.0.1:38585_solr c:testNodeAdded s:shard1 r:core_node4 x:testNodeAdded_shard1_replica_n2 ] o.a.s.c.ShardLeaderElectionContextBase make sure parent is created /collections/testNodeAdded/leaders/shard1
   [junit4]   2> 372500 DEBUG (OverseerStateUpdate-72110040925732869-127.0.0.1:38585_solr-n_0000000000) [n:127.0.0.1:38585_solr     ] o.a.s.c.o.ZkStateWriter going to update_collection /collections/testNodeAdded/state.json version: 1
   [junit4]   2> 372900 INFO  (qtp2062746144-9913) [n:127.0.0.1:38585_solr c:testNodeAdded s:shard1 r:core_node3 x:testNodeAdded_shard1_replica_n1 ] o.a.s.c.ShardLeaderElectionContext Enough replicas found to continue.
   [junit4]   2> 372900 INFO  (qtp2062746144-9913) [n:127.0.0.1:38585_solr c:testNodeAdded s:shard1 r:core_node3 x:testNodeAdded_shard1_replica_n1 ] o.a.s.c.ShardLeaderElectionContext I may be the new leader - try and sync
   [junit4]   2> 372900 INFO  (qtp2062746144-9913) [n:127.0.0.1:38585_solr c:testNodeAdded s:shard1 r:core_node3 x:testNodeAdded_shard1_replica_n1 ] o.a.s.c.SyncStrategy Sync replicas to https://127.0.0.1:38585/solr/testNodeAdded_shard1_replica_n1/
   [junit4]   2> 372900 INFO  (qtp2062746144-9913) [n:127.0.0.1:38585_solr c:testNodeAdded s:shard1 r:core_node3 x:testNodeAdded_shard1_replica_n1 ] o.a.s.u.PeerSync PeerSync: core=testNodeAdded_shard1_replica_n1 url=https://127.0.0.1:38585/solr  START replicas=[https://127.0.0.1:38585/solr/testNodeAdded_shard1_replica_n2/] nUpdates=100
   [junit4]   2> 372901 INFO  (qtp2062746144-9913) [n:127.0.0.1:38585_solr c:testNodeAdded s:shard1 r:core_node3 x:testNodeAdded_shard1_replica_n1 ] o.a.s.u.PeerSync PeerSync: core=testNodeAdded_shard1_replica_n1 url=https://127.0.0.1:38585/solr  DONE. We have no versions. sync failed.
   [junit4]   2> 372902 INFO  (qtp2062746144-9924) [n:127.0.0.1:38585_solr c:testNodeAdded s:shard1 r:core_node4 x:testNodeAdded_shard1_replica_n2 ] o.a.s.c.S.Request [testNodeAdded_shard1_replica_n2]  webapp=/solr path=/get params={distrib=false&qt=/get&fingerprint=false&getVersions=100&wt=javabin&version=2} status=0 QTime=0
   [junit4]   2> 372902 INFO  (qtp2062746144-9913) [n:127.0.0.1:38585_solr c:testNodeAdded s:shard1 r:core_node3 x:testNodeAdded_shard1_replica_n1 ] o.a.s.c.SyncStrategy Leader's attempt to sync with shard failed, moving to the next candidate
   [junit4]   2> 372902 INFO  (qtp2062746144-9913) [n:127.0.0.1:38585_solr c:testNodeAdded s:shard1 r:core_node3 x:testNodeAdded_shard1_replica_n1 ] o.a.s.c.ShardLeaderElectionContext We failed sync, but we have no versions - we can't sync in that case - we were active before, so become leader anyway
   [junit4]   2> 372902 INFO  (qtp2062746144-9913) [n:127.0.0.1:38585_solr c:testNodeAdded s:shard1 r:core_node3 x:testNodeAdded_shard1_replica_n1 ] o.a.s.c.ShardLeaderElectionContextBase Creating leader registration node /collections/testNodeAdded/leaders/shard1/leader after winning as /collections/testNodeAdded/leader_elect/shard1/election/72110040925732869-core_node3-n_0000000000
   [junit4]   2> 372903 INFO  (qtp2062746144-9913) [n:127.0.0.1:38585_solr c:testNodeAdded s:shard1 r:core_node3 x:testNodeAdded_shard1_replica_n1 ] o.a.s.c.ShardLeaderElectionContext I am the new leader: https://127.0.0.1:38585/solr/testNodeAdded_shard1_replica_n1/ shard1
   [junit4]   2> 372903 DEBUG (OverseerStateUpdate-72110040925732869-127.0.0.1:38585_solr-n_0000000000) [n:127.0.0.1:38585_solr     ] o.a.s.c.Overseer processMessage: queueSize: 1, message = {
   [junit4]   2>   "operation":"leader",
   [junit4]   2>   "shard":"shard1",
   [junit4]   2>   "collection":"testNodeAdded",
   [junit4]   2>   "base_url":"https://127.0.0.1:38585/solr",
   [junit4]   2>   "core":"testNodeAdded_shard1_replica_n1",
   [junit4]   2>   "state":"active"} current state version: 0
   [junit4]   2> 373004 DEBUG (OverseerStateUpdate-72110040925732869-127.0.0.1:38585_solr-n_0000000000) [n:127.0.0.1:38585_solr     ] o.a.s.c.o.ZkStateWriter going to update_collection /collections/testNodeAdded/state.json version: 2
   [junit4]   2> 373004 INFO  (zkCallback-4257-thread-3) [     ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/testNodeAdded/state.json] for collection [testNodeAdded] has occurred - updating... (live nodes size: [1])
   [junit4]   2> 373004 INFO  (qtp2062746144-9913) [n:127.0.0.1:38585_solr c:testNodeAdded s:shard1 r:core_node3 x:testNodeAdded_shard1_replica_n1 ] o.a.s.c.ZkController I am the leader, no recovery necessary
   [junit4]   2> 373005 DEBUG (OverseerStateUpdate-72110040925732869-127.0.0.1:38585_solr-n_0000000000) [n:127.0.0.1:38585_solr     ] o.a.s.c.Overseer processMessage: queueSize: 1, message = {
   [junit4]   2>   "core":"testNodeAdded_shard1_replica_n1",
   [junit4]   2>   "core_node_name":"core_node3",
   [junit4]   2>   "roles":null,
   [junit4]   2>   "base_url":"https://127.0.0.1:38585/solr",
   [junit4]   2>   "node_name":"127.0.0.1:38585_solr",
   [junit4]   2>   "numShards":"1",
   [junit4]   2>   "state":"active",
   [junit4]   2>   "shard":"shard1",
   [junit4]   2>   "collection":"testNodeAdded",
   [junit4]   2>   "type":"NRT",
   [junit4]   2>   "force_set_state":"false",
   [junit4]   2>   "operation":"state"} current state version: 0
   [junit4]   2> 373005 DEBUG (OverseerStateUpdate-72110040925732869-127.0.0.1:38585_solr-n_0000000000) [n:127.0.0.1:38585_solr     ] o.a.s.c.o.ReplicaMutator Update state numShards=1 message={
   [junit4]   2>   "core":"testNodeAdded_shard1_replica_n1",
   [junit4]   2>   "core_node_name":"core_node3",
   [junit4]   2>   "roles":null,
   [junit4]   2>   "base_url":"https://127.0.0.1:38585/solr",
   [junit4]   2>   "node_name":"127.0.0.1:38585_solr",
   [junit4]   2>   "numShards":"1",
   [junit4]   2>   "state":"active",
   [junit4]   2>   "shard":"shard1",
   [junit4]   2>   "collection":"testNodeAdded",
   [junit4]   2>   "type":"NRT",
   [junit4]   2>   "force_set_state":"false",
   [junit4]   2>   "operation":"state"}
   [junit4]   2> 373005 DEBUG (OverseerStateUpdate-72110040925732869-127.0.0.1:38585_solr-n_0000000000) [n:127.0.0.1:38585_solr     ] o.a.s.c.o.ReplicaMutator Will update state for replica: core_node3:{
   [junit4]   2>   "core":"testNodeAdded_shard1_replica_n1",
   [junit4]   2>   "base_url":"https://127.0.0.1:38585/solr",
   [junit4]   2>   "node_name":"127.0.0.1:38585_solr",
   [junit4]   2>   "state":"active",
   [junit4]   2>   "type":"NRT",
   [junit4]   2>   "force_set_state":"false",
   [junit4]   2>   "leader":"true"}
   [junit4]   2> 373005 DEBUG (OverseerStateUpdate-72110040925732869-127.0.0.1:38585_solr-n_0000000000) [n:127.0.0.1:38585_solr     ] o.a.s.c.o.ReplicaMutator Collection is now: DocCollection(testNodeAdded//collections/testNodeAdded/state.json/3)={
   [junit4]   2>   "pullReplicas":"0",
   [junit4]   2>   "replicationFactor":"2",
   [junit4]   2>   "router":{"name":"compositeId"},
   [junit4]   2>   "maxShardsPerNode":"2",
   [junit4]   2>   "autoAddReplicas":"false",
   [junit4]   2>   "nrtReplicas":"2",
   [junit4]   2>   "tlogReplicas":"0",
   [junit4]   2>   "shards":{"shard1":{
   [junit4]   2>       "range":"80000000-7fffffff",
   [junit4]   2>       "state":"active",
   [junit4]   2>       "replicas":{
   [junit4]   2>         "core_node3":{
   [junit4]   2>           "core":"testNodeAdded_shard1_replica_n1",
   [junit4]   2>           "base_url":"https://127.0.0.1:38585/solr",
   [junit4]   2>           "node_name":"127.0.0.1:38585_solr",
   [junit4]   2>           "state":"active",
   [junit4]   2>           "type":"NRT",
   [junit4]   2>           "force_set_state":"false",
   [junit4]   2>           "leader":"true"},
   [junit4]   2>         "core_node4":{
   [junit4]   2>           "core":"testNodeAdded_shard1_replica_n2",
   [junit4]   2>           "base_url":"https://127.0.0.1:38585/solr",
   [junit4]   2>           "node_name":"127.0.0.1:38585_solr",
   [junit4]   2>           "state":"down",
   [junit4]   2>           "type":"NRT",
   [junit4]   2>           "force_set_state":"false"}}}}}
   [junit4]   2> 373007 INFO  (qtp2062746144-9913) [n:127.0.0.1:38585_solr     ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/cores params={qt=/admin/cores&coreNodeName=core_node3&collection.configName=conf&newCollection=true&name=testNodeAdded_shard1_replica_n1&action=CREATE&numShards=1&collection=testNodeAdded&shard=shard1&wt=javabin&version=2&replicaType=NRT} status=0 QTime=662
   [junit4]   2> 373018 DEBUG (ScheduledTrigger-4263-thread-2) [     ] o.a.s.c.a.NodeAddedTrigger Running NodeAddedTrigger node_added_trigger
   [junit4]   2> 373018 DEBUG (ScheduledTrigger-4263-thread-2) [     ] o.a.s.c.a.NodeAddedTrigger Found livenodes: 1
   [junit4]   2> 373105 DEBUG (OverseerStateUpdate-72110040925732869-127.0.0.1:38585_solr-n_0000000000) [n:127.0.0.1:38585_solr     ] o.a.s.c.o.ZkStateWriter going to update_collection /collections/testNodeAdded/state.json version: 3
   [junit4]   2> 373106 INFO  (zkCallback-4257-thread-2) [     ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/testNodeAdded/state.json] for collection [testNodeAdded] has occurred - updating... (live nodes size: [1])
   [junit4]   2> 373106 INFO  (zkCallback-4257-thread-3) [     ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/testNodeAdded/state.json] for collection [testNodeAdded] has occurred - updating... (live nodes size: [1])
   [junit4]   2> 373408 DEBUG (OverseerStateUpdate-72110040925732869-127.0.0.1:38585_solr-n_0000000000) [n:127.0.0.1:38585_solr     ] o.a.s.c.Overseer processMessage: queueSize: 1, message = {
   [junit4]   2>   "core":"testNodeAdded_shard1_replica_n2",
   [junit4]   2>   "core_node_name":"core_node4",
   [junit4]   2>   "roles":null,
   [junit4]   2>   "base_url":"https://127.0.0.1:38585/solr",
   [junit4]   2>   "node_name":"127.0.0.1:38585_solr",
   [junit4]   2>   "numShards":"1",
   [junit4]   2>   "state":"active",
   [junit4]   2>   "shard":"shard1",
   [junit4]   2>   "collection":"testNodeAdded",
   [junit4]   2>   "type":"NRT",
   [junit4]   2>   "force_set_state":"false",
   [junit4]   2>   "operation":"state"} current state version: 0
   [junit4]   2> 373408 DEBUG (OverseerStateUpdate-72110040925732869-127.0.0.1:38585_solr-n_0000000000) [n:127.0.0.1:38585_solr     ] o.a.s.c.o.ReplicaMutator Update state numShards=1 message={
   [junit4]   2>   "core":"testNodeAdded_shard1_replica_n2",
   [junit4]   2>   "core_node_name":"core_node4",
   [junit4]   2>   "roles":null,
   [junit4]   2>   "base_url":"https://127.0.0.1:38585/solr",
   [junit4]   2>   "node_name":"127.0.0.1:38585_solr",
   [junit4]   2>   "numShards":"1",
   [junit4]   2>   "state":"active",
   [junit4]   2>   "shard":"shard1",
   [junit4]   2>   "collection":"testNodeAdded",
   [junit4]   2>   "type":"NRT",
   [junit4]   2>   "force_set_state":"false",
   [junit4]   2>   "operation":"state"}
   [junit4]   2> 373408 DEBUG (OverseerStateUpdate-72110040925732869-127.0.0.1:38585_solr-n_0000000000) [n:127.0.0.1:38585_solr     ] o.a.s.c.o.ReplicaMutator Will update state for replica: core_node4:{
   [junit4]   2>   "core":"testNodeAdded_shard1_replica_n2",
   [junit4]   2>   "base_url":"https://127.0.0.1:38585/solr",
   [junit4]   2>   "node_name":"127.0.0.1:38585_solr",
   [junit4]   2>   "state":"active",
   [junit4]   2>   "type":"NRT",
   [junit4]   2>   "force_set_state":"false"}
   [junit4]   2> 373408 DEBUG (OverseerStateUpdate-72110040925732869-127.0.0.1:38585_solr-n_0000000000) [n:127.0.0.1:38585_solr     ] o.a.s.c.o.ReplicaMutator Collection is now: DocCollection(testNodeAdded//collections/testNodeAdded/state.json/4)={
   [junit4]   2>   "pullReplicas":"0",
   [junit4]   2>   "replicationFactor":"2",
   [junit4]   2>   "router":{"name":"compositeId"},
   [junit4]   2>   "maxShardsPerNode":"2",
   [junit4]   2>   "autoAddReplicas":"false",
   [junit4]   2>   "nrtReplicas":"2",
   [junit4]   2>   "tlogReplicas":"0",
   [junit4]   2>   "shards":{"shard1":{
   [junit4]   2>       "range":"80000000-7fffffff",
   [junit4]   2>       "state":"active",
   [junit4]   2>       "replicas":{
   [junit4]   2>         "core_node3":{
   [junit4]   2>           "core":"testNodeAdded_shard1_replica_n1",
   [junit4]   2>           "base_url":"https://127.0.0.1:38585/solr",
   [junit4]   2>           "node_name":"127.0.0.1:38585_solr",
   [junit4]   2>           "state":"active",
   [junit4]   2>           "type":"NRT",
   [junit4]   2>           "force_set_state":"false",
   [junit4]   2>           "leader":"true"},
   [junit4]   2>         "core_node4":{
   [junit4]   2>           "core":"testNodeAdded_shard1_replica_n2",
   [junit4]   2>           "base_url":"https://127.0.0.1:38585/solr",
   [junit4]   2>           "node_name":"127.0.0.1:38585_solr",
   [junit4]   2>           "state":"active",
   [junit4]   2>           "type":"NRT",
   [junit4]   2>           "force_set_state":"false"}}}}}
   [junit4]   2> 373408 INFO  (qtp2062746144-9914) [n:127.0.0.1:38585_solr     ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/cores params={qt=/admin/cores&coreNodeName=core_node4&collection.configName=conf&newCollection=true&name=testNodeAdded_shard1_replica_n2&action=CREATE&numShards=1&collection=testNodeAdded&shard=shard1&wt=javabin&version=2&replicaType=NRT} status=0 QTime=1064
   [junit4]   2> 373409 INFO  (qtp2062746144-9911) [n:127.0.0.1:38585_solr     ] o.a.s.h.a.CollectionsHandler Wait for new collection to be active for at most 45 seconds. Check all shard replicas
   [junit4]   2> 373508 DEBUG (OverseerStateUpdate-72110040925732869-127.0.0.1:38585_solr-n_0000000000) [n:127.0.0.1:38585_solr     ] o.a.s.c.o.ZkStateWriter going to update_collection /collections/testNodeAdded/state.json version: 4
   [junit4]   2> 373509 INFO  (zkCallback-4257-thread-2) [     ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/testNodeAdded/state.json] for collection [testNodeAdded] has occurred - updating... (live nodes size: [1])
   [junit4]   2> 373509 INFO  (zkCallback-4257-thread-3) [     ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/testNodeAdded/state.json] for collection [testNodeAdded] has occurred - updating... (live nodes size: [1])
   [junit4]   2> 373509 INFO  (qtp2062746144-9911) [n:127.0.0.1:38585_solr     ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/collections params={collection.configName=conf&maxShardsPerNode=2&name=testNodeAdded&nrtReplicas=2&action=CREATE&numShards=1&wt=javabin&version=2} status=0 QTime=1489
   [junit4]   2> 373510 INFO  (TEST-ComputePlanActionTest.testNodeAdded-seed#[D6BE127202370C75]) [     ] o.a.s.c.SolrCloudTestCase waitForState (testNodeAdded): Timed out waiting for replicas of new collection to be active
   [junit4]   2> 373513 INFO  (qtp2062746144-9913) [n:127.0.0.1:38585_solr     ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/metrics params={wt=javabin&version=2&key=solr.core.testNodeAdded.shard1.replica_n1:INDEX.sizeInBytes&key=solr.core.testNodeAdded.shard1.replica_n2:INDEX.sizeInBytes} status=0 QTime=0
   [junit4]   2> 373514 INFO  (qtp2062746144-9914) [n:127.0.0.1:38585_solr     ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/metrics params={prefix=CONTAINER.fs.usableSpace,CONTAINER.cores&wt=javabin&version=2&group=solr.node} status=0 QTime=0
   [junit4]   2> 373514 DEBUG (qtp2062746144-9924) [n:127.0.0.1:38585_solr     ] o.a.s.c.a.AutoScalingHandler Verified autoscaling configuration
   [junit4]   2> 373514 INFO  (qtp2062746144-9924) [n:127.0.0.1:38585_solr     ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/cluster/autoscaling params={wt=javabin&version=2} status=0 QTime=3
   [junit4]   2> 373514 DEBUG (zkCallback-4257-thread-3) [     ] o.a.s.c.a.OverseerTriggerThread Refreshing /autoscaling.json with znode version 7
   [junit4]   2> 373515 DEBUG (OverseerAutoScalingTriggerThread-72110040925732869-127.0.0.1:38585_solr-n_0000000000) [     ] o.a.s.c.a.OverseerTriggerThread Processed trigger updates upto znodeVersion 7
   [junit4]   2> 373515 DEBUG (OverseerAutoScalingTriggerThread-72110040925732869-127.0.0.1:38585_solr-n_0000000000) [     ] o.a.s.c.a.OverseerTriggerThread -- deactivating old nodeLost / nodeAdded markers
   [junit4]   2> 373515 DEBUG (OverseerAutoScalingTriggerThread-72110040925732869-127.0.0.1:38585_solr-n_0000000000) [     ] o.a.s.c.a.OverseerTriggerThread Current znodeVersion 7, lastZnodeVersion 7
   [junit4]   2> 373516 WARN  (TEST-ComputePlanActionTest.testNodeAdded-seed#[D6BE127202370C75]) [     ] o.e.j.s.h.g.GzipHandler minGzipSize of 0 is inefficient for short content, break even is size 23
   [junit4]   2> 373516 INFO  (TEST-ComputePlanActionTest.testNodeAdded-seed#[D6BE127202370C75]) [     ] o.a.s.c.s.e.JettySolrRunner Start Jetty (configured port=0, binding port=0)
   [junit4]   2> 373516 INFO  (TEST-ComputePlanActionTest.testNodeAdded-seed#[D6BE127202370C75]) [     ] o.a.s.c.s.e.JettySolrRunner Trying to start Jetty on port 0 try number 2 ...
   [junit4]   2> 373516 INFO  (TEST-ComputePlanActionTest.testNodeAdded-seed#[D6BE127202370C75]) [     ] o.e.j.s.Server jetty-9.4.27.v20200227; built: 2020-02-27T18:37:21.340Z; git: a304fd9f351f337e7c0e2a7c28878dd536149c6c; jvm 12.0.2+10
   [junit4]   2> 373519 INFO  (TEST-ComputePlanActionTest.testNodeAdded-seed#[D6BE127202370C75]) [     ] o.e.j.s.session DefaultSessionIdManager workerName=node0
   [junit4]   2> 373519 INFO  (TEST-ComputePlanActionTest.testNodeAdded-seed#[D6BE127202370C75]) [     ] o.e.j.s.session No SessionScavenger set, using defaults
   [junit4]   2> 373519 INFO  (TEST-ComputePlanActionTest.testNodeAdded-seed#[D6BE127202370C75]) [     ] o.e.j.s.session node0 Scavenging every 600000ms
   [junit4]   2> 373519 INFO  (TEST-ComputePlanActionTest.testNodeAdded-seed#[D6BE127202370C75]) [     ] o.e.j.s.h.ContextHandler Started o.e.j.s.ServletContextHandler@22cb1bd{/solr,null,AVAILABLE}
   [junit4]   2> 373520 INFO  (TEST-ComputePlanActionTest.testNodeAdded-seed#[D6BE127202370C75]) [     ] o.e.j.s.AbstractConnector Started ServerConnector@2b7321e{ssl, (ssl, alpn, http/1.1, h2)}{127.0.0.1:39949}
   [junit4]   2> 373520 INFO  (TEST-ComputePlanActionTest.testNodeAdded-seed#[D6BE127202370C75]) [     ] o.e.j.s.Server Started @373540ms
   [junit4]   2> 373520 INFO  (TEST-ComputePlanActionTest.testNodeAdded-seed#[D6BE127202370C75]) [     ] o.a.s.c.s.e.JettySolrRunner Jetty properties: {hostContext=/solr, hostPort=39949}
   [junit4]   2> 373520 ERROR (TEST-ComputePlanActionTest.testNodeAdded-seed#[D6BE127202370C75]) [     ] o.a.s.u.StartupLoggingUtils Missing Java Option solr.log.dir. Logging may be missing or incomplete.
   [junit4]   2> 373520 INFO  (TEST-ComputePlanActionTest.testNodeAdded-seed#[D6BE127202370C75]) [     ] o.a.s.s.SolrDispatchFilter Using logger factory org.apache.logging.slf4j.Log4jLoggerFactory
   [junit4]   2> 373520 INFO  (TEST-ComputePlanActionTest.testNodeAdded-seed#[D6BE127202370C75]) [     ] o.a.s.s.SolrDispatchFilter  ___      _       Welcome to Apache Solr™ version 8.7.0
   [junit4]   2> 373520 INFO  (TEST-ComputePlanActionTest.testNodeAdded-seed#[D6BE127202370C75]) [     ] o.a.s.s.SolrDispatchFilter / __| ___| |_ _   Starting in cloud mode on port null
   [junit4]   2> 373520 INFO  (TEST-ComputePlanActionTest.testNodeAdded-seed#[D6BE127202370C75]) [     ] o.a.s.s.SolrDispatchFilter \__ \/ _ \ | '_|  Install dir: /home/jenkins/workspace/Lucene-Solr-8.x-Linux/solr
   [junit4]   2> 373520 INFO  (TEST-ComputePlanActionTest.testNodeAdded-seed#[D6BE127202370C75]) [     ] o.a.s.s.SolrDispatchFilter |___/\___/_|_|    Start time: 2020-09-10T16:34:43.874680Z
   [junit4]   2> 373521 INFO  (TEST-ComputePlanActionTest.testNodeAdded-seed#[D6BE127202370C75]) [     ] o.a.s.c.c.ConnectionManager Waiting for client to connect to ZooKeeper
   [junit4]   2> 373521 INFO  (zkConnectionManagerCallback-4291-thread-1) [     ] o.a.s.c.c.ConnectionManager zkClient has connected
   [junit4]   2> 373521 INFO  (TEST-ComputePlanActionTest.testNodeAdded-seed#[D6BE127202370C75]) [     ] o.a.s.c.c.ConnectionManager Client is connected to ZooKeeper
   [junit4]   2> 373522 INFO  (TEST-ComputePlanActionTest.testNodeAdded-seed#[D6BE127202370C75]) [     ] o.a.s.s.SolrDispatchFilter solr.xml found in ZooKeeper. Loading...
   [junit4]   2> 373683 INFO  (TEST-ComputePlanActionTest.testNodeAdded-seed#[D6BE127202370C75]) [     ] o.a.s.h.c.HttpShardHandlerFactory Host whitelist initialized: WhitelistHostChecker [whitelistHosts=null, whitelistHostCheckingEnabled=true]
   [junit4]   2> 373683 WARN  (TEST-ComputePlanActionTest.testNodeAdded-seed#[D6BE127202370C75]) [     ] o.e.j.u.s.S.config Trusting all certificates configured for Client@3fe79b26[provider=null,keyStore=null,trustStore=null]
   [junit4]   2> 373683 WARN  (TEST-ComputePlanActionTest.testNodeAdded-seed#[D6BE127202370C75]) [     ] o.e.j.u.s.S.config No Client EndPointIdentificationAlgorithm configured for Client@3fe79b26[provider=null,keyStore=null,trustStore=null]
   [junit4]   2> 373685 WARN  (TEST-ComputePlanActionTest.testNodeAdded-seed#[D6BE127202370C75]) [     ] o.e.j.u.s.S.config Trusting all certificates configured for Client@22f3b5f7[provider=null,keyStore=null,trustStore=null]
   [junit4]   2> 373685 WARN  (TEST-ComputePlanActionTest.testNodeAdded-seed#[D6BE127202370C75]) [     ] o.e.j.u.s.S.config No Client EndPointIdentificationAlgorithm configured for Client@22f3b5f7[provider=null,keyStore=null,trustStore=null]
   [junit4]   2> 373686 INFO  (TEST-ComputePlanActionTest.testNodeAdded-seed#[D6BE127202370C75]) [     ] o.a.s.c.ZkContainer Zookeeper client=127.0.0.1:32911/solr
   [junit4]   2> 373686 INFO  (TEST-ComputePlanActionTest.testNodeAdded-seed#[D6BE127202370C75]) [     ] o.a.s.c.c.ConnectionManager Waiting for client to connect to ZooKeeper
   [junit4]   2> 373687 INFO  (zkConnectionManagerCallback-4301-thread-1) [     ] o.a.s.c.c.ConnectionManager zkClient has connected
   [junit4]   2> 373687 INFO  (TEST-ComputePlanActionTest.testNodeAdded-seed#[D6BE127202370C75]) [     ] o.a.s.c.c.ConnectionManager Client is connected to ZooKeeper
   [junit4]   2> 373788 INFO  (TEST-ComputePlanActionTest.testNodeAdded-seed#[D6BE127202370C75]) [n:127.0.0.1:39949_solr     ] o.a.s.c.c.ConnectionManager Waiting for client to connect to ZooKeeper
   [junit4]   2> 373789 INFO  (zkConnectionManagerCallback-4303-thread-1) [     ] o.a.s.c.c.ConnectionManager zkClient has connected
   [junit4]   2> 373789 INFO  (TEST-ComputePlanActionTest.testNodeAdded-seed#[D6BE127202370C75]) [n:127.0.0.1:39949_solr     ] o.a.s.c.c.ConnectionManager Client is connected to ZooKeeper
   [junit4]   2> 373791 INFO  (TEST-ComputePlanActionTest.testNodeAdded-seed#[D6BE127202370C75]) [n:127.0.0.1:39949_solr     ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (1)
   [junit4]   2> 373794 INFO  (TEST-ComputePlanActionTest.testNodeAdded-seed#[D6BE127202370C75]) [n:127.0.0.1:39949_solr     ] o.a.s.c.ZkController Publish node=127.0.0.1:39949_solr as DOWN
   [junit4]   2> 373794 INFO  (TEST-ComputePlanActionTest.testNodeAdded-seed#[D6BE127202370C75]) [n:127.0.0.1:39949_solr     ] o.a.s.c.TransientSolrCoreCacheDefault Allocating transient cache for 2147483647 transient cores
   [junit4]   2> 373794 INFO  (TEST-ComputePlanActionTest.testNodeAdded-seed#[D6BE127202370C75]) [n:127.0.0.1:39949_solr     ] o.a.s.c.ZkController Register node as live in ZooKeeper:/live_nodes/127.0.0.1:39949_solr
   [junit4]   2> 373794 DEBUG (OverseerStateUpdate-72110040925732869-127.0.0.1:38585_solr-n_0000000000) [n:127.0.0.1:38585_solr     ] o.a.s.c.Overseer processMessage: queueSize: 1, message = {
   [junit4]   2>   "operation":"downnode",
   [junit4]   2>   "node_name":"127.0.0.1:39949_solr"} current state version: 0
   [junit4]   2> 373794 DEBUG (OverseerStateUpdate-72110040925732869-127.0.0.1:38585_solr-n_0000000000) [n:127.0.0.1:38585_solr     ] o.a.s.c.o.NodeMutator DownNode state invoked for node: 127.0.0.1:39949_solr
   [junit4]   2> 373795 INFO  (zkCallback-4257-thread-3) [     ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (1) -> (2)
   [junit4]   2> 373795 INFO  (zkCallback-4274-thread-1) [     ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (1) -> (2)
   [junit4]   2> 373795 INFO  (zkCallback-4274-thread-2) [     ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (1) -> (2)
   [junit4]   2> 373795 INFO  (zkCallback-4302-thread-1) [     ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (1) -> (2)
   [junit4]   2> 373797 INFO  (TEST-ComputePlanActionTest.testNodeAdded-seed#[D6BE127202370C75]) [n:127.0.0.1:39949_solr     ] o.a.s.p.PackageLoader /packages.json updated to version -1
   [junit4]   2> 373797 WARN  (TEST-ComputePlanActionTest.testNodeAdded-seed#[D6BE127202370C75]) [n:127.0.0.1:39949_solr     ] o.a.s.c.CoreContainer Not all security plugins configured!  authentication=disabled authorization=disabled.  Solr is only as secure as you make it. Consider configuring authentication/authorization before exposing Solr to users internal or external.  See https://s.apache.org/solrsecurity for more info
   [junit4]   2> 373806 INFO  (TEST-ComputePlanActionTest.testNodeAdded-seed#[D6BE127202370C75]) [n:127.0.0.1:39949_solr     ] o.a.s.h.a.MetricsHistoryHandler No .system collection, keeping metrics history in memory.
   [junit4]   2> 373821 INFO  (TEST-ComputePlanActionTest.testNodeAdded-seed#[D6BE127202370C75]) [n:127.0.0.1:39949_solr     ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_39949.solr.node' (registry 'solr.node') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@1dfb013
   [junit4]   2> 373829 INFO  (TEST-ComputePlanActionTest.testNodeAdded-seed#[D6BE127202370C75]) [n:127.0.0.1:39949_solr     ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_39949.solr.jvm' (registry 'solr.jvm') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@1dfb013
   [junit4]   2> 373829 INFO  (TEST-ComputePlanActionTest.testNodeAdded-seed#[D6BE127202370C75]) [n:127.0.0.1:39949_solr     ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_39949.solr.jetty' (registry 'solr.jetty') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@1dfb013
   [junit4]   2> 373830 INFO  (TEST-ComputePlanActionTest.testNodeAdded-seed#[D6BE127202370C75]) [n:127.0.0.1:39949_solr     ] o.a.s.c.CorePropertiesLocator Found 0 core definitions underneath /home/jenkins/workspace/Lucene-Solr-8.x-Linux/solr/build/solr-core/test/J4/temp/solr.cloud.autoscaling.ComputePlanActionTest_D6BE127202370C75-001/tempDir-001/node2
   [junit4]   2> 374019 DEBUG (ScheduledTrigger-4263-thread-2) [     ] o.a.s.c.a.NodeAddedTrigger Running NodeAddedTrigger node_added_trigger
   [junit4]   2> 374019 DEBUG (ScheduledTrigger-4263-thread-2) [     ] o.a.s.c.a.NodeAddedTrigger Found livenodes: 2
   [junit4]   2> 374019 DEBUG (ScheduledTrigger-4263-thread-2) [     ] o.a.s.c.a.NodeAddedTrigger Tracking new node: 127.0.0.1:39949_solr at time 800278623797861
   [junit4]   2> 374024 INFO  (OverseerCollectionConfigSetProcessor-72110040925732869-127.0.0.1:38585_solr-n_0000000000) [n:127.0.0.1:38585_solr     ] o.a.s.c.OverseerTaskQueue Response ZK path: /overseer/collection-queue-work/qnr-0000000000 doesn't exist. Requestor may have disconnected from ZooKeeper
   [junit4]   2> 375019 DEBUG (ScheduledTrigger-4263-thread-2) [     ] o.a.s.c.a.NodeAddedTrigger Running NodeAddedTrigger node_added_trigger
   [junit4]   2> 375019 DEBUG (ScheduledTrigger-4263-thread-2) [     ] o.a.s.c.a.NodeAddedTrigger Found livenodes: 2
   [junit4]   2> 375020 DEBUG (ScheduledTrigger-4263-thread-2) [     ] o.a.s.c.a.NodeAddedTrigger NodeAddedTrigger node_added_trigger firing registered processor for nodes: [127.0.0.1:39949_solr] added at times [800278623797861], now=800279624593658
   [junit4]   2> 375020 DEBUG (ScheduledTrigger-4263-thread-2) [     ] o.a.s.c.a.ScheduledTriggers ++++++++ Cooldown inactive - processing event: {
   [junit4]   2>   "id":"2d7d96317c265T6bnnx51i5gi7y2r7s77vlpmri",
   [junit4]   2>   "source":"node_added_trigger",
   [junit4]   2>   "eventTime":800278623797861,
   [junit4]   2>   "eventType":"NODEADDED",
   [junit4]   2>   "properties":{
   [junit4]   2>     "eventTimes":[800278623797861],
   [junit4]   2>     "preferredOperation":"movereplica",
   [junit4]   2>     "nodeNames":["127.0.0.1:39949_solr"],
   [junit4]   2>     "replicaType":"NRT"}}
   [junit4]   2> 375020 DEBUG (ScheduledTrigger-4263-thread-2) [     ] o.a.s.c.a.ScheduledTriggers Pausing all triggers: [node_added_trigger]
   [junit4]   2> 375020 DEBUG (ScheduledTrigger-4263-thread-2) [     ] o.a.s.c.a.SystemLogListener Collection .system missing, skip sending event {
   [junit4]   2>   "id":"2d7d96317c265T6bnnx51i5gi7y2r7s77vlpmri",
   [junit4]   2>   "source":"node_added_trigger",
   [junit4]   2>   "eventTime":800278623797861,
   [junit4]   2>   "eventType":"NODEADDED",
   [junit4]   2>   "properties":{
   [junit4]   2>     "eventTimes":[800278623797861],
   [junit4]   2>     "preferredOperation":"movereplica",
   [junit4]   2>     "_enqueue_time_":800279625007330,
   [junit4]   2>     "nodeNames":["127.0.0.1:39949_solr"],
   [junit4]   2>     "replicaType":"NRT"}}
   [junit4]   2> 375021 DEBUG (AutoscalingActionExecutor-4264-thread-1) [     ] o.a.s.c.a.ScheduledTriggers -- processing actions for {
   [junit4]   2>   "id":"2d7d96317c265T6bnnx51i5gi7y2r7s77vlpmri",
   [junit4]   2>   "source":"node_added_trigger",
   [junit4]   2>   "eventTime":800278623797861,
   [junit4]   2>   "eventType":"NODEADDED",
   [junit4]   2>   "properties":{
   [junit4]   2>     "eventTimes":[800278623797861],
   [junit4]   2>     "preferredOperation":"movereplica",
   [junit4]   2>     "_enqueue_time_":800279625007330,
   [junit4]   2>     "nodeNames":["127.0.0.1:39949_solr"],
   [junit4]   2>     "replicaType":"NRT"}}
   [junit4]   2> 375021 DEBUG (AutoscalingActionExecutor-4264-thread-1) [     ] o.a.s.c.a.ComputePlanAction -- processing event: {
   [junit4]   2>   "id":"2d7d96317c265T6bnnx51i5gi7y2r7s77vlpmri",
   [junit4]   2>   "source":"node_added_trigger",
   [junit4]   2>   "eventTime":800278623797861,
   [junit4]   2>   "eventType":"NODEADDED",
   [junit4]   2>   "properties":{
   [junit4]   2>     "eventTimes":[800278623797861],
   [junit4]   2>     "preferredOperation":"movereplica",
   [junit4]   2>     "_enqueue_time_":800279625007330,
   [junit4]   2>     "nodeNames":["127.0.0.1:39949_solr"],
   [junit4]   2>     "replicaType":"NRT"}} with context properties: {BEFORE_ACTION=[compute_plan]}
   [junit4]   2> 375021 DEBUG (ScheduledTrigger-4263-thread-2) [     ] o.a.s.c.a.NodeAddedTrigger Removing new node from tracking: 127.0.0.1:39949_solr
   [junit4]   2> 375023 INFO  (qtp2062746144-9911) [n:127.0.0.1:38585_solr     ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/metrics params={wt=javabin&version=2&key=solr.core.testNodeAdded.shard1.replica_n1:INDEX.sizeInBytes&key=solr.core.testNodeAdded.shard1.replica_n2:INDEX.sizeInBytes} status=0 QTime=0
   [junit4]   2> 375024 INFO  (qtp2062746144-9913) [n:127.0.0.1:38585_solr     ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/metrics params={prefix=CONTAINER.fs.usableSpace,CONTAINER.fs.totalSpace,CONTAINER.cores&wt=javabin&version=2&group=solr.node} status=0 QTime=0
   [junit4]   2> 375034 INFO  (qtp478109965-9957) [n:127.0.0.1:39949_solr     ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/metrics params={prefix=CONTAINER.fs.usableSpace,CONTAINER.fs.totalSpace,CONTAINER.cores&wt=javabin&version=2&group=solr.node} status=0 QTime=0
   [junit4]   2> 375035 DEBUG (AutoscalingActionExecutor-4264-thread-1) [     ] o.a.s.c.a.ComputePlanAction Computed Plan: action=MOVEREPLICA&collection=testNodeAdded&targetNode=127.0.0.1:39949_solr&inPlaceMove=true&replica=core_node3
   [junit4]   2> 375035 DEBUG (AutoscalingActionExecutor-4264-thread-1) [     ] o.a.s.c.a.SystemLogListener Collection .system missing, skip sending event {
   [junit4]   2>   "id":"2d7d96317c265T6bnnx51i5gi7y2r7s77vlpmri",
   [junit4]   2>   "source":"node_added_trigger",
   [junit4]   2>   "eventTime":800278623797861,
   [junit4]   2>   "eventType":"NODEADDED",
   [junit4]   2>   "properties":{
   [junit4]   2>     "eventTimes":[800278623797861],
   [junit4]   2>     "preferredOperation":"movereplica",
   [junit4]   2>     "_enqueue_time_":800279625007330,
   [junit4]   2>     "nodeNames":["127.0.0.1:39949_solr"],
   [junit4]   2>     "replicaType":"NRT"}}
   [junit4]   2> 375035 DEBUG (AutoscalingActionExecutor-4264-thread-1) [     ] o.a.s.c.a.SystemLogListener Collection .system missing, skip sending event {
   [junit4]   2>   "id":"2d7d96317c265T6bnnx51i5gi7y2r7s77vlpmri",
   [junit4]   2>   "source":"node_added_trigger",
   [junit4]   2>   "eventTime":800278623797861,
   [junit4]   2>   "eventType":"NODEADDED",
   [junit4]   2>   "properties":{
   [junit4]   2>     "eventTimes":[800278623797861],
   [junit4]   2>     "preferredOperation":"movereplica",
   [junit4]   2>     "_enqueue_time_":800279625007330,
   [junit4]   2>     "nodeNames":["127.0.0.1:39949_solr"],
   [junit4]   2>     "replicaType":"NRT"}}
   [junit4]   2> 375035 DEBUG (TEST-ComputePlanActionTest.testNodeAdded-seed#[D6BE127202370C75]) [     ] o.a.s.c.a.ComputePlanActionTest -------------_ FINAL STATE --------------
   [junit4]   2> 375036 DEBUG (AutoscalingActionExecutor-4264-thread-1) [     ] o.a.s.c.a.SystemLogListener Collection .system missing, skip sending event {
   [junit4]   2>   "id":"2d7d96317c265T6bnnx51i5gi7y2r7s77vlpmri",
   [junit4]   2>   "source":"node_added_trigger",
   [junit4]   2>   "eventTime":800278623797861,
   [junit4]   2>   "eventType":"NODEADDED",
   [junit4]   2>   "properties":{
   [junit4]   2>     "eventTimes":[800278623797861],
   [junit4]   2>     "preferredOperation":"movereplica",
   [junit4]   2>     "_enqueue_time_":800279625007330,
   [junit4]   2>     "nodeNames":["127.0.0.1:39949_solr"],
   [junit4]   2>     "replicaType":"NRT"}}
   [junit4]   2> 375036 DEBUG (AutoscalingActionExecutor-4264-thread-1) [     ] o.a.s.c.a.ScheduledTriggers Resuming trigger: node_added_trigger after 5000ms
   [junit4]   2> 375036 DEBUG (AutoscalingActionExecutor-4264-thread-1) [     ] o.a.s.c.a.ScheduledTriggers -- processing took 15 ms for event id=2d7d96317c265T6bnnx51i5gi7y2r7s77vlpmri
   [junit4]   2> 375036 INFO  (qtp2062746144-9914) [n:127.0.0.1:38585_solr     ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/metrics params={prefix=CONTAINER.fs.usableSpace,CONTAINER.cores&wt=javabin&version=2&group=solr.node} status=0 QTime=0
   [junit4]   2> 375037 DEBUG (TEST-ComputePlanActionTest.testNodeAdded-seed#[D6BE127202370C75]) [     ] o.a.s.c.a.ComputePlanActionTest * Node values: 127.0.0.1:38585_solr
   [junit4]   2> {
   [junit4]   2>   "node":"127.0.0.1:38585_solr",
   [junit4]   2>   "cores":2,
   [junit4]   2>   "port":"38585",
   [junit4]   2>   "host":"127.0.0.1",
   [junit4]   2>   "ip_1":"1",
   [junit4]   2>   "ip_3":"0",
   [junit4]   2>   "ip_2":"0",
   [junit4]   2>   "ip_4":"127",
   [junit4]   2>   "freedisk":615.6610069274902}
   [junit4]   2> 375038 INFO  (qtp478109965-9959) [n:127.0.0.1:39949_solr     ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/metrics params={prefix=CONTAINER.fs.usableSpace,CONTAINER.cores&wt=javabin&version=2&group=solr.node} status=0 QTime=0
   [junit4]   2> 375038 DEBUG (TEST-ComputePlanActionTest.testNodeAdded-seed#[D6BE127202370C75]) [     ] o.a.s.c.a.ComputePlanActionTest * Node values: 127.0.0.1:39949_solr
   [junit4]   2> {
   [junit4]   2>   "node":"127.0.0.1:39949_solr",
   [junit4]   2>   "cores":0,
   [junit4]   2>   "port":"39949",
   [junit4]   2>   "host":"127.0.0.1",
   [junit4]   2>   "ip_1":"1",
   [junit4]   2>   "ip_3":"0",
   [junit4]   2>   "ip_2":"0",
   [junit4]   2>   "ip_4":"127",
   [junit4]   2>   "freedisk":615.6610069274902}
   [junit4]   2> 375038 DEBUG (TEST-ComputePlanActionTest.testNodeAdded-seed#[D6BE127202370C75]) [     ] o.a.s.c.a.ComputePlanActionTest * Live nodes: [127.0.0.1:38585_solr, 127.0.0.1:39949_solr]
   [junit4]   2> 375039 DEBUG (TEST-ComputePlanActionTest.testNodeAdded-seed#[D6BE127202370C75]) [     ] o.a.s.c.a.ComputePlanActionTest * Collection testNodeAdded state: DocCollection(testNodeAdded//collections/testNodeAdded/state.json/5)={
   [junit4]   2>   "pullReplicas":"0",
   [junit4]   2>   "replicationFactor":"2",
   [junit4]   2>   "shards":{"shard1":{
   [junit4]   2>       "range":"80000000-7fffffff",
   [junit4]   2>       "state":"active",
   [junit4]   2>       "replicas":{
   [junit4]   2>         "core_node3":{
   [junit4]   2>           "core":"testNodeAdded_shard1_replica_n1",
   [junit4]   2>           "base_url":"https://127.0.0.1:38585/solr",
   [junit4]   2>           "node_name":"127.0.0.1:38585_solr",
   [junit4]   2>           "state":"active",
   [junit4]   2>           "type":"NRT",
   [junit4]   2>           "force_set_state":"false",
   [junit4]   2>           "leader":"true"},
   [junit4]   2>         "core_node4":{
   [junit4]   2>           "core":"testNodeAdded_shard1_replica_n2",
   [junit4]   2>           "base_url":"https://127.0.0.1:38585/solr",
   [junit4]   2>           "node_name":"127.0.0.1:38585_solr",
   [junit4]   2>           "state":"active",
   [junit4]   2>           "type":"NRT",
   [junit4]   2>           "force_set_state":"false"}}}},
   [junit4]   2>   "router":{"name":"compositeId"},
   [junit4]   2>   "maxShardsPerNode":"2",
   [junit4]   2>   "autoAddReplicas":"false",
   [junit4]   2>   "nrtReplicas":"2",
   [junit4]   2>   "tlogReplicas":"0"}
   [junit4]   2> 375039 INFO  (TEST-ComputePlanActionTest.testNodeAdded-seed#[D6BE127202370C75]) [     ] o.a.s.SolrTestCaseJ4 ###Ending testNodeAdded
   [junit4]   2> 375055 INFO  (TEST-ComputePlanActionTest.testSelectedCollectionsByName-seed#[D6BE127202370C7

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

hard_2/terms/shard1
   [junit4]   2> 	6	/solr/collections/testNodeAddedTriggerWithAddReplicaPreferredOp_2Shard_2/terms/shard2
   [junit4]   2> 	6	/solr/collections/testNodeLostTriggerWithDeleteNodePreferredOp_0/terms/shard1
   [junit4]   2> 	6	/solr/collections/testNodeAddedTriggerWithAddReplicaPreferredOp_1Shard_4/terms/shard1
   [junit4]   2> 	6	/solr/collections/testSelected2/state.json
   [junit4]   2> 	5	/solr/collections/testSelected1/state.json
   [junit4]   2> 	5	/solr/collections/testNodeAddedTriggerWithAddReplicaPreferredOpReplicaType_1Shard_1/terms/shard1
   [junit4]   2> 	5	/solr/collections/testNodeAddedTriggerWithAddReplicaPreferredOpReplicaType_1Shard_3/terms/shard1
   [junit4]   2> 	5	/solr/collections/testNodeAddedTriggerWithAddReplicaPreferredOpReplicaType_1Shard_2/terms/shard1
   [junit4]   2> 	5	/solr/collections/testNodeAddedTriggerWithAddReplicaPreferredOp_2Shard_4/state.json
   [junit4]   2> 	5	/solr/collections/testNodeAddedTriggerWithAddReplicaPreferredOpReplicaType_1Shard_4/terms/shard1
   [junit4]   2> 	5	/solr/collections/testNodeAddedTriggerWithAddReplicaPreferredOp_2Shard_3/state.json
   [junit4]   2> 	5	/solr/collections/testNodeAddedTriggerWithAddReplicaPreferredOp_2Shard_1/terms/shard1
   [junit4]   2> 	5	/solr/collections/testNodeAddedTriggerWithAddReplicaPreferredOp_2Shard_1/terms/shard2
   [junit4]   2> 	5	/solr/collections/testNodeAddedTriggerWithAddReplicaPreferredOp_1Shard_2/terms/shard1
   [junit4]   2> 	5	/solr/collections/testNodeAddedTriggerWithAddReplicaPreferredOp_2Shard_0/state.json
   [junit4]   2> 	4	/solr/collections/testNodeAddedTriggerWithAddReplicaPreferredOp_1Shard_3/state.json
   [junit4]   2> 	3	/solr/collections/testNodeAddedTriggerWithAddReplicaPreferredOp_1Shard_1/state.json
   [junit4]   2> 	3	/solr/collections/testNodeAddedTriggerWithAddReplicaPreferredOp_2Shard_0/terms/shard2
   [junit4]   2> 	3	/solr/collections/testNodeAddedTriggerWithAddReplicaPreferredOp_1Shard_2/state.json
   [junit4]   2> 	3	/solr/collections/testNodeAddedTriggerWithAddReplicaPreferredOp_2Shard_0/terms/shard1
   [junit4]   2> 	3	/solr/collections/testNodeAddedTriggerWithAddReplicaPreferredOp_2Shard_2/state.json
   [junit4]   2> 	3	/solr/collections/testNodeAdded/terms/shard1
   [junit4]   2> 	2	/solr/collections/testNodeAddedTriggerWithAddReplicaPreferredOp_1Shard_4/state.json
   [junit4]   2> 	2	/solr/collections/testNodeAddedTriggerWithAddReplicaPreferredOp_2Shard_1/state.json
   [junit4]   2> 	2	/solr/collections/testNodeAddedTriggerWithAddReplicaPreferredOpReplicaType_1Shard_0/terms/shard1
   [junit4]   2> 	2	/solr/collections/testNodeAddedTriggerWithAddReplicaPreferredOp_1Shard_0/terms/shard1
   [junit4]   2> 	2	/solr/collections/testNodeWithMultipleReplicasLost/state.json
   [junit4]   2> 	2	/solr/collections/testNodeLostTriggerWithDeleteNodePreferredOp_0/state.json
   [junit4]   2> 
   [junit4]   2> Maximum concurrent data watches above limit:
   [junit4]   2> 
   [junit4]   2> 	122	/solr/collections/testSelected2/state.json
   [junit4]   2> 	108	/solr/collections/testSelected3/state.json
   [junit4]   2> 	102	/solr/collections/testSelected1/state.json
   [junit4]   2> 	63	/solr/collections/testNodeWithMultipleReplicasLost/state.json
   [junit4]   2> 	52	/solr/aliases.json
   [junit4]   2> 	47	/solr/collections/testNodeAddedTriggerWithAddReplicaPreferredOp_2Shard_4/state.json
   [junit4]   2> 	45	/solr/autoscaling.json
   [junit4]   2> 	44	/solr/collections/testNodeAddedTriggerWithAddReplicaPreferredOp_2Shard_3/state.json
   [junit4]   2> 	28	/solr/collections/testNodeAddedTriggerWithAddReplicaPreferredOp_2Shard_2/state.json
   [junit4]   2> 	27	/solr/clusterstate.json
   [junit4]   2> 	27	/solr/clusterprops.json
   [junit4]   2> 	26	/solr/collections/testNodeAddedTriggerWithAddReplicaPreferredOp_1Shard_3/state.json
   [junit4]   2> 	23	/solr/collections/testNodeAddedTriggerWithAddReplicaPreferredOp_1Shard_1/state.json
   [junit4]   2> 	23	/solr/collections/testNodeLostTriggerWithDeleteNodePreferredOp_0/state.json
   [junit4]   2> 	22	/solr/collections/testNodeAddedTriggerWithAddReplicaPreferredOp_2Shard_1/state.json
   [junit4]   2> 	22	/solr/collections/testNodeAddedTriggerWithAddReplicaPreferredOp_1Shard_2/state.json
   [junit4]   2> 	18	/solr/collections/testNodeAddedTriggerWithAddReplicaPreferredOp_1Shard_4/state.json
   [junit4]   2> 	16	/solr/collections/testNodeAddedTriggerWithAddReplicaPreferredOpReplicaType_1Shard_2/state.json
   [junit4]   2> 	16	/solr/collections/testNodeAddedTriggerWithAddReplicaPreferredOpReplicaType_1Shard_3/state.json
   [junit4]   2> 	16	/solr/collections/testNodeAddedTriggerWithAddReplicaPreferredOpReplicaType_1Shard_4/state.json
   [junit4]   2> 	16	/solr/collections/testNodeAddedTriggerWithAddReplicaPreferredOpReplicaType_1Shard_1/state.json
   [junit4]   2> 	15	/solr/collections/testNodeAddedTriggerWithAddReplicaPreferredOp_2Shard_0/state.json
   [junit4]   2> 	13	/solr/collections/testNodeAddedTriggerWithAddReplicaPreferredOp_1Shard_0/state.json
   [junit4]   2> 	12	/solr/collections/testNodeAdded/state.json
   [junit4]   2> 	12	/solr/collections/testNodeAddedTriggerWithAddReplicaPreferredOpReplicaType_1Shard_0/state.json
   [junit4]   2> 	5	/solr/overseer_elect/election/72110040925732873-127.0.0.1:39949_solr-n_0000000001
   [junit4]   2> 	4	/solr/overseer_elect/election/72110040925732903-127.0.0.1:36733_solr-n_0000000011
   [junit4]   2> 	2	/solr/overseer_elect/election/72110040925732876-127.0.0.1:38501_solr-n_0000000002
   [junit4]   2> 	2	/solr/collections/testSelected1/leader_elect/shard1/election/72110040925732873-core_node3-n_0000000000
   [junit4]   2> 	2	/solr/overseer_elect/election/72110040925732894-127.0.0.1:36379_solr-n_0000000008
   [junit4]   2> 	2	/solr/collections/testNodeWithMultipleReplicasLost/leader_elect/shard1/election/72110040925732903-core_node2-n_0000000000
   [junit4]   2> 
   [junit4]   2> Maximum concurrent children watches above limit:
   [junit4]   2> 
   [junit4]   2> 	544	/solr/overseer/queue
   [junit4]   2> 	275	/solr/live_nodes
   [junit4]   2> 	166	/solr/collections
   [junit4]   2> 	159	/solr/overseer/collection-queue-work
   [junit4]   2> 	11	/solr/autoscaling/events/node_added_trigger
   [junit4]   2> 	9	/solr/autoscaling/events/node_lost_trigger
   [junit4]   2> 	6	/solr/autoscaling/events/.scheduled_maintenance
   [junit4]   2> 	6	/solr/autoscaling/events/.auto_add_replicas
   [junit4]   2> 	6	/solr/overseer/queue-work
   [junit4]   2> 
   [junit4]   2> 455360 INFO  (SUITE-ComputePlanActionTest-seed#[D6BE127202370C75]-worker) [     ] o.a.s.c.ZkTestServer waitForServerDown: 127.0.0.1:32911
   [junit4]   2> 455360 INFO  (SUITE-ComputePlanActionTest-seed#[D6BE127202370C75]-worker) [     ] o.a.s.c.ZkTestServer parse host and port list: 127.0.0.1:32911
   [junit4]   2> 455360 INFO  (SUITE-ComputePlanActionTest-seed#[D6BE127202370C75]-worker) [     ] o.a.s.c.ZkTestServer connecting to 127.0.0.1 32911
   [junit4]   2> NOTE: leaving temporary files on disk at: /home/jenkins/workspace/Lucene-Solr-8.x-Linux/solr/build/solr-core/test/J4/temp/solr.cloud.autoscaling.ComputePlanActionTest_D6BE127202370C75-001
   [junit4]   2> NOTE: test params are: codec=Asserting(Lucene87): {}, docValues:{}, maxPointsInLeafNode=414, maxMBSortInHeap=6.074031207741529, sim=Asserting(RandomSimilarity(queryNorm=true): {}), locale=fr-FR, timezone=SST
   [junit4]   2> NOTE: Linux 5.4.0-45-generic amd64/AdoptOpenJDK 12.0.2 (64-bit)/cpus=16,threads=1,free=238651512,total=536870912
   [junit4]   2> NOTE: All tests run in this JVM: [TestIndexingPerformance, ClusterStateUpdateTest, OverseerTaskQueueTest, ZkShardTermsTest, UpdateRequestProcessorFactoryTest, InfixSuggestersTest, TestValueSourceCache, TestUtilizeNode, PathHierarchyTokenizerFactoryTest, SolrShardReporterTest, SolrCoreTest, TestConfigSetImmutable, StatsReloadRaceTest, HdfsNNFailoverTest, AlternateDirectoryTest, MultiSolrCloudTestCaseTest, DistanceUnitsTest, BlockCacheTest, DistributedUpdateProcessorTest, IndexSizeTriggerTest, BasicDistributedZk2Test, CollectionsAPIAsyncDistributedZkTest, SignatureUpdateProcessorFactoryTest, ConnectionManagerTest, TestLegacyNumericUtils, UnloadDistributedZkTest, ReindexCollectionTest, MetricsHistoryWithAuthIntegrationTest, SpellCheckCollatorTest, XmlUpdateRequestHandlerTest, TestSolrJ, TestRecoveryHdfs, TestReplicationHandlerBackup, TestUnInvertedFieldException, TestExtendedDismaxParser, HighlighterMaxOffsetTest, TestSolrDeletionPolicy2, SpatialRPTFieldTypeTest, VersionInfoTest, TestDocTermOrdsUninvertLimit, TestSchemaResource, ComputePlanActionTest]
   [junit4] Completed [317/919 (1!)] on J4 in 84.06s, 9 tests, 1 error, 1 skipped <<< FAILURES!

[...truncated 49831 lines...]
[repro] Jenkins log URL: https://jenkins.thetaphi.de/job/Lucene-Solr-8.x-Linux/4351/consoleText

[repro] Revision: b313618cc1d104ae8994aad9aa71565562407ee1

[repro] Ant options: "-Dargs=-XX:+UseCompressedOops -XX:+UseG1GC"
[repro] Repro line:  ant test  -Dtestcase=ComputePlanActionTest -Dtests.method=testNodeWithMultipleReplicasLost -Dtests.seed=D6BE127202370C75 -Dtests.multiplier=3 -Dtests.slow=true -Dtests.locale=fr-FR -Dtests.timezone=SST -Dtests.asserts=true -Dtests.file.encoding=UTF-8

[repro] JUnit rest result XML files will be moved to: ./repro-reports
[repro] ant clean

[...truncated 6 lines...]
[repro] Test suites by module:
[repro]    solr/core
[repro]       ComputePlanActionTest
[repro] ant compile-test

[...truncated 3453 lines...]
[repro] ant test-nocompile -Dtests.dups=5 -Dtests.maxfailures=5 -Dtests.class="*.ComputePlanActionTest" -Dtests.showOutput=onerror "-Dargs=-XX:+UseCompressedOops -XX:+UseG1GC" -Dtests.seed=D6BE127202370C75 -Dtests.multiplier=3 -Dtests.slow=true -Dtests.locale=fr-FR -Dtests.timezone=SST -Dtests.asserts=true -Dtests.file.encoding=UTF-8

[...truncated 126 lines...]
[repro] Failures w/original seeds:
[repro]   0/5 failed: org.apache.solr.cloud.autoscaling.ComputePlanActionTest
[repro] Exiting with code 0

[...truncated 61 lines...]