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/02/03 01:12:07 UTC
[JENKINS] Lucene-Solr-8.x-MacOSX (64bit/jdk-11.0.6) - Build # 586 -
Still Unstable!
Build: https://jenkins.thetaphi.de/job/Lucene-Solr-8.x-MacOSX/586/
Java: 64bit/jdk-11.0.6 -XX:+UseCompressedOops -XX:+UseParallelGC
2 tests failed.
FAILED: org.apache.solr.cloud.SystemCollectionCompatTest.testBackCompat
Error Message:
re-indexing warning not found
Stack Trace:
java.lang.AssertionError: re-indexing warning not found
at __randomizedtesting.SeedInfo.seed([CE745378FA90F3F5:BE81F0D19A585A83]:0)
at org.junit.Assert.fail(Assert.java:88)
at org.junit.Assert.assertTrue(Assert.java:41)
at org.apache.solr.cloud.SystemCollectionCompatTest.testBackCompat(SystemCollectionCompatTest.java:215)
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:566)
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:834)
FAILED: org.apache.solr.cloud.autoscaling.MetricTriggerIntegrationTest.testMetricTrigger
Error Message:
The trigger did not fire at all
Stack Trace:
java.lang.AssertionError: The trigger did not fire at all
at __randomizedtesting.SeedInfo.seed([CE745378FA90F3F5:747864F7A57825BA]:0)
at org.junit.Assert.fail(Assert.java:88)
at org.junit.Assert.assertTrue(Assert.java:41)
at org.apache.solr.cloud.autoscaling.MetricTriggerIntegrationTest.testMetricTrigger(MetricTriggerIntegrationTest.java:193)
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:566)
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:834)
Build Log:
[...truncated 14393 lines...]
[junit4] Suite: org.apache.solr.cloud.autoscaling.MetricTriggerIntegrationTest
[junit4] 2> 657380 INFO (SUITE-MetricTriggerIntegrationTest-seed#[CE745378FA90F3F5]-worker) [ ] o.a.s.SolrTestCaseJ4 Created dataDir: /Users/jenkins/workspace/Lucene-Solr-8.x-MacOSX/solr/build/solr-core/test/J0/temp/solr.cloud.autoscaling.MetricTriggerIntegrationTest_CE745378FA90F3F5-001/data-dir-87-001
[junit4] 2> 657380 WARN (SUITE-MetricTriggerIntegrationTest-seed#[CE745378FA90F3F5]-worker) [ ] o.a.s.SolrTestCaseJ4 startTrackingSearchers: numOpens=5 numCloses=5
[junit4] 2> 657380 INFO (SUITE-MetricTriggerIntegrationTest-seed#[CE745378FA90F3F5]-worker) [ ] o.a.s.SolrTestCaseJ4 Using PointFields (NUMERIC_POINTS_SYSPROP=true) w/NUMERIC_DOCVALUES_SYSPROP=false
[junit4] 2> 657381 INFO (SUITE-MetricTriggerIntegrationTest-seed#[CE745378FA90F3F5]-worker) [ ] o.a.s.SolrTestCaseJ4 Randomized ssl (false) 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) w/ MAC_OS_X supressed clientAuth
[junit4] 2> 657381 INFO (SUITE-MetricTriggerIntegrationTest-seed#[CE745378FA90F3F5]-worker) [ ] o.a.s.SolrTestCaseJ4 SecureRandom sanity checks: test.solr.allowed.securerandom=null & java.security.egd=file:/dev/./urandom
[junit4] 2> 657381 INFO (SUITE-MetricTriggerIntegrationTest-seed#[CE745378FA90F3F5]-worker) [ ] o.a.s.c.MiniSolrCloudCluster Starting cluster of 2 servers in /Users/jenkins/workspace/Lucene-Solr-8.x-MacOSX/solr/build/solr-core/test/J0/temp/solr.cloud.autoscaling.MetricTriggerIntegrationTest_CE745378FA90F3F5-001/tempDir-001
[junit4] 2> 657382 INFO (SUITE-MetricTriggerIntegrationTest-seed#[CE745378FA90F3F5]-worker) [ ] o.a.s.c.ZkTestServer STARTING ZK TEST SERVER
[junit4] 2> 657382 INFO (ZkTestServer Run Thread) [ ] o.a.s.c.ZkTestServer client port:0.0.0.0/0.0.0.0:0
[junit4] 2> 657382 INFO (ZkTestServer Run Thread) [ ] o.a.s.c.ZkTestServer Starting server
[junit4] 2> 657483 INFO (SUITE-MetricTriggerIntegrationTest-seed#[CE745378FA90F3F5]-worker) [ ] o.a.s.c.ZkTestServer start zk server on port:57406
[junit4] 2> 657483 INFO (SUITE-MetricTriggerIntegrationTest-seed#[CE745378FA90F3F5]-worker) [ ] o.a.s.c.ZkTestServer waitForServerUp: 127.0.0.1:57406
[junit4] 2> 657483 INFO (SUITE-MetricTriggerIntegrationTest-seed#[CE745378FA90F3F5]-worker) [ ] o.a.s.c.ZkTestServer parse host and port list: 127.0.0.1:57406
[junit4] 2> 657483 INFO (SUITE-MetricTriggerIntegrationTest-seed#[CE745378FA90F3F5]-worker) [ ] o.a.s.c.ZkTestServer connecting to 127.0.0.1 57406
[junit4] 2> 657485 INFO (SUITE-MetricTriggerIntegrationTest-seed#[CE745378FA90F3F5]-worker) [ ] o.a.s.c.c.ConnectionManager Waiting for client to connect to ZooKeeper
[junit4] 2> 657490 INFO (zkConnectionManagerCallback-3302-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 657490 INFO (SUITE-MetricTriggerIntegrationTest-seed#[CE745378FA90F3F5]-worker) [ ] o.a.s.c.c.ConnectionManager Client is connected to ZooKeeper
[junit4] 2> 657494 INFO (SUITE-MetricTriggerIntegrationTest-seed#[CE745378FA90F3F5]-worker) [ ] o.a.s.c.c.ConnectionManager Waiting for client to connect to ZooKeeper
[junit4] 2> 657499 INFO (zkConnectionManagerCallback-3304-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 657499 INFO (SUITE-MetricTriggerIntegrationTest-seed#[CE745378FA90F3F5]-worker) [ ] o.a.s.c.c.ConnectionManager Client is connected to ZooKeeper
[junit4] 2> 657500 INFO (SUITE-MetricTriggerIntegrationTest-seed#[CE745378FA90F3F5]-worker) [ ] o.a.s.c.c.ConnectionManager Waiting for client to connect to ZooKeeper
[junit4] 2> 657503 INFO (zkConnectionManagerCallback-3306-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 657503 INFO (SUITE-MetricTriggerIntegrationTest-seed#[CE745378FA90F3F5]-worker) [ ] o.a.s.c.c.ConnectionManager Client is connected to ZooKeeper
[junit4] 2> 657618 WARN (jetty-launcher-3307-thread-1) [ ] o.e.j.s.h.g.GzipHandler minGzipSize of 0 is inefficient for short content, break even is size 23
[junit4] 2> 657618 WARN (jetty-launcher-3307-thread-2) [ ] o.e.j.s.h.g.GzipHandler minGzipSize of 0 is inefficient for short content, break even is size 23
[junit4] 2> 657618 INFO (jetty-launcher-3307-thread-1) [ ] o.a.s.c.s.e.JettySolrRunner Start Jetty (configured port=0, binding port=0)
[junit4] 2> 657618 INFO (jetty-launcher-3307-thread-1) [ ] o.a.s.c.s.e.JettySolrRunner Trying to start Jetty on port 0 try number 1 ...
[junit4] 2> 657618 INFO (jetty-launcher-3307-thread-2) [ ] o.a.s.c.s.e.JettySolrRunner Start Jetty (configured port=0, binding port=0)
[junit4] 2> 657618 INFO (jetty-launcher-3307-thread-2) [ ] o.a.s.c.s.e.JettySolrRunner Trying to start Jetty on port 0 try number 1 ...
[junit4] 2> 657618 INFO (jetty-launcher-3307-thread-1) [ ] o.e.j.s.Server jetty-9.4.24.v20191120; built: 2019-11-20T21:37:49.771Z; git: 363d5f2df3a8a28de40604320230664b9c793c16; jvm 11.0.6+10
[junit4] 2> 657618 INFO (jetty-launcher-3307-thread-2) [ ] o.e.j.s.Server jetty-9.4.24.v20191120; built: 2019-11-20T21:37:49.771Z; git: 363d5f2df3a8a28de40604320230664b9c793c16; jvm 11.0.6+10
[junit4] 2> 657625 INFO (jetty-launcher-3307-thread-1) [ ] o.e.j.s.session DefaultSessionIdManager workerName=node0
[junit4] 2> 657625 INFO (jetty-launcher-3307-thread-1) [ ] o.e.j.s.session No SessionScavenger set, using defaults
[junit4] 2> 657625 INFO (jetty-launcher-3307-thread-1) [ ] o.e.j.s.session node0 Scavenging every 660000ms
[junit4] 2> 657626 INFO (jetty-launcher-3307-thread-1) [ ] o.e.j.s.h.ContextHandler Started o.e.j.s.ServletContextHandler@4ba3d858{/solr,null,AVAILABLE}
[junit4] 2> 657626 INFO (jetty-launcher-3307-thread-2) [ ] o.e.j.s.session DefaultSessionIdManager workerName=node0
[junit4] 2> 657626 INFO (jetty-launcher-3307-thread-2) [ ] o.e.j.s.session No SessionScavenger set, using defaults
[junit4] 2> 657626 INFO (jetty-launcher-3307-thread-2) [ ] o.e.j.s.session node0 Scavenging every 600000ms
[junit4] 2> 657626 INFO (jetty-launcher-3307-thread-2) [ ] o.e.j.s.h.ContextHandler Started o.e.j.s.ServletContextHandler@a536303{/solr,null,AVAILABLE}
[junit4] 2> 657627 INFO (jetty-launcher-3307-thread-1) [ ] o.e.j.s.AbstractConnector Started ServerConnector@2730723b{HTTP/1.1,[http/1.1, h2c]}{127.0.0.1:57412}
[junit4] 2> 657627 INFO (jetty-launcher-3307-thread-1) [ ] o.e.j.s.Server Started @657687ms
[junit4] 2> 657627 INFO (jetty-launcher-3307-thread-1) [ ] o.a.s.c.s.e.JettySolrRunner Jetty properties: {hostContext=/solr, hostPort=57412}
[junit4] 2> 657628 ERROR (jetty-launcher-3307-thread-1) [ ] o.a.s.u.StartupLoggingUtils Missing Java Option solr.log.dir. Logging may be missing or incomplete.
[junit4] 2> 657628 INFO (jetty-launcher-3307-thread-1) [ ] o.a.s.s.SolrDispatchFilter Using logger factory org.apache.logging.slf4j.Log4jLoggerFactory
[junit4] 2> 657628 INFO (jetty-launcher-3307-thread-2) [ ] o.e.j.s.AbstractConnector Started ServerConnector@5507b1ec{HTTP/1.1,[http/1.1, h2c]}{127.0.0.1:57413}
[junit4] 2> 657628 INFO (jetty-launcher-3307-thread-2) [ ] o.e.j.s.Server Started @657688ms
[junit4] 2> 657628 INFO (jetty-launcher-3307-thread-1) [ ] o.a.s.s.SolrDispatchFilter ___ _ Welcome to Apache Solr™ version 8.5.0
[junit4] 2> 657628 INFO (jetty-launcher-3307-thread-1) [ ] o.a.s.s.SolrDispatchFilter / __| ___| |_ _ Starting in cloud mode on port null
[junit4] 2> 657628 INFO (jetty-launcher-3307-thread-2) [ ] o.a.s.c.s.e.JettySolrRunner Jetty properties: {hostContext=/solr, hostPort=57413}
[junit4] 2> 657628 INFO (jetty-launcher-3307-thread-1) [ ] o.a.s.s.SolrDispatchFilter \__ \/ _ \ | '_| Install dir: /Users/jenkins/workspace/Lucene-Solr-8.x-MacOSX/solr
[junit4] 2> 657628 INFO (jetty-launcher-3307-thread-1) [ ] o.a.s.s.SolrDispatchFilter |___/\___/_|_| Start time: 2020-02-03T00:20:50.791467Z
[junit4] 2> 657628 ERROR (jetty-launcher-3307-thread-2) [ ] o.a.s.u.StartupLoggingUtils Missing Java Option solr.log.dir. Logging may be missing or incomplete.
[junit4] 2> 657628 INFO (jetty-launcher-3307-thread-2) [ ] o.a.s.s.SolrDispatchFilter Using logger factory org.apache.logging.slf4j.Log4jLoggerFactory
[junit4] 2> 657628 INFO (jetty-launcher-3307-thread-2) [ ] o.a.s.s.SolrDispatchFilter ___ _ Welcome to Apache Solr™ version 8.5.0
[junit4] 2> 657628 INFO (jetty-launcher-3307-thread-2) [ ] o.a.s.s.SolrDispatchFilter / __| ___| |_ _ Starting in cloud mode on port null
[junit4] 2> 657628 INFO (jetty-launcher-3307-thread-2) [ ] o.a.s.s.SolrDispatchFilter \__ \/ _ \ | '_| Install dir: /Users/jenkins/workspace/Lucene-Solr-8.x-MacOSX/solr
[junit4] 2> 657628 INFO (jetty-launcher-3307-thread-2) [ ] o.a.s.s.SolrDispatchFilter |___/\___/_|_| Start time: 2020-02-03T00:20:50.791796Z
[junit4] 2> 657629 INFO (jetty-launcher-3307-thread-1) [ ] o.a.s.c.c.ConnectionManager Waiting for client to connect to ZooKeeper
[junit4] 2> 657630 INFO (jetty-launcher-3307-thread-2) [ ] o.a.s.c.c.ConnectionManager Waiting for client to connect to ZooKeeper
[junit4] 2> 657633 INFO (zkConnectionManagerCallback-3311-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 657633 INFO (jetty-launcher-3307-thread-2) [ ] o.a.s.c.c.ConnectionManager Client is connected to ZooKeeper
[junit4] 2> 657634 INFO (zkConnectionManagerCallback-3309-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 657634 INFO (jetty-launcher-3307-thread-1) [ ] o.a.s.c.c.ConnectionManager Client is connected to ZooKeeper
[junit4] 2> 657635 INFO (jetty-launcher-3307-thread-1) [ ] o.a.s.s.SolrDispatchFilter solr.xml found in ZooKeeper. Loading...
[junit4] 2> 657635 INFO (jetty-launcher-3307-thread-2) [ ] o.a.s.s.SolrDispatchFilter solr.xml found in ZooKeeper. Loading...
[junit4] 2> 657830 INFO (jetty-launcher-3307-thread-2) [ ] o.a.s.h.c.HttpShardHandlerFactory Host whitelist initialized: WhitelistHostChecker [whitelistHosts=null, whitelistHostCheckingEnabled=true]
[junit4] 2> 657831 WARN (jetty-launcher-3307-thread-2) [ ] o.e.j.u.s.S.config Trusting all certificates configured for Client@15a7fa81[provider=null,keyStore=null,trustStore=null]
[junit4] 2> 657831 WARN (jetty-launcher-3307-thread-2) [ ] o.e.j.u.s.S.config No Client EndPointIdentificationAlgorithm configured for Client@15a7fa81[provider=null,keyStore=null,trustStore=null]
[junit4] 2> 657833 WARN (jetty-launcher-3307-thread-2) [ ] o.e.j.u.s.S.config Trusting all certificates configured for Client@7e826434[provider=null,keyStore=null,trustStore=null]
[junit4] 2> 657833 WARN (jetty-launcher-3307-thread-2) [ ] o.e.j.u.s.S.config No Client EndPointIdentificationAlgorithm configured for Client@7e826434[provider=null,keyStore=null,trustStore=null]
[junit4] 2> 657834 INFO (jetty-launcher-3307-thread-2) [ ] o.a.s.c.ZkContainer Zookeeper client=127.0.0.1:57406/solr
[junit4] 2> 657835 INFO (jetty-launcher-3307-thread-2) [ ] o.a.s.c.c.ConnectionManager Waiting for client to connect to ZooKeeper
[junit4] 2> 657839 INFO (zkConnectionManagerCallback-3318-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 657839 INFO (jetty-launcher-3307-thread-2) [ ] o.a.s.c.c.ConnectionManager Client is connected to ZooKeeper
[junit4] 2> 657969 INFO (jetty-launcher-3307-thread-2) [n:127.0.0.1:57413_solr ] o.a.s.c.c.ConnectionManager Waiting for client to connect to ZooKeeper
[junit4] 2> 657975 INFO (zkConnectionManagerCallback-3321-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 657975 INFO (jetty-launcher-3307-thread-2) [n:127.0.0.1:57413_solr ] o.a.s.c.c.ConnectionManager Client is connected to ZooKeeper
[junit4] 2> 658118 INFO (jetty-launcher-3307-thread-1) [ ] o.a.s.h.c.HttpShardHandlerFactory Host whitelist initialized: WhitelistHostChecker [whitelistHosts=null, whitelistHostCheckingEnabled=true]
[junit4] 2> 658122 WARN (jetty-launcher-3307-thread-1) [ ] o.e.j.u.s.S.config Trusting all certificates configured for Client@59f88172[provider=null,keyStore=null,trustStore=null]
[junit4] 2> 658122 WARN (jetty-launcher-3307-thread-1) [ ] o.e.j.u.s.S.config No Client EndPointIdentificationAlgorithm configured for Client@59f88172[provider=null,keyStore=null,trustStore=null]
[junit4] 2> 658137 WARN (jetty-launcher-3307-thread-1) [ ] o.e.j.u.s.S.config Trusting all certificates configured for Client@160be7f[provider=null,keyStore=null,trustStore=null]
[junit4] 2> 658137 WARN (jetty-launcher-3307-thread-1) [ ] o.e.j.u.s.S.config No Client EndPointIdentificationAlgorithm configured for Client@160be7f[provider=null,keyStore=null,trustStore=null]
[junit4] 2> 658138 INFO (jetty-launcher-3307-thread-1) [ ] o.a.s.c.ZkContainer Zookeeper client=127.0.0.1:57406/solr
[junit4] 2> 658144 INFO (jetty-launcher-3307-thread-1) [ ] o.a.s.c.c.ConnectionManager Waiting for client to connect to ZooKeeper
[junit4] 2> 658155 INFO (zkConnectionManagerCallback-3329-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 658156 INFO (jetty-launcher-3307-thread-1) [ ] o.a.s.c.c.ConnectionManager Client is connected to ZooKeeper
[junit4] 2> 658271 INFO (jetty-launcher-3307-thread-1) [n:127.0.0.1:57412_solr ] o.a.s.c.c.ConnectionManager Waiting for client to connect to ZooKeeper
[junit4] 2> 658294 INFO (zkConnectionManagerCallback-3331-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 658294 INFO (jetty-launcher-3307-thread-1) [n:127.0.0.1:57412_solr ] o.a.s.c.c.ConnectionManager Client is connected to ZooKeeper
[junit4] 2> 658474 INFO (jetty-launcher-3307-thread-1) [n:127.0.0.1:57412_solr ] o.a.s.c.OverseerElectionContext I am going to be the leader 127.0.0.1:57412_solr
[junit4] 2> 658484 INFO (jetty-launcher-3307-thread-1) [n:127.0.0.1:57412_solr ] o.a.s.c.Overseer Overseer (id=72085986488745992-127.0.0.1:57412_solr-n_0000000000) starting
[junit4] 2> 658578 INFO (OverseerStateUpdate-72085986488745992-127.0.0.1:57412_solr-n_0000000000) [n:127.0.0.1:57412_solr ] o.a.s.c.Overseer Starting to work on the main queue : 127.0.0.1:57412_solr
[junit4] 2> 658582 DEBUG (OverseerAutoScalingTriggerThread-72085986488745992-127.0.0.1:57412_solr-n_0000000000) [ ] o.a.s.c.a.OverseerTriggerThread Adding .auto_add_replicas and .scheduled_maintenance triggers
[junit4] 2> 658584 INFO (jetty-launcher-3307-thread-1) [n:127.0.0.1:57412_solr ] o.a.s.c.ZkController Register node as live in ZooKeeper:/live_nodes/127.0.0.1:57412_solr
[junit4] 2> 658595 DEBUG (OverseerAutoScalingTriggerThread-72085986488745992-127.0.0.1:57412_solr-n_0000000000) [ ] o.a.s.c.a.OverseerTriggerThread Refreshing /autoscaling.json with znode version 1
[junit4] 2> 658595 DEBUG (OverseerAutoScalingTriggerThread-72085986488745992-127.0.0.1:57412_solr-n_0000000000) [ ] o.a.s.c.a.OverseerTriggerThread Current znodeVersion 1, lastZnodeVersion 0
[junit4] 2> 658595 DEBUG (OverseerAutoScalingTriggerThread-72085986488745992-127.0.0.1:57412_solr-n_0000000000) [ ] o.a.s.c.a.OverseerTriggerThread Processed trigger updates upto znodeVersion 1
[junit4] 2> 658600 INFO (zkCallback-3330-thread-1) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (1)
[junit4] 2> 658628 INFO (jetty-launcher-3307-thread-1) [n:127.0.0.1:57412_solr ] o.a.s.p.PackageLoader /packages.json updated to version -1
[junit4] 2> 658629 WARN (jetty-launcher-3307-thread-1) [n:127.0.0.1:57412_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> 658643 DEBUG (OverseerAutoScalingTriggerThread-72085986488745992-127.0.0.1:57412_solr-n_0000000000) [ ] o.a.s.c.a.NodeLostTrigger NodeLostTrigger .auto_add_replicas - Initial livenodes: [127.0.0.1:57412_solr]
[junit4] 2> 658645 DEBUG (OverseerAutoScalingTriggerThread-72085986488745992-127.0.0.1:57412_solr-n_0000000000) [ ] o.a.s.c.a.OverseerTriggerThread -- deactivating old nodeLost / nodeAdded markers
[junit4] 2> 658649 DEBUG (ScheduledTrigger-3101-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> 658649 DEBUG (OverseerAutoScalingTriggerThread-72085986488745992-127.0.0.1:57412_solr-n_0000000000) [ ] o.a.s.c.a.OverseerTriggerThread Current znodeVersion 1, lastZnodeVersion 1
[junit4] 2> 658658 INFO (jetty-launcher-3307-thread-1) [n:127.0.0.1:57412_solr ] o.a.s.h.a.MetricsHistoryHandler No .system collection, keeping metrics history in memory.
[junit4] 2> 658675 INFO (jetty-launcher-3307-thread-1) [n:127.0.0.1:57412_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_57412.solr.node' (registry 'solr.node') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@47171dc1
[junit4] 2> 658675 INFO (jetty-launcher-3307-thread-2) [n:127.0.0.1:57413_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (1)
[junit4] 2> 658680 INFO (jetty-launcher-3307-thread-1) [n:127.0.0.1:57412_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_57412.solr.jvm' (registry 'solr.jvm') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@47171dc1
[junit4] 2> 658681 INFO (jetty-launcher-3307-thread-1) [n:127.0.0.1:57412_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_57412.solr.jetty' (registry 'solr.jetty') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@47171dc1
[junit4] 2> 658682 INFO (jetty-launcher-3307-thread-1) [n:127.0.0.1:57412_solr ] o.a.s.c.CorePropertiesLocator Found 0 core definitions underneath /Users/jenkins/workspace/Lucene-Solr-8.x-MacOSX/solr/build/solr-core/test/J0/temp/solr.cloud.autoscaling.MetricTriggerIntegrationTest_CE745378FA90F3F5-001/tempDir-001/node1/.
[junit4] 2> 658685 INFO (jetty-launcher-3307-thread-2) [n:127.0.0.1:57413_solr ] o.a.s.c.ZkController Publish node=127.0.0.1:57413_solr as DOWN
[junit4] 2> 658688 INFO (jetty-launcher-3307-thread-2) [n:127.0.0.1:57413_solr ] o.a.s.c.TransientSolrCoreCacheDefault Allocating transient cache for 2147483647 transient cores
[junit4] 2> 658688 INFO (jetty-launcher-3307-thread-2) [n:127.0.0.1:57413_solr ] o.a.s.c.ZkController Register node as live in ZooKeeper:/live_nodes/127.0.0.1:57413_solr
[junit4] 2> 658691 INFO (zkCallback-3330-thread-1) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (1) -> (2)
[junit4] 2> 658691 INFO (zkCallback-3320-thread-1) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (1) -> (2)
[junit4] 2> 658694 INFO (jetty-launcher-3307-thread-2) [n:127.0.0.1:57413_solr ] o.a.s.p.PackageLoader /packages.json updated to version -1
[junit4] 2> 658694 WARN (jetty-launcher-3307-thread-2) [n:127.0.0.1:57413_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> 658711 INFO (jetty-launcher-3307-thread-2) [n:127.0.0.1:57413_solr ] o.a.s.h.a.MetricsHistoryHandler No .system collection, keeping metrics history in memory.
[junit4] 2> 658729 INFO (jetty-launcher-3307-thread-2) [n:127.0.0.1:57413_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_57413.solr.node' (registry 'solr.node') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@47171dc1
[junit4] 2> 658735 INFO (jetty-launcher-3307-thread-2) [n:127.0.0.1:57413_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_57413.solr.jvm' (registry 'solr.jvm') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@47171dc1
[junit4] 2> 658735 INFO (jetty-launcher-3307-thread-2) [n:127.0.0.1:57413_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_57413.solr.jetty' (registry 'solr.jetty') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@47171dc1
[junit4] 2> 658736 INFO (jetty-launcher-3307-thread-2) [n:127.0.0.1:57413_solr ] o.a.s.c.CorePropertiesLocator Found 0 core definitions underneath /Users/jenkins/workspace/Lucene-Solr-8.x-MacOSX/solr/build/solr-core/test/J0/temp/solr.cloud.autoscaling.MetricTriggerIntegrationTest_CE745378FA90F3F5-001/tempDir-001/node2/.
[junit4] 2> 658764 INFO (SUITE-MetricTriggerIntegrationTest-seed#[CE745378FA90F3F5]-worker) [ ] o.a.s.c.MiniSolrCloudCluster waitForAllNodes: numServers=2
[junit4] 2> 658765 INFO (SUITE-MetricTriggerIntegrationTest-seed#[CE745378FA90F3F5]-worker) [ ] o.a.s.c.c.ConnectionManager Waiting for client to connect to ZooKeeper
[junit4] 2> 658771 INFO (zkConnectionManagerCallback-3342-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 658771 INFO (SUITE-MetricTriggerIntegrationTest-seed#[CE745378FA90F3F5]-worker) [ ] o.a.s.c.c.ConnectionManager Client is connected to ZooKeeper
[junit4] 2> 658777 INFO (SUITE-MetricTriggerIntegrationTest-seed#[CE745378FA90F3F5]-worker) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (2)
[junit4] 2> 658779 INFO (SUITE-MetricTriggerIntegrationTest-seed#[CE745378FA90F3F5]-worker) [ ] o.a.s.c.s.i.ZkClientClusterStateProvider Cluster at 127.0.0.1:57406/solr ready
[junit4] 2> 658787 INFO (qtp704092533-9373) [n:127.0.0.1:57412_solr ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/autoscaling params={wt=javabin&version=2} status=0 QTime=0
[junit4] 2> 658791 INFO (qtp704092533-9371) [n:127.0.0.1:57412_solr ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/metrics params={prefix=CONTAINER.fs.usableSpace,CONTAINER.fs.totalSpace,CORE.coreName&wt=javabin&version=2&group=solr.node,solr.core} status=0 QTime=0
[junit4] 2> 658793 INFO (qtp1539331300-9375) [n:127.0.0.1:57413_solr ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/metrics params={prefix=CONTAINER.fs.usableSpace,CONTAINER.fs.totalSpace,CORE.coreName&wt=javabin&version=2&group=solr.node,solr.core} status=0 QTime=0
[junit4] 2> 658793 DEBUG (qtp704092533-9376) [n:127.0.0.1:57412_solr ] o.a.s.c.a.AutoScalingHandler Verified autoscaling configuration
[junit4] 2> 658794 INFO (qtp704092533-9376) [n:127.0.0.1:57412_solr ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/cluster/autoscaling params={wt=javabin&version=2} status=0 QTime=6
[junit4] 2> 658795 DEBUG (zkCallback-3330-thread-1) [ ] o.a.s.c.a.OverseerTriggerThread Refreshing /autoscaling.json with znode version 2
[junit4] 2> 658796 DEBUG (OverseerAutoScalingTriggerThread-72085986488745992-127.0.0.1:57412_solr-n_0000000000) [ ] o.a.s.c.a.OverseerTriggerThread Processed trigger updates upto znodeVersion 2
[junit4] 2> 658828 DEBUG (OverseerAutoScalingTriggerThread-72085986488745992-127.0.0.1:57412_solr-n_0000000000) [ ] o.a.s.c.a.OverseerTriggerThread -- deactivating old nodeLost / nodeAdded markers
[junit4] 2> 658833 DEBUG (OverseerAutoScalingTriggerThread-72085986488745992-127.0.0.1:57412_solr-n_0000000000) [ ] o.a.s.c.a.OverseerTriggerThread Current znodeVersion 2, lastZnodeVersion 2
[junit4] 2> 658844 INFO (TEST-MetricTriggerIntegrationTest.testMetricTrigger-seed#[CE745378FA90F3F5]) [ ] o.a.s.SolrTestCaseJ4 ###Starting testMetricTrigger
[junit4] 2> 658846 INFO (qtp704092533-9377) [n:127.0.0.1:57412_solr ] o.a.s.h.a.CollectionsHandler Invoked Collection Action :create with params collection.configName=conf&maxShardsPerNode=2&name=testMetricTrigger&nrtReplicas=2&action=CREATE&numShards=2&wt=javabin&version=2 and sendToOCPQueue=true
[junit4] 2> 658856 INFO (OverseerThreadFactory-3103-thread-1-processing-n:127.0.0.1:57412_solr) [n:127.0.0.1:57412_solr ] o.a.s.c.a.c.CreateCollectionCmd Create collection testMetricTrigger
[junit4] 2> 658992 INFO (OverseerStateUpdate-72085986488745992-127.0.0.1:57412_solr-n_0000000000) [n:127.0.0.1:57412_solr ] o.a.s.c.o.SliceMutator createReplica() {
[junit4] 2> "operation":"ADDREPLICA",
[junit4] 2> "collection":"testMetricTrigger",
[junit4] 2> "shard":"shard1",
[junit4] 2> "core":"testMetricTrigger_shard1_replica_n1",
[junit4] 2> "state":"down",
[junit4] 2> "base_url":"http://127.0.0.1:57412/solr",
[junit4] 2> "type":"NRT",
[junit4] 2> "waitForFinalState":"false"}
[junit4] 2> 659000 INFO (OverseerStateUpdate-72085986488745992-127.0.0.1:57412_solr-n_0000000000) [n:127.0.0.1:57412_solr ] o.a.s.c.o.SliceMutator createReplica() {
[junit4] 2> "operation":"ADDREPLICA",
[junit4] 2> "collection":"testMetricTrigger",
[junit4] 2> "shard":"shard1",
[junit4] 2> "core":"testMetricTrigger_shard1_replica_n2",
[junit4] 2> "state":"down",
[junit4] 2> "base_url":"http://127.0.0.1:57413/solr",
[junit4] 2> "type":"NRT",
[junit4] 2> "waitForFinalState":"false"}
[junit4] 2> 659008 INFO (OverseerStateUpdate-72085986488745992-127.0.0.1:57412_solr-n_0000000000) [n:127.0.0.1:57412_solr ] o.a.s.c.o.SliceMutator createReplica() {
[junit4] 2> "operation":"ADDREPLICA",
[junit4] 2> "collection":"testMetricTrigger",
[junit4] 2> "shard":"shard2",
[junit4] 2> "core":"testMetricTrigger_shard2_replica_n4",
[junit4] 2> "state":"down",
[junit4] 2> "base_url":"http://127.0.0.1:57412/solr",
[junit4] 2> "type":"NRT",
[junit4] 2> "waitForFinalState":"false"}
[junit4] 2> 659016 INFO (OverseerStateUpdate-72085986488745992-127.0.0.1:57412_solr-n_0000000000) [n:127.0.0.1:57412_solr ] o.a.s.c.o.SliceMutator createReplica() {
[junit4] 2> "operation":"ADDREPLICA",
[junit4] 2> "collection":"testMetricTrigger",
[junit4] 2> "shard":"shard2",
[junit4] 2> "core":"testMetricTrigger_shard2_replica_n6",
[junit4] 2> "state":"down",
[junit4] 2> "base_url":"http://127.0.0.1:57413/solr",
[junit4] 2> "type":"NRT",
[junit4] 2> "waitForFinalState":"false"}
[junit4] 2> 659228 INFO (qtp704092533-9371) [n:127.0.0.1:57412_solr x:testMetricTrigger_shard1_replica_n1 ] o.a.s.h.a.CoreAdminOperation core create command qt=/admin/cores&coreNodeName=core_node3&collection.configName=conf&newCollection=true&name=testMetricTrigger_shard1_replica_n1&action=CREATE&numShards=2&collection=testMetricTrigger&shard=shard1&wt=javabin&version=2&replicaType=NRT
[junit4] 2> 659228 INFO (qtp704092533-9371) [n:127.0.0.1:57412_solr x:testMetricTrigger_shard1_replica_n1 ] o.a.s.c.TransientSolrCoreCacheDefault Allocating transient cache for 2147483647 transient cores
[junit4] 2> 659228 INFO (qtp704092533-9376) [n:127.0.0.1:57412_solr x:testMetricTrigger_shard2_replica_n4 ] o.a.s.h.a.CoreAdminOperation core create command qt=/admin/cores&coreNodeName=core_node7&collection.configName=conf&newCollection=true&name=testMetricTrigger_shard2_replica_n4&action=CREATE&numShards=2&collection=testMetricTrigger&shard=shard2&wt=javabin&version=2&replicaType=NRT
[junit4] 2> 659230 INFO (qtp1539331300-9379) [n:127.0.0.1:57413_solr x:testMetricTrigger_shard1_replica_n2 ] o.a.s.h.a.CoreAdminOperation core create command qt=/admin/cores&coreNodeName=core_node5&collection.configName=conf&newCollection=true&name=testMetricTrigger_shard1_replica_n2&action=CREATE&numShards=2&collection=testMetricTrigger&shard=shard1&wt=javabin&version=2&replicaType=NRT
[junit4] 2> 659237 INFO (qtp1539331300-9374) [n:127.0.0.1:57413_solr x:testMetricTrigger_shard2_replica_n6 ] o.a.s.h.a.CoreAdminOperation core create command qt=/admin/cores&coreNodeName=core_node8&collection.configName=conf&newCollection=true&name=testMetricTrigger_shard2_replica_n6&action=CREATE&numShards=2&collection=testMetricTrigger&shard=shard2&wt=javabin&version=2&replicaType=NRT
[junit4] 2> 659653 DEBUG (ScheduledTrigger-3101-thread-3) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 2 and last live nodes: 1
[junit4] 2> 660288 INFO (qtp1539331300-9374) [n:127.0.0.1:57413_solr c:testMetricTrigger s:shard2 r:core_node8 x:testMetricTrigger_shard2_replica_n6 ] o.a.s.c.SolrConfig Using Lucene MatchVersion: 8.5.0
[junit4] 2> 660288 INFO (qtp704092533-9371) [n:127.0.0.1:57412_solr c:testMetricTrigger s:shard1 r:core_node3 x:testMetricTrigger_shard1_replica_n1 ] o.a.s.c.SolrConfig Using Lucene MatchVersion: 8.5.0
[junit4] 2> 660292 INFO (qtp1539331300-9379) [n:127.0.0.1:57413_solr c:testMetricTrigger s:shard1 r:core_node5 x:testMetricTrigger_shard1_replica_n2 ] o.a.s.c.SolrConfig Using Lucene MatchVersion: 8.5.0
[junit4] 2> 660293 INFO (qtp704092533-9376) [n:127.0.0.1:57412_solr c:testMetricTrigger s:shard2 r:core_node7 x:testMetricTrigger_shard2_replica_n4 ] o.a.s.c.SolrConfig Using Lucene MatchVersion: 8.5.0
[junit4] 2> 660303 INFO (qtp1539331300-9374) [n:127.0.0.1:57413_solr c:testMetricTrigger s:shard2 r:core_node8 x:testMetricTrigger_shard2_replica_n6 ] o.a.s.s.IndexSchema [testMetricTrigger_shard2_replica_n6] Schema name=minimal
[junit4] 2> 660303 INFO (qtp704092533-9371) [n:127.0.0.1:57412_solr c:testMetricTrigger s:shard1 r:core_node3 x:testMetricTrigger_shard1_replica_n1 ] o.a.s.s.IndexSchema [testMetricTrigger_shard1_replica_n1] Schema name=minimal
[junit4] 2> 660304 INFO (qtp1539331300-9374) [n:127.0.0.1:57413_solr c:testMetricTrigger s:shard2 r:core_node8 x:testMetricTrigger_shard2_replica_n6 ] o.a.s.s.IndexSchema Loaded schema minimal/1.1 with uniqueid field id
[junit4] 2> 660304 INFO (qtp1539331300-9374) [n:127.0.0.1:57413_solr c:testMetricTrigger s:shard2 r:core_node8 x:testMetricTrigger_shard2_replica_n6 ] o.a.s.c.CoreContainer Creating SolrCore 'testMetricTrigger_shard2_replica_n6' using configuration from configset conf, trusted=true
[junit4] 2> 660304 INFO (qtp704092533-9371) [n:127.0.0.1:57412_solr c:testMetricTrigger s:shard1 r:core_node3 x:testMetricTrigger_shard1_replica_n1 ] o.a.s.s.IndexSchema Loaded schema minimal/1.1 with uniqueid field id
[junit4] 2> 660304 INFO (qtp704092533-9371) [n:127.0.0.1:57412_solr c:testMetricTrigger s:shard1 r:core_node3 x:testMetricTrigger_shard1_replica_n1 ] o.a.s.c.CoreContainer Creating SolrCore 'testMetricTrigger_shard1_replica_n1' using configuration from configset conf, trusted=true
[junit4] 2> 660307 INFO (qtp1539331300-9374) [n:127.0.0.1:57413_solr c:testMetricTrigger s:shard2 r:core_node8 x:testMetricTrigger_shard2_replica_n6 ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_57413.solr.core.testMetricTrigger.shard2.replica_n6' (registry 'solr.core.testMetricTrigger.shard2.replica_n6') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@47171dc1
[junit4] 2> 660307 INFO (qtp704092533-9371) [n:127.0.0.1:57412_solr c:testMetricTrigger s:shard1 r:core_node3 x:testMetricTrigger_shard1_replica_n1 ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_57412.solr.core.testMetricTrigger.shard1.replica_n1' (registry 'solr.core.testMetricTrigger.shard1.replica_n1') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@47171dc1
[junit4] 2> 660307 INFO (qtp1539331300-9374) [n:127.0.0.1:57413_solr c:testMetricTrigger s:shard2 r:core_node8 x:testMetricTrigger_shard2_replica_n6 ] o.a.s.c.SolrCore [[testMetricTrigger_shard2_replica_n6] ] Opening new SolrCore at [/Users/jenkins/workspace/Lucene-Solr-8.x-MacOSX/solr/build/solr-core/test/J0/temp/solr.cloud.autoscaling.MetricTriggerIntegrationTest_CE745378FA90F3F5-001/tempDir-001/node2/testMetricTrigger_shard2_replica_n6], dataDir=[/Users/jenkins/workspace/Lucene-Solr-8.x-MacOSX/solr/build/solr-core/test/J0/temp/solr.cloud.autoscaling.MetricTriggerIntegrationTest_CE745378FA90F3F5-001/tempDir-001/node2/./testMetricTrigger_shard2_replica_n6/data/]
[junit4] 2> 660307 INFO (qtp704092533-9371) [n:127.0.0.1:57412_solr c:testMetricTrigger s:shard1 r:core_node3 x:testMetricTrigger_shard1_replica_n1 ] o.a.s.c.SolrCore [[testMetricTrigger_shard1_replica_n1] ] Opening new SolrCore at [/Users/jenkins/workspace/Lucene-Solr-8.x-MacOSX/solr/build/solr-core/test/J0/temp/solr.cloud.autoscaling.MetricTriggerIntegrationTest_CE745378FA90F3F5-001/tempDir-001/node1/testMetricTrigger_shard1_replica_n1], dataDir=[/Users/jenkins/workspace/Lucene-Solr-8.x-MacOSX/solr/build/solr-core/test/J0/temp/solr.cloud.autoscaling.MetricTriggerIntegrationTest_CE745378FA90F3F5-001/tempDir-001/node1/./testMetricTrigger_shard1_replica_n1/data/]
[junit4] 2> 660307 INFO (qtp1539331300-9379) [n:127.0.0.1:57413_solr c:testMetricTrigger s:shard1 r:core_node5 x:testMetricTrigger_shard1_replica_n2 ] o.a.s.s.IndexSchema [testMetricTrigger_shard1_replica_n2] Schema name=minimal
[junit4] 2> 660308 INFO (qtp704092533-9376) [n:127.0.0.1:57412_solr c:testMetricTrigger s:shard2 r:core_node7 x:testMetricTrigger_shard2_replica_n4 ] o.a.s.s.IndexSchema [testMetricTrigger_shard2_replica_n4] Schema name=minimal
[junit4] 2> 660308 INFO (qtp1539331300-9379) [n:127.0.0.1:57413_solr c:testMetricTrigger s:shard1 r:core_node5 x:testMetricTrigger_shard1_replica_n2 ] o.a.s.s.IndexSchema Loaded schema minimal/1.1 with uniqueid field id
[junit4] 2> 660309 INFO (qtp1539331300-9379) [n:127.0.0.1:57413_solr c:testMetricTrigger s:shard1 r:core_node5 x:testMetricTrigger_shard1_replica_n2 ] o.a.s.c.CoreContainer Creating SolrCore 'testMetricTrigger_shard1_replica_n2' using configuration from configset conf, trusted=true
[junit4] 2> 660309 INFO (qtp1539331300-9379) [n:127.0.0.1:57413_solr c:testMetricTrigger s:shard1 r:core_node5 x:testMetricTrigger_shard1_replica_n2 ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_57413.solr.core.testMetricTrigger.shard1.replica_n2' (registry 'solr.core.testMetricTrigger.shard1.replica_n2') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@47171dc1
[junit4] 2> 660309 INFO (qtp1539331300-9379) [n:127.0.0.1:57413_solr c:testMetricTrigger s:shard1 r:core_node5 x:testMetricTrigger_shard1_replica_n2 ] o.a.s.c.SolrCore [[testMetricTrigger_shard1_replica_n2] ] Opening new SolrCore at [/Users/jenkins/workspace/Lucene-Solr-8.x-MacOSX/solr/build/solr-core/test/J0/temp/solr.cloud.autoscaling.MetricTriggerIntegrationTest_CE745378FA90F3F5-001/tempDir-001/node2/testMetricTrigger_shard1_replica_n2], dataDir=[/Users/jenkins/workspace/Lucene-Solr-8.x-MacOSX/solr/build/solr-core/test/J0/temp/solr.cloud.autoscaling.MetricTriggerIntegrationTest_CE745378FA90F3F5-001/tempDir-001/node2/./testMetricTrigger_shard1_replica_n2/data/]
[junit4] 2> 660309 INFO (qtp704092533-9376) [n:127.0.0.1:57412_solr c:testMetricTrigger s:shard2 r:core_node7 x:testMetricTrigger_shard2_replica_n4 ] o.a.s.s.IndexSchema Loaded schema minimal/1.1 with uniqueid field id
[junit4] 2> 660309 INFO (qtp704092533-9376) [n:127.0.0.1:57412_solr c:testMetricTrigger s:shard2 r:core_node7 x:testMetricTrigger_shard2_replica_n4 ] o.a.s.c.CoreContainer Creating SolrCore 'testMetricTrigger_shard2_replica_n4' using configuration from configset conf, trusted=true
[junit4] 2> 660309 INFO (qtp704092533-9376) [n:127.0.0.1:57412_solr c:testMetricTrigger s:shard2 r:core_node7 x:testMetricTrigger_shard2_replica_n4 ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_57412.solr.core.testMetricTrigger.shard2.replica_n4' (registry 'solr.core.testMetricTrigger.shard2.replica_n4') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@47171dc1
[junit4] 2> 660309 INFO (qtp704092533-9376) [n:127.0.0.1:57412_solr c:testMetricTrigger s:shard2 r:core_node7 x:testMetricTrigger_shard2_replica_n4 ] o.a.s.c.SolrCore [[testMetricTrigger_shard2_replica_n4] ] Opening new SolrCore at [/Users/jenkins/workspace/Lucene-Solr-8.x-MacOSX/solr/build/solr-core/test/J0/temp/solr.cloud.autoscaling.MetricTriggerIntegrationTest_CE745378FA90F3F5-001/tempDir-001/node1/testMetricTrigger_shard2_replica_n4], dataDir=[/Users/jenkins/workspace/Lucene-Solr-8.x-MacOSX/solr/build/solr-core/test/J0/temp/solr.cloud.autoscaling.MetricTriggerIntegrationTest_CE745378FA90F3F5-001/tempDir-001/node1/./testMetricTrigger_shard2_replica_n4/data/]
[junit4] 2> 660402 INFO (qtp704092533-9376) [n:127.0.0.1:57412_solr c:testMetricTrigger s:shard2 r:core_node7 x:testMetricTrigger_shard2_replica_n4 ] o.a.s.u.UpdateHandler Using UpdateLog implementation: org.apache.solr.update.UpdateLog
[junit4] 2> 660402 INFO (qtp704092533-9376) [n:127.0.0.1:57412_solr c:testMetricTrigger s:shard2 r:core_node7 x:testMetricTrigger_shard2_replica_n4 ] o.a.s.u.UpdateLog Initializing UpdateLog: dataDir=null defaultSyncLevel=FLUSH numRecordsToKeep=100 maxNumLogsToKeep=10 numVersionBuckets=65536
[junit4] 2> 660403 INFO (qtp704092533-9371) [n:127.0.0.1:57412_solr c:testMetricTrigger s:shard1 r:core_node3 x:testMetricTrigger_shard1_replica_n1 ] o.a.s.u.UpdateHandler Using UpdateLog implementation: org.apache.solr.update.UpdateLog
[junit4] 2> 660403 INFO (qtp704092533-9371) [n:127.0.0.1:57412_solr c:testMetricTrigger s:shard1 r:core_node3 x:testMetricTrigger_shard1_replica_n1 ] o.a.s.u.UpdateLog Initializing UpdateLog: dataDir=null defaultSyncLevel=FLUSH numRecordsToKeep=100 maxNumLogsToKeep=10 numVersionBuckets=65536
[junit4] 2> 660403 INFO (qtp704092533-9376) [n:127.0.0.1:57412_solr c:testMetricTrigger s:shard2 r:core_node7 x:testMetricTrigger_shard2_replica_n4 ] o.a.s.u.CommitTracker Hard AutoCommit: disabled
[junit4] 2> 660403 INFO (qtp704092533-9376) [n:127.0.0.1:57412_solr c:testMetricTrigger s:shard2 r:core_node7 x:testMetricTrigger_shard2_replica_n4 ] o.a.s.u.CommitTracker Soft AutoCommit: disabled
[junit4] 2> 660403 INFO (qtp1539331300-9374) [n:127.0.0.1:57413_solr c:testMetricTrigger s:shard2 r:core_node8 x:testMetricTrigger_shard2_replica_n6 ] o.a.s.u.UpdateHandler Using UpdateLog implementation: org.apache.solr.update.UpdateLog
[junit4] 2> 660404 INFO (qtp1539331300-9374) [n:127.0.0.1:57413_solr c:testMetricTrigger s:shard2 r:core_node8 x:testMetricTrigger_shard2_replica_n6 ] o.a.s.u.UpdateLog Initializing UpdateLog: dataDir=null defaultSyncLevel=FLUSH numRecordsToKeep=100 maxNumLogsToKeep=10 numVersionBuckets=65536
[junit4] 2> 660404 INFO (qtp1539331300-9379) [n:127.0.0.1:57413_solr c:testMetricTrigger s:shard1 r:core_node5 x:testMetricTrigger_shard1_replica_n2 ] o.a.s.u.UpdateHandler Using UpdateLog implementation: org.apache.solr.update.UpdateLog
[junit4] 2> 660404 INFO (qtp1539331300-9379) [n:127.0.0.1:57413_solr c:testMetricTrigger s:shard1 r:core_node5 x:testMetricTrigger_shard1_replica_n2 ] o.a.s.u.UpdateLog Initializing UpdateLog: dataDir=null defaultSyncLevel=FLUSH numRecordsToKeep=100 maxNumLogsToKeep=10 numVersionBuckets=65536
[junit4] 2> 660404 INFO (qtp704092533-9376) [n:127.0.0.1:57412_solr c:testMetricTrigger s:shard2 r:core_node7 x:testMetricTrigger_shard2_replica_n4 ] o.a.s.s.SolrIndexSearcher Opening [Searcher@1b21086e[testMetricTrigger_shard2_replica_n4] main]
[junit4] 2> 660404 INFO (qtp704092533-9371) [n:127.0.0.1:57412_solr c:testMetricTrigger s:shard1 r:core_node3 x:testMetricTrigger_shard1_replica_n1 ] o.a.s.u.CommitTracker Hard AutoCommit: disabled
[junit4] 2> 660404 INFO (qtp704092533-9371) [n:127.0.0.1:57412_solr c:testMetricTrigger s:shard1 r:core_node3 x:testMetricTrigger_shard1_replica_n1 ] o.a.s.u.CommitTracker Soft AutoCommit: disabled
[junit4] 2> 660405 INFO (qtp1539331300-9374) [n:127.0.0.1:57413_solr c:testMetricTrigger s:shard2 r:core_node8 x:testMetricTrigger_shard2_replica_n6 ] o.a.s.u.CommitTracker Hard AutoCommit: disabled
[junit4] 2> 660405 INFO (qtp704092533-9371) [n:127.0.0.1:57412_solr c:testMetricTrigger s:shard1 r:core_node3 x:testMetricTrigger_shard1_replica_n1 ] o.a.s.s.SolrIndexSearcher Opening [Searcher@558aa8ac[testMetricTrigger_shard1_replica_n1] main]
[junit4] 2> 660405 INFO (qtp1539331300-9374) [n:127.0.0.1:57413_solr c:testMetricTrigger s:shard2 r:core_node8 x:testMetricTrigger_shard2_replica_n6 ] o.a.s.u.CommitTracker Soft AutoCommit: disabled
[junit4] 2> 660406 INFO (qtp1539331300-9379) [n:127.0.0.1:57413_solr c:testMetricTrigger s:shard1 r:core_node5 x:testMetricTrigger_shard1_replica_n2 ] o.a.s.u.CommitTracker Hard AutoCommit: disabled
[junit4] 2> 660406 INFO (qtp1539331300-9379) [n:127.0.0.1:57413_solr c:testMetricTrigger s:shard1 r:core_node5 x:testMetricTrigger_shard1_replica_n2 ] o.a.s.u.CommitTracker Soft AutoCommit: disabled
[junit4] 2> 660406 INFO (qtp1539331300-9374) [n:127.0.0.1:57413_solr c:testMetricTrigger s:shard2 r:core_node8 x:testMetricTrigger_shard2_replica_n6 ] o.a.s.s.SolrIndexSearcher Opening [Searcher@50a9fc35[testMetricTrigger_shard2_replica_n6] main]
[junit4] 2> 660406 INFO (qtp1539331300-9379) [n:127.0.0.1:57413_solr c:testMetricTrigger s:shard1 r:core_node5 x:testMetricTrigger_shard1_replica_n2 ] o.a.s.s.SolrIndexSearcher Opening [Searcher@826d112[testMetricTrigger_shard1_replica_n2] main]
[junit4] 2> 660408 INFO (qtp704092533-9376) [n:127.0.0.1:57412_solr c:testMetricTrigger s:shard2 r:core_node7 x:testMetricTrigger_shard2_replica_n4 ] o.a.s.r.ManagedResourceStorage Configured ZooKeeperStorageIO with znodeBase: /configs/conf
[junit4] 2> 660409 INFO (qtp704092533-9371) [n:127.0.0.1:57412_solr c:testMetricTrigger s:shard1 r:core_node3 x:testMetricTrigger_shard1_replica_n1 ] o.a.s.r.ManagedResourceStorage Configured ZooKeeperStorageIO with znodeBase: /configs/conf
[junit4] 2> 660409 INFO (qtp704092533-9376) [n:127.0.0.1:57412_solr c:testMetricTrigger s:shard2 r:core_node7 x:testMetricTrigger_shard2_replica_n4 ] o.a.s.r.ManagedResourceStorage Loaded null at path _rest_managed.json using ZooKeeperStorageIO:path=/configs/conf
[junit4] 2> 660410 INFO (qtp704092533-9376) [n:127.0.0.1:57412_solr c:testMetricTrigger s:shard2 r:core_node7 x:testMetricTrigger_shard2_replica_n4 ] o.a.s.h.ReplicationHandler Commits will be reserved for 10000ms.
[junit4] 2> 660410 INFO (qtp704092533-9376) [n:127.0.0.1:57412_solr c:testMetricTrigger s:shard2 r:core_node7 x:testMetricTrigger_shard2_replica_n4 ] o.a.s.u.UpdateLog Could not find max version in index or recent updates, using new clock 1657472814754562048
[junit4] 2> 660410 INFO (qtp704092533-9371) [n:127.0.0.1:57412_solr c:testMetricTrigger s:shard1 r:core_node3 x:testMetricTrigger_shard1_replica_n1 ] o.a.s.r.ManagedResourceStorage Loaded null at path _rest_managed.json using ZooKeeperStorageIO:path=/configs/conf
[junit4] 2> 660410 INFO (qtp704092533-9371) [n:127.0.0.1:57412_solr c:testMetricTrigger s:shard1 r:core_node3 x:testMetricTrigger_shard1_replica_n1 ] o.a.s.h.ReplicationHandler Commits will be reserved for 10000ms.
[junit4] 2> 660411 INFO (qtp704092533-9371) [n:127.0.0.1:57412_solr c:testMetricTrigger s:shard1 r:core_node3 x:testMetricTrigger_shard1_replica_n1 ] o.a.s.u.UpdateLog Could not find max version in index or recent updates, using new clock 1657472814755610624
[junit4] 2> 660411 INFO (qtp1539331300-9379) [n:127.0.0.1:57413_solr c:testMetricTrigger s:shard1 r:core_node5 x:testMetricTrigger_shard1_replica_n2 ] o.a.s.r.ManagedResourceStorage Configured ZooKeeperStorageIO with znodeBase: /configs/conf
[junit4] 2> 660411 INFO (qtp1539331300-9374) [n:127.0.0.1:57413_solr c:testMetricTrigger s:shard2 r:core_node8 x:testMetricTrigger_shard2_replica_n6 ] o.a.s.r.ManagedResourceStorage Configured ZooKeeperStorageIO with znodeBase: /configs/conf
[junit4] 2> 660412 INFO (qtp1539331300-9374) [n:127.0.0.1:57413_solr c:testMetricTrigger s:shard2 r:core_node8 x:testMetricTrigger_shard2_replica_n6 ] o.a.s.r.ManagedResourceStorage Loaded null at path _rest_managed.json using ZooKeeperStorageIO:path=/configs/conf
[junit4] 2> 660412 INFO (qtp1539331300-9379) [n:127.0.0.1:57413_solr c:testMetricTrigger s:shard1 r:core_node5 x:testMetricTrigger_shard1_replica_n2 ] o.a.s.r.ManagedResourceStorage Loaded null at path _rest_managed.json using ZooKeeperStorageIO:path=/configs/conf
[junit4] 2> 660413 INFO (qtp1539331300-9379) [n:127.0.0.1:57413_solr c:testMetricTrigger s:shard1 r:core_node5 x:testMetricTrigger_shard1_replica_n2 ] o.a.s.h.ReplicationHandler Commits will be reserved for 10000ms.
[junit4] 2> 660413 INFO (qtp1539331300-9379) [n:127.0.0.1:57413_solr c:testMetricTrigger s:shard1 r:core_node5 x:testMetricTrigger_shard1_replica_n2 ] o.a.s.u.UpdateLog Could not find max version in index or recent updates, using new clock 1657472814757707776
[junit4] 2> 660414 INFO (qtp1539331300-9374) [n:127.0.0.1:57413_solr c:testMetricTrigger s:shard2 r:core_node8 x:testMetricTrigger_shard2_replica_n6 ] o.a.s.h.ReplicationHandler Commits will be reserved for 10000ms.
[junit4] 2> 660414 INFO (qtp1539331300-9374) [n:127.0.0.1:57413_solr c:testMetricTrigger s:shard2 r:core_node8 x:testMetricTrigger_shard2_replica_n6 ] o.a.s.u.UpdateLog Could not find max version in index or recent updates, using new clock 1657472814758756352
[junit4] 2> 660414 INFO (searcherExecutor-3113-thread-1-processing-n:127.0.0.1:57412_solr x:testMetricTrigger_shard1_replica_n1 c:testMetricTrigger s:shard1 r:core_node3) [n:127.0.0.1:57412_solr c:testMetricTrigger s:shard1 r:core_node3 x:testMetricTrigger_shard1_replica_n1 ] o.a.s.c.SolrCore [testMetricTrigger_shard1_replica_n1] Registered new searcher Searcher@558aa8ac[testMetricTrigger_shard1_replica_n1] main{ExitableDirectoryReader(UninvertingDirectoryReader())}
[junit4] 2> 660414 INFO (searcherExecutor-3115-thread-1-processing-n:127.0.0.1:57412_solr x:testMetricTrigger_shard2_replica_n4 c:testMetricTrigger s:shard2 r:core_node7) [n:127.0.0.1:57412_solr c:testMetricTrigger s:shard2 r:core_node7 x:testMetricTrigger_shard2_replica_n4 ] o.a.s.c.SolrCore [testMetricTrigger_shard2_replica_n4] Registered new searcher Searcher@1b21086e[testMetricTrigger_shard2_replica_n4] main{ExitableDirectoryReader(UninvertingDirectoryReader())}
[junit4] 2> 660417 INFO (searcherExecutor-3114-thread-1-processing-n:127.0.0.1:57413_solr x:testMetricTrigger_shard1_replica_n2 c:testMetricTrigger s:shard1 r:core_node5) [n:127.0.0.1:57413_solr c:testMetricTrigger s:shard1 r:core_node5 x:testMetricTrigger_shard1_replica_n2 ] o.a.s.c.SolrCore [testMetricTrigger_shard1_replica_n2] Registered new searcher Searcher@826d112[testMetricTrigger_shard1_replica_n2] main{ExitableDirectoryReader(UninvertingDirectoryReader())}
[junit4] 2> 660419 INFO (searcherExecutor-3112-thread-1-processing-n:127.0.0.1:57413_solr x:testMetricTrigger_shard2_replica_n6 c:testMetricTrigger s:shard2 r:core_node8) [n:127.0.0.1:57413_solr c:testMetricTrigger s:shard2 r:core_node8 x:testMetricTrigger_shard2_replica_n6 ] o.a.s.c.SolrCore [testMetricTrigger_shard2_replica_n6] Registered new searcher Searcher@50a9fc35[testMetricTrigger_shard2_replica_n6] main{ExitableDirectoryReader(UninvertingDirectoryReader())}
[junit4] 2> 660427 INFO (qtp704092533-9371) [n:127.0.0.1:57412_solr c:testMetricTrigger s:shard1 r:core_node3 x:testMetricTrigger_shard1_replica_n1 ] o.a.s.c.ZkShardTerms Successful update of terms at /collections/testMetricTrigger/terms/shard1 to Terms{values={core_node3=0}, version=0}
[junit4] 2> 660427 INFO (qtp704092533-9371) [n:127.0.0.1:57412_solr c:testMetricTrigger s:shard1 r:core_node3 x:testMetricTrigger_shard1_replica_n1 ] o.a.s.c.ShardLeaderElectionContextBase make sure parent is created /collections/testMetricTrigger/leaders/shard1
[junit4] 2> 660431 INFO (qtp1539331300-9374) [n:127.0.0.1:57413_solr c:testMetricTrigger s:shard2 r:core_node8 x:testMetricTrigger_shard2_replica_n6 ] o.a.s.c.ZkShardTerms Successful update of terms at /collections/testMetricTrigger/terms/shard2 to Terms{values={core_node8=0}, version=0}
[junit4] 2> 660432 INFO (qtp1539331300-9374) [n:127.0.0.1:57413_solr c:testMetricTrigger s:shard2 r:core_node8 x:testMetricTrigger_shard2_replica_n6 ] o.a.s.c.ShardLeaderElectionContextBase make sure parent is created /collections/testMetricTrigger/leaders/shard2
[junit4] 2> 660440 INFO (qtp704092533-9376) [n:127.0.0.1:57412_solr c:testMetricTrigger s:shard2 r:core_node7 x:testMetricTrigger_shard2_replica_n4 ] o.a.s.c.ZkShardTerms Successful update of terms at /collections/testMetricTrigger/terms/shard2 to Terms{values={core_node7=0, core_node8=0}, version=1}
[junit4] 2> 660440 INFO (qtp704092533-9376) [n:127.0.0.1:57412_solr c:testMetricTrigger s:shard2 r:core_node7 x:testMetricTrigger_shard2_replica_n4 ] o.a.s.c.ShardLeaderElectionContextBase make sure parent is created /collections/testMetricTrigger/leaders/shard2
[junit4] 2> 660447 INFO (qtp1539331300-9379) [n:127.0.0.1:57413_solr c:testMetricTrigger s:shard1 r:core_node5 x:testMetricTrigger_shard1_replica_n2 ] o.a.s.c.ZkShardTerms Successful update of terms at /collections/testMetricTrigger/terms/shard1 to Terms{values={core_node3=0, core_node5=0}, version=1}
[junit4] 2> 660449 INFO (qtp1539331300-9379) [n:127.0.0.1:57413_solr c:testMetricTrigger s:shard1 r:core_node5 x:testMetricTrigger_shard1_replica_n2 ] o.a.s.c.ShardLeaderElectionContextBase make sure parent is created /collections/testMetricTrigger/leaders/shard1
[junit4] 2> 660456 INFO (qtp704092533-9371) [n:127.0.0.1:57412_solr c:testMetricTrigger s:shard1 r:core_node3 x:testMetricTrigger_shard1_replica_n1 ] o.a.s.c.ShardLeaderElectionContext Waiting until we see more replicas up for shard shard1: total=2 found=1 timeoutin=9996ms
[junit4] 2> 660461 INFO (qtp1539331300-9374) [n:127.0.0.1:57413_solr c:testMetricTrigger s:shard2 r:core_node8 x:testMetricTrigger_shard2_replica_n6 ] o.a.s.c.ShardLeaderElectionContext Enough replicas found to continue.
[junit4] 2> 660461 INFO (qtp1539331300-9374) [n:127.0.0.1:57413_solr c:testMetricTrigger s:shard2 r:core_node8 x:testMetricTrigger_shard2_replica_n6 ] o.a.s.c.ShardLeaderElectionContext I may be the new leader - try and sync
[junit4] 2> 660461 INFO (qtp1539331300-9374) [n:127.0.0.1:57413_solr c:testMetricTrigger s:shard2 r:core_node8 x:testMetricTrigger_shard2_replica_n6 ] o.a.s.c.SyncStrategy Sync replicas to http://127.0.0.1:57413/solr/testMetricTrigger_shard2_replica_n6/
[junit4] 2> 660462 INFO (qtp1539331300-9374) [n:127.0.0.1:57413_solr c:testMetricTrigger s:shard2 r:core_node8 x:testMetricTrigger_shard2_replica_n6 ] o.a.s.u.PeerSync PeerSync: core=testMetricTrigger_shard2_replica_n6 url=http://127.0.0.1:57413/solr START replicas=[http://127.0.0.1:57412/solr/testMetricTrigger_shard2_replica_n4/] nUpdates=100
[junit4] 2> 660463 INFO (qtp1539331300-9374) [n:127.0.0.1:57413_solr c:testMetricTrigger s:shard2 r:core_node8 x:testMetricTrigger_shard2_replica_n6 ] o.a.s.u.PeerSync PeerSync: core=testMetricTrigger_shard2_replica_n6 url=http://127.0.0.1:57413/solr DONE. We have no versions. sync failed.
[junit4] 2> 660465 INFO (qtp704092533-9373) [n:127.0.0.1:57412_solr c:testMetricTrigger s:shard2 r:core_node7 x:testMetricTrigger_shard2_replica_n4 ] o.a.s.c.S.Request [testMetricTrigger_shard2_replica_n4] webapp=/solr path=/get params={distrib=false&qt=/get&fingerprint=false&getVersions=100&wt=javabin&version=2} status=0 QTime=0
[junit4] 2> 660465 INFO (qtp1539331300-9374) [n:127.0.0.1:57413_solr c:testMetricTrigger s:shard2 r:core_node8 x:testMetricTrigger_shard2_replica_n6 ] o.a.s.c.SyncStrategy Leader's attempt to sync with shard failed, moving to the next candidate
[junit4] 2> 660465 INFO (qtp1539331300-9374) [n:127.0.0.1:57413_solr c:testMetricTrigger s:shard2 r:core_node8 x:testMetricTrigger_shard2_replica_n6 ] 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> 660465 INFO (qtp1539331300-9374) [n:127.0.0.1:57413_solr c:testMetricTrigger s:shard2 r:core_node8 x:testMetricTrigger_shard2_replica_n6 ] o.a.s.c.ShardLeaderElectionContextBase Creating leader registration node /collections/testMetricTrigger/leaders/shard2/leader after winning as /collections/testMetricTrigger/leader_elect/shard2/election/72085986488745990-core_node8-n_0000000000
[junit4] 2> 660469 INFO (qtp1539331300-9374) [n:127.0.0.1:57413_solr c:testMetricTrigger s:shard2 r:core_node8 x:testMetricTrigger_shard2_replica_n6 ] o.a.s.c.ShardLeaderElectionContext I am the new leader: http://127.0.0.1:57413/solr/testMetricTrigger_shard2_replica_n6/ shard2
[junit4] 2> 660583 INFO (zkCallback-3320-thread-1) [ ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/testMetricTrigger/state.json] for collection [testMetricTrigger] has occurred - updating... (live nodes size: [2])
[junit4] 2> 660583 INFO (zkCallback-3320-thread-2) [ ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/testMetricTrigger/state.json] for collection [testMetricTrigger] has occurred - updating... (live nodes size: [2])
[junit4] 2> 660584 INFO (qtp1539331300-9374) [n:127.0.0.1:57413_solr c:testMetricTrigger s:shard2 r:core_node8 x:testMetricTrigger_shard2_replica_n6 ] o.a.s.c.ZkController I am the leader, no recovery necessary
[junit4] 2> 660588 INFO (qtp1539331300-9374) [n:127.0.0.1:57413_solr c:testMetricTrigger s:shard2 r:core_node8 x:testMetricTrigger_shard2_replica_n6 ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/cores params={qt=/admin/cores&coreNodeName=core_node8&collection.configName=conf&newCollection=true&name=testMetricTrigger_shard2_replica_n6&action=CREATE&numShards=2&collection=testMetricTrigger&shard=shard2&wt=javabin&version=2&replicaType=NRT} status=0 QTime=1351
[junit4] 2> 660667 DEBUG (ScheduledTrigger-3101-thread-3) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 2 and last live nodes: 2
[junit4] 2> 660693 INFO (zkCallback-3320-thread-2) [ ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/testMetricTrigger/state.json] for collection [testMetricTrigger] has occurred - updating... (live nodes size: [2])
[junit4] 2> 660694 INFO (zkCallback-3320-thread-1) [ ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/testMetricTrigger/state.json] for collection [testMetricTrigger] has occurred - updating... (live nodes size: [2])
[junit4] 2> 660695 INFO (zkCallback-3320-thread-3) [ ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/testMetricTrigger/state.json] for collection [testMetricTrigger] has occurred - updating... (live nodes size: [2])
[junit4] 2> 660959 INFO (qtp704092533-9371) [n:127.0.0.1:57412_solr c:testMetricTrigger s:shard1 r:core_node3 x:testMetricTrigger_shard1_replica_n1 ] o.a.s.c.ShardLeaderElectionContext Enough replicas found to continue.
[junit4] 2> 660959 INFO (qtp704092533-9371) [n:127.0.0.1:57412_solr c:testMetricTrigger s:shard1 r:core_node3 x:testMetricTrigger_shard1_replica_n1 ] o.a.s.c.ShardLeaderElectionContext I may be the new leader - try and sync
[junit4] 2> 660959 INFO (qtp704092533-9371) [n:127.0.0.1:57412_solr c:testMetricTrigger s:shard1 r:core_node3 x:testMetricTrigger_shard1_replica_n1 ] o.a.s.c.SyncStrategy Sync replicas to http://127.0.0.1:57412/solr/testMetricTrigger_shard1_replica_n1/
[junit4] 2> 660961 INFO (qtp704092533-9371) [n:127.0.0.1:57412_solr c:testMetricTrigger s:shard1 r:core_node3 x:testMetricTrigger_shard1_replica_n1 ] o.a.s.u.PeerSync PeerSync: core=testMetricTrigger_shard1_replica_n1 url=http://127.0.0.1:57412/solr START replicas=[http://127.0.0.1:57413/solr/testMetricTrigger_shard1_replica_n2/] nUpdates=100
[junit4] 2> 660961 INFO (qtp704092533-9371) [n:127.0.0.1:57412_solr c:testMetricTrigger s:shard1 r:core_node3 x:testMetricTrigger_shard1_replica_n1 ] o.a.s.u.PeerSync PeerSync: core=testMetricTrigger_shard1_replica_n1 url=http://127.0.0.1:57412/solr DONE. We have no versions. sync failed.
[junit4] 2> 660963 INFO (qtp1539331300-9375) [n:127.0.0.1:57413_solr c:testMetricTrigger s:shard1 r:core_node5 x:testMetricTrigger_shard1_replica_n2 ] o.a.s.c.S.Request [testMetricTrigger_shard1_replica_n2] webapp=/solr path=/get params={distrib=false&qt=/get&fingerprint=false&getVersions=100&wt=javabin&version=2} status=0 QTime=1
[junit4] 2> 660964 INFO (qtp704092533-9371) [n:127.0.0.1:57412_solr c:testMetricTrigger s:shard1 r:core_node3 x:testMetricTrigger_shard1_replica_n1 ] o.a.s.c.SyncStrategy Leader's attempt to sync with shard failed, moving to the next candidate
[junit4] 2> 660964 INFO (qtp704092533-9371) [n:127.0.0.1:57412_solr c:testMetricTrigger s:shard1 r:core_node3 x:testMetricTrigger_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> 660964 INFO (qtp704092533-9371) [n:127.0.0.1:57412_solr c:testMetricTrigger s:shard1 r:core_node3 x:testMetricTrigger_shard1_replica_n1 ] o.a.s.c.ShardLeaderElectionContextBase Creating leader registration node /collections/testMetricTrigger/leaders/shard1/leader after winning as /collections/testMetricTrigger/leader_elect/shard1/election/72085986488745992-core_node3-n_0000000000
[junit4] 2> 660969 INFO (qtp704092533-9371) [n:127.0.0.1:57412_solr c:testMetricTrigger s:shard1 r:core_node3 x:testMetricTrigger_shard1_replica_n1 ] o.a.s.c.ShardLeaderElectionContext I am the new leader: http://127.0.0.1:57412/solr/testMetricTrigger_shard1_replica_n1/ shard1
[junit4] 2> 661073 INFO (zkCallback-3320-thread-3) [ ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/testMetricTrigger/state.json] for collection [testMetricTrigger] has occurred - updating... (live nodes size: [2])
[junit4] 2> 661073 INFO (zkCallback-3330-thread-1) [ ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/testMetricTrigger/state.json] for collection [testMetricTrigger] has occurred - updating... (live nodes size: [2])
[junit4] 2> 661073 INFO (zkCallback-3320-thread-1) [ ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/testMetricTrigger/state.json] for collection [testMetricTrigger] has occurred - updating... (live nodes size: [2])
[junit4] 2> 661073 INFO (zkCallback-3320-thread-2) [ ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/testMetricTrigger/state.json] for collection [testMetricTrigger] has occurred - updating... (live nodes size: [2])
[junit4] 2> 661076 INFO (qtp704092533-9371) [n:127.0.0.1:57412_solr c:testMetricTrigger s:shard1 r:core_node3 x:testMetricTrigger_shard1_replica_n1 ] o.a.s.c.ZkController I am the leader, no recovery necessary
[junit4] 2> 661083 INFO (qtp704092533-9371) [n:127.0.0.1:57412_solr c:testMetricTrigger s:shard1 r:core_node3 x:testMetricTrigger_shard1_replica_n1 ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/cores params={qt=/admin/cores&coreNodeName=core_node3&collection.configName=conf&newCollection=true&name=testMetricTrigger_shard1_replica_n1&action=CREATE&numShards=2&collection=testMetricTrigger&shard=shard1&wt=javabin&version=2&replicaType=NRT} status=0 QTime=1855
[junit4] 2> 661190 INFO (zkCallback-3330-thread-1) [ ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/testMetricTrigger/state.json] for collection [testMetricTrigger] has occurred - updating... (live nodes size: [2])
[junit4] 2> 661191 INFO (zkCallback-3320-thread-2) [ ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/testMetricTrigger/state.json] for collection [testMetricTrigger] has occurred - updating... (live nodes size: [2])
[junit4] 2> 661191 INFO (zkCallback-3320-thread-3) [ ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/testMetricTrigger/state.json] for collection [testMetricTrigger] has occurred - updating... (live nodes size: [2])
[junit4] 2> 661191 INFO (zkCallback-3330-thread-2) [ ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/testMetricTrigger/state.json] for collection [testMetricTrigger] has occurred - updating... (live nodes size: [2])
[junit4] 2> 661191 INFO (zkCallback-3320-thread-1) [ ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/testMetricTrigger/state.json] for collection [testMetricTrigger] has occurred - updating... (live nodes size: [2])
[junit4] 2> 661469 INFO (qtp704092533-9376) [n:127.0.0.1:57412_solr c:testMetricTrigger s:shard2 r:core_node7 x:testMetricTrigger_shard2_replica_n4 ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/cores params={qt=/admin/cores&coreNodeName=core_node7&collection.configName=conf&newCollection=true&name=testMetricTrigger_shard2_replica_n4&action=CREATE&numShards=2&collection=testMetricTrigger&shard=shard2&wt=javabin&version=2&replicaType=NRT} status=0 QTime=2241
[junit4] 2> 661478 INFO (qtp1539331300-9379) [n:127.0.0.1:57413_solr c:testMetricTrigger s:shard1 r:core_node5 x:testMetricTrigger_shard1_replica_n2 ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/cores params={qt=/admin/cores&coreNodeName=core_node5&collection.configName=conf&newCollection=true&name=testMetricTrigger_shard1_replica_n2&action=CREATE&numShards=2&collection=testMetricTrigger&shard=shard1&wt=javabin&version=2&replicaType=NRT} status=0 QTime=2247
[junit4] 2> 661498 INFO (qtp704092533-9377) [n:127.0.0.1:57412_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> 661597 INFO (zkCallback-3330-thread-2) [ ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/testMetricTrigger/state.json] for collection [testMetricTrigger] has occurred - updating... (live nodes size: [2])
[junit4] 2> 661597 INFO (zkCallback-3320-thread-1) [ ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/testMetricTrigger/state.json] for collection [testMetricTrigger] has occurred - updating... (live nodes size: [2])
[junit4] 2> 661597 INFO (zkCallback-3320-thread-2) [ ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/testMetricTrigger/state.json] for collection [testMetricTrigger] has occurred - updating... (live nodes size: [2])
[junit4] 2> 661597 INFO (zkCallback-3320-thread-3) [ ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/testMetricTrigger/state.json] for collection [testMetricTrigger] has occurred - updating... (live nodes size: [2])
[junit4] 2> 661597 INFO (zkCallback-3330-thread-3) [ ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/testMetricTrigger/state.json] for collection [testMetricTrigger] has occurred - updating... (live nodes size: [2])
[junit4] 2> 661599 INFO (qtp704092533-9377) [n:127.0.0.1:57412_solr ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/collections params={collection.configName=conf&maxShardsPerNode=2&name=testMetricTrigger&nrtReplicas=2&action=CREATE&numShards=2&wt=javabin&version=2} status=0 QTime=2752
[junit4] 2> 661599 INFO (TEST-MetricTriggerIntegrationTest.testMetricTrigger-seed#[CE745378FA90F3F5]) [ ] o.a.s.c.MiniSolrCloudCluster waitForActiveCollection: testMetricTrigger
[junit4] 2> 661611 INFO (qtp704092533-9371) [n:127.0.0.1:57412_solr ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/metrics params={wt=javabin&version=2&key=solr.core.testMetricTrigger.shard1.replica_n1:INDEX.sizeInBytes&key=solr.core.testMetricTrigger.shard2.replica_n4:INDEX.sizeInBytes} status=0 QTime=0
[junit4] 2> 661612 INFO (qtp704092533-9376) [n:127.0.0.1:57412_solr ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/metrics params={prefix=CONTAINER.fs.usableSpace,CONTAINER.fs.totalSpace,CORE.coreName&wt=javabin&version=2&group=solr.node,solr.core} status=0 QTime=0
[junit4] 2> 661614 INFO (qtp1539331300-9380) [n:127.0.0.1:57413_solr ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/metrics params={wt=javabin&version=2&key=solr.core.testMetricTrigger.shard2.replica_n6:INDEX.sizeInBytes&key=solr.core.testMetricTrigger.shard1.replica_n2:INDEX.sizeInBytes} status=0 QTime=0
[junit4] 2> 661615 INFO (qtp1539331300-9374) [n:127.0.0.1:57413_solr ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/metrics params={prefix=CONTAINER.fs.usableSpace,CONTAINER.fs.totalSpace,CORE.coreName&wt=javabin&version=2&group=solr.node,solr.core} status=0 QTime=0
[junit4] 2> 661615 DEBUG (qtp704092533-9373) [n:127.0.0.1:57412_solr ] o.a.s.c.a.AutoScalingHandler Verified autoscaling configuration
[junit4] 2> 661616 INFO (qtp704092533-9373) [n:127.0.0.1:57412_solr ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/cluster/autoscaling params={wt=javabin&version=2} status=0 QTime=11
[junit4] 2> 661617 DEBUG (zkCallback-3330-thread-1) [ ] o.a.s.c.a.OverseerTriggerThread Refreshing /autoscaling.json with znode version 3
[junit4] 2> 661617 DEBUG (OverseerAutoScalingTriggerThread-72085986488745992-127.0.0.1:57412_solr-n_0000000000) [ ] o.a.s.c.a.OverseerTriggerThread Processed trigger updates upto znodeVersion 3
[junit4] 2> 661621 INFO (qtp704092533-9377) [n:127.0.0.1:57412_solr ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/metrics params={wt=javabin&version=2&key=solr.core.testMetricTrigger.shard1.replica_n1:INDEX.sizeInBytes&key=solr.core.testMetricTrigger.shard2.replica_n4:INDEX.sizeInBytes} status=0 QTime=0
[junit4] 2> 661622 DEBUG (OverseerAutoScalingTriggerThread-72085986488745992-127.0.0.1:57412_solr-n_0000000000) [ ] o.a.s.c.a.OverseerTriggerThread -- deactivating old nodeLost / nodeAdded markers
[junit4] 2> 661622 INFO (qtp704092533-9371) [n:127.0.0.1:57412_solr ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/metrics params={prefix=CONTAINER.fs.usableSpace,CONTAINER.fs.totalSpace,CORE.coreName&wt=javabin&version=2&group=solr.node,solr.core} status=0 QTime=0
[junit4] 2> 661624 DEBUG (OverseerAutoScalingTriggerThread-72085986488745992-127.0.0.1:57412_solr-n_0000000000) [ ] o.a.s.c.a.OverseerTriggerThread Current znodeVersion 3, lastZnodeVersion 3
[junit4] 2> 661624 INFO (qtp704092533-9376) [n:127.0.0.1:57412_solr ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/metrics params={wt=javabin&version=2&key=solr.core.testMetricTrigger.shard1.replica_n1:INDEX.sizeInBytes} status=0 QTime=0
[junit4] 2> 661624 INFO (qtp1539331300-9374) [n:127.0.0.1:57413_solr ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/metrics params={wt=javabin&version=2&key=solr.core.testMetricTrigger.shard2.replica_n6:INDEX.sizeInBytes&key=solr.core.testMetricTrigger.shard1.replica_n2:INDEX.sizeInBytes} status=0 QTime=0
[junit4] 2> 661625 INFO (qtp1539331300-9380) [n:127.0.0.1:57413_solr ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/metrics params={wt=javabin&version=2&key=solr.core.testMetricTrigger.shard1.replica_n1:INDEX.sizeInBytes} status=0 QTime=0
[junit4] 2> 661626 INFO (qtp1539331300-9375) [n:127.0.0.1:57413_solr ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/metrics params={prefix=CONTAINER.fs.usableSpace,CONTAINER.fs.totalSpace,CORE.coreName&wt=javabin&version=2&group=solr.node,solr.core} status=0 QTime=0
[junit4] 2> 661626 DEBUG (qtp1539331300-9379) [n:127.0.0.1:57413_solr ] o.a.s.c.a.AutoScalingHandler Verified autoscaling configuration
[junit4] 2> 661627 INFO (qtp1539331300-9379) [n:127.0.0.1:57413_solr ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/cluster/autoscaling params={wt=javabin&version=2} status=0 QTime=8
[junit4] 2> 661628 WARN (TEST-MetricTriggerIntegrationTest.testMetricTrigger-seed#[CE745378FA90F3F5]) [ ] o.e.j.s.h.g.GzipHandler minGzipSize of 0 is inefficient for short content, break even is size 23
[junit4] 2> 661628 DEBUG (zkCallback-3330-thread-1) [ ] o.a.s.c.a.OverseerTriggerThread Refreshing /autoscaling.json with znode version 4
[junit4] 2> 661628 INFO (TEST-MetricTriggerIntegrationTest.testMetricTrigger-seed#[CE745378FA90F3F5]) [ ] o.a.s.c.s.e.JettySolrRunner Start Jetty (configured port=0, binding port=0)
[junit4] 2> 661628 INFO (TEST-MetricTriggerIntegrationTest.testMetricTrigger-seed#[CE745378FA90F3F5]) [ ] o.a.s.c.s.e.JettySolrRunner Trying to start Jetty on port 0 try number 1 ...
[junit4] 2> 661628 INFO (TEST-MetricTriggerIntegrationTest.testMetricTrigger-seed#[CE745378FA90F3F5]) [ ] o.e.j.s.Server jetty-9.4.24.v20191120; built: 2019-11-20T21:37:49.771Z; git: 363d5f2df3a8a28de40604320230664b9c793c16; jvm 11.0.6+10
[junit4] 2> 661628 DEBUG (OverseerAutoScalingTriggerThread-72085986488745992-127.0.0.1:57412_solr-n_0000000000) [ ] o.a.s.c.a.OverseerTriggerThread Processed trigger updates upto znodeVersion 4
[junit4] 2> 661630 INFO (TEST-MetricTriggerIntegrationTest.testMetricTrigger-seed#[CE745378FA90F3F5]) [ ] o.e.j.s.session DefaultSessionIdManager workerName=node0
[junit4] 2> 661630 INFO (TEST-MetricTriggerIntegrationTest.testMetricTrigger-seed#[CE745378FA90F3F5]) [ ] o.e.j.s.session No SessionScavenger set, using defaults
[junit4] 2> 661630 INFO (TEST-MetricTriggerIntegrationTest.testMetricTrigger-seed#[CE745378FA90F3F5]) [ ] o.e.j.s.session node0 Scavenging every 600000ms
[junit4] 2> 661630 DEBUG (OverseerAutoScalingTriggerThread-72085986488745992-127.0.0.1:57412_solr-n_0000000000) [ ] o.a.s.c.a.OverseerTriggerThread -- deactivating old nodeLost / nodeAdded markers
[junit4] 2> 661630 INFO (TEST-MetricTriggerIntegrationTest.testMetricTrigger-seed#[CE745378FA90F3F5]) [ ] o.e.j.s.h.ContextHandler Started o.e.j.s.ServletContextHandler@45b071a8{/solr,null,AVAILABLE}
[junit4] 2> 661631 INFO (TEST-MetricTriggerIntegrationTest.testMetricTrigger-seed#[CE745378FA90F3F5]) [ ] o.e.j.s.AbstractConnector Started ServerConnector@70979844{HTTP/1.1,[http/1.1, h2c]}{127.0.0.1:57512}
[junit4] 2> 661632 INFO (TEST-MetricTriggerIntegrationTest.testMetricTrigger-seed#[CE745378FA90F3F5]) [ ] o.e.j.s.Server Started @661692ms
[junit4] 2> 661632 INFO (TEST-MetricTriggerIntegrationTest.testMetricTrigger-seed#[CE745378FA90F3F5]) [ ] o.a.s.c.s.e.JettySolrRunner Jetty properties: {hostContext=/solr, hostPort=57512}
[junit4] 2> 661632 ERROR (TEST-MetricTriggerIntegrationTest.testMetricTrigger-seed#[CE745378FA90F3F5]) [ ] o.a.s.u.StartupLoggingUtils Missing Java Option solr.log.dir. Logging may be missing or incomplete.
[junit4] 2> 661632 INFO (TEST-MetricTriggerIntegrationTest.testMetricTrigger-seed#[CE745378FA90F3F5]) [ ] o.a.s.s.SolrDispatchFilter Using logger factory org.apache.logging.slf4j.Log4jLoggerFactory
[junit4] 2> 661632 INFO (TEST-MetricTriggerIntegrationTest.testMetricTrigger-seed#[CE745378FA90F3F5]) [ ] o.a.s.s.SolrDispatchFilter ___ _ Welcome to Apache Solr™ version 8.5.0
[junit4] 2> 661632 INFO (TEST-MetricTriggerIntegrationTest.testMetricTrigger-seed#[CE745378FA90F3F5]) [ ] o.a.s.s.SolrDispatchFilter / __| ___| |_ _ Starting in cloud mode on port null
[junit4] 2> 661632 INFO (TEST-MetricTriggerIntegrationTest.testMetricTrigger-seed#[CE745378FA90F3F5]) [ ] o.a.s.s.SolrDispatchFilter \__ \/ _ \ | '_| Install dir: /Users/jenkins/workspace/Lucene-Solr-8.x-MacOSX/solr
[junit4] 2> 661632 INFO (TEST-MetricTriggerIntegrationTest.testMetricTrigger-seed#[CE745378FA90F3F5]) [ ] o.a.s.s.SolrDispatchFilter |___/\___/_|_| Start time: 2020-02-03T00:20:54.795437Z
[junit4] 2> 661632 DEBUG (OverseerAutoScalingTriggerThread-72085986488745992-127.0.0.1:57412_solr-n_0000000000) [ ] o.a.s.c.a.OverseerTriggerThread Current znodeVersion 4, lastZnodeVersion 4
[junit4] 2> 661633 INFO (TEST-MetricTriggerIntegrationTest.testMetricTrigger-seed#[CE745378FA90F3F5]) [ ] o.a.s.c.c.ConnectionManager Waiting for client to connect to ZooKeeper
[junit4] 2> 661635 INFO (zkConnectionManagerCallback-3348-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 661635 INFO (TEST-MetricTriggerIntegrationTest.testMetricTrigger-seed#[CE745378FA90F3F5]) [ ] o.a.s.c.c.ConnectionManager Client is connected to ZooKeeper
[junit4] 2> 661636 INFO (TEST-MetricTriggerIntegrationTest.testMetricTrigger-seed#[CE745378FA90F3F5]) [ ] o.a.s.s.SolrDispatchFilter solr.xml found in ZooKeeper. Loading...
[junit4] 2> 661669 DEBUG (ScheduledTrigger-3101-thread-3) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 2 and last live nodes: 2
[junit4] 2> 661802 INFO (TEST-MetricTriggerIntegrationTest.testMetricTrigger-seed#[CE745378FA90F3F5]) [ ] o.a.s.h.c.HttpShardHandlerFactory Host whitelist initialized: WhitelistHostChecker [whitelistHosts=null, whitelistHostCheckingEnabled=true]
[junit4] 2> 661803 WARN (TEST-MetricTriggerIntegrationTest.testMetricTrigger-seed#[CE745378FA90F3F5]) [ ] o.e.j.u.s.S.config Trusting all certificates configured for Client@5f6f4dc3[provider=null,keyStore=null,trustStore=null]
[junit4] 2> 661803 WARN (TEST-MetricTriggerIntegrationTest.testMetricTrigger-seed#[CE745378FA90F3F5]) [ ] o.e.j.u.s.S.config No Client EndPointIdentificationAlgorithm configured for Client@5f6f4dc3[provider=null,keyStore=null,trustStore=null]
[junit4] 2> 661806 WARN (TEST-MetricTriggerIntegrationTest.testMetricTrigger-seed#[CE745378FA90F3F5]) [ ] o.e.j.u.s.S.config Trusting all certificates configured for Client@e9aea38[provider=null,keyStore=null,trustStore=null]
[junit4] 2> 661806 WARN (TEST-MetricTriggerIntegrationTest.testMetricTrigger-seed#[CE745378FA90F3F5]) [ ] o.e.j.u.s.S.config No Client EndPointIdentificationAlgorithm configured for Client@e9aea38[provider=null,keyStore=null,trustStore=null]
[junit4] 2> 661807 INFO (TEST-MetricTriggerIntegrationTest.testMetricTrigger-seed#[CE745378FA90F3F5]) [ ] o.a.s.c.ZkContainer Zookeeper client=127.0.0.1:57406/solr
[junit4] 2> 661807 INFO (TEST-MetricTriggerIntegrationTest.testMetricTrigger-seed#[CE745378FA90F3F5]) [ ] o.a.s.c.c.ConnectionManager Waiting for client to connect to ZooKeeper
[junit4] 2> 661810 INFO (zkConnectionManagerCallback-3355-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 661810 INFO (TEST-MetricTriggerIntegrationTest.testMetricTrigger-seed#[CE745378FA90F3F5]) [ ] o.a.s.c.c.ConnectionManager Client is connected to ZooKeeper
[junit4] 2> 661922 INFO (TEST-MetricTriggerIntegrationTest.testMetricTrigger-seed#[CE745378FA90F3F5]) [n:127.0.0.1:57512_solr ] o.a.s.c.c.ConnectionManager Waiting for client to connect to ZooKeeper
[junit4] 2> 661925 INFO (zkConnectionManagerCallback-3357-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 661925 INFO (TEST-MetricTriggerIntegrationTest.testMetricTrigger-seed#[CE745378FA90F3F5]) [n:127.0.0.1:57512_solr ] o.a.s.c.c.ConnectionManager Client is connected to ZooKeeper
[junit4] 2> 661939 INFO (TEST-MetricTriggerIntegrationTest.testMetricTrigger-seed#[CE745378FA90F3F5]) [n:127.0.0.1:57512_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (2)
[junit4] 2> 661948 INFO (TEST-MetricTriggerIntegrationTest.testMetricTrigger-seed#[CE745378FA90F3F5]) [n:127.0.0.1:57512_solr ] o.a.s.c.ZkController Publish node=127.0.0.1:57512_solr as DOWN
[junit4] 2> 661951 INFO (TEST-MetricTriggerIntegrationTest.testMetricTrigger-seed#[CE745378FA90F3F5]) [n:127.0.0.1:57512_solr ] o.a.s.c.TransientSolrCoreCacheDefault Allocating transient cache for 2147483647 transient cores
[junit4] 2> 661951 INFO (TEST-MetricTriggerIntegrationTest.testMetricTrigger-seed#[CE745378FA90F3F5]) [n:127.0.0.1:57512_solr ] o.a.s.c.ZkController Register node as live in ZooKeeper:/live_nodes/127.0.0.1:57512_solr
[junit4] 2> 661955 INFO (zkCallback-3330-thread-1) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (2) -> (3)
[junit4] 2> 661956 INFO (zkCallback-3341-thread-1) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (2) -> (3)
[junit4] 2> 661956 INFO (zkCallback-3320-thread-1) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (2) -> (3)
[junit4] 2> 661957 INFO (zkCallback-3356-thread-1) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (2) -> (3)
[junit4] 2> 661962 INFO (TEST-MetricTriggerIntegrationTest.testMetricTrigger-seed#[CE745378FA90F3F5]) [n:127.0.0.1:57512_solr ] o.a.s.p.PackageLoader /packages.json updated to version -1
[junit4] 2> 661962 WARN (TEST-MetricTriggerIntegrationTest.testMetricTrigger-seed#[CE745378FA90F3F5]) [n:127.0.0.1:57512_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> 661978 INFO (TEST-MetricTriggerIntegrationTest.testMetricTrigger-seed#[CE745378FA90F3F5]) [n:127.0.0.1:57512_solr ] o.a.s.h.a.MetricsHistoryHandler No .system collection, keeping metrics history in memory.
[junit4] 2> 662000 INFO (TEST-MetricTriggerIntegrationTest.testMetricTrigger-seed#[CE745378FA90F3F5]) [n:127.0.0.1:57512_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_57512.solr.node' (registry 'solr.node') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@47171dc1
[junit4] 2> 662012 INFO (TEST-MetricTriggerIntegrationTest.testMetricTrigger-seed#[CE745378FA90F3F5]) [n:127.0.0.1:57512_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_57512.solr.jvm' (registry 'solr.jvm') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@47171dc1
[junit4] 2> 662013 INFO (TEST-MetricTriggerIntegrationTest.testMetricTrigger-seed#[CE745378FA90F3F5]) [n:127.0.0.1:57512_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_57512.solr.jetty' (registry 'solr.jetty') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@47171dc1
[junit4] 2> 662015 INFO (TEST-MetricTriggerIntegrationTest.testMetricTrigger-seed#[CE745378FA90F3F5]) [n:127.0.0.1:57512_solr ] o.a.s.c.CorePropertiesLocator Found 0 core definitions underneath /Users/jenkins/workspace/Lucene-Solr-8.x-MacOSX/solr/build/solr-core/test/J0/temp/solr.cloud.autoscaling.MetricTriggerIntegrationTest_CE745378FA90F3F5-001/tempDir-001/node3/.
[junit4] 2> 662057 WARN (TEST-MetricTriggerIntegrationTest.testMetricTrigger-seed#[CE745378FA90F3F5]) [ ] o.e.j.s.h.g.GzipHandler minGzipSize of 0 is inefficient for short content, break even is size 23
[junit4] 2> 662057 INFO (TEST-MetricTriggerIntegrationTest.testMetricTrigger-seed#[CE745378FA90F3F5]) [ ] o.a.s.c.s.e.JettySolrRunner Start Jetty (configured port=0, binding port=0)
[junit4] 2> 662057 INFO (TEST-MetricTriggerIntegrationTest.testMetricTrigger-seed#[CE745378FA90F3F5]) [ ] o.a.s.c.s.e.JettySolrRunner Trying to start Jetty on port 0 tr
[...truncated too long message...]
[1])
[junit4] 2> 226260 INFO (qtp260043672-61) [n:127.0.0.1:63111_solr ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/collections params={name=.system&action=DELETE&wt=javabin&version=2} status=0 QTime=647
[junit4] 2> 226473 INFO (TEST-SystemCollectionCompatTest.testBackCompat-seed#[CE745378FA90F3F5]) [ ] o.a.s.SolrTestCaseJ4 ###Ending testBackCompat
[junit4] 2> NOTE: reproduce with: ant test -Dtestcase=SystemCollectionCompatTest -Dtests.method=testBackCompat -Dtests.seed=CE745378FA90F3F5 -Dtests.slow=true -Dtests.badapples=true -Dtests.locale=en-BW -Dtests.timezone=Pacific/Noumea -Dtests.asserts=true -Dtests.file.encoding=UTF-8
[junit4] FAILURE 206s J4 | SystemCollectionCompatTest.testBackCompat <<<
[junit4] > Throwable #1: java.lang.AssertionError: re-indexing warning not found
[junit4] > at __randomizedtesting.SeedInfo.seed([CE745378FA90F3F5:BE81F0D19A585A83]:0)
[junit4] > at org.apache.solr.cloud.SystemCollectionCompatTest.testBackCompat(SystemCollectionCompatTest.java:215)
[junit4] > at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
[junit4] > at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
[junit4] > at java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
[junit4] > at java.base/java.lang.reflect.Method.invoke(Method.java:566)
[junit4] > at java.base/java.lang.Thread.run(Thread.java:834)
[junit4] 2> 226660 INFO (jetty-closer-59984-thread-1) [ ] o.a.s.c.CoreContainer Shutting down CoreContainer instance=185929905
[junit4] 2> 226660 INFO (jetty-closer-59984-thread-1) [ ] o.a.s.c.ZkController Remove node as live in ZooKeeper:/live_nodes/127.0.0.1:63111_solr
[junit4] 2> 226668 INFO (jetty-closer-59984-thread-1) [ ] o.a.s.c.ZkController Publish this node as DOWN...
[junit4] 2> 226668 INFO (jetty-closer-59984-thread-1) [ ] o.a.s.c.ZkController Publish node=127.0.0.1:63111_solr as DOWN
[junit4] 2> 226893 INFO (jetty-closer-59984-thread-1) [ ] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.node, tag=null
[junit4] 2> 226894 INFO (jetty-closer-59984-thread-1) [ ] o.a.s.m.r.SolrJmxReporter Closing reporter [org.apache.solr.metrics.reporters.SolrJmxReporter@13de68f: rootName = solr_63111, domain = solr.node, service url = null, agent id = null] for registry solr.node / com.codahale.metrics.MetricRegistry@9a8dc7d
[junit4] 2> 226903 INFO (jetty-closer-59984-thread-1) [ ] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.jvm, tag=null
[junit4] 2> 226904 INFO (jetty-closer-59984-thread-1) [ ] o.a.s.m.r.SolrJmxReporter Closing reporter [org.apache.solr.metrics.reporters.SolrJmxReporter@34417cd2: rootName = solr_63111, domain = solr.jvm, service url = null, agent id = null] for registry solr.jvm / com.codahale.metrics.MetricRegistry@74f453d9
[junit4] 2> 226907 INFO (jetty-closer-59984-thread-1) [ ] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.jetty, tag=null
[junit4] 2> 226907 INFO (jetty-closer-59984-thread-1) [ ] o.a.s.m.r.SolrJmxReporter Closing reporter [org.apache.solr.metrics.reporters.SolrJmxReporter@7603cc14: rootName = solr_63111, domain = solr.jetty, service url = null, agent id = null] for registry solr.jetty / com.codahale.metrics.MetricRegistry@1513b400
[junit4] 2> 226907 INFO (jetty-closer-59984-thread-1) [ ] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.cluster, tag=null
[junit4] 2> 226912 INFO (closeThreadPool-59988-thread-1) [ ] o.a.s.c.Overseer Overseer (id=72086165295661063-127.0.0.1:63111_solr-n_0000000001) closing
[junit4] 2> 226913 INFO (OverseerStateUpdate-72086165295661063-127.0.0.1:63111_solr-n_0000000001) [n:127.0.0.1:63111_solr ] o.a.s.c.Overseer Overseer Loop exiting : 127.0.0.1:63111_solr
[junit4] 2> 226913 INFO (OverseerAutoScalingTriggerThread-72086165295661063-127.0.0.1:63111_solr-n_0000000001) [ ] o.a.s.c.a.OverseerTriggerThread OverseerTriggerThread woken up but we are closed, exiting.
[junit4] 2> 226975 INFO (closeThreadPool-59988-thread-2) [ ] o.a.s.c.Overseer Overseer (id=72086165295661063-127.0.0.1:63111_solr-n_0000000001) closing
[junit4] 2> 227094 INFO (jetty-closer-59984-thread-1) [ ] o.a.s.c.Overseer Overseer (id=72086165295661063-127.0.0.1:63111_solr-n_0000000001) closing
[junit4] 2> 227114 INFO (jetty-closer-59984-thread-1) [ ] o.e.j.s.AbstractConnector Stopped ServerConnector@75922f8b{HTTP/1.1,[http/1.1, h2c]}{127.0.0.1:0}
[junit4] 2> 227116 INFO (jetty-closer-59984-thread-1) [ ] o.e.j.s.h.ContextHandler Stopped o.e.j.s.ServletContextHandler@7e387f46{/solr,null,UNAVAILABLE}
[junit4] 2> 227117 INFO (jetty-closer-59984-thread-1) [ ] o.e.j.s.session node0 Stopped scavenging
[junit4] 2> 227135 INFO (SUITE-SystemCollectionCompatTest-seed#[CE745378FA90F3F5]-worker) [ ] o.a.s.c.ZkTestServer Shutting down ZkTestServer.
[junit4] 2> 227406 WARN (ZkTestServer Run Thread) [ ] o.a.s.c.ZkTestServer Watch limit violations:
[junit4] 2> Maximum concurrent create/delete watches above limit:
[junit4] 2>
[junit4] 2> 9 /solr/configs/.system/managed-schema
[junit4] 2> 8 /solr/clusterprops.json
[junit4] 2> 8 /solr/aliases.json
[junit4] 2> 8 /solr/collections/.system/terms/shard1
[junit4] 2> 6 /solr/configs/.system
[junit4] 2> 5 /solr/collections/.system/collectionprops.json
[junit4] 2> 3 /solr/collections/.system/state.json
[junit4] 2> 2 /solr/packages.json
[junit4] 2> 2 /solr/security.json
[junit4] 2>
[junit4] 2> Maximum concurrent data watches above limit:
[junit4] 2>
[junit4] 2> 25 /solr/collections/.system/state.json
[junit4] 2> 8 /solr/clusterstate.json
[junit4] 2> 5 /solr/aliases.json
[junit4] 2> 3 /solr/configs/.system/managed-schema
[junit4] 2> 2 /solr/autoscaling.json
[junit4] 2>
[junit4] 2> Maximum concurrent children watches above limit:
[junit4] 2>
[junit4] 2> 28 /solr/overseer/queue
[junit4] 2> 20 /solr/overseer/collection-queue-work
[junit4] 2> 16 /solr/collections
[junit4] 2> 15 /solr/live_nodes
[junit4] 2> 2 /solr/autoscaling/events/.scheduled_maintenance
[junit4] 2> 2 /solr/autoscaling/events/.auto_add_replicas
[junit4] 2> 2 /solr/overseer/queue-work
[junit4] 2>
[junit4] 2> 227599 INFO (SUITE-SystemCollectionCompatTest-seed#[CE745378FA90F3F5]-worker) [ ] o.a.s.c.ZkTestServer waitForServerDown: 127.0.0.1:63073
[junit4] 2> 227599 INFO (SUITE-SystemCollectionCompatTest-seed#[CE745378FA90F3F5]-worker) [ ] o.a.s.c.ZkTestServer parse host and port list: 127.0.0.1:63073
[junit4] 2> 227599 INFO (SUITE-SystemCollectionCompatTest-seed#[CE745378FA90F3F5]-worker) [ ] o.a.s.c.ZkTestServer connecting to 127.0.0.1 63073
[junit4] 2> NOTE: leaving temporary files on disk at: /Users/jenkins/workspace/Lucene-Solr-8.x-MacOSX/solr/build/solr-core/test/J4/temp/solr.cloud.SystemCollectionCompatTest_CE745378FA90F3F5-001
[junit4] 2> NOTE: test params are: codec=CheapBastard, sim=Asserting(org.apache.lucene.search.similarities.AssertingSimilarity@7814e1ec), locale=en-BW, timezone=Pacific/Noumea
[junit4] 2> NOTE: Mac OS X 10.14.6 x86_64/AdoptOpenJDK 11.0.6 (64-bit)/cpus=6,threads=2,free=108701632,total=235929600
[junit4] 2> NOTE: All tests run in this JVM: [SystemCollectionCompatTest]
[junit4] Completed [10/10 (2!)] on J4 in 225.33s, 1 test, 1 failure <<< FAILURES!
[...truncated 15 lines...]
BUILD FAILED
/Users/jenkins/workspace/Lucene-Solr-8.x-MacOSX/lucene/common-build.xml:1594: The following error occurred while executing this line:
/Users/jenkins/workspace/Lucene-Solr-8.x-MacOSX/lucene/common-build.xml:1121: There were test failures: 10 suites, 10 tests, 2 failures [seed: CE745378FA90F3F5]
Total time: 4 minutes 55 seconds
[repro] Setting last failure code to 256
[repro] Failures w/original seeds:
[repro] 0/5 failed: org.apache.solr.cloud.autoscaling.MetricTriggerIntegrationTest
[repro] 2/5 failed: org.apache.solr.cloud.SystemCollectionCompatTest
[repro] Exiting with code 256
+ mv lucene/build lucene/build.repro
+ mv solr/build solr/build.repro
+ mv lucene/build.orig lucene/build
+ mv solr/build.orig solr/build
Archiving artifacts
Setting ANT_1_8_2_HOME=/Users/jenkins/tools/hudson.tasks.Ant_AntInstallation/ANT_1.8.2
[WARNINGS] Parsing warnings in console log with parser Java Compiler (javac)
Setting ANT_1_8_2_HOME=/Users/jenkins/tools/hudson.tasks.Ant_AntInstallation/ANT_1.8.2
No credentials specified
Setting ANT_1_8_2_HOME=/Users/jenkins/tools/hudson.tasks.Ant_AntInstallation/ANT_1.8.2
<Git Blamer> Using GitBlamer to create author and commit information for all warnings.
<Git Blamer> GIT_COMMIT=34d299018e24e10d3b60dc3dce4354039bc765dd, workspace=/Users/jenkins/workspace/Lucene-Solr-8.x-MacOSX
[WARNINGS] Computing warning deltas based on reference build #585
Recording test results
Setting ANT_1_8_2_HOME=/Users/jenkins/tools/hudson.tasks.Ant_AntInstallation/ANT_1.8.2
Build step 'Publish JUnit test result report' changed build result to UNSTABLE
Email was triggered for: Unstable (Test Failures)
Sending email for trigger: Unstable (Test Failures)
Setting ANT_1_8_2_HOME=/Users/jenkins/tools/hudson.tasks.Ant_AntInstallation/ANT_1.8.2
Setting ANT_1_8_2_HOME=/Users/jenkins/tools/hudson.tasks.Ant_AntInstallation/ANT_1.8.2
Setting ANT_1_8_2_HOME=/Users/jenkins/tools/hudson.tasks.Ant_AntInstallation/ANT_1.8.2
Setting ANT_1_8_2_HOME=/Users/jenkins/tools/hudson.tasks.Ant_AntInstallation/ANT_1.8.2
Setting ANT_1_8_2_HOME=/Users/jenkins/tools/hudson.tasks.Ant_AntInstallation/ANT_1.8.2
Setting ANT_1_8_2_HOME=/Users/jenkins/tools/hudson.tasks.Ant_AntInstallation/ANT_1.8.2
[JENKINS] Lucene-Solr-8.x-MacOSX (64bit/jdk1.8.0) - Build # 587 -
Still Unstable!
Posted by Policeman Jenkins Server <je...@thetaphi.de>.
Build: https://jenkins.thetaphi.de/job/Lucene-Solr-8.x-MacOSX/587/
Java: 64bit/jdk1.8.0 -XX:-UseCompressedOops -XX:+UseSerialGC
1 tests failed.
FAILED: org.apache.solr.cloud.autoscaling.ComputePlanActionTest.testNodeAdded
Error Message:
Trigger was not fired even after 5 seconds
Stack Trace:
java.lang.AssertionError: Trigger was not fired even after 5 seconds
at __randomizedtesting.SeedInfo.seed([A827C9A252A9AF04:CDE49FD5F00A0707]:0)
at org.junit.Assert.fail(Assert.java:88)
at org.junit.Assert.assertTrue(Assert.java:41)
at org.apache.solr.cloud.autoscaling.ComputePlanActionTest.testNodeAdded(ComputePlanActionTest.java:386)
at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
at java.lang.reflect.Method.invoke(Method.java:498)
at com.carrotsearch.randomizedtesting.RandomizedRunner.invoke(RandomizedRunner.java: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 com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at org.apache.lucene.util.TestRuleAssertionsRequired$1.evaluate(TestRuleAssertionsRequired.java:53)
at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:47)
at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:64)
at org.apache.lucene.util.TestRuleIgnoreTestSuites$1.evaluate(TestRuleIgnoreTestSuites.java:54)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:368)
at java.lang.Thread.run(Thread.java:748)
Build Log:
[...truncated 14168 lines...]
[junit4] Suite: org.apache.solr.cloud.autoscaling.ComputePlanActionTest
[junit4] 2> 541894 INFO (SUITE-ComputePlanActionTest-seed#[A827C9A252A9AF04]-worker) [ ] o.a.s.SolrTestCaseJ4 SecureRandom sanity checks: test.solr.allowed.securerandom=null & java.security.egd=file:/dev/./urandom
[junit4] 2> 541895 INFO (SUITE-ComputePlanActionTest-seed#[A827C9A252A9AF04]-worker) [ ] o.a.s.SolrTestCaseJ4 Created dataDir: /Users/jenkins/workspace/Lucene-Solr-8.x-MacOSX/solr/build/solr-core/test/J3/temp/solr.cloud.autoscaling.ComputePlanActionTest_A827C9A252A9AF04-001/data-dir-60-001
[junit4] 2> 541895 WARN (SUITE-ComputePlanActionTest-seed#[A827C9A252A9AF04]-worker) [ ] o.a.s.SolrTestCaseJ4 startTrackingSearchers: numOpens=2 numCloses=2
[junit4] 2> 541895 INFO (SUITE-ComputePlanActionTest-seed#[A827C9A252A9AF04]-worker) [ ] o.a.s.SolrTestCaseJ4 Using TrieFields (NUMERIC_POINTS_SYSPROP=false) w/NUMERIC_DOCVALUES_SYSPROP=true
[junit4] 2> 541900 INFO (SUITE-ComputePlanActionTest-seed#[A827C9A252A9AF04]-worker) [ ] o.a.s.SolrTestCaseJ4 Randomized ssl (false) and clientAuth (false) via: @org.apache.solr.util.RandomizeSSL(reason=, value=NaN, ssl=NaN, clientAuth=NaN) w/ MAC_OS_X supressed clientAuth
[junit4] 2> 541901 INFO (SUITE-ComputePlanActionTest-seed#[A827C9A252A9AF04]-worker) [ ] o.a.s.c.MiniSolrCloudCluster Starting cluster of 1 servers in /Users/jenkins/workspace/Lucene-Solr-8.x-MacOSX/solr/build/solr-core/test/J3/temp/solr.cloud.autoscaling.ComputePlanActionTest_A827C9A252A9AF04-001/tempDir-001
[junit4] 2> 541901 INFO (SUITE-ComputePlanActionTest-seed#[A827C9A252A9AF04]-worker) [ ] o.a.s.c.ZkTestServer STARTING ZK TEST SERVER
[junit4] 2> 541901 INFO (ZkTestServer Run Thread) [ ] o.a.s.c.ZkTestServer client port:0.0.0.0/0.0.0.0:0
[junit4] 2> 541901 INFO (ZkTestServer Run Thread) [ ] o.a.s.c.ZkTestServer Starting server
[junit4] 2> 542001 INFO (SUITE-ComputePlanActionTest-seed#[A827C9A252A9AF04]-worker) [ ] o.a.s.c.ZkTestServer start zk server on port:65486
[junit4] 2> 542001 INFO (SUITE-ComputePlanActionTest-seed#[A827C9A252A9AF04]-worker) [ ] o.a.s.c.ZkTestServer waitForServerUp: 127.0.0.1:65486
[junit4] 2> 542002 INFO (SUITE-ComputePlanActionTest-seed#[A827C9A252A9AF04]-worker) [ ] o.a.s.c.ZkTestServer parse host and port list: 127.0.0.1:65486
[junit4] 2> 542002 INFO (SUITE-ComputePlanActionTest-seed#[A827C9A252A9AF04]-worker) [ ] o.a.s.c.ZkTestServer connecting to 127.0.0.1 65486
[junit4] 2> 542004 INFO (SUITE-ComputePlanActionTest-seed#[A827C9A252A9AF04]-worker) [ ] o.a.s.c.c.ConnectionManager Waiting for client to connect to ZooKeeper
[junit4] 2> 542011 INFO (zkConnectionManagerCallback-2395-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 542011 INFO (SUITE-ComputePlanActionTest-seed#[A827C9A252A9AF04]-worker) [ ] o.a.s.c.c.ConnectionManager Client is connected to ZooKeeper
[junit4] 2> 542015 INFO (SUITE-ComputePlanActionTest-seed#[A827C9A252A9AF04]-worker) [ ] o.a.s.c.c.ConnectionManager Waiting for client to connect to ZooKeeper
[junit4] 2> 542018 INFO (zkConnectionManagerCallback-2397-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 542018 INFO (SUITE-ComputePlanActionTest-seed#[A827C9A252A9AF04]-worker) [ ] o.a.s.c.c.ConnectionManager Client is connected to ZooKeeper
[junit4] 2> 542019 INFO (SUITE-ComputePlanActionTest-seed#[A827C9A252A9AF04]-worker) [ ] o.a.s.c.c.ConnectionManager Waiting for client to connect to ZooKeeper
[junit4] 2> 542023 INFO (zkConnectionManagerCallback-2399-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 542023 INFO (SUITE-ComputePlanActionTest-seed#[A827C9A252A9AF04]-worker) [ ] o.a.s.c.c.ConnectionManager Client is connected to ZooKeeper
[junit4] 2> 542129 WARN (jetty-launcher-2400-thread-1) [ ] o.e.j.s.h.g.GzipHandler minGzipSize of 0 is inefficient for short content, break even is size 23
[junit4] 2> 542129 INFO (jetty-launcher-2400-thread-1) [ ] o.a.s.c.s.e.JettySolrRunner Start Jetty (configured port=0, binding port=0)
[junit4] 2> 542129 INFO (jetty-launcher-2400-thread-1) [ ] o.a.s.c.s.e.JettySolrRunner Trying to start Jetty on port 0 try number 1 ...
[junit4] 2> 542129 INFO (jetty-launcher-2400-thread-1) [ ] o.e.j.s.Server jetty-9.4.24.v20191120; built: 2019-11-20T21:37:49.771Z; git: 363d5f2df3a8a28de40604320230664b9c793c16; jvm 1.8.0_201-b09
[junit4] 2> 542131 INFO (jetty-launcher-2400-thread-1) [ ] o.e.j.s.session DefaultSessionIdManager workerName=node0
[junit4] 2> 542131 INFO (jetty-launcher-2400-thread-1) [ ] o.e.j.s.session No SessionScavenger set, using defaults
[junit4] 2> 542131 INFO (jetty-launcher-2400-thread-1) [ ] o.e.j.s.session node0 Scavenging every 600000ms
[junit4] 2> 542131 INFO (jetty-launcher-2400-thread-1) [ ] o.e.j.s.h.ContextHandler Started o.e.j.s.ServletContextHandler@6164a974{/solr,null,AVAILABLE}
[junit4] 2> 542132 INFO (jetty-launcher-2400-thread-1) [ ] o.e.j.s.AbstractConnector Started ServerConnector@357c0999{HTTP/1.1,[http/1.1, h2c]}{127.0.0.1:65491}
[junit4] 2> 542132 INFO (jetty-launcher-2400-thread-1) [ ] o.e.j.s.Server Started @542242ms
[junit4] 2> 542132 INFO (jetty-launcher-2400-thread-1) [ ] o.a.s.c.s.e.JettySolrRunner Jetty properties: {hostContext=/solr, hostPort=65491}
[junit4] 2> 542132 ERROR (jetty-launcher-2400-thread-1) [ ] o.a.s.u.StartupLoggingUtils Missing Java Option solr.log.dir. Logging may be missing or incomplete.
[junit4] 2> 542132 INFO (jetty-launcher-2400-thread-1) [ ] o.a.s.s.SolrDispatchFilter Using logger factory org.apache.logging.slf4j.Log4jLoggerFactory
[junit4] 2> 542132 INFO (jetty-launcher-2400-thread-1) [ ] o.a.s.s.SolrDispatchFilter ___ _ Welcome to Apache Solr™ version 8.5.0
[junit4] 2> 542132 INFO (jetty-launcher-2400-thread-1) [ ] o.a.s.s.SolrDispatchFilter / __| ___| |_ _ Starting in cloud mode on port null
[junit4] 2> 542132 INFO (jetty-launcher-2400-thread-1) [ ] o.a.s.s.SolrDispatchFilter \__ \/ _ \ | '_| Install dir: /Users/jenkins/workspace/Lucene-Solr-8.x-MacOSX/solr
[junit4] 2> 542132 INFO (jetty-launcher-2400-thread-1) [ ] o.a.s.s.SolrDispatchFilter |___/\___/_|_| Start time: 2020-02-03T06:08:38.712Z
[junit4] 2> 542134 INFO (jetty-launcher-2400-thread-1) [ ] o.a.s.c.c.ConnectionManager Waiting for client to connect to ZooKeeper
[junit4] 2> 542137 INFO (zkConnectionManagerCallback-2402-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 542137 INFO (jetty-launcher-2400-thread-1) [ ] o.a.s.c.c.ConnectionManager Client is connected to ZooKeeper
[junit4] 2> 542138 INFO (jetty-launcher-2400-thread-1) [ ] o.a.s.s.SolrDispatchFilter solr.xml found in ZooKeeper. Loading...
[junit4] 2> 542293 INFO (jetty-launcher-2400-thread-1) [ ] o.a.s.h.c.HttpShardHandlerFactory Host whitelist initialized: WhitelistHostChecker [whitelistHosts=null, whitelistHostCheckingEnabled=true]
[junit4] 2> 542294 WARN (jetty-launcher-2400-thread-1) [ ] o.e.j.u.s.S.config Trusting all certificates configured for Client@8b92e23[provider=null,keyStore=null,trustStore=null]
[junit4] 2> 542294 WARN (jetty-launcher-2400-thread-1) [ ] o.e.j.u.s.S.config No Client EndPointIdentificationAlgorithm configured for Client@8b92e23[provider=null,keyStore=null,trustStore=null]
[junit4] 2> 542299 WARN (jetty-launcher-2400-thread-1) [ ] o.e.j.u.s.S.config Trusting all certificates configured for Client@68187b4a[provider=null,keyStore=null,trustStore=null]
[junit4] 2> 542299 WARN (jetty-launcher-2400-thread-1) [ ] o.e.j.u.s.S.config No Client EndPointIdentificationAlgorithm configured for Client@68187b4a[provider=null,keyStore=null,trustStore=null]
[junit4] 2> 542300 INFO (jetty-launcher-2400-thread-1) [ ] o.a.s.c.ZkContainer Zookeeper client=127.0.0.1:65486/solr
[junit4] 2> 542301 INFO (jetty-launcher-2400-thread-1) [ ] o.a.s.c.c.ConnectionManager Waiting for client to connect to ZooKeeper
[junit4] 2> 542306 INFO (zkConnectionManagerCallback-2409-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 542306 INFO (jetty-launcher-2400-thread-1) [ ] o.a.s.c.c.ConnectionManager Client is connected to ZooKeeper
[junit4] 2> 542416 INFO (jetty-launcher-2400-thread-1) [n:127.0.0.1:65491_solr ] o.a.s.c.c.ConnectionManager Waiting for client to connect to ZooKeeper
[junit4] 2> 542419 INFO (zkConnectionManagerCallback-2411-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 542419 INFO (jetty-launcher-2400-thread-1) [n:127.0.0.1:65491_solr ] o.a.s.c.c.ConnectionManager Client is connected to ZooKeeper
[junit4] 2> 542618 INFO (jetty-launcher-2400-thread-1) [n:127.0.0.1:65491_solr ] o.a.s.c.OverseerElectionContext I am going to be the leader 127.0.0.1:65491_solr
[junit4] 2> 542620 INFO (jetty-launcher-2400-thread-1) [n:127.0.0.1:65491_solr ] o.a.s.c.Overseer Overseer (id=72087354090061829-127.0.0.1:65491_solr-n_0000000000) starting
[junit4] 2> 542636 INFO (OverseerStateUpdate-72087354090061829-127.0.0.1:65491_solr-n_0000000000) [n:127.0.0.1:65491_solr ] o.a.s.c.Overseer Starting to work on the main queue : 127.0.0.1:65491_solr
[junit4] 2> 542636 DEBUG (OverseerAutoScalingTriggerThread-72087354090061829-127.0.0.1:65491_solr-n_0000000000) [ ] o.a.s.c.a.OverseerTriggerThread Adding .auto_add_replicas and .scheduled_maintenance triggers
[junit4] 2> 542636 INFO (jetty-launcher-2400-thread-1) [n:127.0.0.1:65491_solr ] o.a.s.c.ZkController Register node as live in ZooKeeper:/live_nodes/127.0.0.1:65491_solr
[junit4] 2> 542639 DEBUG (OverseerAutoScalingTriggerThread-72087354090061829-127.0.0.1:65491_solr-n_0000000000) [ ] o.a.s.c.a.OverseerTriggerThread Refreshing /autoscaling.json with znode version 1
[junit4] 2> 542640 DEBUG (OverseerAutoScalingTriggerThread-72087354090061829-127.0.0.1:65491_solr-n_0000000000) [ ] o.a.s.c.a.OverseerTriggerThread Current znodeVersion 1, lastZnodeVersion 0
[junit4] 2> 542640 DEBUG (OverseerAutoScalingTriggerThread-72087354090061829-127.0.0.1:65491_solr-n_0000000000) [ ] o.a.s.c.a.OverseerTriggerThread Processed trigger updates upto znodeVersion 1
[junit4] 2> 542640 INFO (OverseerStateUpdate-72087354090061829-127.0.0.1:65491_solr-n_0000000000) [n:127.0.0.1:65491_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (1)
[junit4] 2> 542645 INFO (jetty-launcher-2400-thread-1) [n:127.0.0.1:65491_solr ] o.a.s.p.PackageLoader /packages.json updated to version -1
[junit4] 2> 542645 WARN (jetty-launcher-2400-thread-1) [n:127.0.0.1:65491_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> 542649 DEBUG (OverseerAutoScalingTriggerThread-72087354090061829-127.0.0.1:65491_solr-n_0000000000) [ ] o.a.s.c.a.NodeLostTrigger NodeLostTrigger .auto_add_replicas - Initial livenodes: [127.0.0.1:65491_solr]
[junit4] 2> 542651 DEBUG (OverseerAutoScalingTriggerThread-72087354090061829-127.0.0.1:65491_solr-n_0000000000) [ ] o.a.s.c.a.OverseerTriggerThread -- deactivating old nodeLost / nodeAdded markers
[junit4] 2> 542653 DEBUG (OverseerAutoScalingTriggerThread-72087354090061829-127.0.0.1:65491_solr-n_0000000000) [ ] o.a.s.c.a.OverseerTriggerThread Current znodeVersion 1, lastZnodeVersion 1
[junit4] 2> 542653 DEBUG (ScheduledTrigger-2384-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> 542705 INFO (jetty-launcher-2400-thread-1) [n:127.0.0.1:65491_solr ] o.a.s.h.a.MetricsHistoryHandler No .system collection, keeping metrics history in memory.
[junit4] 2> 542757 INFO (jetty-launcher-2400-thread-1) [n:127.0.0.1:65491_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_65491.solr.node' (registry 'solr.node') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@5bf17579
[junit4] 2> 542761 INFO (jetty-launcher-2400-thread-1) [n:127.0.0.1:65491_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_65491.solr.jvm' (registry 'solr.jvm') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@5bf17579
[junit4] 2> 542761 INFO (jetty-launcher-2400-thread-1) [n:127.0.0.1:65491_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_65491.solr.jetty' (registry 'solr.jetty') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@5bf17579
[junit4] 2> 542763 INFO (jetty-launcher-2400-thread-1) [n:127.0.0.1:65491_solr ] o.a.s.c.CorePropertiesLocator Found 0 core definitions underneath /Users/jenkins/workspace/Lucene-Solr-8.x-MacOSX/solr/build/solr-core/test/J3/temp/solr.cloud.autoscaling.ComputePlanActionTest_A827C9A252A9AF04-001/tempDir-001/node1/.
[junit4] 2> 542794 INFO (SUITE-ComputePlanActionTest-seed#[A827C9A252A9AF04]-worker) [ ] o.a.s.c.MiniSolrCloudCluster waitForAllNodes: numServers=1
[junit4] 2> 542795 INFO (SUITE-ComputePlanActionTest-seed#[A827C9A252A9AF04]-worker) [ ] o.a.s.c.c.ConnectionManager Waiting for client to connect to ZooKeeper
[junit4] 2> 542797 INFO (zkConnectionManagerCallback-2420-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 542798 INFO (SUITE-ComputePlanActionTest-seed#[A827C9A252A9AF04]-worker) [ ] o.a.s.c.c.ConnectionManager Client is connected to ZooKeeper
[junit4] 2> 542801 INFO (SUITE-ComputePlanActionTest-seed#[A827C9A252A9AF04]-worker) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (1)
[junit4] 2> 542804 INFO (SUITE-ComputePlanActionTest-seed#[A827C9A252A9AF04]-worker) [ ] o.a.s.c.s.i.ZkClientClusterStateProvider Cluster at 127.0.0.1:65486/solr ready
[junit4] IGNOR/A 0.00s J3 | ComputePlanActionTest.testNodeLost
[junit4] > Assumption #1: 'awaitsfix' test group is disabled (@AwaitsFix(bugUrl=https://issues.apache.org/jira/browse/SOLR-12028))
[junit4] 2> 542828 INFO (TEST-ComputePlanActionTest.testNodeAddedTriggerWithAddReplicaPreferredOp_1Shard-seed#[A827C9A252A9AF04]) [ ] o.a.s.SolrTestCaseJ4 ###Starting testNodeAddedTriggerWithAddReplicaPreferredOp_1Shard
[junit4] 2> 542830 DEBUG (zkCallback-2410-thread-1) [ ] o.a.s.c.a.OverseerTriggerThread Refreshing /autoscaling.json with znode version 2
[junit4] 2> 542830 DEBUG (OverseerAutoScalingTriggerThread-72087354090061829-127.0.0.1:65491_solr-n_0000000000) [ ] o.a.s.c.a.OverseerTriggerThread Processed trigger updates upto znodeVersion 2
[junit4] 2> 542833 INFO (TEST-ComputePlanActionTest.testNodeAddedTriggerWithAddReplicaPreferredOp_1Shard-seed#[A827C9A252A9AF04]) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (1)
[junit4] 2> 542838 DEBUG (OverseerAutoScalingTriggerThread-72087354090061829-127.0.0.1:65491_solr-n_0000000000) [ ] o.a.s.c.a.OverseerTriggerThread -- deactivating old nodeLost / nodeAdded markers
[junit4] 2> 542840 DEBUG (OverseerAutoScalingTriggerThread-72087354090061829-127.0.0.1:65491_solr-n_0000000000) [ ] o.a.s.c.a.OverseerTriggerThread Current znodeVersion 2, lastZnodeVersion 2
[junit4] 2> 542845 INFO (qtp1002168478-6538) [n:127.0.0.1:65491_solr ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/metrics params={prefix=CONTAINER.fs.usableSpace,CORE.coreName&wt=javabin&version=2&group=solr.node,solr.core} status=0 QTime=0
[junit4] 2> 542845 DEBUG (qtp1002168478-6536) [n:127.0.0.1:65491_solr ] o.a.s.c.a.AutoScalingHandler Verified autoscaling configuration
[junit4] 2> 542846 INFO (qtp1002168478-6536) [n:127.0.0.1:65491_solr ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/cluster/autoscaling params={wt=javabin&version=2} status=0 QTime=5
[junit4] 2> 542847 DEBUG (zkCallback-2410-thread-1) [ ] o.a.s.c.a.OverseerTriggerThread Refreshing /autoscaling.json with znode version 3
[junit4] 2> 542847 DEBUG (OverseerAutoScalingTriggerThread-72087354090061829-127.0.0.1:65491_solr-n_0000000000) [ ] o.a.s.c.a.OverseerTriggerThread Processed trigger updates upto znodeVersion 3
[junit4] 2> 542847 DEBUG (OverseerAutoScalingTriggerThread-72087354090061829-127.0.0.1:65491_solr-n_0000000000) [ ] o.a.s.c.a.OverseerTriggerThread -- deactivating old nodeLost / nodeAdded markers
[junit4] 2> 542849 DEBUG (OverseerAutoScalingTriggerThread-72087354090061829-127.0.0.1:65491_solr-n_0000000000) [ ] o.a.s.c.a.OverseerTriggerThread Current znodeVersion 3, lastZnodeVersion 3
[junit4] 2> 542851 INFO (qtp1002168478-6537) [n:127.0.0.1:65491_solr ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/metrics params={prefix=CONTAINER.fs.usableSpace,CORE.coreName&wt=javabin&version=2&group=solr.node,solr.core} status=0 QTime=0
[junit4] 2> 542852 DEBUG (qtp1002168478-6535) [n:127.0.0.1:65491_solr ] o.a.s.c.a.AutoScalingHandler Verified autoscaling configuration
[junit4] 2> 542853 INFO (qtp1002168478-6535) [n:127.0.0.1:65491_solr ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/cluster/autoscaling params={wt=javabin&version=2} status=0 QTime=5
[junit4] 2> 542853 DEBUG (zkCallback-2410-thread-1) [ ] o.a.s.c.a.OverseerTriggerThread Refreshing /autoscaling.json with znode version 4
[junit4] 2> 542853 DEBUG (OverseerAutoScalingTriggerThread-72087354090061829-127.0.0.1:65491_solr-n_0000000000) [ ] o.a.s.c.a.OverseerTriggerThread Processed trigger updates upto znodeVersion 4
[junit4] 2> 542853 DEBUG (OverseerAutoScalingTriggerThread-72087354090061829-127.0.0.1:65491_solr-n_0000000000) [ ] o.a.s.c.a.OverseerTriggerThread -- deactivating old nodeLost / nodeAdded markers
[junit4] 2> 542853 DEBUG (OverseerAutoScalingTriggerThread-72087354090061829-127.0.0.1:65491_solr-n_0000000000) [ ] o.a.s.c.a.OverseerTriggerThread Current znodeVersion 4, lastZnodeVersion 4
[junit4] 2> 542941 INFO (qtp1002168478-6536) [n:127.0.0.1:65491_solr ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/metrics params={prefix=CONTAINER.fs.usableSpace,CONTAINER.fs.totalSpace,CORE.coreName&wt=javabin&version=2&group=solr.node,solr.core} status=0 QTime=0
[junit4] 2> 542941 DEBUG (qtp1002168478-6538) [n:127.0.0.1:65491_solr ] o.a.s.c.a.AutoScalingHandler Verified autoscaling configuration
[junit4] 2> 542945 INFO (qtp1002168478-6538) [n:127.0.0.1:65491_solr ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/autoscaling params={wt=javabin&version=2} status=0 QTime=85
[junit4] 2> 542946 DEBUG (zkCallback-2410-thread-1) [ ] o.a.s.c.a.OverseerTriggerThread Refreshing /autoscaling.json with znode version 5
[junit4] 2> 542947 DEBUG (OverseerAutoScalingTriggerThread-72087354090061829-127.0.0.1:65491_solr-n_0000000000) [ ] o.a.s.c.a.OverseerTriggerThread Processed trigger updates upto znodeVersion 5
[junit4] 2> 542954 INFO (qtp1002168478-6535) [n:127.0.0.1:65491_solr ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/metrics params={prefix=CONTAINER.fs.usableSpace,CORE.coreName&wt=javabin&version=2&group=solr.node,solr.core} status=0 QTime=0
[junit4] 2> 542955 DEBUG (qtp1002168478-6537) [n:127.0.0.1:65491_solr ] o.a.s.c.a.AutoScalingHandler Verified autoscaling configuration
[junit4] 2> 542960 DEBUG (OverseerAutoScalingTriggerThread-72087354090061829-127.0.0.1:65491_solr-n_0000000000) [ ] o.a.s.c.a.NodeAddedTrigger NodeAddedTrigger node_added_trigger - Initial livenodes: [127.0.0.1:65491_solr]
[junit4] 2> 542960 DEBUG (OverseerAutoScalingTriggerThread-72087354090061829-127.0.0.1:65491_solr-n_0000000000) [ ] o.a.s.c.a.NodeAddedTrigger NodeAddedTrigger node_added_trigger instantiated with properties: {preferredOperation=addreplica, 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> 542967 DEBUG (OverseerAutoScalingTriggerThread-72087354090061829-127.0.0.1:65491_solr-n_0000000000) [ ] o.a.s.c.a.OverseerTriggerThread -- deactivating old nodeLost / nodeAdded markers
[junit4] 2> 542967 INFO (qtp1002168478-6537) [n:127.0.0.1:65491_solr ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/autoscaling params={wt=javabin&version=2} status=0 QTime=21
[junit4] 2> 542970 DEBUG (zkCallback-2410-thread-1) [ ] o.a.s.c.a.OverseerTriggerThread Refreshing /autoscaling.json with znode version 6
[junit4] 2> 542970 INFO (qtp1002168478-6536) [n:127.0.0.1:65491_solr ] o.a.s.h.a.CollectionsHandler Invoked Collection Action :create with params collection.configName=conf&maxShardsPerNode=2&name=testNodeAddedTriggerWithAddReplicaPreferredOp_1Shard_0&nrtReplicas=1&action=CREATE&numShards=1&wt=javabin&version=2 and sendToOCPQueue=true
[junit4] 2> 542971 DEBUG (OverseerAutoScalingTriggerThread-72087354090061829-127.0.0.1:65491_solr-n_0000000000) [ ] o.a.s.c.a.OverseerTriggerThread Current znodeVersion 6, lastZnodeVersion 5
[junit4] 2> 542971 DEBUG (OverseerAutoScalingTriggerThread-72087354090061829-127.0.0.1:65491_solr-n_0000000000) [ ] o.a.s.c.a.OverseerTriggerThread Processed trigger updates upto znodeVersion 6
[junit4] 2> 542975 DEBUG (OverseerAutoScalingTriggerThread-72087354090061829-127.0.0.1:65491_solr-n_0000000000) [ ] o.a.s.c.a.OverseerTriggerThread -- deactivating old nodeLost / nodeAdded markers
[junit4] 2> 542975 DEBUG (ScheduledTrigger-2384-thread-3) [ ] o.a.s.c.a.NodeAddedTrigger Running NodeAddedTrigger node_added_trigger
[junit4] 2> 542975 DEBUG (ScheduledTrigger-2384-thread-3) [ ] o.a.s.c.a.NodeAddedTrigger Found livenodes: 1
[junit4] 2> 542980 DEBUG (OverseerAutoScalingTriggerThread-72087354090061829-127.0.0.1:65491_solr-n_0000000000) [ ] o.a.s.c.a.OverseerTriggerThread Current znodeVersion 6, lastZnodeVersion 6
[junit4] 2> 542987 INFO (OverseerThreadFactory-2386-thread-1-processing-n:127.0.0.1:65491_solr) [n:127.0.0.1:65491_solr ] o.a.s.c.a.c.CreateCollectionCmd Create collection testNodeAddedTriggerWithAddReplicaPreferredOp_1Shard_0
[junit4] 2> 543015 DEBUG (OverseerStateUpdate-72087354090061829-127.0.0.1:65491_solr-n_0000000000) [n:127.0.0.1:65491_solr ] o.a.s.c.Overseer processMessage: queueSize: 1, message = {
[junit4] 2> "name":"testNodeAddedTriggerWithAddReplicaPreferredOp_1Shard_0",
[junit4] 2> "fromApi":"true",
[junit4] 2> "collection.configName":"conf",
[junit4] 2> "numShards":"1",
[junit4] 2> "maxShardsPerNode":"2",
[junit4] 2> "nrtReplicas":"1",
[junit4] 2> "stateFormat":"2",
[junit4] 2> "replicationFactor":"1",
[junit4] 2> "operation":"create"} current state version: 0
[junit4] 2> 543015 DEBUG (OverseerStateUpdate-72087354090061829-127.0.0.1:65491_solr-n_0000000000) [n:127.0.0.1:65491_solr ] o.a.s.c.o.ClusterStateMutator building a new cName: testNodeAddedTriggerWithAddReplicaPreferredOp_1Shard_0
[junit4] 2> 543016 DEBUG (OverseerStateUpdate-72087354090061829-127.0.0.1:65491_solr-n_0000000000) [n:127.0.0.1:65491_solr ] o.a.s.c.o.ZkStateWriter going to create_collection /collections/testNodeAddedTriggerWithAddReplicaPreferredOp_1Shard_0/state.json
[junit4] 2> 543118 INFO (qtp1002168478-6538) [n:127.0.0.1:65491_solr ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/metrics params={prefix=CONTAINER.fs.usableSpace,CONTAINER.fs.totalSpace,CORE.coreName&wt=javabin&version=2&group=solr.node,solr.core} status=0 QTime=0
[junit4] 2> 543134 DEBUG (OverseerStateUpdate-72087354090061829-127.0.0.1:65491_solr-n_0000000000) [n:127.0.0.1:65491_solr ] o.a.s.c.Overseer processMessage: queueSize: 1, message = {
[junit4] 2> "operation":"ADDREPLICA",
[junit4] 2> "collection":"testNodeAddedTriggerWithAddReplicaPreferredOp_1Shard_0",
[junit4] 2> "shard":"shard1",
[junit4] 2> "core":"testNodeAddedTriggerWithAddReplicaPreferredOp_1Shard_0_shard1_replica_n1",
[junit4] 2> "state":"down",
[junit4] 2> "base_url":"http://127.0.0.1:65491/solr",
[junit4] 2> "type":"NRT",
[junit4] 2> "waitForFinalState":"false"} current state version: 0
[junit4] 2> 543134 INFO (OverseerStateUpdate-72087354090061829-127.0.0.1:65491_solr-n_0000000000) [n:127.0.0.1:65491_solr ] o.a.s.c.o.SliceMutator createReplica() {
[junit4] 2> "operation":"ADDREPLICA",
[junit4] 2> "collection":"testNodeAddedTriggerWithAddReplicaPreferredOp_1Shard_0",
[junit4] 2> "shard":"shard1",
[junit4] 2> "core":"testNodeAddedTriggerWithAddReplicaPreferredOp_1Shard_0_shard1_replica_n1",
[junit4] 2> "state":"down",
[junit4] 2> "base_url":"http://127.0.0.1:65491/solr",
[junit4] 2> "type":"NRT",
[junit4] 2> "waitForFinalState":"false"}
[junit4] 2> 543140 DEBUG (OverseerStateUpdate-72087354090061829-127.0.0.1:65491_solr-n_0000000000) [n:127.0.0.1:65491_solr ] o.a.s.c.o.SliceMutator Old Slice: shard1:{
[junit4] 2> "range":"80000000-7fffffff",
[junit4] 2> "state":"active",
[junit4] 2> "replicas":{}}
[junit4] 2> 543140 DEBUG (OverseerStateUpdate-72087354090061829-127.0.0.1:65491_solr-n_0000000000) [n:127.0.0.1:65491_solr ] o.a.s.c.o.SliceMutator New Slice: shard1:{
[junit4] 2> "range":"80000000-7fffffff",
[junit4] 2> "state":"active",
[junit4] 2> "replicas":{"core_node2":{
[junit4] 2> "core":"testNodeAddedTriggerWithAddReplicaPreferredOp_1Shard_0_shard1_replica_n1",
[junit4] 2> "base_url":"http://127.0.0.1:65491/solr",
[junit4] 2> "state":"down",
[junit4] 2> "node_name":null,
[junit4] 2> "type":"NRT"}}}
[junit4] 2> 543241 DEBUG (OverseerStateUpdate-72087354090061829-127.0.0.1:65491_solr-n_0000000000) [n:127.0.0.1:65491_solr ] o.a.s.c.o.ZkStateWriter going to update_collection /collections/testNodeAddedTriggerWithAddReplicaPreferredOp_1Shard_0/state.json version: 0
[junit4] 2> 543337 INFO (qtp1002168478-6535) [n:127.0.0.1:65491_solr x:testNodeAddedTriggerWithAddReplicaPreferredOp_1Shard_0_shard1_replica_n1 ] o.a.s.h.a.CoreAdminOperation core create command qt=/admin/cores&coreNodeName=core_node2&collection.configName=conf&newCollection=true&name=testNodeAddedTriggerWithAddReplicaPreferredOp_1Shard_0_shard1_replica_n1&action=CREATE&numShards=1&collection=testNodeAddedTriggerWithAddReplicaPreferredOp_1Shard_0&shard=shard1&wt=javabin&version=2&replicaType=NRT
[junit4] 2> 543338 INFO (qtp1002168478-6535) [n:127.0.0.1:65491_solr x:testNodeAddedTriggerWithAddReplicaPreferredOp_1Shard_0_shard1_replica_n1 ] o.a.s.c.TransientSolrCoreCacheDefault Allocating transient cache for 2147483647 transient cores
[junit4] 2> 543346 DEBUG (OverseerStateUpdate-72087354090061829-127.0.0.1:65491_solr-n_0000000000) [n:127.0.0.1:65491_solr ] o.a.s.c.Overseer processMessage: queueSize: 1, message = {
[junit4] 2> "core":"testNodeAddedTriggerWithAddReplicaPreferredOp_1Shard_0_shard1_replica_n1",
[junit4] 2> "core_node_name":"core_node2",
[junit4] 2> "roles":null,
[junit4] 2> "base_url":"http://127.0.0.1:65491/solr",
[junit4] 2> "node_name":"127.0.0.1:65491_solr",
[junit4] 2> "numShards":"1",
[junit4] 2> "state":"down",
[junit4] 2> "shard":"shard1",
[junit4] 2> "collection":"testNodeAddedTriggerWithAddReplicaPreferredOp_1Shard_0",
[junit4] 2> "type":"NRT",
[junit4] 2> "force_set_state":"false",
[junit4] 2> "operation":"state"} current state version: 0
[junit4] 2> 543346 DEBUG (OverseerStateUpdate-72087354090061829-127.0.0.1:65491_solr-n_0000000000) [n:127.0.0.1:65491_solr ] o.a.s.c.o.ReplicaMutator Update state numShards=1 message={
[junit4] 2> "core":"testNodeAddedTriggerWithAddReplicaPreferredOp_1Shard_0_shard1_replica_n1",
[junit4] 2> "core_node_name":"core_node2",
[junit4] 2> "roles":null,
[junit4] 2> "base_url":"http://127.0.0.1:65491/solr",
[junit4] 2> "node_name":"127.0.0.1:65491_solr",
[junit4] 2> "numShards":"1",
[junit4] 2> "state":"down",
[junit4] 2> "shard":"shard1",
[junit4] 2> "collection":"testNodeAddedTriggerWithAddReplicaPreferredOp_1Shard_0",
[junit4] 2> "type":"NRT",
[junit4] 2> "force_set_state":"false",
[junit4] 2> "operation":"state"}
[junit4] 2> 543346 DEBUG (OverseerStateUpdate-72087354090061829-127.0.0.1:65491_solr-n_0000000000) [n:127.0.0.1:65491_solr ] o.a.s.c.o.ReplicaMutator Will update state for replica: core_node2:{
[junit4] 2> "core":"testNodeAddedTriggerWithAddReplicaPreferredOp_1Shard_0_shard1_replica_n1",
[junit4] 2> "base_url":"http://127.0.0.1:65491/solr",
[junit4] 2> "node_name":"127.0.0.1:65491_solr",
[junit4] 2> "state":"down",
[junit4] 2> "type":"NRT",
[junit4] 2> "force_set_state":"false"}
[junit4] 2> 543346 DEBUG (OverseerStateUpdate-72087354090061829-127.0.0.1:65491_solr-n_0000000000) [n:127.0.0.1:65491_solr ] o.a.s.c.o.ReplicaMutator Collection is now: DocCollection(testNodeAddedTriggerWithAddReplicaPreferredOp_1Shard_0//collections/testNodeAddedTriggerWithAddReplicaPreferredOp_1Shard_0/state.json/1)={
[junit4] 2> "pullReplicas":"0",
[junit4] 2> "replicationFactor":"1",
[junit4] 2> "router":{"name":"compositeId"},
[junit4] 2> "maxShardsPerNode":"2",
[junit4] 2> "autoAddReplicas":"false",
[junit4] 2> "nrtReplicas":"1",
[junit4] 2> "tlogReplicas":"0",
[junit4] 2> "shards":{"shard1":{
[junit4] 2> "range":"80000000-7fffffff",
[junit4] 2> "state":"active",
[junit4] 2> "replicas":{"core_node2":{
[junit4] 2> "core":"testNodeAddedTriggerWithAddReplicaPreferredOp_1Shard_0_shard1_replica_n1",
[junit4] 2> "base_url":"http://127.0.0.1:65491/solr",
[junit4] 2> "node_name":"127.0.0.1:65491_solr",
[junit4] 2> "state":"down",
[junit4] 2> "type":"NRT",
[junit4] 2> "force_set_state":"false"}}}}}
[junit4] 2> 543451 DEBUG (OverseerStateUpdate-72087354090061829-127.0.0.1:65491_solr-n_0000000000) [n:127.0.0.1:65491_solr ] o.a.s.c.o.ZkStateWriter going to update_collection /collections/testNodeAddedTriggerWithAddReplicaPreferredOp_1Shard_0/state.json version: 1
[junit4] 2> 543984 DEBUG (ScheduledTrigger-2384-thread-3) [ ] o.a.s.c.a.NodeAddedTrigger Running NodeAddedTrigger node_added_trigger
[junit4] 2> 543984 DEBUG (ScheduledTrigger-2384-thread-3) [ ] o.a.s.c.a.NodeAddedTrigger Found livenodes: 1
[junit4] 2> 544373 INFO (qtp1002168478-6535) [n:127.0.0.1:65491_solr c:testNodeAddedTriggerWithAddReplicaPreferredOp_1Shard_0 s:shard1 r:core_node2 x:testNodeAddedTriggerWithAddReplicaPreferredOp_1Shard_0_shard1_replica_n1 ] o.a.s.c.SolrConfig Using Lucene MatchVersion: 8.5.0
[junit4] 2> 544394 INFO (qtp1002168478-6535) [n:127.0.0.1:65491_solr c:testNodeAddedTriggerWithAddReplicaPreferredOp_1Shard_0 s:shard1 r:core_node2 x:testNodeAddedTriggerWithAddReplicaPreferredOp_1Shard_0_shard1_replica_n1 ] o.a.s.s.IndexSchema [testNodeAddedTriggerWithAddReplicaPreferredOp_1Shard_0_shard1_replica_n1] Schema name=minimal
[junit4] 2> 544398 INFO (qtp1002168478-6535) [n:127.0.0.1:65491_solr c:testNodeAddedTriggerWithAddReplicaPreferredOp_1Shard_0 s:shard1 r:core_node2 x:testNodeAddedTriggerWithAddReplicaPreferredOp_1Shard_0_shard1_replica_n1 ] o.a.s.s.IndexSchema Loaded schema minimal/1.1 with uniqueid field id
[junit4] 2> 544398 INFO (qtp1002168478-6535) [n:127.0.0.1:65491_solr c:testNodeAddedTriggerWithAddReplicaPreferredOp_1Shard_0 s:shard1 r:core_node2 x:testNodeAddedTriggerWithAddReplicaPreferredOp_1Shard_0_shard1_replica_n1 ] o.a.s.c.CoreContainer Creating SolrCore 'testNodeAddedTriggerWithAddReplicaPreferredOp_1Shard_0_shard1_replica_n1' using configuration from configset conf, trusted=true
[junit4] 2> 544399 INFO (qtp1002168478-6535) [n:127.0.0.1:65491_solr c:testNodeAddedTriggerWithAddReplicaPreferredOp_1Shard_0 s:shard1 r:core_node2 x:testNodeAddedTriggerWithAddReplicaPreferredOp_1Shard_0_shard1_replica_n1 ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_65491.solr.core.testNodeAddedTriggerWithAddReplicaPreferredOp_1Shard_0.shard1.replica_n1' (registry 'solr.core.testNodeAddedTriggerWithAddReplicaPreferredOp_1Shard_0.shard1.replica_n1') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@5bf17579
[junit4] 2> 544399 INFO (qtp1002168478-6535) [n:127.0.0.1:65491_solr c:testNodeAddedTriggerWithAddReplicaPreferredOp_1Shard_0 s:shard1 r:core_node2 x:testNodeAddedTriggerWithAddReplicaPreferredOp_1Shard_0_shard1_replica_n1 ] o.a.s.c.SolrCore [[testNodeAddedTriggerWithAddReplicaPreferredOp_1Shard_0_shard1_replica_n1] ] Opening new SolrCore at [/Users/jenkins/workspace/Lucene-Solr-8.x-MacOSX/solr/build/solr-core/test/J3/temp/solr.cloud.autoscaling.ComputePlanActionTest_A827C9A252A9AF04-001/tempDir-001/node1/testNodeAddedTriggerWithAddReplicaPreferredOp_1Shard_0_shard1_replica_n1], dataDir=[/Users/jenkins/workspace/Lucene-Solr-8.x-MacOSX/solr/build/solr-core/test/J3/temp/solr.cloud.autoscaling.ComputePlanActionTest_A827C9A252A9AF04-001/tempDir-001/node1/./testNodeAddedTriggerWithAddReplicaPreferredOp_1Shard_0_shard1_replica_n1/data/]
[junit4] 2> 544501 INFO (qtp1002168478-6535) [n:127.0.0.1:65491_solr c:testNodeAddedTriggerWithAddReplicaPreferredOp_1Shard_0 s:shard1 r:core_node2 x:testNodeAddedTriggerWithAddReplicaPreferredOp_1Shard_0_shard1_replica_n1 ] o.a.s.u.UpdateHandler Using UpdateLog implementation: org.apache.solr.update.UpdateLog
[junit4] 2> 544502 INFO (qtp1002168478-6535) [n:127.0.0.1:65491_solr c:testNodeAddedTriggerWithAddReplicaPreferredOp_1Shard_0 s:shard1 r:core_node2 x:testNodeAddedTriggerWithAddReplicaPreferredOp_1Shard_0_shard1_replica_n1 ] o.a.s.u.UpdateLog Initializing UpdateLog: dataDir=null defaultSyncLevel=FLUSH numRecordsToKeep=100 maxNumLogsToKeep=10 numVersionBuckets=65536
[junit4] 2> 544503 INFO (qtp1002168478-6535) [n:127.0.0.1:65491_solr c:testNodeAddedTriggerWithAddReplicaPreferredOp_1Shard_0 s:shard1 r:core_node2 x:testNodeAddedTriggerWithAddReplicaPreferredOp_1Shard_0_shard1_replica_n1 ] o.a.s.u.CommitTracker Hard AutoCommit: disabled
[junit4] 2> 544503 INFO (qtp1002168478-6535) [n:127.0.0.1:65491_solr c:testNodeAddedTriggerWithAddReplicaPreferredOp_1Shard_0 s:shard1 r:core_node2 x:testNodeAddedTriggerWithAddReplicaPreferredOp_1Shard_0_shard1_replica_n1 ] o.a.s.u.CommitTracker Soft AutoCommit: disabled
[junit4] 2> 544505 INFO (qtp1002168478-6535) [n:127.0.0.1:65491_solr c:testNodeAddedTriggerWithAddReplicaPreferredOp_1Shard_0 s:shard1 r:core_node2 x:testNodeAddedTriggerWithAddReplicaPreferredOp_1Shard_0_shard1_replica_n1 ] o.a.s.s.SolrIndexSearcher Opening [Searcher@7466803c[testNodeAddedTriggerWithAddReplicaPreferredOp_1Shard_0_shard1_replica_n1] main]
[junit4] 2> 544508 INFO (qtp1002168478-6535) [n:127.0.0.1:65491_solr c:testNodeAddedTriggerWithAddReplicaPreferredOp_1Shard_0 s:shard1 r:core_node2 x:testNodeAddedTriggerWithAddReplicaPreferredOp_1Shard_0_shard1_replica_n1 ] o.a.s.r.ManagedResourceStorage Configured ZooKeeperStorageIO with znodeBase: /configs/conf
[junit4] 2> 544509 INFO (qtp1002168478-6535) [n:127.0.0.1:65491_solr c:testNodeAddedTriggerWithAddReplicaPreferredOp_1Shard_0 s:shard1 r:core_node2 x:testNodeAddedTriggerWithAddReplicaPreferredOp_1Shard_0_shard1_replica_n1 ] o.a.s.r.ManagedResourceStorage Loaded null at path _rest_managed.json using ZooKeeperStorageIO:path=/configs/conf
[junit4] 2> 544509 INFO (qtp1002168478-6535) [n:127.0.0.1:65491_solr c:testNodeAddedTriggerWithAddReplicaPreferredOp_1Shard_0 s:shard1 r:core_node2 x:testNodeAddedTriggerWithAddReplicaPreferredOp_1Shard_0_shard1_replica_n1 ] o.a.s.h.ReplicationHandler Commits will be reserved for 10000ms.
[junit4] 2> 544509 INFO (qtp1002168478-6535) [n:127.0.0.1:65491_solr c:testNodeAddedTriggerWithAddReplicaPreferredOp_1Shard_0 s:shard1 r:core_node2 x:testNodeAddedTriggerWithAddReplicaPreferredOp_1Shard_0_shard1_replica_n1 ] o.a.s.u.UpdateLog Could not find max version in index or recent updates, using new clock 1657494695931019264
[junit4] 2> 544512 INFO (searcherExecutor-2391-thread-1-processing-n:127.0.0.1:65491_solr x:testNodeAddedTriggerWithAddReplicaPreferredOp_1Shard_0_shard1_replica_n1 c:testNodeAddedTriggerWithAddReplicaPreferredOp_1Shard_0 s:shard1 r:core_node2) [n:127.0.0.1:65491_solr c:testNodeAddedTriggerWithAddReplicaPreferredOp_1Shard_0 s:shard1 r:core_node2 x:testNodeAddedTriggerWithAddReplicaPreferredOp_1Shard_0_shard1_replica_n1 ] o.a.s.c.SolrCore [testNodeAddedTriggerWithAddReplicaPreferredOp_1Shard_0_shard1_replica_n1] Registered new searcher Searcher@7466803c[testNodeAddedTriggerWithAddReplicaPreferredOp_1Shard_0_shard1_replica_n1] main{ExitableDirectoryReader(UninvertingDirectoryReader())}
[junit4] 2> 544521 INFO (qtp1002168478-6535) [n:127.0.0.1:65491_solr c:testNodeAddedTriggerWithAddReplicaPreferredOp_1Shard_0 s:shard1 r:core_node2 x:testNodeAddedTriggerWithAddReplicaPreferredOp_1Shard_0_shard1_replica_n1 ] o.a.s.c.ZkShardTerms Successful update of terms at /collections/testNodeAddedTriggerWithAddReplicaPreferredOp_1Shard_0/terms/shard1 to Terms{values={core_node2=0}, version=0}
[junit4] 2> 544521 INFO (qtp1002168478-6535) [n:127.0.0.1:65491_solr c:testNodeAddedTriggerWithAddReplicaPreferredOp_1Shard_0 s:shard1 r:core_node2 x:testNodeAddedTriggerWithAddReplicaPreferredOp_1Shard_0_shard1_replica_n1 ] o.a.s.c.ShardLeaderElectionContextBase make sure parent is created /collections/testNodeAddedTriggerWithAddReplicaPreferredOp_1Shard_0/leaders/shard1
[junit4] 2> 544530 INFO (qtp1002168478-6535) [n:127.0.0.1:65491_solr c:testNodeAddedTriggerWithAddReplicaPreferredOp_1Shard_0 s:shard1 r:core_node2 x:testNodeAddedTriggerWithAddReplicaPreferredOp_1Shard_0_shard1_replica_n1 ] o.a.s.c.ShardLeaderElectionContext Enough replicas found to continue.
[junit4] 2> 544530 INFO (qtp1002168478-6535) [n:127.0.0.1:65491_solr c:testNodeAddedTriggerWithAddReplicaPreferredOp_1Shard_0 s:shard1 r:core_node2 x:testNodeAddedTriggerWithAddReplicaPreferredOp_1Shard_0_shard1_replica_n1 ] o.a.s.c.ShardLeaderElectionContext I may be the new leader - try and sync
[junit4] 2> 544530 INFO (qtp1002168478-6535) [n:127.0.0.1:65491_solr c:testNodeAddedTriggerWithAddReplicaPreferredOp_1Shard_0 s:shard1 r:core_node2 x:testNodeAddedTriggerWithAddReplicaPreferredOp_1Shard_0_shard1_replica_n1 ] o.a.s.c.SyncStrategy Sync replicas to http://127.0.0.1:65491/solr/testNodeAddedTriggerWithAddReplicaPreferredOp_1Shard_0_shard1_replica_n1/
[junit4] 2> 544531 INFO (qtp1002168478-6535) [n:127.0.0.1:65491_solr c:testNodeAddedTriggerWithAddReplicaPreferredOp_1Shard_0 s:shard1 r:core_node2 x:testNodeAddedTriggerWithAddReplicaPreferredOp_1Shard_0_shard1_replica_n1 ] o.a.s.c.SyncStrategy Sync Success - now sync replicas to me
[junit4] 2> 544533 INFO (qtp1002168478-6535) [n:127.0.0.1:65491_solr c:testNodeAddedTriggerWithAddReplicaPreferredOp_1Shard_0 s:shard1 r:core_node2 x:testNodeAddedTriggerWithAddReplicaPreferredOp_1Shard_0_shard1_replica_n1 ] o.a.s.c.SyncStrategy http://127.0.0.1:65491/solr/testNodeAddedTriggerWithAddReplicaPreferredOp_1Shard_0_shard1_replica_n1/ has no replicas
[junit4] 2> 544534 INFO (qtp1002168478-6535) [n:127.0.0.1:65491_solr c:testNodeAddedTriggerWithAddReplicaPreferredOp_1Shard_0 s:shard1 r:core_node2 x:testNodeAddedTriggerWithAddReplicaPreferredOp_1Shard_0_shard1_replica_n1 ] o.a.s.c.ShardLeaderElectionContextBase Creating leader registration node /collections/testNodeAddedTriggerWithAddReplicaPreferredOp_1Shard_0/leaders/shard1/leader after winning as /collections/testNodeAddedTriggerWithAddReplicaPreferredOp_1Shard_0/leader_elect/shard1/election/72087354090061829-core_node2-n_0000000000
[junit4] 2> 544539 INFO (qtp1002168478-6535) [n:127.0.0.1:65491_solr c:testNodeAddedTriggerWithAddReplicaPreferredOp_1Shard_0 s:shard1 r:core_node2 x:testNodeAddedTriggerWithAddReplicaPreferredOp_1Shard_0_shard1_replica_n1 ] o.a.s.c.ShardLeaderElectionContext I am the new leader: http://127.0.0.1:65491/solr/testNodeAddedTriggerWithAddReplicaPreferredOp_1Shard_0_shard1_replica_n1/ shard1
[junit4] 2> 544541 DEBUG (OverseerStateUpdate-72087354090061829-127.0.0.1:65491_solr-n_0000000000) [n:127.0.0.1:65491_solr ] o.a.s.c.Overseer processMessage: queueSize: 1, message = {
[junit4] 2> "operation":"leader",
[junit4] 2> "shard":"shard1",
[junit4] 2> "collection":"testNodeAddedTriggerWithAddReplicaPreferredOp_1Shard_0",
[junit4] 2> "base_url":"http://127.0.0.1:65491/solr",
[junit4] 2> "core":"testNodeAddedTriggerWithAddReplicaPreferredOp_1Shard_0_shard1_replica_n1",
[junit4] 2> "state":"active"} current state version: 0
[junit4] 2> 544642 DEBUG (OverseerStateUpdate-72087354090061829-127.0.0.1:65491_solr-n_0000000000) [n:127.0.0.1:65491_solr ] o.a.s.c.o.ZkStateWriter going to update_collection /collections/testNodeAddedTriggerWithAddReplicaPreferredOp_1Shard_0/state.json version: 2
[junit4] 2> 544644 INFO (zkCallback-2410-thread-1) [ ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/testNodeAddedTriggerWithAddReplicaPreferredOp_1Shard_0/state.json] for collection [testNodeAddedTriggerWithAddReplicaPreferredOp_1Shard_0] has occurred - updating... (live nodes size: [1])
[junit4] 2> 544644 INFO (zkCallback-2410-thread-2) [ ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/testNodeAddedTriggerWithAddReplicaPreferredOp_1Shard_0/state.json] for collection [testNodeAddedTriggerWithAddReplicaPreferredOp_1Shard_0] has occurred - updating... (live nodes size: [1])
[junit4] 2> 544645 INFO (qtp1002168478-6535) [n:127.0.0.1:65491_solr c:testNodeAddedTriggerWithAddReplicaPreferredOp_1Shard_0 s:shard1 r:core_node2 x:testNodeAddedTriggerWithAddReplicaPreferredOp_1Shard_0_shard1_replica_n1 ] o.a.s.c.ZkController I am the leader, no recovery necessary
[junit4] 2> 544648 DEBUG (OverseerStateUpdate-72087354090061829-127.0.0.1:65491_solr-n_0000000000) [n:127.0.0.1:65491_solr ] o.a.s.c.Overseer processMessage: queueSize: 1, message = {
[junit4] 2> "core":"testNodeAddedTriggerWithAddReplicaPreferredOp_1Shard_0_shard1_replica_n1",
[junit4] 2> "core_node_name":"core_node2",
[junit4] 2> "roles":null,
[junit4] 2> "base_url":"http://127.0.0.1:65491/solr",
[junit4] 2> "node_name":"127.0.0.1:65491_solr",
[junit4] 2> "numShards":"1",
[junit4] 2> "state":"active",
[junit4] 2> "shard":"shard1",
[junit4] 2> "collection":"testNodeAddedTriggerWithAddReplicaPreferredOp_1Shard_0",
[junit4] 2> "type":"NRT",
[junit4] 2> "force_set_state":"false",
[junit4] 2> "operation":"state"} current state version: 0
[junit4] 2> 544649 DEBUG (OverseerStateUpdate-72087354090061829-127.0.0.1:65491_solr-n_0000000000) [n:127.0.0.1:65491_solr ] o.a.s.c.o.ReplicaMutator Update state numShards=1 message={
[junit4] 2> "core":"testNodeAddedTriggerWithAddReplicaPreferredOp_1Shard_0_shard1_replica_n1",
[junit4] 2> "core_node_name":"core_node2",
[junit4] 2> "roles":null,
[junit4] 2> "base_url":"http://127.0.0.1:65491/solr",
[junit4] 2> "node_name":"127.0.0.1:65491_solr",
[junit4] 2> "numShards":"1",
[junit4] 2> "state":"active",
[junit4] 2> "shard":"shard1",
[junit4] 2> "collection":"testNodeAddedTriggerWithAddReplicaPreferredOp_1Shard_0",
[junit4] 2> "type":"NRT",
[junit4] 2> "force_set_state":"false",
[junit4] 2> "operation":"state"}
[junit4] 2> 544649 DEBUG (OverseerStateUpdate-72087354090061829-127.0.0.1:65491_solr-n_0000000000) [n:127.0.0.1:65491_solr ] o.a.s.c.o.ReplicaMutator Will update state for replica: core_node2:{
[junit4] 2> "core":"testNodeAddedTriggerWithAddReplicaPreferredOp_1Shard_0_shard1_replica_n1",
[junit4] 2> "base_url":"http://127.0.0.1:65491/solr",
[junit4] 2> "node_name":"127.0.0.1:65491_solr",
[junit4] 2> "state":"active",
[junit4] 2> "type":"NRT",
[junit4] 2> "force_set_state":"false",
[junit4] 2> "leader":"true"}
[junit4] 2> 544649 DEBUG (OverseerStateUpdate-72087354090061829-127.0.0.1:65491_solr-n_0000000000) [n:127.0.0.1:65491_solr ] o.a.s.c.o.ReplicaMutator Collection is now: DocCollection(testNodeAddedTriggerWithAddReplicaPreferredOp_1Shard_0//collections/testNodeAddedTriggerWithAddReplicaPreferredOp_1Shard_0/state.json/3)={
[junit4] 2> "pullReplicas":"0",
[junit4] 2> "replicationFactor":"1",
[junit4] 2> "router":{"name":"compositeId"},
[junit4] 2> "maxShardsPerNode":"2",
[junit4] 2> "autoAddReplicas":"false",
[junit4] 2> "nrtReplicas":"1",
[junit4] 2> "tlogReplicas":"0",
[junit4] 2> "shards":{"shard1":{
[junit4] 2> "range":"80000000-7fffffff",
[junit4] 2> "state":"active",
[junit4] 2> "replicas":{"core_node2":{
[junit4] 2> "core":"testNodeAddedTriggerWithAddReplicaPreferredOp_1Shard_0_shard1_replica_n1",
[junit4] 2> "base_url":"http://127.0.0.1:65491/solr",
[junit4] 2> "node_name":"127.0.0.1:65491_solr",
[junit4] 2> "state":"active",
[junit4] 2> "type":"NRT",
[junit4] 2> "force_set_state":"false",
[junit4] 2> "leader":"true"}}}}}
[junit4] 2> 544651 INFO (qtp1002168478-6535) [n:127.0.0.1:65491_solr c:testNodeAddedTriggerWithAddReplicaPreferredOp_1Shard_0 s:shard1 r:core_node2 x:testNodeAddedTriggerWithAddReplicaPreferredOp_1Shard_0_shard1_replica_n1 ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/cores params={qt=/admin/cores&coreNodeName=core_node2&collection.configName=conf&newCollection=true&name=testNodeAddedTriggerWithAddReplicaPreferredOp_1Shard_0_shard1_replica_n1&action=CREATE&numShards=1&collection=testNodeAddedTriggerWithAddReplicaPreferredOp_1Shard_0&shard=shard1&wt=javabin&version=2&replicaType=NRT} status=0 QTime=1317
[junit4] 2> 544657 INFO (qtp1002168478-6536) [n:127.0.0.1:65491_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> 544750 DEBUG (OverseerStateUpdate-72087354090061829-127.0.0.1:65491_solr-n_0000000000) [n:127.0.0.1:65491_solr ] o.a.s.c.o.ZkStateWriter going to update_collection /collections/testNodeAddedTriggerWithAddReplicaPreferredOp_1Shard_0/state.json version: 3
[junit4] 2> 544751 INFO (zkCallback-2410-thread-2) [ ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/testNodeAddedTriggerWithAddReplicaPreferredOp_1Shard_0/state.json] for collection [testNodeAddedTriggerWithAddReplicaPreferredOp_1Shard_0] has occurred - updating... (live nodes size: [1])
[junit4] 2> 544751 INFO (zkCallback-2410-thread-1) [ ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/testNodeAddedTriggerWithAddReplicaPreferredOp_1Shard_0/state.json] for collection [testNodeAddedTriggerWithAddReplicaPreferredOp_1Shard_0] has occurred - updating... (live nodes size: [1])
[junit4] 2> 544751 INFO (zkCallback-2410-thread-3) [ ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/testNodeAddedTriggerWithAddReplicaPreferredOp_1Shard_0/state.json] for collection [testNodeAddedTriggerWithAddReplicaPreferredOp_1Shard_0] has occurred - updating... (live nodes size: [1])
[junit4] 2> 544753 INFO (qtp1002168478-6536) [n:127.0.0.1:65491_solr ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/collections params={collection.configName=conf&maxShardsPerNode=2&name=testNodeAddedTriggerWithAddReplicaPreferredOp_1Shard_0&nrtReplicas=1&action=CREATE&numShards=1&wt=javabin&version=2} status=0 QTime=1783
[junit4] 2> 544755 INFO (TEST-ComputePlanActionTest.testNodeAddedTriggerWithAddReplicaPreferredOp_1Shard-seed#[A827C9A252A9AF04]) [ ] o.a.s.c.SolrCloudTestCase waitForState (testNodeAddedTriggerWithAddReplicaPreferredOp_1Shard_0): Timed out waiting for replicas of new collection to be active
[junit4] 2> 544757 WARN (TEST-ComputePlanActionTest.testNodeAddedTriggerWithAddReplicaPreferredOp_1Shard-seed#[A827C9A252A9AF04]) [ ] o.e.j.s.h.g.GzipHandler minGzipSize of 0 is inefficient for short content, break even is size 23
[junit4] 2> 544757 INFO (TEST-ComputePlanActionTest.testNodeAddedTriggerWithAddReplicaPreferredOp_1Shard-seed#[A827C9A252A9AF04]) [ ] o.a.s.c.s.e.JettySolrRunner Start Jetty (configured port=0, binding port=0)
[junit4] 2> 544757 INFO (TEST-ComputePlanActionTest.testNodeAddedTriggerWithAddReplicaPreferredOp_1Shard-seed#[A827C9A252A9AF04]) [ ] o.a.s.c.s.e.JettySolrRunner Trying to start Jetty on port 0 try number 1 ...
[junit4] 2> 544757 INFO (TEST-ComputePlanActionTest.testNodeAddedTriggerWithAddReplicaPreferredOp_1Shard-seed#[A827C9A252A9AF04]) [ ] o.e.j.s.Server jetty-9.4.24.v20191120; built: 2019-11-20T21:37:49.771Z; git: 363d5f2df3a8a28de40604320230664b9c793c16; jvm 1.8.0_201-b09
[junit4] 2> 544762 INFO (TEST-ComputePlanActionTest.testNodeAddedTriggerWithAddReplicaPreferredOp_1Shard-seed#[A827C9A252A9AF04]) [ ] o.e.j.s.session DefaultSessionIdManager workerName=node0
[junit4] 2> 544763 INFO (TEST-ComputePlanActionTest.testNodeAddedTriggerWithAddReplicaPreferredOp_1Shard-seed#[A827C9A252A9AF04]) [ ] o.e.j.s.session No SessionScavenger set, using defaults
[junit4] 2> 544763 INFO (TEST-ComputePlanActionTest.testNodeAddedTriggerWithAddReplicaPreferredOp_1Shard-seed#[A827C9A252A9AF04]) [ ] o.e.j.s.session node0 Scavenging every 600000ms
[junit4] 2> 544763 INFO (TEST-ComputePlanActionTest.testNodeAddedTriggerWithAddReplicaPreferredOp_1Shard-seed#[A827C9A252A9AF04]) [ ] o.e.j.s.h.ContextHandler Started o.e.j.s.ServletContextHandler@217bc926{/solr,null,AVAILABLE}
[junit4] 2> 544764 INFO (TEST-ComputePlanActionTest.testNodeAddedTriggerWithAddReplicaPreferredOp_1Shard-seed#[A827C9A252A9AF04]) [ ] o.e.j.s.AbstractConnector Started ServerConnector@61380c6c{HTTP/1.1,[http/1.1, h2c]}{127.0.0.1:65506}
[junit4] 2> 544764 INFO (TEST-ComputePlanActionTest.testNodeAddedTriggerWithAddReplicaPreferredOp_1Shard-seed#[A827C9A252A9AF04]) [ ] o.e.j.s.Server Started @544874ms
[junit4] 2> 544764 INFO (TEST-ComputePlanActionTest.testNodeAddedTriggerWithAddReplicaPreferredOp_1Shard-seed#[A827C9A252A9AF04]) [ ] o.a.s.c.s.e.JettySolrRunner Jetty properties: {hostContext=/solr, hostPort=65506}
[junit4] 2> 544764 ERROR (TEST-ComputePlanActionTest.testNodeAddedTriggerWithAddReplicaPreferredOp_1Shard-seed#[A827C9A252A9AF04]) [ ] o.a.s.u.StartupLoggingUtils Missing Java Option solr.log.dir. Logging may be missing or incomplete.
[junit4] 2> 544764 INFO (TEST-ComputePlanActionTest.testNodeAddedTriggerWithAddReplicaPreferredOp_1Shard-seed#[A827C9A252A9AF04]) [ ] o.a.s.s.SolrDispatchFilter Using logger factory org.apache.logging.slf4j.Log4jLoggerFactory
[junit4] 2> 544764 INFO (TEST-ComputePlanActionTest.testNodeAddedTriggerWithAddReplicaPreferredOp_1Shard-seed#[A827C9A252A9AF04]) [ ] o.a.s.s.SolrDispatchFilter ___ _ Welcome to Apache Solr™ version 8.5.0
[junit4] 2> 544764 INFO (TEST-ComputePlanActionTest.testNodeAddedTriggerWithAddReplicaPreferredOp_1Shard-seed#[A827C9A252A9AF04]) [ ] o.a.s.s.SolrDispatchFilter / __| ___| |_ _ Starting in cloud mode on port null
[junit4] 2> 544764 INFO (TEST-ComputePlanActionTest.testNodeAddedTriggerWithAddReplicaPreferredOp_1Shard-seed#[A827C9A252A9AF04]) [ ] o.a.s.s.SolrDispatchFilter \__ \/ _ \ | '_| Install dir: /Users/jenkins/workspace/Lucene-Solr-8.x-MacOSX/solr
[junit4] 2> 544764 INFO (TEST-ComputePlanActionTest.testNodeAddedTriggerWithAddReplicaPreferredOp_1Shard-seed#[A827C9A252A9AF04]) [ ] o.a.s.s.SolrDispatchFilter |___/\___/_|_| Start time: 2020-02-03T06:08:41.344Z
[junit4] 2> 544765 INFO (TEST-ComputePlanActionTest.testNodeAddedTriggerWithAddReplicaPreferredOp_1Shard-seed#[A827C9A252A9AF04]) [ ] o.a.s.c.c.ConnectionManager Waiting for client to connect to ZooKeeper
[junit4] 2> 544768 INFO (zkConnectionManagerCallback-2425-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 544768 INFO (TEST-ComputePlanActionTest.testNodeAddedTriggerWithAddReplicaPreferredOp_1Shard-seed#[A827C9A252A9AF04]) [ ] o.a.s.c.c.ConnectionManager Client is connected to ZooKeeper
[junit4] 2> 544770 INFO (TEST-ComputePlanActionTest.testNodeAddedTriggerWithAddReplicaPreferredOp_1Shard-seed#[A827C9A252A9AF04]) [ ] o.a.s.s.SolrDispatchFilter solr.xml found in ZooKeeper. Loading...
[junit4] 2> 544947 INFO (TEST-ComputePlanActionTest.testNodeAddedTriggerWithAddReplicaPreferredOp_1Shard-seed#[A827C9A252A9AF04]) [ ] o.a.s.h.c.HttpShardHandlerFactory Host whitelist initialized: WhitelistHostChecker [whitelistHosts=null, whitelistHostCheckingEnabled=true]
[junit4] 2> 544948 WARN (TEST-ComputePlanActionTest.testNodeAddedTriggerWithAddReplicaPreferredOp_1Shard-seed#[A827C9A252A9AF04]) [ ] o.e.j.u.s.S.config Trusting all certificates configured for Client@617d4371[provider=null,keyStore=null,trustStore=null]
[junit4] 2> 544948 WARN (TEST-ComputePlanActionTest.testNodeAddedTriggerWithAddReplicaPreferredOp_1Shard-seed#[A827C9A252A9AF04]) [ ] o.e.j.u.s.S.config No Client EndPointIdentificationAlgorithm configured for Client@617d4371[provider=null,keyStore=null,trustStore=null]
[junit4] 2> 544952 WARN (TEST-ComputePlanActionTest.testNodeAddedTriggerWithAddReplicaPreferredOp_1Shard-seed#[A827C9A252A9AF04]) [ ] o.e.j.u.s.S.config Trusting all certificates configured for Client@7a893a21[provider=null,keyStore=null,trustStore=null]
[junit4] 2> 544952 WARN (TEST-ComputePlanActionTest.testNodeAddedTriggerWithAddReplicaPreferredOp_1Shard-seed#[A827C9A252A9AF04]) [ ] o.e.j.u.s.S.config No Client EndPointIdentificationAlgorithm configured for Client@7a893a21[provider=null,keyStore=null,trustStore=null]
[junit4] 2> 544953 INFO (TEST-ComputePlanActionTest.testNodeAddedTriggerWithAddReplicaPreferredOp_1Shard-seed#[A827C9A252A9AF04]) [ ] o.a.s.c.ZkContainer Zookeeper client=127.0.0.1:65486/solr
[junit4] 2> 544954 INFO (TEST-ComputePlanActionTest.testNodeAddedTriggerWithAddReplicaPreferredOp_1Shard-seed#[A827C9A252A9AF04]) [ ] o.a.s.c.c.ConnectionManager Waiting for client to connect to ZooKeeper
[junit4] 2> 544957 INFO (zkConnectionManagerCallback-2432-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 544957 INFO (TEST-ComputePlanActionTest.testNodeAddedTriggerWithAddReplicaPreferredOp_1Shard-seed#[A827C9A252A9AF04]) [ ] o.a.s.c.c.ConnectionManager Client is connected to ZooKeeper
[junit4] 2> 544985 DEBUG (ScheduledTrigger-2384-thread-3) [ ] o.a.s.c.a.NodeAddedTrigger Running NodeAddedTrigger node_added_trigger
[junit4] 2> 544985 DEBUG (ScheduledTrigger-2384-thread-3) [ ] o.a.s.c.a.NodeAddedTrigger Found livenodes: 1
[junit4] 2> 544993 INFO (OverseerCollectionConfigSetProcessor-72087354090061829-127.0.0.1:65491_solr-n_0000000000) [n:127.0.0.1:65491_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> 545060 INFO (TEST-ComputePlanActionTest.testNodeAddedTriggerWithAddReplicaPreferredOp_1Shard-seed#[A827C9A252A9AF04]) [n:127.0.0.1:65506_solr ] o.a.s.c.c.ConnectionManager Waiting for client to connect to ZooKeeper
[junit4] 2> 545061 INFO (zkConnectionManagerCallback-2434-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 545061 INFO (TEST-ComputePlanActionTest.testNodeAddedTriggerWithAddReplicaPreferredOp_1Shard-seed#[A827C9A252A9AF04]) [n:127.0.0.1:65506_solr ] o.a.s.c.c.ConnectionManager Client is connected to ZooKeeper
[junit4] 2> 545078 INFO (TEST-ComputePlanActionTest.testNodeAddedTriggerWithAddReplicaPreferredOp_1Shard-seed#[A827C9A252A9AF04]) [n:127.0.0.1:65506_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (1)
[junit4] 2> 545087 INFO (TEST-ComputePlanActionTest.testNodeAddedTriggerWithAddReplicaPreferredOp_1Shard-seed#[A827C9A252A9AF04]) [n:127.0.0.1:65506_solr ] o.a.s.c.ZkController Publish node=127.0.0.1:65506_solr as DOWN
[junit4] 2> 545090 INFO (TEST-ComputePlanActionTest.testNodeAddedTriggerWithAddReplicaPreferredOp_1Shard-seed#[A827C9A252A9AF04]) [n:127.0.0.1:65506_solr ] o.a.s.c.TransientSolrCoreCacheDefault Allocating transient cache for 2147483647 transient cores
[junit4] 2> 545090 INFO (TEST-ComputePlanActionTest.testNodeAddedTriggerWithAddReplicaPreferredOp_1Shard-seed#[A827C9A252A9AF04]) [n:127.0.0.1:65506_solr ] o.a.s.c.ZkController Register node as live in ZooKeeper:/live_nodes/127.0.0.1:65506_solr
[junit4] 2> 545091 DEBUG (OverseerStateUpdate-72087354090061829-127.0.0.1:65491_solr-n_0000000000) [n:127.0.0.1:65491_solr ] o.a.s.c.Overseer processMessage: queueSize: 1, message = {
[junit4] 2> "operation":"downnode",
[junit4] 2> "node_name":"127.0.0.1:65506_solr"} current state version: 0
[junit4] 2> 545091 DEBUG (OverseerStateUpdate-72087354090061829-127.0.0.1:65491_solr-n_0000000000) [n:127.0.0.1:65491_solr ] o.a.s.c.o.NodeMutator DownNode state invoked for node: 127.0.0.1:65506_solr
[junit4] 2> 545094 INFO (zkCallback-2410-thread-3) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (1) -> (2)
[junit4] 2> 545095 INFO (zkCallback-2419-thread-2) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (1) -> (2)
[junit4] 2> 545095 INFO (zkCallback-2433-thread-1) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (1) -> (2)
[junit4] 2> 545095 INFO (zkCallback-2419-thread-1) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (1) -> (2)
[junit4] 2> 545099 INFO (TEST-ComputePlanActionTest.testNodeAddedTriggerWithAddReplicaPreferredOp_1Shard-seed#[A827C9A252A9AF04]) [n:127.0.0.1:65506_solr ] o.a.s.p.PackageLoader /packages.json updated to version -1
[junit4] 2> 545099 WARN (TEST-ComputePlanActionTest.testNodeAddedTriggerWithAddReplicaPreferredOp_1Shard-seed#[A827C9A252A9AF04]) [n:127.0.0.1:65506_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> 545140 INFO (TEST-ComputePlanActionTest.testNodeAddedTriggerWithAddReplicaPreferredOp_1Shard-seed#[A827C9A252A9AF04]) [n:127.0.0.1:65506_solr ] o.a.s.h.a.MetricsHistoryHandler No .system collection, keeping metrics history in memory.
[junit4] 2> 545164 INFO (TEST-ComputePlanActionTest.testNodeAddedTriggerWithAddReplicaPreferredOp_1Shard-seed#[A827C9A252A9AF04]) [n:127.0.0.1:65506_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_65506.solr.node' (registry 'solr.node') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@5bf17579
[junit4] 2> 545170 INFO (TEST-ComputePlanActionTest.testNodeAddedTriggerWithAddReplicaPreferredOp_1Shard-seed#[A827C9A252A9AF04]) [n:127.0.0.1:65506_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_65506.solr.jvm' (registry 'solr.jvm') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@5bf17579
[junit4] 2> 545170 INFO (TEST-ComputePlanActionTest.testNodeAddedTriggerWithAddReplicaPreferredOp_1Shard-seed#[A827C9A252A9AF04]) [n:127.0.0.1:65506_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_65506.solr.jetty' (registry 'solr.jetty') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@5bf17579
[junit4] 2> 545171 INFO (TEST-ComputePlanActionTest.testNodeAddedTriggerWithAddReplicaPreferredOp_1Shard-seed#[A827C9A252A9AF04]) [n:127.0.0.1:65506_solr ] o.a.s.c.CorePropertiesLocator Found 0 core definitions underneath /Users/jenkins/workspace/Lucene-Solr-8.x-MacOSX/solr/build/solr-core/test/J3/temp/solr.cloud.autoscaling.ComputePlanActionTest_A827C9A252A9AF04-001/tempDir-001/node2/.
[junit4] 2> 545207 INFO (TEST-ComputePlanActionTest.testNodeAddedTriggerWithAddReplicaPreferredOp_1Shard-seed#[A827C9A252A9AF04]) [ ] o.a.s.c.MiniSolrCloudCluster waitForAllNodes: numServers=2
[junit4] 2> 545985 DEBUG (ScheduledTrigger-2384-thread-3) [ ] o.a.s.c.a.NodeAddedTrigger Running NodeAddedTrigger node_added_trigger
[junit4] 2> 545985 DEBUG (ScheduledTrigger-2384-thread-3) [ ] o.a.s.c.a.NodeAddedTrigger Found livenodes: 2
[junit4] 2> 545985 DEBUG (ScheduledTrigger-2384-thread-3) [ ] o.a.s.c.a.NodeAddedTrigger Tracking new node: 127.0.0.1:65506_solr at time 454106437961123
[junit4] 2> 546988 DEBUG (ScheduledTrigger-2384-thread-3) [ ] o.a.s.c.a.NodeAddedTrigger Running NodeAddedTrigger node_added_trigger
[junit4] 2> 546988 DEBUG (ScheduledTrigger-2384-thread-3) [ ] o.a.s.c.a.NodeAddedTrigger Found livenodes: 2
[junit4] 2> 546988 DEBUG (ScheduledTrigger-2384-thread-3) [ ] o.a.s.c.a.NodeAddedTrigger NodeAddedTrigger node_added_trigger firing registered processor for nodes: [127.0.0.1:65506_solr] added at times [454106437961123], now=454107441228997
[junit4] 2> 546988 DEBUG (ScheduledTrigger-2384-thread-3) [ ] o.a.s.c.a.ScheduledTriggers ++++++++ Cooldown inactive - processing event: {
[junit4] 2> "id":"19d01e4ecc5a3Tcdhuy8njou8zkl8pdsocdk8y2",
[junit4] 2> "source":"node_added_trigger",
[junit4] 2> "eventTime":454106437961123,
[junit4] 2> "eventType":"NODEADDED",
[junit4] 2> "properties":{
[junit4] 2> "eventTimes":[454106437961123],
[junit4] 2> "preferredOperation":"addreplica",
[junit4] 2> "nodeNames":["127.0.0.1:65506_solr"],
[junit4] 2> "replicaType":"NRT"}}
[junit4] 2> 546989 DEBUG (ScheduledTrigger-2384-thread-3) [ ] o.a.s.c.a.ScheduledTriggers Pausing all triggers: [node_added_trigger]
[junit4] 2> 546990 DEBUG (ScheduledTrigger-2384-thread-3) [ ] o.a.s.c.a.SystemLogListener Collection .system missing, skip sending event {
[junit4] 2> "id":"19d01e4ecc5a3Tcdhuy8njou8zkl8pdsocdk8y2",
[junit4] 2> "source":"node_added_trigger",
[junit4] 2> "eventTime":454106437961123,
[junit4] 2> "eventType":"NODEADDED",
[junit4] 2> "properties":{
[junit4] 2> "eventTimes":[454106437961123],
[junit4] 2> "preferredOperation":"addreplica",
[junit4] 2> "_enqueue_time_":454107441992819,
[junit4] 2> "nodeNames":["127.0.0.1:65506_solr"],
[junit4] 2> "replicaType":"NRT"}}
[junit4] 2> 546990 DEBUG (ScheduledTrigger-2384-thread-3) [ ] o.a.s.c.a.NodeAddedTrigger Removing new node from tracking: 127.0.0.1:65506_solr
[junit4] 2> 546991 DEBUG (AutoscalingActionExecutor-2385-thread-1) [ ] o.a.s.c.a.ScheduledTriggers -- processing actions for {
[junit4] 2> "id":"19d01e4ecc5a3Tcdhuy8njou8zkl8pdsocdk8y2",
[junit4] 2> "source":"node_added_trigger",
[junit4] 2> "eventTime":454106437961123,
[junit4] 2> "eventType":"NODEADDED",
[junit4] 2> "properties":{
[junit4] 2> "eventTimes":[454106437961123],
[junit4] 2> "preferredOperation":"addreplica",
[junit4] 2> "_enqueue_time_":454107441992819,
[junit4] 2> "nodeNames":["127.0.0.1:65506_solr"],
[junit4] 2> "replicaType":"NRT"}}
[junit4] 2> 546991 DEBUG (AutoscalingActionExecutor-2385-thread-1) [ ] o.a.s.c.a.ComputePlanAction -- processing event: {
[junit4] 2> "id":"19d01e4ecc5a3Tcdhuy8njou8zkl8pdsocdk8y2",
[junit4] 2> "source":"node_added_trigger",
[junit4] 2> "eventTime":454106437961123,
[junit4] 2> "eventType":"NODEADDED",
[junit4] 2> "properties":{
[junit4] 2> "eventTimes":[454106437961123],
[junit4] 2> "preferredOperation":"addreplica",
[junit4] 2> "_enqueue_time_":454107441992819,
[junit4] 2> "nodeNames":["127.0.0.1:65506_solr"],
[junit4] 2> "replicaType":"NRT"}} with context properties: {BEFORE_ACTION=[compute_plan]}
[junit4] 2> 546996 INFO (qtp1002168478-6537) [n:127.0.0.1:65491_solr ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/metrics params={wt=javabin&version=2&key=solr.core.testNodeAddedTriggerWithAddReplicaPreferredOp_1Shard_0.shard1.replica_n1:INDEX.sizeInBytes} status=0 QTime=2
[junit4] 2> 547001 INFO (qtp1002168478-6538) [n:127.0.0.1:65491_solr ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/metrics params={prefix=CONTAINER.fs.usableSpace,CONTAINER.fs.totalSpace,CORE.coreName&wt=javabin&version=2&group=solr.node,solr.core} status=0 QTime=1
[junit4] 2> 547003 INFO (qtp233848012-6588) [n:127.0.0.1:65506_solr ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/metrics params={prefix=CONTAINER.fs.usableSpace,CONTAINER.fs.totalSpace,CORE.coreName&wt=javabin&version=2&group=solr.node,solr.core} status=0 QTime=0
[junit4] 2> 547008 DEBUG (AutoscalingActionExecutor-2385-thread-1) [ ] o.a.s.c.a.ComputePlanAction Computed Plan: action=ADDREPLICA&collection=testNodeAddedTriggerWithAddReplicaPreferredOp_1Shard_0&shard=shard1&node=127.0.0.1:65506_solr&type=NRT
[junit4] 2> 547009 DEBUG (AutoscalingActionExecutor-2385-thread-1) [ ] o.a.s.c.a.SystemLogListener Collection .system missing, skip sending event {
[junit4] 2> "id":"19d01e4ecc5a3Tcdhuy8njou8zkl8pdsocdk8y2",
[junit4] 2> "source":"node_added_trigger",
[junit4] 2> "eventTime":454106437961123,
[junit4] 2> "eventType":"NODEADDED",
[junit4] 2> "properties":{
[junit4] 2> "eventTimes":[454106437961123],
[junit4] 2> "preferredOperation":"addreplica",
[junit4] 2> "_enqueue_time_":454107441992819,
[junit4] 2> "nodeNames":["127.0.0.1:65506_solr"],
[junit4] 2> "replicaType":"NRT"}}
[junit4] 2> 547009 DEBUG (AutoscalingActionExecutor-2385-thread-1) [ ] o.a.s.c.a.SystemLogListener Collection .system missing, skip sending event {
[junit4] 2> "id":"19d01e4ecc5a3Tcdhuy8njou8zkl8pdsocdk8y2",
[junit4] 2> "source":"node_added_trigger",
[junit4] 2> "eventTime":454106437961123,
[junit4] 2> "eventType":"NODEADDED",
[junit4] 2> "properties":{
[junit4] 2> "eventTimes":[454106437961123],
[junit4] 2> "preferredOperation":"addreplica",
[junit4] 2> "_enqueue_time_":454107441992819,
[junit4] 2> "nodeNames":["127.0.0.1:65506_solr"],
[junit4] 2> "replicaType":"NRT"}}
[junit4] 2> 547010 INFO (qtp1002168478-6535) [n:127.0.0.1:65491_solr ] o.a.s.h.a.CollectionsHandler Invoked Collection Action :create with params collection.configName=conf&maxShardsPerNode=2&name=testNodeAddedTriggerWithAddReplicaPreferredOp_1Shard_1&nrtReplicas=2&action=CREATE&numShards=1&wt=javabin&version=2 and sendToOCPQueue=true
[junit4] 2> 547012 DEBUG (AutoscalingActionExecutor-2385-thread-1) [ ] o.a.s.c.a.SystemLogListener Collection .system missing, skip sending event {
[junit4] 2> "id":"19d01e4ecc5a3Tcdhuy8njou8zkl8pdsocdk8y2",
[junit4] 2> "source":"node_added_trigger",
[junit4] 2> "eventTime":454106437961123,
[junit4] 2> "eventType":"NODEADDED",
[junit4] 2> "properties":{
[junit4] 2> "eventTimes":[454106437961123],
[junit4] 2> "preferredOperation":"addreplica",
[junit4] 2> "_enqueue_time_":454107441992819,
[junit4] 2> "nodeNames":["127.0.0.1:65506_solr"],
[junit4] 2> "replicaType":"NRT"}}
[junit4] 2> 547012 DEBUG (AutoscalingActionExecutor-2385-thread-1) [ ] o.a.s.c.a.ScheduledTriggers Resuming trigger: node_added_trigger after 5000ms
[junit4] 2> 547013 DEBUG (AutoscalingActionExecutor-2385-thread-1) [ ] o.a.s.c.a.ScheduledTriggers -- processing took 22 ms for event id=19d01e4ecc5a3Tcdhuy8njou8zkl8pdsocdk8y2
[junit4] 2> 547020 INFO (OverseerThreadFactory-2386-thread-2-processing-n:127.0.0.1:65491_solr) [n:127.0.0.1:65491_solr ] o.a.s.c.a.c.CreateCollectionCmd Create collection testNodeAddedTriggerWithAddReplicaPreferredOp_1Shard_1
[junit4] 2> 547036 DEBUG (OverseerStateUpdate-72087354090061829-127.0.0.1:65491_solr-n_0000000000) [n:127.0.0.1:65491_solr ] o.a.s.c.Overseer processMessage: queueSize: 1, message = {
[junit4] 2> "name":"testNodeAddedTriggerWithAddReplicaPreferredOp_1Shard_1",
[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> 547036 DEBUG (OverseerStateUpdate-72087354090061829-127.0.0.1:65491_solr-n_0000000000) [n:127.0.0.1:65491_solr ] o.a.s.c.o.ClusterStateMutator building a new cName: testNodeAddedTriggerWithAddReplicaPreferredOp_1Shard_1
[junit4] 2> 547037 DEBUG (OverseerStateUpdate-72087354090061829-127.0.0.1:65491_solr-n_0000000000) [n:127.0.0.1:65491_solr ] o.a.s.c.o.ZkStateWriter going to create_collection /collections/testNodeAddedTriggerWithAddReplicaPreferredOp_1Shard_1/state.json
[junit4] 2> 547144 INFO (qtp233848012-6589) [n:127.0.0.1:65506_solr ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/metrics params={prefix=CONTAINER.fs.usableSpace,CONTAINER.fs.totalSpace,CORE.coreName&wt=javabin&version=2&group=solr.node,solr.core} status=0 QTime=0
[junit4] 2> 547145 INFO (qtp1002168478-6536) [n:127.0.0.1:65491_solr ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/metrics params={wt=javabin&version=2&key=solr.core.testNodeAddedTriggerWithAddReplicaPreferredOp_1Shard_0.shard1.replica_n1:INDEX.sizeInBytes} status=0 QTime=0
[junit4] 2> 547146 INFO (qtp1002168478-6537) [n:127.0.0.1:65491_solr ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/metrics params={prefix=CONTAINER.fs.usableSpace,CONTAINER.fs.totalSpace,CORE.coreName&wt=javabin&version=2&group=solr.node,solr.core} status=0 QTime=0
[junit4] 2> 547160 DEBUG (OverseerStateUpdate-72087354090061829-127.0.0.1:65491_solr-n_0000000000) [n:127.0.0.1:65491_solr ] o.a.s.c.Overseer processMessage: queueSize: 1, message = {
[junit4] 2> "operation":"ADDREPLICA",
[junit4] 2> "collection":"testNodeAddedTriggerWithAddReplicaPreferredOp_1Shard_1",
[junit4] 2> "shard":"shard1",
[junit4] 2> "core":"testNodeAddedTriggerWithAddReplicaPreferredOp_1Shard_1_shard1_replica_n1",
[junit4] 2> "state":"down",
[junit4] 2> "base_url":"http://127.0.0.1:65506/solr",
[junit4] 2> "type":"NRT",
[junit4] 2> "waitForFinalState":"false"} current state version: 0
[junit4] 2> 547160 INFO (OverseerStateUpdate-72087354090061829-127.0.0.1:65491_solr-n_0000000000) [n:127.0.0.1:65491_solr ] o.a.s.c.o.SliceMutator createReplica() {
[junit4] 2> "operation":"ADDREPLICA",
[junit4] 2> "collection":"testNodeAddedTriggerWithAddReplicaPreferredOp_1Shard_1",
[junit4] 2> "shard":"shard1",
[junit4] 2> "core":"testNodeAddedTriggerWithAddReplicaPreferredOp_1Shard_1_shard1_replica_n1",
[junit4] 2> "state":"down",
[junit4] 2> "base_url":"http://127.0.0.1:65506/solr",
[junit4] 2> "type":"NRT",
[junit4] 2> "waitForFinalState":"false"}
[junit4] 2> 547165 DEBUG (OverseerStateUpdate-72087354090061829-127.0.0.1:65491_solr-n_0000000000) [n:127.0.0.1:65491_solr ] o.a.s.c.o.SliceMutator Old Slice: shard1:{
[junit4] 2> "range":"80000000-7fffffff",
[junit4] 2> "state":"active",
[junit4] 2> "replicas":{}}
[junit4] 2> 547165 DEBUG (OverseerStateUpdate-72087354090061829-127.0.0.1:65491_solr-n_0000000000) [n:127.0.0.1:65491_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":"testNodeAddedTriggerWithAddReplicaPreferredOp_1Shard_1_shard1_replica_n1",
[junit4] 2> "base_url":"http://127.0.0.1:65506/solr",
[junit4] 2> "state":"down",
[junit4] 2> "node_name":null,
[junit4] 2> "type":"NRT"}}}
[junit4] 2> 547170 DEBUG (OverseerStateUpdate-72087354090061829-127.0.0.1:65491_solr-n_0000000000) [n:127.0.0.1:65491_solr ] o.a.s.c.Overseer processMessage: queueSize: 2, message = {
[junit4] 2> "operation":"ADDREPLICA",
[junit4] 2> "collection":"testNodeAddedTriggerWithAddReplicaPreferredOp_1Shard_1",
[junit4] 2> "shard":"shard1",
[junit4] 2> "core":"testNodeAddedTriggerWithAddReplicaPreferredOp_1Shard_1_shard1_replica_n2",
[junit4] 2> "state":"down",
[junit4] 2> "base_url":"http://127.0.0.1:65491/solr",
[junit4] 2> "type":"NRT",
[junit4] 2> "waitForFinalState":"false"} current state version: 0
[junit4] 2> 547170 INFO (OverseerStateUpdate-72087354090061829-127.0.0.1:65491_solr-n_0000000000) [n:127.0.0.1:65491_solr ] o.a.s.c.o.SliceMutator createReplica() {
[junit4] 2> "operation":"ADDREPLICA",
[junit4] 2> "collection":"testNodeAddedTriggerWithAddReplicaPreferredOp_1Shard_1",
[junit4] 2> "shard":"shard1",
[junit4] 2> "core":"testNodeAddedTriggerWithAddReplicaPreferredOp_1Shard_1_shard1_replica_n2",
[junit4] 2> "state":"down",
[junit4] 2> "base_url":"http://127.0.0.1:65491/solr",
[junit4] 2> "type":"NRT",
[junit4] 2> "waitForFinalState":"false"}
[junit4] 2> 547174 DEBUG (OverseerStateUpdate-72087354090061829-127.0.0.1:65491_solr-n_0000000000) [n:127.0.0.1:65491_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":"testNodeAddedTriggerWithAddReplicaPreferredOp_1Shard_1_shard1_replica_n1",
[junit4] 2> "base_url":"http://127.0.0.1:65506/solr",
[junit4] 2> "state":"down",
[junit4] 2> "node_name":null,
[junit4] 2> "type":"NRT"}}}
[junit4] 2> 547174 DEBUG (OverseerStateUpdate-72087354090061829-127.0.0.1:65491_solr-n_0000000000) [n:127.0.0.1:65491_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":"testNodeAddedTriggerWithAddReplicaPreferredOp_1Shard_1_shard1_replica_n1",
[junit4] 2> "base_url":"http://127.0.0.1:65506/solr",
[junit4] 2> "state":"down",
[junit4] 2> "node_name":null,
[junit4] 2> "type":"NRT"},
[junit4] 2> "core_node4":{
[junit4] 2> "core":"testNodeAddedTriggerWithAddReplicaPreferredOp_1Shard_1_shard1_replica_n2",
[junit4] 2> "base_url":"http://127.0.0.1:65491/solr",
[junit4] 2> "state":"down",
[junit4] 2> "node_name":null,
[junit4] 2> "type":"NRT"}}}
[junit4] 2> 547275 DEBUG (OverseerStateUpdate-72087354090061829-127.0.0.1:65491_solr-n_0000000000) [n:127.0.0.1:65491_solr ] o.a.s.c.o.ZkStateWriter going to update_collection /collections/testNodeAddedTriggerWithAddReplicaPreferredOp_1Shard_1/state.json version: 0
[junit4] 2> 547377 INFO (qtp1002168478-6538) [n:127.0.0.1:65491_solr x:testNodeAddedTriggerWithAddReplicaPreferredOp_1Shard_1_shard1_replica_n2 ] o.a.s.h.a.CoreAdminOperation core create command qt=/admin/cores&coreNodeName=core_node4&collection.configName=conf&newCollection=true&name=testNodeAddedTriggerWithAddReplicaPreferredOp_1Shard_1_shard1_replica_n2&action=CREATE&numShards=1&collection=testNodeAddedTriggerWithAddReplicaPreferredOp_1Shard_1&shard=shard1&wt=javabin&version=2&replicaType=NRT
[junit4] 2> 547377 INFO (qtp233848012-6590) [n:127.0.0.1:65506_solr x:testNodeAddedTriggerWithAddReplicaPreferredOp_1Shard_1_shard1_replica_n1 ] o.a.s.h.a.CoreAdminOperation core create command qt=/admin/cores&coreNodeName=core_node3&collection.configName=conf&newCollection=true&name=testNodeAddedTriggerWithAddReplicaPreferredOp_1Shard_1_shard1_replica_n1&action=CREATE&numShards=1&collection=testNodeAddedTriggerWithAddReplicaPreferredOp_1Shard_1&shard=shard1&wt=javabin&version=2&replicaType=NRT
[junit4] 2> 547388 DEBUG (OverseerStateUpdate-72087354090061829-127.0.0.1:65491_solr-n_0000000000) [n:127.0.0.1:65491_solr ] o.a.s.c.Overseer processMessage: queueSize: 1, message = {
[junit4] 2> "core":"testNodeAddedTriggerWithAddReplicaPreferredOp_1Shard_1_shard1_replica_n2",
[junit4] 2> "core_node_name":"core_node4",
[junit4] 2> "roles":null,
[junit4] 2> "base_url":"http://127.0.0.1:65491/solr",
[junit4] 2> "node_name":"127.0.0.1:65491_solr",
[junit4] 2> "numShards":"1",
[junit4] 2> "state":"down",
[junit4] 2> "shard":"shard1",
[junit4] 2> "collection":"testNodeAddedTriggerWithAddReplicaPreferredOp_1Shard_1",
[junit4] 2> "type":"NRT",
[junit4] 2> "force_set_state":"false",
[junit4] 2> "operation":"state"} current state version: 0
[junit4] 2> 547389 DEBUG (OverseerStateUpdate-72087354090061829-127.0.0.1:65491_solr-n_0000000000) [n:127.0.0.1:65491_solr ] o.a.s.c.o.ReplicaMutator Update state numShards=1 message={
[junit4] 2> "core":"testNodeAddedTriggerWithAddReplicaPreferredOp_1Shard_1_shard1_replica_n2",
[junit4] 2> "core_node_name":"core_node4",
[junit4] 2> "roles":null,
[junit4] 2> "base_url":"http://127.0.0.1:65491/solr",
[junit4] 2> "node_name":"127.0.0.1:65491_solr",
[junit4] 2> "numShards":"1",
[junit4] 2> "state":"down",
[junit4] 2> "shard":"shard1",
[junit4] 2> "collection":"testNodeAddedTriggerWithAddReplicaPreferredOp_1Shard_1",
[junit4] 2> "type":"NRT",
[junit4] 2> "force_set_state":"false",
[junit4] 2> "operation":"state"}
[junit4] 2> 547389 DEBUG (OverseerStateUpdate-72087354090061829-127.0.0.1:65491_solr-n_0000000000) [n:127.0.0.1:65491_solr ] o.a.s.c.o.ReplicaMutator Will update state for replica: core_node4:{
[junit4] 2> "core":"testNodeAddedTriggerWithAddReplicaPreferredOp_1Shard_1_shard1_replica_n2",
[junit4] 2> "base_url":"http://127.0.0.1:65491/solr",
[junit4] 2> "node_name":"127.0.0.1:65491_solr",
[junit4] 2> "state":"down",
[junit4] 2> "type":"NRT",
[junit4] 2> "force_set_state":"false"}
[junit4] 2> 547389 DEBUG (OverseerStateUpdate-72087354090061829-127.0.0.1:65491_solr-n_0000000000) [n:127.0.0.1:65491_solr ] o.a.s.c.o.ReplicaMutator Collection is now: DocCollection(testNodeAddedTriggerWithAddReplicaPreferredOp_1Shard_1//collections/testNodeAddedTriggerWithAddReplicaPreferredOp_1Shard_1/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":"testNodeAddedTriggerWithAddReplicaPreferredOp_1Shard_1_shard1_replica_n1",
[junit4] 2> "base_url":"http://127.0.0.1:65506/solr",
[junit4] 2> "state":"down",
[junit4] 2> "node_name":null,
[junit4] 2> "type":"NRT"},
[junit4] 2> "core_node4":{
[junit4] 2> "core":"testNodeAddedTriggerWithAddReplicaPreferredOp_1Shard_1_shard1_replica_n2",
[junit4] 2> "base_url":"http://127.0.0.1:65491/solr",
[junit4] 2> "node_name":"127.0.0.1:65491_solr",
[junit4] 2> "state":"down",
[junit4] 2> "type":"NRT",
[junit4] 2> "force_set_state":"false"}}}}}
[junit4] 2> 547391 DEBUG (OverseerStateUpdate-72087354090061829-127.0.0.1:65491_solr-n_0000000000) [n:127.0.0.1:65491_solr ] o.a.s.c.Overseer processMessage: queueSize: 2, message = {
[junit4] 2> "core":"testNodeAddedTriggerWithAddReplicaPreferredOp_1Shard_1_shard1_replica_n1",
[junit4] 2> "core_node_name":"core_node3",
[junit4] 2> "roles":null,
[junit4] 2> "base_url":"http://127.0.0.1:65506/solr",
[junit4] 2> "node_name":"127.0.0.1:65506_solr",
[junit4] 2> "numShards":"1",
[junit4] 2> "state":"down",
[junit4] 2> "shard":"shard1",
[junit4] 2> "collection":"testNodeAddedTriggerWithAddReplicaPreferredOp_1Shard_1",
[junit4] 2> "type":"NRT",
[junit4] 2> "force_set_state":"false",
[junit4] 2> "operation":"state"} current state version: 0
[junit4] 2> 547391 DEBUG (OverseerStateUpdate-72087354090061829-127.0.0.1:65491_solr-n_0000000000) [n:127.0.0.1:65491_solr ] o.a.s.c.o.ReplicaMutator Update state numShards=1 message={
[junit4] 2> "core":"testNodeAddedTriggerWithAddReplicaPreferredOp_1Shard_1_shard1_replica_n1",
[junit4] 2> "core_node_name":"core_node3",
[junit4] 2> "roles":null,
[junit4] 2> "base_url":"http://127.0.0.1:65506/solr",
[junit4] 2> "node_name":"127.0.0.1:65506_solr",
[junit4] 2> "numShards":"1",
[junit4] 2> "state":"down",
[junit4] 2> "shard":"shard1",
[junit4] 2> "collection":"testNodeAddedTriggerWithAddReplicaPreferredOp_1Shard_1",
[junit4] 2> "type":"NRT",
[junit4] 2> "force_set_state":"false",
[junit4] 2> "operation":"state"}
[junit4] 2> 547391 DEBUG (OverseerStateUpdate-72087354090061829-127.0.0.1:65491_solr-n_0000000000) [n:127.0.0.1:65491_solr ] o.a.s.c.o.ReplicaMutator Will update state for replica: core_node3:{
[junit4] 2> "core":"testNodeAddedTriggerWithAddReplicaPreferredOp_1Shard_1_shard1_replica_n1",
[junit4] 2> "base_url":"http://127.0.0.1:65506/solr",
[junit4] 2> "node_name":"127.0.0.1:65506_solr",
[junit4] 2> "state":"down",
[junit4] 2> "type":"NRT",
[junit4] 2> "force_set_state":"false"}
[junit4] 2> 547391 DEBUG (OverseerStateUpdate-72087354090061829-127.0.0.1:65491_solr-n_0000000000) [n:127.0.0.1:65491_solr ] o.a.s.c.o.ReplicaMutator Collection is now: DocCollection(testNodeAddedTriggerWithAddReplicaPreferredOp_1Shard_1//collections/testNodeAddedTriggerWithAddReplicaPreferredOp_1Shard_1/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":"testNodeAddedTriggerWithAddReplicaPreferredOp_1Shard_1_shard1_replica_n1",
[junit4] 2> "base_url":"http://127.0.0.1:65506/solr",
[junit4] 2> "node_name":"127.0.0.1:65506_solr",
[junit4] 2> "state":"down",
[junit4] 2> "type":"NRT",
[junit4] 2> "force_set_state":"false"},
[junit4] 2> "core_node4":{
[junit4] 2> "core":"testNodeAddedTriggerWithAddReplicaPreferredOp_1Shard_1_shard1_replica_n2",
[junit4] 2> "base_url":"http://127.0.0.1:65491/solr",
[junit4] 2> "node_name":"127.0.0.1:65491_solr",
[junit4] 2> "state":"down",
[junit4] 2> "type":"NRT",
[junit4] 2> "force_set_stat
[...truncated too long message...]
ddedTriggerWithAddReplicaPreferredOp_2Shard_2/terms/shard2
[junit4] 2> 6 /solr/collections/testNodeLostTriggerWithDeleteNodePreferredOp_0/terms/shard2
[junit4] 2> 6 /solr/collections/testNodeAddedTriggerWithAddReplicaPreferredOp_1Shard_4/terms/shard1
[junit4] 2> 5 /solr/collections/testNodeAddedTriggerWithAddReplicaPreferredOp_1Shard_1/terms/shard1
[junit4] 2> 5 /solr/collections/testNodeAddedTriggerWithAddReplicaPreferredOp_1Shard_3/terms/shard1
[junit4] 2> 5 /solr/collections/testNodeAddedTriggerWithAddReplicaPreferredOp_2Shard_4/terms/shard2
[junit4] 2> 5 /solr/collections/testNodeAddedTriggerWithAddReplicaPreferredOpReplicaType_1Shard_2/terms/shard1
[junit4] 2> 5 /solr/collections/testNodeAddedTriggerWithAddReplicaPreferredOpReplicaType_1Shard_4/terms/shard1
[junit4] 2> 5 /solr/collections/testSelected1/terms/shard2
[junit4] 2> 5 /solr/collections/testSelected2/terms/shard2
[junit4] 2> 5 /solr/collections/testSelected3/terms/shard2
[junit4] 2> 5 /solr/collections/testNodeLostTriggerWithDeleteNodePreferredOp_0/terms/shard3
[junit4] 2> 5 /solr/collections/testNodeLostTriggerWithDeleteNodePreferredOp_0/terms/shard1
[junit4] 2> 5 /solr/collections/testNodeAddedTriggerWithAddReplicaPreferredOp_1Shard_2/terms/shard1
[junit4] 2> 5 /solr/collections/testNodeLostTriggerWithDeleteNodePreferredOp_0/state.json
[junit4] 2> 4 /solr/collections/testNodeAddedTriggerWithAddReplicaPreferredOp_2Shard_1/state.json
[junit4] 2> 4 /solr/collections/testNodeAddedTriggerWithAddReplicaPreferredOp_2Shard_3/state.json
[junit4] 2> 4 /solr/collections/testNodeAddedTriggerWithAddReplicaPreferredOp_2Shard_0/state.json
[junit4] 2> 3 /solr/collections/testSelected3/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> 3 /solr/collections/testSelected2/state.json
[junit4] 2> 2 /solr/collections/testSelected1/state.json
[junit4] 2> 2 /solr/collections/testNodeAddedTriggerWithAddReplicaPreferredOp_2Shard_0/terms/shard2
[junit4] 2> 2 /solr/collections/testNodeAddedTriggerWithAddReplicaPreferredOpReplicaType_1Shard_0/terms/shard1
[junit4] 2> 2 /solr/collections/testNodeAddedTriggerWithAddReplicaPreferredOp_2Shard_4/state.json
[junit4] 2> 2 /solr/collections/testNodeAddedTriggerWithAddReplicaPreferredOp_1Shard_0/terms/shard1
[junit4] 2> 2 /solr/collections/testNodeWithMultipleReplicasLost/state.json
[junit4] 2>
[junit4] 2> Maximum concurrent data watches above limit:
[junit4] 2>
[junit4] 2> 63 /solr/collections/testSelected3/state.json
[junit4] 2> 58 /solr/collections/testNodeLostTriggerWithDeleteNodePreferredOp_0/state.json
[junit4] 2> 57 /solr/collections/testSelected2/state.json
[junit4] 2> 54 /solr/collections/testSelected1/state.json
[junit4] 2> 47 /solr/collections/testNodeWithMultipleReplicasLost/state.json
[junit4] 2> 45 /solr/collections/testNodeAddedTriggerWithAddReplicaPreferredOp_2Shard_3/state.json
[junit4] 2> 42 /solr/aliases.json
[junit4] 2> 38 /solr/autoscaling.json
[junit4] 2> 35 /solr/collections/testNodeAddedTriggerWithAddReplicaPreferredOp_2Shard_4/state.json
[junit4] 2> 31 /solr/collections/testNodeAddedTriggerWithAddReplicaPreferredOp_2Shard_2/state.json
[junit4] 2> 30 /solr/collections/testNodeAddedTriggerWithAddReplicaPreferredOp_2Shard_1/state.json
[junit4] 2> 29 /solr/collections/testNodeAddedTriggerWithAddReplicaPreferredOpReplicaType_1Shard_2/state.json
[junit4] 2> 29 /solr/collections/testNodeAddedTriggerWithAddReplicaPreferredOpReplicaType_1Shard_3/state.json
[junit4] 2> 29 /solr/collections/testNodeAddedTriggerWithAddReplicaPreferredOpReplicaType_1Shard_4/state.json
[junit4] 2> 29 /solr/collections/testNodeAddedTriggerWithAddReplicaPreferredOpReplicaType_1Shard_1/state.json
[junit4] 2> 23 /solr/collections/testNodeAddedTriggerWithAddReplicaPreferredOp_1Shard_4/state.json
[junit4] 2> 23 /solr/clusterstate.json
[junit4] 2> 23 /solr/collections/testNodeAddedTriggerWithAddReplicaPreferredOp_1Shard_3/state.json
[junit4] 2> 22 /solr/collections/testNodeAddedTriggerWithAddReplicaPreferredOp_1Shard_1/state.json
[junit4] 2> 22 /solr/collections/testNodeAddedTriggerWithAddReplicaPreferredOp_1Shard_2/state.json
[junit4] 2> 14 /solr/collections/testNodeAdded/state.json
[junit4] 2> 13 /solr/collections/testNodeAddedTriggerWithAddReplicaPreferredOp_2Shard_0/state.json
[junit4] 2> 13 /solr/collections/testNodeAddedTriggerWithAddReplicaPreferredOpReplicaType_1Shard_0/state.json
[junit4] 2> 11 /solr/collections/testNodeAddedTriggerWithAddReplicaPreferredOp_1Shard_0/state.json
[junit4] 2> 6 /solr/overseer_elect/election/72087354090061848-127.0.0.1:49553_solr-n_0000000006
[junit4] 2> 3 /solr/overseer_elect/election/72087354090061836-127.0.0.1:49216_solr-n_0000000002
[junit4] 2> 2 /solr/overseer_elect/election/72087354090061829-127.0.0.1:65491_solr-n_0000000000
[junit4] 2> 2 /solr/collections/testNodeWithMultipleReplicasLost/leader_elect/shard2/election/72087354090061863-core_node9-n_0000000000
[junit4] 2>
[junit4] 2> Maximum concurrent children watches above limit:
[junit4] 2>
[junit4] 2> 469 /solr/overseer/queue
[junit4] 2> 216 /solr/live_nodes
[junit4] 2> 138 /solr/collections
[junit4] 2> 131 /solr/overseer/collection-queue-work
[junit4] 2> 10 /solr/autoscaling/events/node_added_trigger
[junit4] 2> 6 /solr/autoscaling/events/node_lost_trigger
[junit4] 2> 4 /solr/autoscaling/events/.scheduled_maintenance
[junit4] 2> 4 /solr/autoscaling/events/.auto_add_replicas
[junit4] 2> 4 /solr/overseer/queue-work
[junit4] 2>
[junit4] 2> 665006 INFO (SUITE-ComputePlanActionTest-seed#[A827C9A252A9AF04]-worker) [ ] o.a.s.c.ZkTestServer waitForServerDown: 127.0.0.1:65486
[junit4] 2> 665006 INFO (SUITE-ComputePlanActionTest-seed#[A827C9A252A9AF04]-worker) [ ] o.a.s.c.ZkTestServer parse host and port list: 127.0.0.1:65486
[junit4] 2> 665006 INFO (SUITE-ComputePlanActionTest-seed#[A827C9A252A9AF04]-worker) [ ] o.a.s.c.ZkTestServer connecting to 127.0.0.1 65486
[junit4] 2> NOTE: leaving temporary files on disk at: /Users/jenkins/workspace/Lucene-Solr-8.x-MacOSX/solr/build/solr-core/test/J3/temp/solr.cloud.autoscaling.ComputePlanActionTest_A827C9A252A9AF04-001
[junit4] 2> Feb 03, 2020 6:10:41 AM com.carrotsearch.randomizedtesting.ThreadLeakControl checkThreadLeaks
[junit4] 2> WARNING: Will linger awaiting termination of 1 leaked thread(s).
[junit4] 2> NOTE: test params are: codec=Asserting(Lucene84): {}, docValues:{}, maxPointsInLeafNode=915, maxMBSortInHeap=7.1275208186663, sim=Asserting(org.apache.lucene.search.similarities.AssertingSimilarity@782929a9), locale=ja-JP-u-ca-japanese-x-lvariant-JP, timezone=Pacific/Chuuk
[junit4] 2> NOTE: Mac OS X 10.14.6 x86_64/Oracle Corporation 1.8.0_201 (64-bit)/cpus=6,threads=1,free=155902480,total=518979584
[junit4] 2> NOTE: All tests run in this JVM: [PeerSyncTest, TaggingAttributeTest, OverseerRolesTest, XsltUpdateRequestHandlerTest, ReindexCollectionTest, SplitByPrefixTest, ForceLeaderTest, TestFastLRUCache, TestSnapshotCloudManager, FieldAnalysisRequestHandlerTest, AddSchemaFieldsUpdateProcessorFactoryTest, BasicZkTest, ScheduledMaintenanceTriggerTest, TestClusterProperties, TestReload, TestQueryingOnDownCollection, TestMergePolicyConfig, TestPackages, TestSolrCLIRunExample, TestAuthorizationFramework, DistributedFacetExistsSmallTest, NumericFieldsTest, TriLevelCompositeIdRoutingTest, TestRangeQuery, SortByFunctionTest, TestExclusionRuleCollectionAccess, TestShardHandlerFactory, ZkFailoverTest, TestSolrCoreSnapshots, TestSchemaResource, SuggesterTSTTest, HdfsRecoverLeaseTest, TestDeleteCollectionOnDownNodes, TestBM25SimilarityFactory, AddReplicaTest, InfoHandlerTest, ResourceLoaderTest, MetricsHistoryIntegrationTest, TestFieldCollectionResource, MoreLikeThisComponentTest, TestPerFieldSimilarityWithDefaultOverride, CursorMarkTest, NodeMutatorTest, TestUpdate, MoveReplicaHDFSTest, OutputWriterTest, TestEmbeddedSolrServerConstructors, DimensionalRoutedAliasUpdateProcessorTest, ComputePlanActionTest]
[junit4] Completed [270/897 (1!)] on J3 in 123.69s, 8 tests, 1 failure, 1 skipped <<< FAILURES!
[...truncated 54675 lines...]
[repro] Jenkins log URL: https://jenkins.thetaphi.de/job/Lucene-Solr-8.x-MacOSX/587/consoleText
[repro] Revision: 34d299018e24e10d3b60dc3dce4354039bc765dd
[repro] Ant options: "-Dargs=-XX:-UseCompressedOops -XX:+UseSerialGC"
[repro] Repro line: ant test -Dtestcase=ComputePlanActionTest -Dtests.method=testNodeAdded -Dtests.seed=A827C9A252A9AF04 -Dtests.slow=true -Dtests.locale=ja-JP-u-ca-japanese-x-lvariant-JP -Dtests.timezone=Pacific/Chuuk -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 3457 lines...]
[repro] ant test-nocompile -Dtests.dups=5 -Dtests.maxfailures=5 -Dtests.class="*.ComputePlanActionTest" -Dtests.showOutput=onerror "-Dargs=-XX:-UseCompressedOops -XX:+UseSerialGC" -Dtests.seed=A827C9A252A9AF04 -Dtests.slow=true -Dtests.locale=ja-JP-u-ca-japanese-x-lvariant-JP -Dtests.timezone=Pacific/Chuuk -Dtests.asserts=true -Dtests.file.encoding=UTF-8
[...truncated 116 lines...]
[repro] Failures w/original seeds:
[repro] 0/5 failed: org.apache.solr.cloud.autoscaling.ComputePlanActionTest
[repro] Exiting with code 0
[...truncated 73 lines...]