Build: https://builds.apache.org/job/Lucene-Solr-Tests-master/2424/
1 tests failed.
FAILED:
org.apache.solr.cloud.autoscaling.ComputePlanActionTest.testNodeWithMultipleReplicasLost
Error Message:
The operations computed by ComputePlanAction should not be null
SolrClientNodeStateProvider.DEBUG{AFTER_ACTION=[compute_plan, null],
BEFORE_ACTION=[compute_plan, null]}
Stack Trace:
java.lang.AssertionError: The operations computed by ComputePlanAction should
not be null SolrClientNodeStateProvider.DEBUG{AFTER_ACTION=[compute_plan,
null], BEFORE_ACTION=[compute_plan, null]}
at
__randomizedtesting.SeedInfo.seed([DB3957B6117D9155:EBF9B634990F7009]:0)
at org.junit.Assert.fail(Assert.java:93)
at org.junit.Assert.assertTrue(Assert.java:43)
at org.junit.Assert.assertNotNull(Assert.java:526)
at
org.apache.solr.cloud.autoscaling.ComputePlanActionTest.testNodeWithMultipleReplicasLost(ComputePlanActionTest.java:291)
at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
at
sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
at
sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
at java.lang.reflect.Method.invoke(Method.java:498)
at
com.carrotsearch.randomizedtesting.RandomizedRunner.invoke(RandomizedRunner.java:1737)
at
com.carrotsearch.randomizedtesting.RandomizedRunner$8.evaluate(RandomizedRunner.java:934)
at
com.carrotsearch.randomizedtesting.RandomizedRunner$9.evaluate(RandomizedRunner.java:970)
at
com.carrotsearch.randomizedtesting.RandomizedRunner$10.evaluate(RandomizedRunner.java:984)
at
com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:57)
at
org.apache.lucene.util.TestRuleSetupTeardownChained$1.evaluate(TestRuleSetupTeardownChained.java:49)
at
org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:45)
at
org.apache.lucene.util.TestRuleThreadAndTestName$1.evaluate(TestRuleThreadAndTestName.java:48)
at
org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:64)
at
org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:47)
at
com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at
com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:368)
at
com.carrotsearch.randomizedtesting.ThreadLeakControl.forkTimeoutingTask(ThreadLeakControl.java:817)
at
com.carrotsearch.randomizedtesting.ThreadLeakControl$3.evaluate(ThreadLeakControl.java:468)
at
com.carrotsearch.randomizedtesting.RandomizedRunner.runSingleTest(RandomizedRunner.java:943)
at
com.carrotsearch.randomizedtesting.RandomizedRunner$5.evaluate(RandomizedRunner.java:829)
at
com.carrotsearch.randomizedtesting.RandomizedRunner$6.evaluate(RandomizedRunner.java:879)
at
com.carrotsearch.randomizedtesting.RandomizedRunner$7.evaluate(RandomizedRunner.java:890)
at
com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at
com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:57)
at
org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:45)
at
com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at
org.apache.lucene.util.TestRuleStoreClassName$1.evaluate(TestRuleStoreClassName.java:41)
at
com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:40)
at
com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:40)
at
com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at
com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at
com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at
org.apache.lucene.util.TestRuleAssertionsRequired$1.evaluate(TestRuleAssertionsRequired.java:53)
at
org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:47)
at
org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:64)
at
org.apache.lucene.util.TestRuleIgnoreTestSuites$1.evaluate(TestRuleIgnoreTestSuites.java:54)
at
com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at
com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:368)
at java.lang.Thread.run(Thread.java:748)
Build Log:
[...truncated 1834 lines...]
[junit4] JVM J0: stdout was not empty, see:
/home/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-master/lucene/build/core/test/temp/junit4-J0-20180314_162046_28122566093485749154.sysout
[junit4] >>> JVM J0 emitted unexpected output (verbatim) ----
[junit4] codec: SimpleText, pf: BloomFilter, dvf: Asserting
[junit4] <<< JVM J0: EOF ----
[...truncated 11881 lines...]
[junit4] Suite: org.apache.solr.cloud.autoscaling.ComputePlanActionTest
[junit4] 2> Creating dataDir:
/home/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-master/solr/build/solr-core/test/J0/temp/solr.cloud.autoscaling.ComputePlanActionTest_DB3957B6117D9155-001/init-core-data-001
[junit4] 2> 2300946 WARN
(SUITE-ComputePlanActionTest-seed#[DB3957B6117D9155]-worker) [ ]
o.a.s.SolrTestCaseJ4 startTrackingSearchers: numOpens=11 numCloses=11
[junit4] 2> 2300946 INFO
(SUITE-ComputePlanActionTest-seed#[DB3957B6117D9155]-worker) [ ]
o.a.s.SolrTestCaseJ4 Using PointFields (NUMERIC_POINTS_SYSPROP=true)
w/NUMERIC_DOCVALUES_SYSPROP=false
[junit4] 2> 2300959 INFO
(SUITE-ComputePlanActionTest-seed#[DB3957B6117D9155]-worker) [ ]
o.a.s.SolrTestCaseJ4 Randomized ssl (true) and clientAuth (true) via:
@org.apache.solr.util.RandomizeSSL(reason=, ssl=NaN, value=NaN, clientAuth=NaN)
[junit4] 2> 2300960 INFO
(SUITE-ComputePlanActionTest-seed#[DB3957B6117D9155]-worker) [ ]
o.a.s.SolrTestCaseJ4 SecureRandom sanity checks:
test.solr.allowed.securerandom=null & java.security.egd=file:/dev/./urandom
[junit4] 2> 2300961 INFO
(SUITE-ComputePlanActionTest-seed#[DB3957B6117D9155]-worker) [ ]
o.a.s.c.MiniSolrCloudCluster Starting cluster of 1 servers in
/home/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-master/solr/build/solr-core/test/J0/temp/solr.cloud.autoscaling.ComputePlanActionTest_DB3957B6117D9155-001/tempDir-001
[junit4] 2> 2300961 INFO
(SUITE-ComputePlanActionTest-seed#[DB3957B6117D9155]-worker) [ ]
o.a.s.c.ZkTestServer STARTING ZK TEST SERVER
[junit4] 2> 2300975 INFO (Thread-2620) [ ] o.a.s.c.ZkTestServer client
port:0.0.0.0/0.0.0.0:0
[junit4] 2> 2300975 INFO (Thread-2620) [ ] o.a.s.c.ZkTestServer
Starting server
[junit4] 2> 2301012 ERROR (Thread-2620) [ ] o.a.z.s.ZooKeeperServer
ZKShutdownHandler is not registered, so ZooKeeper server won't take any action
on ERROR or SHUTDOWN server state changes
[junit4] 2> 2301075 INFO
(SUITE-ComputePlanActionTest-seed#[DB3957B6117D9155]-worker) [ ]
o.a.s.c.ZkTestServer start zk server on port:41341
[junit4] 2> 2301137 INFO (zkConnectionManagerCallback-2022-thread-1) [
] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 2301199 INFO (jetty-launcher-2019-thread-1) [ ]
o.e.j.s.Server jetty-9.4.8.v20171121, build timestamp:
2017-11-22T08:27:37+11:00, git hash: 82b8fb23f757335bb3329d540ce37a2a2615f0a8
[junit4] 2> 2301254 INFO (jetty-launcher-2019-thread-1) [ ]
o.e.j.s.session DefaultSessionIdManager workerName=node0
[junit4] 2> 2301254 INFO (jetty-launcher-2019-thread-1) [ ]
o.e.j.s.session No SessionScavenger set, using defaults
[junit4] 2> 2301254 INFO (jetty-launcher-2019-thread-1) [ ]
o.e.j.s.session Scavenging every 600000ms
[junit4] 2> 2301255 INFO (jetty-launcher-2019-thread-1) [ ]
o.e.j.s.h.ContextHandler Started
o.e.j.s.ServletContextHandler@5e49f98{/solr,null,AVAILABLE}
[junit4] 2> 2301256 INFO (jetty-launcher-2019-thread-1) [ ]
o.e.j.s.AbstractConnector Started ServerConnector@60b2afff{SSL,[ssl,
http/1.1]}{127.0.0.1:45294}
[junit4] 2> 2301256 INFO (jetty-launcher-2019-thread-1) [ ]
o.e.j.s.Server Started @2303659ms
[junit4] 2> 2301256 INFO (jetty-launcher-2019-thread-1) [ ]
o.a.s.c.s.e.JettySolrRunner Jetty properties: {hostContext=/solr,
hostPort=45294}
[junit4] 2> 2301256 ERROR (jetty-launcher-2019-thread-1) [ ]
o.a.s.u.StartupLoggingUtils Missing Java Option solr.log.dir. Logging may be
missing or incomplete.
[junit4] 2> 2301256 INFO (jetty-launcher-2019-thread-1) [ ]
o.a.s.s.SolrDispatchFilter ___ _ Welcome to Apache Solr? version
8.0.0
[junit4] 2> 2301256 INFO (jetty-launcher-2019-thread-1) [ ]
o.a.s.s.SolrDispatchFilter / __| ___| |_ _ Starting in cloud mode on port null
[junit4] 2> 2301256 INFO (jetty-launcher-2019-thread-1) [ ]
o.a.s.s.SolrDispatchFilter \__ \/ _ \ | '_| Install dir: null
[junit4] 2> 2301256 INFO (jetty-launcher-2019-thread-1) [ ]
o.a.s.s.SolrDispatchFilter |___/\___/_|_| Start time:
2018-03-14T17:21:28.917Z
[junit4] 2> 2301283 INFO (zkConnectionManagerCallback-2024-thread-1) [
] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 2301288 INFO (jetty-launcher-2019-thread-1) [ ]
o.a.s.s.SolrDispatchFilter solr.xml found in ZooKeeper. Loading...
[junit4] 2> 2301340 INFO (jetty-launcher-2019-thread-1) [ ]
o.a.s.c.ZkContainer Zookeeper client=127.0.0.1:41341/solr
[junit4] 2> 2301364 INFO (zkConnectionManagerCallback-2028-thread-1) [
] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 2301421 INFO
(zkConnectionManagerCallback-2030-thread-1-processing-n:127.0.0.1:45294_solr)
[n:127.0.0.1:45294_solr ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 2301842 INFO (jetty-launcher-2019-thread-1)
[n:127.0.0.1:45294_solr ] o.a.s.c.Overseer Overseer (id=null) closing
[junit4] 2> 2301842 INFO (jetty-launcher-2019-thread-1)
[n:127.0.0.1:45294_solr ] o.a.s.c.OverseerElectionContext I am going to be
the leader 127.0.0.1:45294_solr
[junit4] 2> 2301859 INFO (jetty-launcher-2019-thread-1)
[n:127.0.0.1:45294_solr ] o.a.s.c.Overseer Overseer
(id=72279465483698179-127.0.0.1:45294_solr-n_0000000000) starting
[junit4] 2> 2301877 INFO
(zkConnectionManagerCallback-2035-thread-1-processing-n:127.0.0.1:45294_solr)
[n:127.0.0.1:45294_solr ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 2301878 INFO (jetty-launcher-2019-thread-1)
[n:127.0.0.1:45294_solr ] o.a.s.c.s.i.ZkClientClusterStateProvider Cluster
at 127.0.0.1:41341/solr ready
[junit4] 2> 2301878 DEBUG
(OverseerStateUpdate-72279465483698179-127.0.0.1:45294_solr-n_0000000000)
[n:127.0.0.1:45294_solr ] o.a.s.c.Overseer Starting to work on the main queue
[junit4] 2> 2301969 INFO (jetty-launcher-2019-thread-1)
[n:127.0.0.1:45294_solr ] o.a.s.c.ZkController Register node as live in
ZooKeeper:/live_nodes/127.0.0.1:45294_solr
[junit4] 2> 2301969 DEBUG
(OverseerAutoScalingTriggerThread-72279465483698179-127.0.0.1:45294_solr-n_0000000000)
[n:127.0.0.1:45294_solr ] o.a.s.c.a.OverseerTriggerThread Adding
.auto_add_replicas and .scheduled_maintenance triggers
[junit4] 2> 2301971 DEBUG
(OverseerAutoScalingTriggerThread-72279465483698179-127.0.0.1:45294_solr-n_0000000000)
[n:127.0.0.1:45294_solr ] o.a.s.c.a.OverseerTriggerThread Refreshing
/autoscaling.json with znode version 1
[junit4] 2> 2301972 DEBUG
(OverseerAutoScalingTriggerThread-72279465483698179-127.0.0.1:45294_solr-n_0000000000)
[n:127.0.0.1:45294_solr ] o.a.s.c.a.NodeLostTrigger Initial livenodes: []
[junit4] 2> 2301972 DEBUG
(OverseerAutoScalingTriggerThread-72279465483698179-127.0.0.1:45294_solr-n_0000000000)
[n:127.0.0.1:45294_solr ] o.a.s.c.a.OverseerTriggerThread Current
znodeVersion 1, lastZnodeVersion -1
[junit4] 2> 2301972 DEBUG
(OverseerAutoScalingTriggerThread-72279465483698179-127.0.0.1:45294_solr-n_0000000000)
[n:127.0.0.1:45294_solr ] o.a.s.c.a.OverseerTriggerThread Processed trigger
updates upto znodeVersion 1
[junit4] 2> 2302022 INFO
(zkCallback-2029-thread-1-processing-n:127.0.0.1:45294_solr)
[n:127.0.0.1:45294_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from
ZooKeeper... (0) -> (1)
[junit4] 2> 2302042 INFO
(zkCallback-2034-thread-1-processing-n:127.0.0.1:45294_solr)
[n:127.0.0.1:45294_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from
ZooKeeper... (0) -> (1)
[junit4] 2> 2302237 DEBUG
(OverseerAutoScalingTriggerThread-72279465483698179-127.0.0.1:45294_solr-n_0000000000)
[n:127.0.0.1:45294_solr ] o.a.s.c.a.OverseerTriggerThread -- clean old
nodeAdded markers
[junit4] 2> 2302290 DEBUG
(OverseerAutoScalingTriggerThread-72279465483698179-127.0.0.1:45294_solr-n_0000000000)
[n:127.0.0.1:45294_solr ] o.a.s.c.a.OverseerTriggerThread Current
znodeVersion 1, lastZnodeVersion 1
[junit4] 2> 2302290 DEBUG (ScheduledTrigger-4021-thread-1)
[n:127.0.0.1:45294_solr ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger:
.auto_add_replicas with currently live nodes: 1
[junit4] 2> 2302399 INFO (jetty-launcher-2019-thread-1)
[n:127.0.0.1:45294_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for
'solr_45294.solr.node' (registry 'solr.node') enabled at server:
com.sun.jmx.mbeanserver.JmxMBeanServer@7367bc20
[junit4] 2> 2302418 INFO (jetty-launcher-2019-thread-1)
[n:127.0.0.1:45294_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for
'solr_45294.solr.jvm' (registry 'solr.jvm') enabled at server:
com.sun.jmx.mbeanserver.JmxMBeanServer@7367bc20
[junit4] 2> 2302418 INFO (jetty-launcher-2019-thread-1)
[n:127.0.0.1:45294_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for
'solr_45294.solr.jetty' (registry 'solr.jetty') enabled at server:
com.sun.jmx.mbeanserver.JmxMBeanServer@7367bc20
[junit4] 2> 2302472 INFO (jetty-launcher-2019-thread-1)
[n:127.0.0.1:45294_solr ] o.a.s.c.CorePropertiesLocator Found 0 core
definitions underneath
/home/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-master/solr/build/solr-core/test/J0/temp/solr.cloud.autoscaling.ComputePlanActionTest_DB3957B6117D9155-001/tempDir-001/node1/.
[junit4] 2> 2302564 INFO (zkConnectionManagerCallback-2037-thread-1) [
] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 2302584 INFO (zkConnectionManagerCallback-2041-thread-1) [
] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 2302584 INFO
(SUITE-ComputePlanActionTest-seed#[DB3957B6117D9155]-worker) [ ]
o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (1)
[junit4] 2> 2302585 INFO
(SUITE-ComputePlanActionTest-seed#[DB3957B6117D9155]-worker) [ ]
o.a.s.c.s.i.ZkClientClusterStateProvider Cluster at 127.0.0.1:41341/solr ready
[junit4] IGNOR/A 0.00s J0 | ComputePlanActionTest.testSelectedCollections
[junit4] > Assumption #1: 'badapple' test group is disabled
(@BadApple(bugUrl=https://issues.apache.org/jira/browse/SOLR-12028))
[junit4] 2> 2302655 INFO
(TEST-ComputePlanActionTest.testNodeAdded-seed#[DB3957B6117D9155]) [ ]
o.a.s.SolrTestCaseJ4 ###Starting testNodeAdded
[junit4] 2> 2302656 INFO
(TEST-ComputePlanActionTest.testNodeAdded-seed#[DB3957B6117D9155]) [ ]
o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (1)
[junit4] 2> 2302671 DEBUG
(zkCallback-2034-thread-1-processing-n:127.0.0.1:45294_solr)
[n:127.0.0.1:45294_solr ] o.a.s.c.a.OverseerTriggerThread Refreshing
/autoscaling.json with znode version 2
[junit4] 2> 2302671 DEBUG
(OverseerAutoScalingTriggerThread-72279465483698179-127.0.0.1:45294_solr-n_0000000000)
[n:127.0.0.1:45294_solr ] o.a.s.c.a.OverseerTriggerThread Processed trigger
updates upto znodeVersion 2
[junit4] 2> 2302746 DEBUG
(OverseerAutoScalingTriggerThread-72279465483698179-127.0.0.1:45294_solr-n_0000000000)
[n:127.0.0.1:45294_solr ] o.a.s.c.a.OverseerTriggerThread -- clean old
nodeLost markers
[junit4] 2> 2302746 DEBUG
(OverseerAutoScalingTriggerThread-72279465483698179-127.0.0.1:45294_solr-n_0000000000)
[n:127.0.0.1:45294_solr ] o.a.s.c.a.OverseerTriggerThread -- clean old
nodeAdded markers
[junit4] 2> 2302747 DEBUG
(OverseerAutoScalingTriggerThread-72279465483698179-127.0.0.1:45294_solr-n_0000000000)
[n:127.0.0.1:45294_solr ] o.a.s.c.a.OverseerTriggerThread Current
znodeVersion 2, lastZnodeVersion 2
[junit4] 2> 2302839 INFO (qtp163944847-13324) [n:127.0.0.1:45294_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> 2302839 DEBUG (qtp163944847-13325) [n:127.0.0.1:45294_solr
] o.a.s.c.a.AutoScalingHandler Verified autoscaling configuration
[junit4] 2> 2302840 INFO (qtp163944847-13325) [n:127.0.0.1:45294_solr
] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/autoscaling
params={wt=javabin&version=2} status=0 QTime=58
[junit4] 2> 2302841 DEBUG
(zkCallback-2034-thread-1-processing-n:127.0.0.1:45294_solr)
[n:127.0.0.1:45294_solr ] o.a.s.c.a.OverseerTriggerThread Refreshing
/autoscaling.json with znode version 3
[junit4] 2> 2302841 DEBUG
(OverseerAutoScalingTriggerThread-72279465483698179-127.0.0.1:45294_solr-n_0000000000)
[n:127.0.0.1:45294_solr ] o.a.s.c.a.OverseerTriggerThread Processed trigger
updates upto znodeVersion 3
[junit4] 2> 2302841 DEBUG
(OverseerAutoScalingTriggerThread-72279465483698179-127.0.0.1:45294_solr-n_0000000000)
[n:127.0.0.1:45294_solr ] o.a.s.c.a.OverseerTriggerThread -- clean old
nodeLost markers
[junit4] 2> 2302842 DEBUG
(OverseerAutoScalingTriggerThread-72279465483698179-127.0.0.1:45294_solr-n_0000000000)
[n:127.0.0.1:45294_solr ] o.a.s.c.a.OverseerTriggerThread -- clean old
nodeAdded markers
[junit4] 2> 2302854 DEBUG
(OverseerAutoScalingTriggerThread-72279465483698179-127.0.0.1:45294_solr-n_0000000000)
[n:127.0.0.1:45294_solr ] o.a.s.c.a.OverseerTriggerThread Current
znodeVersion 3, lastZnodeVersion 3
[junit4] 2> 2302855 INFO (qtp163944847-13331) [n:127.0.0.1:45294_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> 2302890 DEBUG (qtp163944847-13327) [n:127.0.0.1:45294_solr
] o.a.s.c.a.AutoScalingHandler Verified autoscaling configuration
[junit4] 2> 2302895 INFO (qtp163944847-13327) [n:127.0.0.1:45294_solr
] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/autoscaling
params={wt=javabin&version=2} status=0 QTime=54
[junit4] 2> 2302896 DEBUG
(zkCallback-2034-thread-1-processing-n:127.0.0.1:45294_solr)
[n:127.0.0.1:45294_solr ] o.a.s.c.a.OverseerTriggerThread Refreshing
/autoscaling.json with znode version 4
[junit4] 2> 2302896 DEBUG
(OverseerAutoScalingTriggerThread-72279465483698179-127.0.0.1:45294_solr-n_0000000000)
[n:127.0.0.1:45294_solr ] o.a.s.c.a.OverseerTriggerThread Processed trigger
updates upto znodeVersion 4
[junit4] 2> 2302897 DEBUG
(OverseerAutoScalingTriggerThread-72279465483698179-127.0.0.1:45294_solr-n_0000000000)
[n:127.0.0.1:45294_solr ] o.a.s.c.a.OverseerTriggerThread -- clean old
nodeLost markers
[junit4] 2> 2302915 DEBUG
(OverseerAutoScalingTriggerThread-72279465483698179-127.0.0.1:45294_solr-n_0000000000)
[n:127.0.0.1:45294_solr ] o.a.s.c.a.OverseerTriggerThread -- clean old
nodeAdded markers
[junit4] 2> 2302918 DEBUG
(OverseerAutoScalingTriggerThread-72279465483698179-127.0.0.1:45294_solr-n_0000000000)
[n:127.0.0.1:45294_solr ] o.a.s.c.a.OverseerTriggerThread Current
znodeVersion 4, lastZnodeVersion 4
[junit4] 2> 2302918 INFO (qtp163944847-13329) [n:127.0.0.1:45294_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> 2302931 DEBUG (qtp163944847-13324) [n:127.0.0.1:45294_solr
] o.a.s.c.a.AutoScalingHandler Verified autoscaling configuration
[junit4] 2> 2302934 DEBUG
(zkCallback-2034-thread-1-processing-n:127.0.0.1:45294_solr)
[n:127.0.0.1:45294_solr ] o.a.s.c.a.OverseerTriggerThread Refreshing
/autoscaling.json with znode version 5
[junit4] 2> 2302950 INFO (qtp163944847-13324) [n:127.0.0.1:45294_solr
] o.a.s.s.HttpSolrCall [admin] webapp=null path=/cluster/autoscaling
params={wt=javabin&version=2} status=0 QTime=54
[junit4] 2> 2302970 DEBUG
(zkCallback-2034-thread-1-processing-n:127.0.0.1:45294_solr)
[n:127.0.0.1:45294_solr ] o.a.s.c.a.NodeAddedTrigger Initial livenodes:
[127.0.0.1:45294_solr]
[junit4] 2> 2302970 DEBUG
(zkCallback-2034-thread-1-processing-n:127.0.0.1:45294_solr)
[n:127.0.0.1:45294_solr ] o.a.s.c.a.NodeAddedTrigger NodeAddedTrigger
node_added_trigger instantiated with properties: {event=nodeAdded, waitFor=1,
actions=[{name=compute_plan, class=solr.ComputePlanAction}, {name=test,
class=org.apache.solr.cloud.autoscaling.ComputePlanActionTest$AssertingTriggerAction}],
enabled=true}
[junit4] 2> 2302970 DEBUG
(OverseerAutoScalingTriggerThread-72279465483698179-127.0.0.1:45294_solr-n_0000000000)
[n:127.0.0.1:45294_solr ] o.a.s.c.a.OverseerTriggerThread Processed trigger
updates upto znodeVersion 5
[junit4] 2> 2302985 DEBUG
(OverseerAutoScalingTriggerThread-72279465483698179-127.0.0.1:45294_solr-n_0000000000)
[n:127.0.0.1:45294_solr ] o.a.s.c.a.OverseerTriggerThread -- clean old
nodeLost markers
[junit4] 2> 2302985 DEBUG
(OverseerAutoScalingTriggerThread-72279465483698179-127.0.0.1:45294_solr-n_0000000000)
[n:127.0.0.1:45294_solr ] o.a.s.c.a.OverseerTriggerThread Current
znodeVersion 5, lastZnodeVersion 5
[junit4] 2> 2302986 DEBUG (ScheduledTrigger-4021-thread-2)
[n:127.0.0.1:45294_solr ] o.a.s.c.a.NodeAddedTrigger Running
NodeAddedTrigger node_added_trigger
[junit4] 2> 2302986 DEBUG (ScheduledTrigger-4021-thread-2)
[n:127.0.0.1:45294_solr ] o.a.s.c.a.NodeAddedTrigger Found livenodes: 1
[junit4] 2> 2302987 INFO (qtp163944847-13328) [n:127.0.0.1:45294_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> 2303002 DEBUG (qtp163944847-13324) [n:127.0.0.1:45294_solr
] o.a.s.c.a.AutoScalingHandler Verified autoscaling configuration
[junit4] 2> 2303003 DEBUG
(zkCallback-2034-thread-1-processing-n:127.0.0.1:45294_solr)
[n:127.0.0.1:45294_solr ] o.a.s.c.a.OverseerTriggerThread Refreshing
/autoscaling.json with znode version 6
[junit4] 2> 2303003 DEBUG
(zkCallback-2034-thread-1-processing-n:127.0.0.1:45294_solr)
[n:127.0.0.1:45294_solr ] o.a.s.c.a.NodeAddedTrigger Initial livenodes:
[127.0.0.1:45294_solr]
[junit4] 2> 2303003 DEBUG
(zkCallback-2034-thread-1-processing-n:127.0.0.1:45294_solr)
[n:127.0.0.1:45294_solr ] o.a.s.c.a.NodeAddedTrigger NodeAddedTrigger
node_added_trigger instantiated with properties: {event=nodeAdded, waitFor=1,
actions=[{name=compute_plan, class=solr.ComputePlanAction}, {name=test,
class=org.apache.solr.cloud.autoscaling.ComputePlanActionTest$AssertingTriggerAction}],
enabled=true}
[junit4] 2> 2303003 DEBUG
(OverseerAutoScalingTriggerThread-72279465483698179-127.0.0.1:45294_solr-n_0000000000)
[n:127.0.0.1:45294_solr ] o.a.s.c.a.OverseerTriggerThread Processed trigger
updates upto znodeVersion 6
[junit4] 2> 2303003 DEBUG
(OverseerAutoScalingTriggerThread-72279465483698179-127.0.0.1:45294_solr-n_0000000000)
[n:127.0.0.1:45294_solr ] o.a.s.c.a.OverseerTriggerThread -- clean old
nodeLost markers
[junit4] 2> 2303003 DEBUG
(OverseerAutoScalingTriggerThread-72279465483698179-127.0.0.1:45294_solr-n_0000000000)
[n:127.0.0.1:45294_solr ] o.a.s.c.a.OverseerTriggerThread Current
znodeVersion 6, lastZnodeVersion 6
[junit4] 2> 2303004 INFO (qtp163944847-13324) [n:127.0.0.1:45294_solr
] o.a.s.s.HttpSolrCall [admin] webapp=null path=/cluster/autoscaling
params={wt=javabin&version=2} status=0 QTime=52
[junit4] 2> 2303024 INFO (qtp163944847-13327) [n:127.0.0.1:45294_solr
] o.a.s.h.a.CollectionsHandler Invoked Collection Action :create with params
replicationFactor=2&collection.configName=conf&name=testNodeAdded&nrtReplicas=2&action=CREATE&numShards=1&wt=javabin&version=2
and sendToOCPQueue=true
[junit4] 2> 2303074 INFO
(OverseerThreadFactory-4023-thread-1-processing-n:127.0.0.1:45294_solr)
[n:127.0.0.1:45294_solr ] o.a.s.c.a.c.CreateCollectionCmd Create collection
testNodeAdded
[junit4] 2> 2303074 WARN
(OverseerThreadFactory-4023-thread-1-processing-n:127.0.0.1:45294_solr)
[n:127.0.0.1:45294_solr ] o.a.s.c.a.c.CreateCollectionCmd Specified number
of replicas of 2 on collection testNodeAdded is higher than the number of Solr
instances currently live or live and part of your createNodeSet(1). It's
unusual to run two replica of the same slice on the same Solr-instance.
[junit4] 2> 2303094 INFO (qtp163944847-13329) [n:127.0.0.1:45294_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> 2303094 INFO
(OverseerThreadFactory-4023-thread-1-processing-n:127.0.0.1:45294_solr)
[n:127.0.0.1:45294_solr ] o.a.s.c.s.c.a.PolicyHelper returnSession,
curr-time 3385491692 sessionWrapper.createTime 3385491692555886,
this.sessionWrapper.createTime 3385491692555886
[junit4] 2> 2303109 DEBUG
(OverseerStateUpdate-72279465483698179-127.0.0.1:45294_solr-n_0000000000)
[n:127.0.0.1:45294_solr ] o.a.s.c.Overseer processMessage: queueSize: 1,
message = {
[junit4] 2> "name":"testNodeAdded",
[junit4] 2> "fromApi":"true",
[junit4] 2> "replicationFactor":"2",
[junit4] 2> "collection.configName":"conf",
[junit4] 2> "numShards":"1",
[junit4] 2> "nrtReplicas":"2",
[junit4] 2> "stateFormat":"2",
[junit4] 2> "operation":"create"} current state version: 0
[junit4] 2> 2303110 DEBUG
(OverseerStateUpdate-72279465483698179-127.0.0.1:45294_solr-n_0000000000)
[n:127.0.0.1:45294_solr ] o.a.s.c.o.ClusterStateMutator building a new
cName: testNodeAdded
[junit4] 2> 2303126 DEBUG
(OverseerStateUpdate-72279465483698179-127.0.0.1:45294_solr-n_0000000000)
[n:127.0.0.1:45294_solr ] o.a.s.c.o.ZkStateWriter going to create_collection
/collections/testNodeAdded/state.json
[junit4] 2> 2303200 DEBUG
(OverseerStateUpdate-72279465483698179-127.0.0.1:45294_solr-n_0000000000)
[n:127.0.0.1:45294_solr ] o.a.s.c.Overseer processMessage: queueSize: 1,
message = {
[junit4] 2> "operation":"ADDREPLICA",
[junit4] 2> "collection":"testNodeAdded",
[junit4] 2> "shard":"shard1",
[junit4] 2> "core":"testNodeAdded_shard1_replica_n1",
[junit4] 2> "state":"down",
[junit4] 2> "base_url":"https://127.0.0.1:45294/solr";,
[junit4] 2> "type":"NRT",
[junit4] 2> "waitForFinalState":"false"} current state version: 0
[junit4] 2> 2303200 INFO
(OverseerStateUpdate-72279465483698179-127.0.0.1:45294_solr-n_0000000000)
[n:127.0.0.1:45294_solr ] o.a.s.c.o.SliceMutator createReplica() {
[junit4] 2> "operation":"ADDREPLICA",
[junit4] 2> "collection":"testNodeAdded",
[junit4] 2> "shard":"shard1",
[junit4] 2> "core":"testNodeAdded_shard1_replica_n1",
[junit4] 2> "state":"down",
[junit4] 2> "base_url":"https://127.0.0.1:45294/solr";,
[junit4] 2> "type":"NRT",
[junit4] 2> "waitForFinalState":"false"}
[junit4] 2> 2303201 DEBUG
(OverseerStateUpdate-72279465483698179-127.0.0.1:45294_solr-n_0000000000)
[n:127.0.0.1:45294_solr ] o.a.s.c.o.SliceMutator Old Slice: shard1:{
[junit4] 2> "range":"80000000-7fffffff",
[junit4] 2> "state":"active",
[junit4] 2> "replicas":{}}
[junit4] 2> 2303201 DEBUG
(OverseerStateUpdate-72279465483698179-127.0.0.1:45294_solr-n_0000000000)
[n:127.0.0.1:45294_solr ] o.a.s.c.o.SliceMutator New Slice: shard1:{
[junit4] 2> "range":"80000000-7fffffff",
[junit4] 2> "state":"active",
[junit4] 2> "replicas":{"core_node3":{
[junit4] 2> "core":"testNodeAdded_shard1_replica_n1",
[junit4] 2> "base_url":"https://127.0.0.1:45294/solr";,
[junit4] 2> "state":"down",
[junit4] 2> "node_name":null,
[junit4] 2> "type":"NRT"}}}
[junit4] 2> 2303202 DEBUG
(OverseerStateUpdate-72279465483698179-127.0.0.1:45294_solr-n_0000000000)
[n:127.0.0.1:45294_solr ] o.a.s.c.Overseer processMessage: queueSize: 2,
message = {
[junit4] 2> "operation":"ADDREPLICA",
[junit4] 2> "collection":"testNodeAdded",
[junit4] 2> "shard":"shard1",
[junit4] 2> "core":"testNodeAdded_shard1_replica_n2",
[junit4] 2> "state":"down",
[junit4] 2> "base_url":"https://127.0.0.1:45294/solr";,
[junit4] 2> "type":"NRT",
[junit4] 2> "waitForFinalState":"false"} current state version: 0
[junit4] 2> 2303202 INFO
(OverseerStateUpdate-72279465483698179-127.0.0.1:45294_solr-n_0000000000)
[n:127.0.0.1:45294_solr ] o.a.s.c.o.SliceMutator createReplica() {
[junit4] 2> "operation":"ADDREPLICA",
[junit4] 2> "collection":"testNodeAdded",
[junit4] 2> "shard":"shard1",
[junit4] 2> "core":"testNodeAdded_shard1_replica_n2",
[junit4] 2> "state":"down",
[junit4] 2> "base_url":"https://127.0.0.1:45294/solr";,
[junit4] 2> "type":"NRT",
[junit4] 2> "waitForFinalState":"false"}
[junit4] 2> 2303220 DEBUG
(OverseerStateUpdate-72279465483698179-127.0.0.1:45294_solr-n_0000000000)
[n:127.0.0.1:45294_solr ] o.a.s.c.o.SliceMutator Old Slice: shard1:{
[junit4] 2> "range":"80000000-7fffffff",
[junit4] 2> "state":"active",
[junit4] 2> "replicas":{"core_node3":{
[junit4] 2> "core":"testNodeAdded_shard1_replica_n1",
[junit4] 2> "base_url":"https://127.0.0.1:45294/solr";,
[junit4] 2> "state":"down",
[junit4] 2> "node_name":null,
[junit4] 2> "type":"NRT"}}}
[junit4] 2> 2303220 DEBUG
(OverseerStateUpdate-72279465483698179-127.0.0.1:45294_solr-n_0000000000)
[n:127.0.0.1:45294_solr ] o.a.s.c.o.SliceMutator New Slice: shard1:{
[junit4] 2> "range":"80000000-7fffffff",
[junit4] 2> "state":"active",
[junit4] 2> "replicas":{
[junit4] 2> "core_node3":{
[junit4] 2> "core":"testNodeAdded_shard1_replica_n1",
[junit4] 2> "base_url":"https://127.0.0.1:45294/solr";,
[junit4] 2> "state":"down",
[junit4] 2> "node_name":null,
[junit4] 2> "type":"NRT"},
[junit4] 2> "core_node4":{
[junit4] 2> "core":"testNodeAdded_shard1_replica_n2",
[junit4] 2> "base_url":"https://127.0.0.1:45294/solr";,
[junit4] 2> "state":"down",
[junit4] 2> "node_name":null,
[junit4] 2> "type":"NRT"}}}
[junit4] 2> 2303320 DEBUG
(OverseerStateUpdate-72279465483698179-127.0.0.1:45294_solr-n_0000000000)
[n:127.0.0.1:45294_solr ] o.a.s.c.o.ZkStateWriter going to update_collection
/collections/testNodeAdded/state.json version: 0
[junit4] 2> 2303416 INFO (qtp163944847-13328) [n:127.0.0.1:45294_solr
] o.a.s.h.a.CoreAdminOperation core create command
qt=/admin/cores&coreNodeName=core_node3&collection.configName=conf&newCollection=true&name=testNodeAdded_shard1_replica_n1&action=CREATE&numShards=1&collection=testNodeAdded&shard=shard1&wt=javabin&version=2&replicaType=NRT
[junit4] 2> 2303416 INFO (qtp163944847-13328) [n:127.0.0.1:45294_solr
] o.a.s.c.TransientSolrCoreCacheDefault Allocating transient cache for
2147483647 transient cores
[junit4] 2> 2303456 INFO (qtp163944847-13329) [n:127.0.0.1:45294_solr
] o.a.s.h.a.CoreAdminOperation core create command
qt=/admin/cores&coreNodeName=core_node4&collection.configName=conf&newCollection=true&name=testNodeAdded_shard1_replica_n2&action=CREATE&numShards=1&collection=testNodeAdded&shard=shard1&wt=javabin&version=2&replicaType=NRT
[junit4] 2> 2303489 DEBUG
(OverseerStateUpdate-72279465483698179-127.0.0.1:45294_solr-n_0000000000)
[n:127.0.0.1:45294_solr ] o.a.s.c.Overseer processMessage: queueSize: 2,
message = {
[junit4] 2> "core":"testNodeAdded_shard1_replica_n2",
[junit4] 2> "core_node_name":"core_node4",
[junit4] 2> "roles":null,
[junit4] 2> "base_url":"https://127.0.0.1:45294/solr";,
[junit4] 2> "node_name":"127.0.0.1:45294_solr",
[junit4] 2> "numShards":"1",
[junit4] 2> "state":"down",
[junit4] 2> "shard":"shard1",
[junit4] 2> "collection":"testNodeAdded",
[junit4] 2> "type":"NRT",
[junit4] 2> "operation":"state"} current state version: 0
[junit4] 2> 2303489 DEBUG
(OverseerStateUpdate-72279465483698179-127.0.0.1:45294_solr-n_0000000000)
[n:127.0.0.1:45294_solr ] o.a.s.c.o.ReplicaMutator Update state numShards=1
message={
[junit4] 2> "core":"testNodeAdded_shard1_replica_n2",
[junit4] 2> "core_node_name":"core_node4",
[junit4] 2> "roles":null,
[junit4] 2> "base_url":"https://127.0.0.1:45294/solr";,
[junit4] 2> "node_name":"127.0.0.1:45294_solr",
[junit4] 2> "numShards":"1",
[junit4] 2> "state":"down",
[junit4] 2> "shard":"shard1",
[junit4] 2> "collection":"testNodeAdded",
[junit4] 2> "type":"NRT",
[junit4] 2> "operation":"state"}
[junit4] 2> 2303490 DEBUG
(OverseerStateUpdate-72279465483698179-127.0.0.1:45294_solr-n_0000000000)
[n:127.0.0.1:45294_solr ] o.a.s.c.o.ReplicaMutator Will update state for
replica:
core_node4:{"core":"testNodeAdded_shard1_replica_n2","base_url":"https://127.0.0.1:45294/solr","node_name":"127.0.0.1:45294_solr","state":"down","type":"NRT"}
[junit4] 2> 2303490 DEBUG
(OverseerStateUpdate-72279465483698179-127.0.0.1:45294_solr-n_0000000000)
[n:127.0.0.1:45294_solr ] o.a.s.c.o.ReplicaMutator Collection is now:
DocCollection(testNodeAdded//collections/testNodeAdded/state.json/1)={
[junit4] 2> "pullReplicas":"0",
[junit4] 2> "replicationFactor":"2",
[junit4] 2> "router":{"name":"compositeId"},
[junit4] 2> "maxShardsPerNode":"1",
[junit4] 2> "autoAddReplicas":"false",
[junit4] 2> "nrtReplicas":"2",
[junit4] 2> "tlogReplicas":"0",
[junit4] 2> "shards":{"shard1":{
[junit4] 2> "range":"80000000-7fffffff",
[junit4] 2> "state":"active",
[junit4] 2> "replicas":{
[junit4] 2> "core_node3":{
[junit4] 2> "core":"testNodeAdded_shard1_replica_n1",
[junit4] 2> "base_url":"https://127.0.0.1:45294/solr";,
[junit4] 2> "state":"down",
[junit4] 2> "node_name":null,
[junit4] 2> "type":"NRT"},
[junit4] 2> "core_node4":{
[junit4] 2> "core":"testNodeAdded_shard1_replica_n2",
[junit4] 2> "base_url":"https://127.0.0.1:45294/solr";,
[junit4] 2> "node_name":"127.0.0.1:45294_solr",
[junit4] 2> "state":"down",
[junit4] 2> "type":"NRT"}}}}}
[junit4] 2> 2303490 DEBUG
(OverseerStateUpdate-72279465483698179-127.0.0.1:45294_solr-n_0000000000)
[n:127.0.0.1:45294_solr ] o.a.s.c.Overseer processMessage: queueSize: 2,
message = {
[junit4] 2> "core":"testNodeAdded_shard1_replica_n1",
[junit4] 2> "core_node_name":"core_node3",
[junit4] 2> "roles":null,
[junit4] 2> "base_url":"https://127.0.0.1:45294/solr";,
[junit4] 2> "node_name":"127.0.0.1:45294_solr",
[junit4] 2> "numShards":"1",
[junit4] 2> "state":"down",
[junit4] 2> "shard":"shard1",
[junit4] 2> "collection":"testNodeAdded",
[junit4] 2> "type":"NRT",
[junit4] 2> "operation":"state"} current state version: 0
[junit4] 2> 2303490 DEBUG
(OverseerStateUpdate-72279465483698179-127.0.0.1:45294_solr-n_0000000000)
[n:127.0.0.1:45294_solr ] o.a.s.c.o.ReplicaMutator Update state numShards=1
message={
[junit4] 2> "core":"testNodeAdded_shard1_replica_n1",
[junit4] 2> "core_node_name":"core_node3",
[junit4] 2> "roles":null,
[junit4] 2> "base_url":"https://127.0.0.1:45294/solr";,
[junit4] 2> "node_name":"127.0.0.1:45294_solr",
[junit4] 2> "numShards":"1",
[junit4] 2> "state":"down",
[junit4] 2> "shard":"shard1",
[junit4] 2> "collection":"testNodeAdded",
[junit4] 2> "type":"NRT",
[junit4] 2> "operation":"state"}
[junit4] 2> 2303490 DEBUG
(OverseerStateUpdate-72279465483698179-127.0.0.1:45294_solr-n_0000000000)
[n:127.0.0.1:45294_solr ] o.a.s.c.o.ReplicaMutator Will update state for
replica:
core_node3:{"core":"testNodeAdded_shard1_replica_n1","base_url":"https://127.0.0.1:45294/solr","node_name":"127.0.0.1:45294_solr","state":"down","type":"NRT"}
[junit4] 2> 2303490 DEBUG
(OverseerStateUpdate-72279465483698179-127.0.0.1:45294_solr-n_0000000000)
[n:127.0.0.1:45294_solr ] o.a.s.c.o.ReplicaMutator Collection is now:
DocCollection(testNodeAdded//collections/testNodeAdded/state.json/1)={
[junit4] 2> "pullReplicas":"0",
[junit4] 2> "replicationFactor":"2",
[junit4] 2> "router":{"name":"compositeId"},
[junit4] 2> "maxShardsPerNode":"1",
[junit4] 2> "autoAddReplicas":"false",
[junit4] 2> "nrtReplicas":"2",
[junit4] 2> "tlogReplicas":"0",
[junit4] 2> "shards":{"shard1":{
[junit4] 2> "range":"80000000-7fffffff",
[junit4] 2> "state":"active",
[junit4] 2> "replicas":{
[junit4] 2> "core_node3":{
[junit4] 2> "core":"testNodeAdded_shard1_replica_n1",
[junit4] 2> "base_url":"https://127.0.0.1:45294/solr";,
[junit4] 2> "node_name":"127.0.0.1:45294_solr",
[junit4] 2> "state":"down",
[junit4] 2> "type":"NRT"},
[junit4] 2> "core_node4":{
[junit4] 2> "core":"testNodeAdded_shard1_replica_n2",
[junit4] 2> "base_url":"https://127.0.0.1:45294/solr";,
[junit4] 2> "node_name":"127.0.0.1:45294_solr",
[junit4] 2> "state":"down",
[junit4] 2> "type":"NRT"}}}}}
[junit4] 2> 2303597 DEBUG
(OverseerStateUpdate-72279465483698179-127.0.0.1:45294_solr-n_0000000000)
[n:127.0.0.1:45294_solr ] o.a.s.c.o.ZkStateWriter going to update_collection
/collections/testNodeAdded/state.json version: 1
[junit4] 2> 2303598 INFO
(zkCallback-2029-thread-2-processing-n:127.0.0.1:45294_solr)
[n:127.0.0.1:45294_solr ] o.a.s.c.c.ZkStateReader A cluster state change:
[WatchedEvent state:SyncConnected type:NodeDataChanged
path:/collections/testNodeAdded/state.json] for collection [testNodeAdded] has
occurred - updating... (live nodes size: [1])
[junit4] 2> 2303598 INFO
(zkCallback-2029-thread-1-processing-n:127.0.0.1:45294_solr)
[n:127.0.0.1:45294_solr ] o.a.s.c.c.ZkStateReader A cluster state change:
[WatchedEvent state:SyncConnected type:NodeDataChanged
path:/collections/testNodeAdded/state.json] for collection [testNodeAdded] has
occurred - updating... (live nodes size: [1])
[junit4] 2> 2303990 DEBUG (ScheduledTrigger-4021-thread-2)
[n:127.0.0.1:45294_solr ] o.a.s.c.a.NodeAddedTrigger Running
NodeAddedTrigger node_added_trigger
[junit4] 2> 2303990 DEBUG (ScheduledTrigger-4021-thread-2)
[n:127.0.0.1:45294_solr ] o.a.s.c.a.NodeAddedTrigger Found livenodes: 1
[junit4] 2> 2304531 INFO (qtp163944847-13328) [n:127.0.0.1:45294_solr
c:testNodeAdded s:shard1 r:core_node3 x:testNodeAdded_shard1_replica_n1]
o.a.s.c.SolrConfig Using Lucene MatchVersion: 8.0.0
[junit4] 2> 2304698 INFO (qtp163944847-13328) [n:127.0.0.1:45294_solr
c:testNodeAdded s:shard1 r:core_node3 x:testNodeAdded_shard1_replica_n1]
o.a.s.s.IndexSchema [testNodeAdded_shard1_replica_n1] Schema name=minimal
[junit4] 2> 2304699 INFO (qtp163944847-13329) [n:127.0.0.1:45294_solr
c:testNodeAdded s:shard1 r:core_node4 x:testNodeAdded_shard1_replica_n2]
o.a.s.c.SolrConfig Using Lucene MatchVersion: 8.0.0
[junit4] 2> 2304713 INFO (qtp163944847-13328) [n:127.0.0.1:45294_solr
c:testNodeAdded s:shard1 r:core_node3 x:testNodeAdded_shard1_replica_n1]
o.a.s.s.IndexSchema Loaded schema minimal/1.1 with uniqueid field id
[junit4] 2> 2304713 INFO (qtp163944847-13328) [n:127.0.0.1:45294_solr
c:testNodeAdded s:shard1 r:core_node3 x:testNodeAdded_shard1_replica_n1]
o.a.s.c.CoreContainer Creating SolrCore 'testNodeAdded_shard1_replica_n1' using
configuration from collection testNodeAdded, trusted=true
[junit4] 2> 2304714 INFO (qtp163944847-13328) [n:127.0.0.1:45294_solr
c:testNodeAdded s:shard1 r:core_node3 x:testNodeAdded_shard1_replica_n1]
o.a.s.m.r.SolrJmxReporter JMX monitoring for
'solr_45294.solr.core.testNodeAdded.shard1.replica_n1' (registry
'solr.core.testNodeAdded.shard1.replica_n1') enabled at server:
com.sun.jmx.mbeanserver.JmxMBeanServer@7367bc20
[junit4] 2> 2304714 INFO (qtp163944847-13328) [n:127.0.0.1:45294_solr
c:testNodeAdded s:shard1 r:core_node3 x:testNodeAdded_shard1_replica_n1]
o.a.s.c.SolrCore solr.RecoveryStrategy.Builder
[junit4] 2> 2304714 INFO (qtp163944847-13328) [n:127.0.0.1:45294_solr
c:testNodeAdded s:shard1 r:core_node3 x:testNodeAdded_shard1_replica_n1]
o.a.s.c.SolrCore [[testNodeAdded_shard1_replica_n1] ] Opening new SolrCore at
[/home/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-master/solr/build/solr-core/test/J0/temp/solr.cloud.autoscaling.ComputePlanActionTest_DB3957B6117D9155-001/tempDir-001/node1/testNodeAdded_shard1_replica_n1],
dataDir=[/home/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-master/solr/build/solr-core/test/J0/temp/solr.cloud.autoscaling.ComputePlanActionTest_DB3957B6117D9155-001/tempDir-001/node1/./testNodeAdded_shard1_replica_n1/data/]
[junit4] 2> 2304731 INFO (qtp163944847-13329) [n:127.0.0.1:45294_solr
c:testNodeAdded s:shard1 r:core_node4 x:testNodeAdded_shard1_replica_n2]
o.a.s.s.IndexSchema [testNodeAdded_shard1_replica_n2] Schema name=minimal
[junit4] 2> 2304733 INFO (qtp163944847-13329) [n:127.0.0.1:45294_solr
c:testNodeAdded s:shard1 r:core_node4 x:testNodeAdded_shard1_replica_n2]
o.a.s.s.IndexSchema Loaded schema minimal/1.1 with uniqueid field id
[junit4] 2> 2304733 INFO (qtp163944847-13329) [n:127.0.0.1:45294_solr
c:testNodeAdded s:shard1 r:core_node4 x:testNodeAdded_shard1_replica_n2]
o.a.s.c.CoreContainer Creating SolrCore 'testNodeAdded_shard1_replica_n2' using
configuration from collection testNodeAdded, trusted=true
[junit4] 2> 2304733 INFO (qtp163944847-13329) [n:127.0.0.1:45294_solr
c:testNodeAdded s:shard1 r:core_node4 x:testNodeAdded_shard1_replica_n2]
o.a.s.m.r.SolrJmxReporter JMX monitoring for
'solr_45294.solr.core.testNodeAdded.shard1.replica_n2' (registry
'solr.core.testNodeAdded.shard1.replica_n2') enabled at server:
com.sun.jmx.mbeanserver.JmxMBeanServer@7367bc20
[junit4] 2> 2304733 INFO (qtp163944847-13329) [n:127.0.0.1:45294_solr
c:testNodeAdded s:shard1 r:core_node4 x:testNodeAdded_shard1_replica_n2]
o.a.s.c.SolrCore solr.RecoveryStrategy.Builder
[junit4] 2> 2304734 INFO (qtp163944847-13329) [n:127.0.0.1:45294_solr
c:testNodeAdded s:shard1 r:core_node4 x:testNodeAdded_shard1_replica_n2]
o.a.s.c.SolrCore [[testNodeAdded_shard1_replica_n2] ] Opening new SolrCore at
[/home/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-master/solr/build/solr-core/test/J0/temp/solr.cloud.autoscaling.ComputePlanActionTest_DB3957B6117D9155-001/tempDir-001/node1/testNodeAdded_shard1_replica_n2],
dataDir=[/home/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-master/solr/build/solr-core/test/J0/temp/solr.cloud.autoscaling.ComputePlanActionTest_DB3957B6117D9155-001/tempDir-001/node1/./testNodeAdded_shard1_replica_n2/data/]
[junit4] 2> 2304989 INFO (qtp163944847-13328) [n:127.0.0.1:45294_solr
c:testNodeAdded s:shard1 r:core_node3 x:testNodeAdded_shard1_replica_n1]
o.a.s.u.UpdateHandler Using UpdateLog implementation:
org.apache.solr.update.UpdateLog
[junit4] 2> 2304989 INFO (qtp163944847-13328) [n:127.0.0.1:45294_solr
c:testNodeAdded s:shard1 r:core_node3 x:testNodeAdded_shard1_replica_n1]
o.a.s.u.UpdateLog Initializing UpdateLog: dataDir=null defaultSyncLevel=FLUSH
numRecordsToKeep=100 maxNumLogsToKeep=10 numVersionBuckets=65536
[junit4] 2> 2304990 INFO (qtp163944847-13328) [n:127.0.0.1:45294_solr
c:testNodeAdded s:shard1 r:core_node3 x:testNodeAdded_shard1_replica_n1]
o.a.s.u.CommitTracker Hard AutoCommit: disabled
[junit4] 2> 2304990 INFO (qtp163944847-13328) [n:127.0.0.1:45294_solr
c:testNodeAdded s:shard1 r:core_node3 x:testNodeAdded_shard1_replica_n1]
o.a.s.u.CommitTracker Soft AutoCommit: disabled
[junit4] 2> 2304992 INFO (qtp163944847-13328) [n:127.0.0.1:45294_solr
c:testNodeAdded s:shard1 r:core_node3 x:testNodeAdded_shard1_replica_n1]
o.a.s.s.SolrIndexSearcher Opening
[Searcher@34d82063[testNodeAdded_shard1_replica_n1] main]
[junit4] 2> 2304997 DEBUG (ScheduledTrigger-4021-thread-2)
[n:127.0.0.1:45294_solr ] o.a.s.c.a.NodeAddedTrigger Running
NodeAddedTrigger node_added_trigger
[junit4] 2> 2304997 DEBUG (ScheduledTrigger-4021-thread-2)
[n:127.0.0.1:45294_solr ] o.a.s.c.a.NodeAddedTrigger Found livenodes: 1
[junit4] 2> 2305003 INFO (qtp163944847-13329) [n:127.0.0.1:45294_solr
c:testNodeAdded s:shard1 r:core_node4 x:testNodeAdded_shard1_replica_n2]
o.a.s.u.UpdateHandler Using UpdateLog implementation:
org.apache.solr.update.UpdateLog
[junit4] 2> 2305003 INFO (qtp163944847-13329) [n:127.0.0.1:45294_solr
c:testNodeAdded s:shard1 r:core_node4 x:testNodeAdded_shard1_replica_n2]
o.a.s.u.UpdateLog Initializing UpdateLog: dataDir=null defaultSyncLevel=FLUSH
numRecordsToKeep=100 maxNumLogsToKeep=10 numVersionBuckets=65536
[junit4] 2> 2305004 INFO (qtp163944847-13329) [n:127.0.0.1:45294_solr
c:testNodeAdded s:shard1 r:core_node4 x:testNodeAdded_shard1_replica_n2]
o.a.s.u.CommitTracker Hard AutoCommit: disabled
[junit4] 2> 2305004 INFO (qtp163944847-13329) [n:127.0.0.1:45294_solr
c:testNodeAdded s:shard1 r:core_node4 x:testNodeAdded_shard1_replica_n2]
o.a.s.u.CommitTracker Soft AutoCommit: disabled
[junit4] 2> 2305022 INFO (qtp163944847-13329) [n:127.0.0.1:45294_solr
c:testNodeAdded s:shard1 r:core_node4 x:testNodeAdded_shard1_replica_n2]
o.a.s.s.SolrIndexSearcher Opening
[Searcher@5d1368d6[testNodeAdded_shard1_replica_n2] main]
[junit4] 2> 2305030 INFO (qtp163944847-13328) [n:127.0.0.1:45294_solr
c:testNodeAdded s:shard1 r:core_node3 x:testNodeAdded_shard1_replica_n1]
o.a.s.r.ManagedResourceStorage Configured ZooKeeperStorageIO with znodeBase:
/configs/conf
[junit4] 2> 2305030 INFO (qtp163944847-13328) [n:127.0.0.1:45294_solr
c:testNodeAdded s:shard1 r:core_node3 x:testNodeAdded_shard1_replica_n1]
o.a.s.r.ManagedResourceStorage Loaded null at path _rest_managed.json using
ZooKeeperStorageIO:path=/configs/conf
[junit4] 2> 2305031 INFO (qtp163944847-13328) [n:127.0.0.1:45294_solr
c:testNodeAdded s:shard1 r:core_node3 x:testNodeAdded_shard1_replica_n1]
o.a.s.h.ReplicationHandler Commits will be reserved for 10000ms.
[junit4] 2> 2305032 INFO
(searcherExecutor-4026-thread-1-processing-n:127.0.0.1:45294_solr
x:testNodeAdded_shard1_replica_n1 s:shard1 c:testNodeAdded r:core_node3)
[n:127.0.0.1:45294_solr c:testNodeAdded s:shard1 r:core_node3
x:testNodeAdded_shard1_replica_n1] o.a.s.c.SolrCore
[testNodeAdded_shard1_replica_n1] Registered new searcher
Searcher@34d82063[testNodeAdded_shard1_replica_n1]
main{ExitableDirectoryReader(UninvertingDirectoryReader())}
[junit4] 2> 2305032 INFO (qtp163944847-13328) [n:127.0.0.1:45294_solr
c:testNodeAdded s:shard1 r:core_node3 x:testNodeAdded_shard1_replica_n1]
o.a.s.u.UpdateLog Could not find max version in index or recent updates, using
new clock 1594934524843655168
[junit4] 2> 2305036 INFO (qtp163944847-13328) [n:127.0.0.1:45294_solr
c:testNodeAdded s:shard1 r:core_node3 x:testNodeAdded_shard1_replica_n1]
o.a.s.c.ZkShardTerms Successful update terms at
/collections/testNodeAdded/terms/shard1 to Terms{values={core_node3=0},
version=0}
[junit4] 2> 2305056 INFO (qtp163944847-13328) [n:127.0.0.1:45294_solr
c:testNodeAdded s:shard1 r:core_node3 x:testNodeAdded_shard1_replica_n1]
o.a.s.c.ShardLeaderElectionContext Waiting until we see more replicas up for
shard shard1: total=2 found=1 timeoutin=9999ms
[junit4] 2> 2305056 DEBUG
(OverseerStateUpdate-72279465483698179-127.0.0.1:45294_solr-n_0000000000)
[n:127.0.0.1:45294_solr ] o.a.s.c.Overseer processMessage: queueSize: 1,
message = {
[junit4] 2> "operation":"leader",
[junit4] 2> "shard":"shard1",
[junit4] 2> "collection":"testNodeAdded"} current state version: 0
[junit4] 2> 2305058 INFO (qtp163944847-13329) [n:127.0.0.1:45294_solr
c:testNodeAdded s:shard1 r:core_node4 x:testNodeAdded_shard1_replica_n2]
o.a.s.r.ManagedResourceStorage Configured ZooKeeperStorageIO with znodeBase:
/configs/conf
[junit4] 2> 2305058 INFO (qtp163944847-13329) [n:127.0.0.1:45294_solr
c:testNodeAdded s:shard1 r:core_node4 x:testNodeAdded_shard1_replica_n2]
o.a.s.r.ManagedResourceStorage Loaded null at path _rest_managed.json using
ZooKeeperStorageIO:path=/configs/conf
[junit4] 2> 2305059 INFO (qtp163944847-13329) [n:127.0.0.1:45294_solr
c:testNodeAdded s:shard1 r:core_node4 x:testNodeAdded_shard1_replica_n2]
o.a.s.h.ReplicationHandler Commits will be reserved for 10000ms.
[junit4] 2> 2305059 INFO
(searcherExecutor-4027-thread-1-processing-n:127.0.0.1:45294_solr
x:testNodeAdded_shard1_replica_n2 s:shard1 c:testNodeAdded r:core_node4)
[n:127.0.0.1:45294_solr c:testNodeAdded s:shard1 r:core_node4
x:testNodeAdded_shard1_replica_n2] o.a.s.c.SolrCore
[testNodeAdded_shard1_replica_n2] Registered new searcher
Searcher@5d1368d6[testNodeAdded_shard1_replica_n2]
main{ExitableDirectoryReader(UninvertingDirectoryReader())}
[junit4] 2> 2305059 INFO (qtp163944847-13329) [n:127.0.0.1:45294_solr
c:testNodeAdded s:shard1 r:core_node4 x:testNodeAdded_shard1_replica_n2]
o.a.s.u.UpdateLog Could not find max version in index or recent updates, using
new clock 1594934524871966720
[junit4] 2> 2305079 INFO (qtp163944847-13329) [n:127.0.0.1:45294_solr
c:testNodeAdded s:shard1 r:core_node4 x:testNodeAdded_shard1_replica_n2]
o.a.s.c.ZkShardTerms Successful update terms at
/collections/testNodeAdded/terms/shard1 to Terms{values={core_node3=0,
core_node4=0}, version=1}
[junit4] 2> 2305157 DEBUG
(OverseerStateUpdate-72279465483698179-127.0.0.1:45294_solr-n_0000000000)
[n:127.0.0.1:45294_solr ] o.a.s.c.o.ZkStateWriter going to update_collection
/collections/testNodeAdded/state.json version: 2
[junit4] 2> 2305163 INFO
(zkCallback-2029-thread-2-processing-n:127.0.0.1:45294_solr)
[n:127.0.0.1:45294_solr ] o.a.s.c.c.ZkStateReader A cluster state change:
[WatchedEvent state:SyncConnected type:NodeDataChanged
path:/collections/testNodeAdded/state.json] for collection [testNodeAdded] has
occurred - updating... (live nodes size: [1])
[junit4] 2> 2305171 INFO
(zkCallback-2029-thread-3-processing-n:127.0.0.1:45294_solr)
[n:127.0.0.1:45294_solr ] o.a.s.c.c.ZkStateReader A cluster state change:
[WatchedEvent state:SyncConnected type:NodeDataChanged
path:/collections/testNodeAdded/state.json] for collection [testNodeAdded] has
occurred - updating... (live nodes size: [1])
[junit4] 2> 2305557 INFO (qtp163944847-13328) [n:127.0.0.1:45294_solr
c:testNodeAdded s:shard1 r:core_node3 x:testNodeAdded_shard1_replica_n1]
o.a.s.c.ShardLeaderElectionContext Enough replicas found to continue.
[junit4] 2> 2305557 INFO (qtp163944847-13328) [n:127.0.0.1:45294_solr
c:testNodeAdded s:shard1 r:core_node3 x:testNodeAdded_shard1_replica_n1]
o.a.s.c.ShardLeaderElectionContext I may be the new leader - try and sync
[junit4] 2> 2305557 INFO (qtp163944847-13328) [n:127.0.0.1:45294_solr
c:testNodeAdded s:shard1 r:core_node3 x:testNodeAdded_shard1_replica_n1]
o.a.s.c.SyncStrategy Sync replicas to
https://127.0.0.1:45294/solr/testNodeAdded_shard1_replica_n1/
[junit4] 2> 2305558 INFO (qtp163944847-13328) [n:127.0.0.1:45294_solr
c:testNodeAdded s:shard1 r:core_node3 x:testNodeAdded_shard1_replica_n1]
o.a.s.u.PeerSync PeerSync: core=testNodeAdded_shard1_replica_n1
url=https://127.0.0.1:45294/solr START
replicas=[https://127.0.0.1:45294/solr/testNodeAdded_shard1_replica_n2/]
nUpdates=100
[junit4] 2> 2305560 INFO (qtp163944847-13331) [n:127.0.0.1:45294_solr
c:testNodeAdded s:shard1 r:core_node4 x:testNodeAdded_shard1_replica_n2]
o.a.s.c.S.Request [testNodeAdded_shard1_replica_n2] webapp=/solr path=/get
params={distrib=false&qt=/get&fingerprint=false&getVersions=100&wt=javabin&version=2}
status=0 QTime=0
[junit4] 2> 2305869 INFO (qtp163944847-13328) [n:127.0.0.1:45294_solr
c:testNodeAdded s:shard1 r:core_node3 x:testNodeAdded_shard1_replica_n1]
o.a.s.u.PeerSync PeerSync: core=testNodeAdded_shard1_replica_n1
url=https://127.0.0.1:45294/solr DONE. We have no versions. sync failed.
[junit4] 2> 2305869 INFO (qtp163944847-13328) [n:127.0.0.1:45294_solr
c:testNodeAdded s:shard1 r:core_node3 x:testNodeAdded_shard1_replica_n1]
o.a.s.c.SyncStrategy Leader's attempt to sync with shard failed, moving to the
next candidate
[junit4] 2> 2305869 INFO (qtp163944847-13328) [n:127.0.0.1:45294_solr
c:testNodeAdded s:shard1 r:core_node3 x:testNodeAdded_shard1_replica_n1]
o.a.s.c.ShardLeaderElectionContext We failed sync, but we have no versions - we
can't sync in that case - we were active before, so become leader anyway
[junit4] 2> 2305869 INFO (qtp163944847-13328) [n:127.0.0.1:45294_solr
c:testNodeAdded s:shard1 r:core_node3 x:testNodeAdded_shard1_replica_n1]
o.a.s.c.ShardLeaderElectionContext Found all replicas participating in
election, clear LIR
[junit4] 2> 2305897 INFO (qtp163944847-13328) [n:127.0.0.1:45294_solr
c:testNodeAdded s:shard1 r:core_node3 x:testNodeAdded_shard1_replica_n1]
o.a.s.c.ShardLeaderElectionContext I am the new leader:
https://127.0.0.1:45294/solr/testNodeAdded_shard1_replica_n1/ shard1
[junit4] 2> 2305906 DEBUG
(OverseerStateUpdate-72279465483698179-127.0.0.1:45294_solr-n_0000000000)
[n:127.0.0.1:45294_solr ] o.a.s.c.Overseer processMessage: queueSize: 1,
message = {
[junit4] 2> "operation":"leader",
[junit4] 2> "shard":"shard1",
[junit4] 2> "collection":"testNodeAdded",
[junit4] 2> "base_url":"https://127.0.0.1:45294/solr";,
[junit4] 2> "core":"testNodeAdded_shard1_replica_n1",
[junit4] 2> "state":"active"} current state version: 0
[junit4] 2> 2305998 DEBUG (ScheduledTrigger-4021-thread-2)
[n:127.0.0.1:45294_solr ] o.a.s.c.a.NodeAddedTrigger Running
NodeAddedTrigger node_added_trigger
[junit4] 2> 2305998 DEBUG (ScheduledTrigger-4021-thread-2)
[n:127.0.0.1:45294_solr ] o.a.s.c.a.NodeAddedTrigger Found livenodes: 1
[junit4] 2> 2306019 DEBUG
(OverseerStateUpdate-72279465483698179-127.0.0.1:45294_solr-n_0000000000)
[n:127.0.0.1:45294_solr ] o.a.s.c.o.ZkStateWriter going to update_collection
/collections/testNodeAdded/state.json version: 3
[junit4] 2> 2306022 INFO
(zkCallback-2029-thread-3-processing-n:127.0.0.1:45294_solr)
[n:127.0.0.1:45294_solr ] o.a.s.c.c.ZkStateReader A cluster state change:
[WatchedEvent state:SyncConnected type:NodeDataChanged
path:/collections/testNodeAdded/state.json] for collection [testNodeAdded] has
occurred - updating... (live nodes size: [1])
[junit4] 2> 2306022 INFO
(zkCallback-2029-thread-2-processing-n:127.0.0.1:45294_solr)
[n:127.0.0.1:45294_solr ] o.a.s.c.c.ZkStateReader A cluster state change:
[WatchedEvent state:SyncConnected type:NodeDataChanged
path:/collections/testNodeAdded/state.json] for collection [testNodeAdded] has
occurred - updating... (live nodes size: [1])
[junit4] 2> 2306076 INFO (qtp163944847-13328) [n:127.0.0.1:45294_solr
c:testNodeAdded s:shard1 r:core_node3 x:testNodeAdded_shard1_replica_n1]
o.a.s.c.ZkController I am the leader, no recovery necessary
[junit4] 2> 2306077 DEBUG
(OverseerStateUpdate-72279465483698179-127.0.0.1:45294_solr-n_0000000000)
[n:127.0.0.1:45294_solr ] o.a.s.c.Overseer processMessage: queueSize: 1,
message = {
[junit4] 2> "core":"testNodeAdded_shard1_replica_n1",
[junit4] 2> "core_node_name":"core_node3",
[junit4] 2> "roles":null,
[junit4] 2> "base_url":"https://127.0.0.1:45294/solr";,
[junit4] 2> "node_name":"127.0.0.1:45294_solr",
[junit4] 2> "numShards":"1",
[junit4] 2> "state":"active",
[junit4] 2> "shard":"shard1",
[junit4] 2> "collection":"testNodeAdded",
[junit4] 2> "type":"NRT",
[junit4] 2> "operation":"state"} current state version: 0
[junit4] 2> 2306077 DEBUG
(OverseerStateUpdate-72279465483698179-127.0.0.1:45294_solr-n_0000000000)
[n:127.0.0.1:45294_solr ] o.a.s.c.o.ReplicaMutator Update state numShards=1
message={
[junit4] 2> "core":"testNodeAdded_shard1_replica_n1",
[junit4] 2> "core_node_name":"core_node3",
[junit4] 2> "roles":null,
[junit4] 2> "base_url":"https://127.0.0.1:45294/solr";,
[junit4] 2> "node_name":"127.0.0.1:45294_solr",
[junit4] 2> "numShards":"1",
[junit4] 2> "state":"active",
[junit4] 2> "shard":"shard1",
[junit4] 2> "collection":"testNodeAdded",
[junit4] 2> "type":"NRT",
[junit4] 2> "operation":"state"}
[junit4] 2> 2306078 DEBUG
(OverseerStateUpdate-72279465483698179-127.0.0.1:45294_solr-n_0000000000)
[n:127.0.0.1:45294_solr ] o.a.s.c.o.ReplicaMutator Will update state for
replica:
core_node3:{"core":"testNodeAdded_shard1_replica_n1","base_url":"https://127.0.0.1:45294/solr","node_name":"127.0.0.1:45294_solr","state":"active","type":"NRT","leader":"true"}
[junit4] 2> 2306078 DEBUG
(OverseerStateUpdate-72279465483698179-127.0.0.1:45294_solr-n_0000000000)
[n:127.0.0.1:45294_solr ] o.a.s.c.o.ReplicaMutator Collection is now:
DocCollection(testNodeAdded//collections/testNodeAdded/state.json/4)={
[junit4] 2> "pullReplicas":"0",
[junit4] 2> "replicationFactor":"2",
[junit4] 2> "router":{"name":"compositeId"},
[junit4] 2> "maxShardsPerNode":"1",
[junit4] 2> "autoAddReplicas":"false",
[junit4] 2> "nrtReplicas":"2",
[junit4] 2> "tlogReplicas":"0",
[junit4] 2> "shards":{"shard1":{
[junit4] 2> "range":"80000000-7fffffff",
[junit4] 2> "state":"active",
[junit4] 2> "replicas":{
[junit4] 2> "core_node3":{
[junit4] 2> "core":"testNodeAdded_shard1_replica_n1",
[junit4] 2> "base_url":"https://127.0.0.1:45294/solr";,
[junit4] 2> "node_name":"127.0.0.1:45294_solr",
[junit4] 2> "state":"active",
[junit4] 2> "type":"NRT",
[junit4] 2> "leader":"true"},
[junit4] 2> "core_node4":{
[junit4] 2> "core":"testNodeAdded_shard1_replica_n2",
[junit4] 2> "base_url":"https://127.0.0.1:45294/solr";,
[junit4] 2> "node_name":"127.0.0.1:45294_solr",
[junit4] 2> "state":"down",
[junit4] 2> "type":"NRT"}}}}}
[junit4] 2> 2306078 INFO (qtp163944847-13328) [n:127.0.0.1:45294_solr
c:testNodeAdded s:shard1 r:core_node3 x:testNodeAdded_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=testNodeAdded_shard1_replica_n1&action=CREATE&numShards=1&collection=testNodeAdded&shard=shard1&wt=javabin&version=2&replicaType=NRT}
status=0 QTime=2662
[junit4] 2> 2306104 INFO (qtp163944847-13329) [n:127.0.0.1:45294_solr
c:testNodeAdded s:shard1 r:core_node4 x:testNodeAdded_shard1_replica_n2]
o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/cores
params={qt=/admin/cores&coreNodeName=core_node4&collection.configName=conf&newCollection=true&name=testNodeAdded_shard1_replica_n2&action=CREATE&numShards=1&collection=testNodeAdded&shard=shard1&wt=javabin&version=2&replicaType=NRT}
status=0 QTime=2648
[junit4] 2> 2306104 DEBUG
(OverseerStateUpdate-72279465483698179-127.0.0.1:45294_solr-n_0000000000)
[n:127.0.0.1:45294_solr ] o.a.s.c.Overseer processMessage: queueSize: 2,
message = {
[junit4] 2> "core":"testNodeAdded_shard1_replica_n2",
[junit4] 2> "core_node_name":"core_node4",
[junit4] 2> "roles":null,
[junit4] 2> "base_url":"https://127.0.0.1:45294/solr";,
[junit4] 2> "node_name":"127.0.0.1:45294_solr",
[junit4] 2> "numShards":"1",
[junit4] 2> "state":"active",
[junit4] 2> "shard":"shard1",
[junit4] 2> "collection":"testNodeAdded",
[junit4] 2> "type":"NRT",
[junit4] 2> "operation":"state"} current state version: 0
[junit4] 2> 2306104 DEBUG
(OverseerStateUpdate-72279465483698179-127.0.0.1:45294_solr-n_0000000000)
[n:127.0.0.1:45294_solr ] o.a.s.c.o.ReplicaMutator Update state numShards=1
message={
[junit4] 2> "core":"testNodeAdded_shard1_replica_n2",
[junit4] 2> "core_node_name":"core_node4",
[junit4] 2> "roles":null,
[junit4] 2> "base_url":"https://127.0.0.1:45294/solr";,
[junit4] 2> "node_name":"127.0.0.1:45294_solr",
[junit4] 2> "numShards":"1",
[junit4] 2> "state":"active",
[junit4] 2> "shard":"shard1",
[junit4] 2> "collection":"testNodeAdded",
[junit4] 2> "type":"NRT",
[junit4] 2> "operation":"state"}
[junit4] 2> 2306104 DEBUG
(OverseerStateUpdate-72279465483698179-127.0.0.1:45294_solr-n_0000000000)
[n:127.0.0.1:45294_solr ] o.a.s.c.o.ReplicaMutator Will update state for
replica:
core_node4:{"core":"testNodeAdded_shard1_replica_n2","base_url":"https://127.0.0.1:45294/solr","node_name":"127.0.0.1:45294_solr","state":"active","type":"NRT"}
[junit4] 2> 2306105 DEBUG
(OverseerStateUpdate-72279465483698179-127.0.0.1:45294_solr-n_0000000000)
[n:127.0.0.1:45294_solr ] o.a.s.c.o.ReplicaMutator Collection is now:
DocCollection(testNodeAdded//collections/testNodeAdded/state.json/4)={
[junit4] 2> "pullReplicas":"0",
[junit4] 2> "replicationFactor":"2",
[junit4] 2> "router":{"name":"compositeId"},
[junit4] 2> "maxShardsPerNode":"1",
[junit4] 2> "autoAddReplicas":"false",
[junit4] 2> "nrtReplicas":"2",
[junit4] 2> "tlogReplicas":"0",
[junit4] 2> "shards":{"shard1":{
[junit4] 2> "range":"80000000-7fffffff",
[junit4] 2> "state":"active",
[junit4] 2> "replicas":{
[junit4] 2> "core_node3":{
[junit4] 2> "core":"testNodeAdded_shard1_replica_n1",
[junit4] 2> "base_url":"https://127.0.0.1:45294/solr";,
[junit4] 2> "node_name":"127.0.0.1:45294_solr",
[junit4] 2> "state":"active",
[junit4] 2> "type":"NRT",
[junit4] 2> "leader":"true"},
[junit4] 2> "core_node4":{
[junit4] 2> "core":"testNodeAdded_shard1_replica_n2",
[junit4] 2> "base_url":"https://127.0.0.1:45294/solr";,
[junit4] 2> "node_name":"127.0.0.1:45294_solr",
[junit4] 2> "state":"active",
[junit4] 2> "type":"NRT"}}}}}
[junit4] 2> 2306106 INFO (qtp163944847-13327) [n:127.0.0.1:45294_solr
] o.a.s.h.a.CollectionsHandler Wait for new collection to be active for at most
30 seconds. Check all shard replicas
[junit4] 2> 2306205 DEBUG
(OverseerStateUpdate-72279465483698179-127.0.0.1:45294_solr-n_0000000000)
[n:127.0.0.1:45294_solr ] o.a.s.c.o.ZkStateWriter going to update_collection
/collections/testNodeAdded/state.json version: 4
[junit4] 2> 2306206 INFO
(zkCallback-2029-thread-3-processing-n:127.0.0.1:45294_solr)
[n:127.0.0.1:45294_solr ] o.a.s.c.c.ZkStateReader A cluster state change:
[WatchedEvent state:SyncConnected type:NodeDataChanged
path:/collections/testNodeAdded/state.json] for collection [testNodeAdded] has
occurred - updating... (live nodes size: [1])
[junit4] 2> 2306206 INFO
(zkCallback-2029-thread-2-processing-n:127.0.0.1:45294_solr)
[n:127.0.0.1:45294_solr ] o.a.s.c.c.ZkStateReader A cluster state change:
[WatchedEvent state:SyncConnected type:NodeDataChanged
path:/collections/testNodeAdded/state.json] for collection [testNodeAdded] has
occurred - updating... (live nodes size: [1])
[junit4] 2> 2307005 DEBUG (ScheduledTrigger-4021-thread-2)
[n:127.0.0.1:45294_solr ] o.a.s.c.a.NodeAddedTrigger Running
NodeAddedTrigger node_added_trigger
[junit4] 2> 2307005 DEBUG (ScheduledTrigger-4021-thread-2)
[n:127.0.0.1:45294_solr ] o.a.s.c.a.NodeAddedTrigger Found livenodes: 1
[junit4] 2> 2307086 INFO
(OverseerCollectionConfigSetProcessor-72279465483698179-127.0.0.1:45294_solr-n_0000000000)
[n:127.0.0.1:45294_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> 2307112 INFO (qtp163944847-13327) [n:127.0.0.1:45294_solr
] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/collections
params={replicationFactor=2&collection.configName=conf&name=testNodeAdded&nrtReplicas=2&action=CREATE&numShards=1&wt=javabin&version=2}
status=0 QTime=4087
[junit4] 2> 2307188 INFO (qtp163944847-13330) [n:127.0.0.1:45294_solr
] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/metrics
params={wt=javabin&version=2&key=solr.core.testNodeAdded.shard1.replica_n1:INDEX.sizeInBytes&key=solr.core.testNodeAdded.shard1.replica_n2:INDEX.sizeInBytes}
status=0 QTime=0
[junit4] 2> 2307190 INFO (qtp163944847-13331) [n:127.0.0.1:45294_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=1
[junit4] 2> 2307218 DEBUG (qtp163944847-13381) [n:127.0.0.1:45294_solr
] o.a.s.c.a.AutoScalingHandler Verified autoscaling configuration
[junit4] 2> 2307232 INFO (qtp163944847-13381) [n:127.0.0.1:45294_solr
] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/autoscaling
params={wt=javabin&version=2} status=0 QTime=84
[junit4] 2> 2307242 INFO
(TEST-ComputePlanActionTest.testNodeAdded-seed#[DB3957B6117D9155]) [ ]
o.e.j.s.Server jetty-9.4.8.v20171121, build timestamp:
2017-11-22T08:27:37+11:00, git hash: 82b8fb23f757335bb3329d540ce37a2a2615f0a8
[junit4] 2> 2307257 DEBUG
(zkCallback-2034-thread-1-processing-n:127.0.0.1:45294_solr)
[n:127.0.0.1:45294_solr ] o.a.s.c.a.OverseerTriggerThread Refreshing
/autoscaling.json with znode version 7
[junit4] 2> 2307277 DEBUG
(zkCallback-2034-thread-1-processing-n:127.0.0.1:45294_solr)
[n:127.0.0.1:45294_solr ] o.a.s.c.a.NodeAddedTrigger Initial livenodes:
[127.0.0.1:45294_solr]
[junit4] 2> 2307277 DEBUG
(zkCallback-2034-thread-1-processing-n:127.0.0.1:45294_solr)
[n:127.0.0.1:45294_solr ] o.a.s.c.a.NodeAddedTrigger NodeAddedTrigger
node_added_trigger instantiated with properties: {event=nodeAdded, waitFor=1,
actions=[{name=compute_plan, class=solr.ComputePlanAction}, {name=test,
class=org.apache.solr.cloud.autoscaling.ComputePlanActionTest$AssertingTriggerAction}],
enabled=true}
[junit4] 2> 2307277 DEBUG
(OverseerAutoScalingTriggerThread-72279465483698179-127.0.0.1:45294_solr-n_0000000000)
[n:127.0.0.1:45294_solr ] o.a.s.c.a.OverseerTriggerThread Processed trigger
updates upto znodeVersion 7
[junit4] 2> 2307277 INFO
(TEST-ComputePlanActionTest.testNodeAdded-seed#[DB3957B6117D9155]) [ ]
o.e.j.s.session DefaultSessionIdManager workerName=node0
[junit4] 2> 2307278 INFO
(TEST-ComputePlanActionTest.testNodeAdded-seed#[DB3957B6117D9155]) [ ]
o.e.j.s.session No SessionScavenger set, using defaults
[junit4] 2> 2307278 INFO
(TEST-ComputePlanActionTest.testNodeAdded-seed#[DB3957B6117D9155]) [ ]
o.e.j.s.session Scavenging every 600000ms
[junit4] 2> 2307278 INFO
(TEST-ComputePlanActionTest.testNodeAdded-seed#[DB3957B6117D9155]) [ ]
o.e.j.s.h.ContextHandler Started
o.e.j.s.ServletContextHandler@6bcf8062{/solr,null,AVAILABLE}
[junit4] 2> 2307279 INFO
(TEST-ComputePlanActionTest.testNodeAdded-seed#[DB3957B6117D9155]) [ ]
o.e.j.s.AbstractConnector Started ServerConnector@66791d66{SSL,[ssl,
http/1.1]}{127.0.0.1:38800}
[junit4] 2> 2307279 INFO
(TEST-ComputePlanActionTest.testNodeAdded-seed#[DB3957B6117D9155]) [ ]
o.e.j.s.Server Started @2309682ms
[junit4] 2> 2307279 INFO
(TEST-ComputePlanActionTest.testNodeAdded-seed#[DB3957B6117D9155]) [ ]
o.a.s.c.s.e.JettySolrRunner Jetty properties: {hostContext=/solr,
hostPort=38800}
[junit4] 2> 2307279 ERROR
(TEST-ComputePlanActionTest.testNodeAdded-seed#[DB3957B6117D9155]) [ ]
o.a.s.u.StartupLoggingUtils Missing Java Option solr.log.dir. Logging may be
missing or incomplete.
[junit4] 2> 2307279 INFO
(TEST-ComputePlanActionTest.testNodeAdded-seed#[DB3957B6117D9155]) [ ]
o.a.s.s.SolrDispatchFilter ___ _ Welcome to Apache Solr? version
8.0.0
[junit4] 2> 2307279 INFO
(TEST-ComputePlanActionTest.testNodeAdded-seed#[DB3957B6117D9155]) [ ]
o.a.s.s.SolrDispatchFilter / __| ___| |_ _ Starting in cloud mode on port null
[junit4] 2> 2307279 INFO
(TEST-ComputePlanActionTest.testNodeAdded-seed#[DB3957B6117D9155]) [ ]
o.a.s.s.SolrDispatchFilter \__ \/ _ \ | '_| Install dir: null
[junit4] 2> 2307279 INFO
(TEST-ComputePlanActionTest.testNodeAdded-seed#[DB3957B6117D9155]) [ ]
o.a.s.s.SolrDispatchFilter |___/\___/_|_| Start time:
2018-03-14T17:21:34.940Z
[junit4] 2> 2307293 DEBUG
(OverseerAutoScalingTriggerThread-72279465483698179-127.0.0.1:45294_solr-n_0000000000)
[n:127.0.0.1:45294_solr ] o.a.s.c.a.OverseerTriggerThread -- clean old
nodeLost markers
[junit4] 2> 2307309 DEBUG
(OverseerAutoScalingTriggerThread-72279465483698179-127.0.0.1:45294_solr-n_0000000000)
[n:127.0.0.1:45294_solr ] o.a.s.c.a.OverseerTriggerThread Current
znodeVersion 7, lastZnodeVersion 7
[junit4] 2> 2307314 INFO (zkConnectionManagerCallback-2044-thread-1) [
] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 2307330 INFO
(TEST-ComputePlanActionTest.testNodeAdded-seed#[DB3957B6117D9155]) [ ]
o.a.s.s.SolrDispatchFilter solr.xml found in ZooKeeper. Loading...
[junit4] 2> 2307419 INFO
(TEST-ComputePlanActionTest.testNodeAdded-seed#[DB3957B6117D9155]) [ ]
o.a.s.c.ZkContainer Zookeeper client=127.0.0.1:41341/solr
[junit4] 2> 2307425 INFO (zkConnectionManagerCallback-2048-thread-1) [
] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 2307440 INFO
(zkConnectionManagerCallback-2050-thread-1-processing-n:127.0.0.1:38800_solr)
[n:127.0.0.1:38800_solr ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 2307458 INFO
(TEST-ComputePlanActionTest.testNodeAdded-seed#[DB3957B6117D9155])
[n:127.0.0.1:38800_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from
ZooKeeper... (0) -> (1)
[junit4] 2> 2307476 INFO
(TEST-ComputePlanActionTest.testNodeAdded-seed#[DB3957B6117D9155])
[n:127.0.0.1:38800_solr ] o.a.s.c.Overseer Overseer (id=null) closing
[junit4] 2> 2307510 INFO
(TEST-ComputePlanActionTest.testNodeAdded-seed#[DB3957B6117D9155])
[n:127.0.0.1:38800_solr ] o.a.s.c.ZkController Register node as live in
ZooKeeper:/live_nodes/127.0.0.1:38800_solr
[junit4] 2> 2307510 DEBUG
(OverseerStateUpdate-72279465483698179-127.0.0.1:45294_solr-n_0000000000)
[n:127.0.0.1:45294_solr ] o.a.s.c.Overseer processMessage: queueSize: 1,
message = {
[junit4] 2> "operation":"downnode",
[junit4] 2> "node_name":"127.0.0.1:38800_solr"} current state version: 0
[junit4] 2> 2307511 DEBUG
(OverseerStateUpdate-72279465483698179-127.0.0.1:45294_solr-n_0000000000)
[n:127.0.0.1:45294_solr ] o.a.s.c.o.NodeMutator DownNode state invoked for
node: 127.0.0.1:38800_solr
[junit4] 2> 2307525 INFO
(zkCallback-2029-thread-2-processing-n:127.0.0.1:45294_solr)
[n:127.0.0.1:45294_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from
ZooKeeper... (1) -> (2)
[junit4] 2> 2307525 INFO
(zkCallback-2034-thread-1-processing-n:127.0.0.1:45294_solr)
[n:127.0.0.1:45294_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from
ZooKeeper... (1) -> (2)
[junit4] 2> 2307525 INFO (zkCallback-2040-thread-2) [ ]
o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (1) -> (2)
[junit4] 2> 2307525 INFO (zkCallback-2040-thread-1) [ ]
o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (1) -> (2)
[junit4] 2> 2307598 INFO
(zkCallback-2049-thread-1-processing-n:127.0.0.1:38800_solr)
[n:127.0.0.1:38800_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from
ZooKeeper... (1) -> (2)
[junit4] 2> 2307797 INFO
(TEST-ComputePlanActionTest.testNodeAdded-seed#[DB3957B6117D9155])
[n:127.0.0.1:38800_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for
'solr_38800.solr.node' (registry 'solr.node') enabled at server:
com.sun.jmx.mbeanserver.JmxMBeanServer@7367bc20
[junit4] 2> 2307831 INFO
(TEST-ComputePlanActionTest.testNodeAdded-seed#[DB3957B6117D9155])
[n:127.0.0.1:38800_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for
'solr_38800.solr.jvm' (registry 'solr.jvm') enabled at server:
com.sun.jmx.mbeanserver.JmxMBeanServer@7367bc20
[junit4] 2> 2307831 INFO
(TEST-ComputePlanActionTest.testNodeAdded-seed#[DB3957B6117D9155])
[n:127.0.0.1:38800_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for
'solr_38800.solr.jetty' (registry 'solr.jetty') enabled at server:
com.sun.jmx.mbeanserver.JmxMBeanServer@7367bc20
[junit4] 2> 2307849 INFO
(TEST-ComputePlanActionTest.testNodeAdded-seed#[DB3957B6117D9155])
[n:127.0.0.1:38800_solr ] o.a.s.c.CorePropertiesLocator Found 0 core
definitions underneath
/home/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-master/solr/build/solr-core/test/J0/temp/solr.cloud.autoscaling.ComputePlanActionTest_DB3957B6117D9155-001/tempDir-001/node2/.
[junit4] 2> 2307876 INFO
(zkConnectionManagerCallback-2055-thread-1-processing-n:127.0.0.1:38800_solr)
[n:127.0.0.1:38800_solr ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 2307877 INFO
(TEST-ComputePlanActionTest.testNodeAdded-seed#[DB3957B6117D9155])
[n:127.0.0.1:38800_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from
ZooKeeper... (0) -> (2)
[junit4] 2> 2307886 INFO
(TEST-ComputePlanActionTest.testNodeAdded-seed#[DB3957B6117D9155])
[n:127.0.0.1:38800_solr ] o.a.s.c.s.i.ZkClientClusterStateProvider Cluster
at 127.0.0.1:41341/solr ready
[junit4] 2> 2308011 DEBUG (ScheduledTrigger-4021-thread-2)
[n:127.0.0.1:45294_solr ] o.a.s.c.a.NodeAddedTrigger Running
NodeAddedTrigger node_added_trigger
[junit4] 2> 2308011 DEBUG (ScheduledTrigger-4021-thread-2)
[n:127.0.0.1:45294_solr ] o.a.s.c.a.NodeAddedTrigger Found livenodes: 2
[junit4] 2> 2308012 DEBUG (ScheduledTrigger-4021-thread-2)
[n:127.0.0.1:45294_solr ] o.a.s.c.a.NodeAddedTrigger Tracking new node:
127.0.0.1:38800_solr at time 3385496610064086
[junit4] 2> 2309013 DEBUG (ScheduledTrigger-4021-thread-2)
[n:127.0.0.1:45294_solr ] o.a.s.c.a.NodeAddedTrigger Running
NodeAddedTrigger node_added_trigger
[junit4] 2> 2309013 DEBUG (ScheduledTrigger-4021-thread-2)
[n:127.0.0.1:45294_solr ] o.a.s.c.a.NodeAddedTrigger Found livenodes: 2
[junit4] 2> 2309014 DEBUG (ScheduledTrigger-4021-thread-2)
[n:127.0.0.1:45294_solr ] o.a.s.c.a.NodeAddedTrigger NodeAddedTrigger
node_added_trigger firing registered processor for nodes:
[127.0.0.1:38800_solr] added at times [3385496610064086], now=3385497612079627
[junit4] 2> 2309014 DEBUG (ScheduledTrigger-4021-thread-2)
[n:127.0.0.1:45294_solr ] o.a.s.c.a.ScheduledTriggers ++++++++ Cooldown
inactive - processing event: {
[junit4] 2> "id":"c07175ad4c6d6T1k4sp01ec6gc35zv21wpeaiqu",
[junit4] 2> "source":"node_added_trigger",
[junit4] 2> "eventTime":3385496610064086,
[junit4] 2> "eventType":"NODEADDED",
[junit4] 2> "properties":{
[junit4] 2> "eventTimes":[3385496610064086],
[junit4] 2> "nodeNames":["127.0.0.1:38800_solr"]}}
[junit4] 2> 2309014 DEBUG (ScheduledTrigger-4021-thread-2)
[n:127.0.0.1:45294_solr ] o.a.s.c.a.ScheduledTriggers Pausing all triggers:
[node_added_trigger]
[junit4] 2> 2309015 INFO (ScheduledTrigger-4021-thread-2)
[n:127.0.0.1:45294_solr ] o.a.s.c.a.SystemLogListener Collection .system
does not exist, disabling logging.
[junit4] 2> 2309016 DEBUG
(AutoscalingActionExecutor-4022-thread-1-processing-n:127.0.0.1:45294_solr)
[n:127.0.0.1:45294_solr ] o.a.s.c.a.ScheduledTriggers -- processing actions
for {
[junit4] 2> "id":"c07175ad4c6d6T1k4sp01ec6gc35zv21wpeaiqu",
[junit4] 2> "source":"node_added_trigger",
[junit4] 2> "eventTime":3385496610064086,
[junit4] 2> "eventType":"NODEADDED",
[junit4] 2> "properties":{
[junit4] 2> "eventTimes":[3385496610064086],
[junit4] 2> "_enqueue_time_":3385497612989813,
[junit4] 2> "nodeNames":["127.0.0.1:38800_solr"]}}
[junit4] 2> 2309016 DEBUG
(AutoscalingActionExecutor-4022-thread-1-processing-n:127.0.0.1:45294_solr)
[n:127.0.0.1:45294_solr ] o.a.s.c.a.ComputePlanAction -- processing event: {
[junit4] 2> "id":"c07175ad4c6d6T1k4sp01ec6gc35zv21wpeaiqu",
[junit4] 2> "source":"node_added_trigger",
[junit4] 2> "eventTime":3385496610064086,
[junit4] 2> "eventType":"NODEADDED",
[junit4] 2> "properties":{
[junit4] 2> "eventTimes":[3385496610064086],
[junit4] 2> "_enqueue_time_":3385497612989813,
[junit4] 2> "nodeNames":["127.0.0.1:38800_solr"]}} with context
properties: {BEFORE_ACTION=[compute_plan]}
[junit4] 2> 2309152 INFO (qtp1307586901-13390) [n:127.0.0.1:38800_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> 2309153 INFO (qtp163944847-13330) [n:127.0.0.1:45294_solr
] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/metrics
params={wt=javabin&version=2&key=solr.core.testNodeAdded.shard1.replica_n1:INDEX.sizeInBytes&key=solr.core.testNodeAdded.shard1.replica_n2:INDEX.sizeInBytes}
status=0 QTime=0
[junit4] 2> 2309156 INFO (qtp163944847-13381) [n:127.0.0.1:45294_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> 2309158 INFO
(AutoscalingActionExecutor-4022-thread-1-processing-n:127.0.0.1:45294_solr)
[n:127.0.0.1:45294_solr ] o.a.s.c.a.ComputePlanAction Computed Plan:
action=MOVEREPLICA&collection=testNodeAdded&targetNode=127.0.0.1:38800_solr&inPlaceMove=true&replica=core_node3
[junit4] 2> 2309159 INFO
(AutoscalingActionExecutor-4022-thread-1-processing-n:127.0.0.1:45294_solr)
[n:127.0.0.1:45294_solr ] o.a.s.c.s.c.a.PolicyHelper returnSession,
curr-time 3385497757 sessionWrapper.createTime 3385497755120549,
this.sessionWrapper.createTime 3385497755120549
[junit4] 2> 2309168 DEBUG
(TEST-ComputePlanActionTest.testNodeAdded-seed#[DB3957B6117D9155]) [ ]
o.a.s.c.a.ComputePlanActionTest -------------_ FINAL STATE --------------
[junit4] 2> 2309204 INFO (qtp1307586901-13388) [n:127.0.0.1:38800_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> 2309205 DEBUG
(TEST-ComputePlanActionTest.testNodeAdded-seed#[DB3957B6117D9155]) [ ]
o.a.s.c.a.ComputePlanActionTest * Node values: 127.0.0.1:38800_solr
[junit4] 2> {
[junit4] 2> "node":"127.0.0.1:38800_solr",
[junit4] 2> "cores":0,
[junit4] 2> "port":"38800",
[junit4] 2> "host":"127.0.0.1",
[junit4] 2> "ip_1":"1",
[junit4] 2> "ip_3":"0",
[junit4] 2> "ip_2":"0",
[junit4] 2> "ip_4":"127",
[junit4] 2> "freedisk":32.569313049316406}
[junit4] 2> 2309209 DEBUG
(AutoscalingActionExecutor-4022-thread-1-processing-n:127.0.0.1:45294_solr)
[n:127.0.0.1:45294_solr ] o.a.s.c.a.ScheduledTriggers Resuming trigger:
node_added_trigger after 5000ms
[junit4] 2> 2309209 DEBUG
(AutoscalingActionExecutor-4022-thread-1-processing-n:127.0.0.1:45294_solr)
[n:127.0.0.1:45294_solr ] o.a.s.c.a.ScheduledTriggers -- processing took 193
ms for event id=c07175ad4c6d6T1k4sp01ec6gc35zv21wpeaiqu
[junit4] 2> 2309211 INFO (qtp163944847-13330) [n:127.0.0.1:45294_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> 2309212 DEBUG
(TEST-ComputePlanActionTest.testNodeAdded-seed#[DB3957B6117D9155]) [ ]
o.a.s.c.a.ComputePlanActionTest * Node values: 127.0.0.1:45294_solr
[junit4] 2> {
[junit4] 2> "node":"127.0.0.1:45294_solr",
[junit4] 2> "cores":2,
[junit4] 2> "port":"45294",
[junit4] 2> "host":"127.0.0.1",
[junit4] 2> "ip_1":"1",
[junit4] 2> "ip_3":"0",
[junit4] 2> "ip_2":"0",
[junit4] 2> "ip_4":"127",
[junit4] 2> "freedisk":32.569313049316406}
[junit4] 2> 2309212 DEBUG
(TEST-ComputePlanActionTest.testNodeAdded-seed#[DB3957B6117D9155]) [ ]
o.a.s.c.a.ComputePlanActionTest * Live nodes: [127.0.0.1:38800_solr,
127.0.0.1:45294_solr]
[junit4] 2> 2309228 DEBUG
(TEST-ComputePlanActionTest.testNodeAdded-seed#[DB3957B6117D9155]) [ ]
o.a.s.c.a.ComputePlanActionTest * Collection testNodeAdded state:
DocCollection(testNodeAdded//collections/testNodeAdded/state.json/5)={
[junit4] 2> "pullReplicas":"0",
[junit4] 2> "replicationFactor":"2",
[junit4] 2> "shards":{"shard1":{
[junit4] 2> "range":"80000000-7fffffff",
[junit4] 2> "state":"active",
[junit4] 2> "replicas":{
[junit4] 2> "core_node3":{
[junit4] 2> "core":"testNodeAdded_shard1_replica_n1",
[junit4] 2> "base_url":"https://127.0.0.1:45294/solr";,
[junit4] 2> "node_name":"127.0.0.1:45294_solr",
[junit4] 2> "state":"active",
[junit4] 2> "type":"NRT",
[junit4] 2> "leader":"true"},
[junit4] 2> "core_node4":{
[junit4] 2> "core":"testNodeAdded_shard1_replica_n2",
[junit4] 2> "base_url":"https://127.0.0.1:45294/solr";,
[junit4] 2> "node_name":"127.0.0.1:45294_solr",
[junit4] 2> "state":"active",
[junit4] 2> "type":"NRT"}}}},
[junit4] 2> "router":{"name":"compositeId"},
[junit4] 2> "maxShardsPerNode":"1",
[junit4] 2> "autoAddReplicas":"false",
[junit4] 2> "nrtReplicas":"2",
[junit4] 2> "tlogReplicas":"0"}
[junit4] 2> 2309228 INFO
(TEST-ComputePlanActionTest.testNodeAdded-seed#[DB3957B6117D9155]) [ ]
o.a.s.SolrTestCaseJ4 ###Ending testNodeAdded
[junit4] 2> 2309478 INFO
(TEST-ComputePlanActionTest.testNodeLost-seed#[DB3957B6117D9155]) [ ]
o.a.s.SolrTestCaseJ4 ###Starting testNodeLost
[junit4] 2> 2309492 DEBUG
(zkCallback-2034-thread-1-processing-n:127.0.0.1:45294_solr)
[n:127.0.0.1:45294_solr ] o.a.s.c.a.OverseerTriggerThread Refreshing
/autoscaling.json with znode version 8
[junit4] 2> 2309493 DEBUG
(OverseerAutoScalingTriggerThread-72279465483698179-127.0.0.1:45294_solr-n_0000000000)
[n:127.0.0.1:45294_solr ] o.a.s.c.a.OverseerTriggerThread Processed trigger
updates upto znodeVersion 8
[junit4] 2> 2309494 DEBUG
(OverseerAutoScalingTriggerThread-72279465483698179-127.0.0.1:45294_solr-n_0000000000)
[n:127.0.0.1:45294_solr ] o.a.s.c.a.OverseerTriggerThread -- clean old
nodeLost markers
[junit4] 2> 2309494 DEBUG
(OverseerAutoScalingTriggerThread-72279465483698179-127.0.0.1:45294_solr-n_0000000000)
[n:127.0.0.1:45294_solr ] o.a.s.c.a.OverseerTriggerThread -- clean old
nodeAdded markers
[junit4] 2> 2309495 INFO
(TEST-ComputePlanActionTest.testNodeLost-seed#[DB3957B6117D9155]) [ ]
o.e.j.s.AbstractConnector Stopped ServerConnector@60b2afff{SSL,[ssl,
http/1.1]}{127.0.0.1:0}
[junit4] 2> 2309495 DEBUG
(OverseerAutoScalingTriggerThread-72279465483698179-127.0.0.1:45294_solr-n_0000000000)
[n:127.0.0.1:45294_solr ] o.a.s.c.a.OverseerTriggerThread Current
znodeVersion 8, lastZnodeVersion 8
[junit4] 2> 2309495 INFO
(TEST-ComputePlanActionTest.testNodeLost-seed#[DB3957B6117D9155]) [ ]
o.a.s.c.CoreContainer Shutting down CoreContainer instance=1254909344
[junit4] 2> 2309496 INFO
(TEST-ComputePlanActionTest.testNodeLost-seed#[DB3957B6117D9155]) [ ]
o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.node,
tag=null
[junit4] 2> 2309496 INFO
(TEST-ComputePlanActionTest.testNodeLost-seed#[DB3957B6117D9155]) [ ]
o.a.s.m.r.SolrJmxReporter Closing reporter
[org.apache.solr.metrics.reporters.SolrJmxReporter@1cf8e8de: rootName =
solr_45294, domain = solr.node, service url = null, agent id = null] for
registry solr.node / com.codahale.metrics.MetricRegistry@23d1ed89
[junit4] 2> 2309581 INFO
(TEST-ComputePlanActionTest.testNodeLost-seed#[DB3957B6117D9155]) [ ]
o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.jvm,
tag=null
[junit4] 2> 2309581 INFO
(TEST-ComputePlanActionTest.testNodeLost-seed#[DB3957B6117D9155]) [ ]
o.a.s.m.r.SolrJmxReporter Closing reporter
[org.apache.solr.metrics.reporters.SolrJmxReporter@75143f04: rootName =
solr_45294, domain = solr.jvm, service url = null, agent id = null] for
registry solr.jvm / com.codahale.metrics.MetricRegistry@161950c6
[junit4] 2> 2309601 INFO
(TEST-ComputePlanActionTest.testNodeLost-seed#[DB3957B6117D9155]) [ ]
o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.jetty,
tag=null
[junit4] 2> 2309601 INFO
(TEST-ComputePlanActionTest.testNodeLost-seed#[DB3957B6117D9155]) [ ]
o.a.s.m.r.SolrJmxReporter Closing reporter
[org.apache.solr.metrics.reporters.SolrJmxReporter@35463e70: rootName =
solr_45294, domain = solr.jetty, service url = null, agent id = null] for
registry solr.jetty / com.codahale.metrics.MetricRegistry@13b95e77
[junit4] 2> 2309615 INFO
(TEST-ComputePlanActionTest.testNodeLost-seed#[DB3957B6117D9155]) [ ]
o.a.s.c.ZkController Remove node as live in
ZooKeeper:/live_nodes/127.0.0.1:45294_solr
[junit4] 2> 2309616 INFO
(zkCallback-2034-thread-1-processing-n:127.0.0.1:45294_solr)
[n:127.0.0.1:45294_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from
ZooKeeper... (2) -> (1)
[junit4] 2> 2309616 DEBUG
(OverseerStateUpdate-72279465483698179-127.0.0.1:45294_solr-n_0000000000)
[n:127.0.0.1:45294_solr ] o.a.s.c.Overseer processMessage: queueSize: 1,
message = {
[junit4] 2> "operation":"downnode",
[junit4] 2> "node_name":"127.0.0.1:45294_solr"} current state version: 0
[junit4] 2> 2309616 DEBUG
(OverseerStateUpdate-72279465483698179-127.0.0.1:45294_solr-n_0000000000)
[n:127.0.0.1:45294_solr ] o.a.s.c.o.NodeMutator DownNode state invoked for
node: 127.0.0.1:45294_solr
[junit4] 2> 2309616 DEBUG
(OverseerStateUpdate-72279465483698179-127.0.0.1:45294_solr-n_0000000000)
[n:127.0.0.1:45294_solr ] o.a.s.c.o.NodeMutator Update replica state for
core_node3:{"core":"testNodeAdded_shard1_replica_n1","base_url":"https://127.0.0.1:45294/solr","node_name":"127.0.0.1:45294_solr","state":"active","type":"NRT","leader":"true"}
to down
[junit4] 2> 2309616 DEBUG
(OverseerStateUpdate-72279465483698179-127.0.0.1:45294_solr-n_0000000000)
[n:127.0.0.1:45294_solr ] o.a.s.c.o.NodeMutator Update replica state for
core_node4:{"core":"testNodeAdded_shard1_replica_n2","base_url":"https://127.0.0.1:45294/solr","node_name":"127.0.0.1:45294_solr","state":"active","type":"NRT"}
to down
[junit4] 2> 2309617 INFO
(TEST-ComputePlanActionTest.testNodeLost-seed#[DB3957B6117D9155]) [ ]
o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.cluster,
tag=null
[junit4] 2> 2309617 DEBUG
(OverseerStateUpdate-72279465483698179-127.0.0.1:45294_solr-n_0000000000)
[n:127.0.0.1:45294_solr ] o.a.s.c.o.ZkStateWriter going to update_collection
/collections/testNodeAdded/state.json version: 5
[junit4] 2> 2309617 INFO
(zkCallback-2029-thread-2-processing-n:127.0.0.1:45294_solr)
[n:127.0.0.1:45294_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from
ZooKeeper... (2) -> (1)
[junit4] 2> 2309617 INFO
(zkCallback-2029-thread-3-processing-n:127.0.0.1:45294_solr)
[n:127.0.0.1:45294_solr ] o.a.s.c.c.ZkStateReader A cluster state change:
[WatchedEvent state:SyncConnected type:NodeDataChanged
path:/collections/testNodeAdded/state.json] for collection [testNodeAdded] has
occurred - updating... (live nodes size: [1])
[junit4] 2> 2309617 INFO
(zkCallback-2029-thread-1-processing-n:127.0.0.1:45294_solr)
[n:127.0.0.1:45294_solr ] o.a.s.c.c.ZkStateReader A cluster state change:
[WatchedEvent state:SyncConnected type:NodeDataChanged
path:/collections/testNodeAdded/state.json] for collection [testNodeAdded] has
occurred - updating... (live nodes size: [1])
[...truncated too long message...]
icasLost.shard2.replica_n8 / com.codahale.metrics.MetricRegistry@3fee5cb5
[junit4] 2> 2350310 INFO
(zkCallback-2120-thread-1-processing-n:127.0.0.1:35909_solr)
[n:127.0.0.1:35909_solr ] o.a.s.c.OverseerElectionContext I am going to be
the leader 127.0.0.1:35909_solr
[junit4] 2> 2350311 INFO (jetty-closer-2020-thread-2) [ ]
o.e.j.s.h.ContextHandler Stopped
o.e.j.s.ServletContextHandler@4869775e{/solr,null,UNAVAILABLE}
[junit4] 2> 2350311 INFO (jetty-closer-2020-thread-2) [ ]
o.e.j.s.session Stopped scavenging
[junit4] 2> 2350333 INFO (coreCloseExecutor-4128-thread-2)
[n:127.0.0.1:35909_solr c:testNodeWithMultipleReplicasLost s:shard2
r:core_node11 x:testNodeWithMultipleReplicasLost_shard2_replica_n8]
o.a.s.m.SolrMetricManager Closing metric reporters for
registry=solr.collection.testNodeWithMultipleReplicasLost.shard2.leader,
tag=971683436
[junit4] 2> 2350334 INFO (coreCloseExecutor-4128-thread-1)
[n:127.0.0.1:35909_solr c:testNodeWithMultipleReplicasLost s:shard1
r:core_node7 x:testNodeWithMultipleReplicasLost_shard1_replica_n4]
o.a.s.m.SolrMetricManager Closing metric reporters for
registry=solr.collection.testNodeWithMultipleReplicasLost.shard1.leader,
tag=162747274
[junit4] 2> 2350345 INFO (jetty-closer-2020-thread-3) [ ]
o.e.j.s.h.ContextHandler Stopped
o.e.j.s.ServletContextHandler@3e4cbb3e{/solr,null,UNAVAILABLE}
[junit4] 2> 2350349 INFO (jetty-closer-2020-thread-3) [ ]
o.e.j.s.session Stopped scavenging
[junit4] 2> 2352511 WARN
(zkCallback-2094-thread-1-processing-n:127.0.0.1:33402_solr)
[n:127.0.0.1:33402_solr c:testNodeWithMultipleReplicasLost s:shard2
r:core_node9 x:testNodeWithMultipleReplicasLost_shard2_replica_n6]
o.a.s.c.SyncStrategy Closed, skipping sync up.
[junit4] 2> 2352511 INFO
(zkCallback-2094-thread-1-processing-n:127.0.0.1:33402_solr)
[n:127.0.0.1:33402_solr c:testNodeWithMultipleReplicasLost s:shard2
r:core_node9 x:testNodeWithMultipleReplicasLost_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> 2352511 INFO
(zkCallback-2094-thread-1-processing-n:127.0.0.1:33402_solr)
[n:127.0.0.1:33402_solr c:testNodeWithMultipleReplicasLost s:shard2
r:core_node9 x:testNodeWithMultipleReplicasLost_shard2_replica_n6]
o.a.s.c.SolrCore [testNodeWithMultipleReplicasLost_shard2_replica_n6] CLOSING
SolrCore org.apache.solr.core.SolrCore@3ca575f
[junit4] 2> 2352511 INFO
(zkCallback-2094-thread-1-processing-n:127.0.0.1:33402_solr)
[n:127.0.0.1:33402_solr c:testNodeWithMultipleReplicasLost s:shard2
r:core_node9 x:testNodeWithMultipleReplicasLost_shard2_replica_n6]
o.a.s.m.SolrMetricManager Closing metric reporters for
registry=solr.core.testNodeWithMultipleReplicasLost.shard2.replica_n6,
tag=63592287
[junit4] 2> 2352511 INFO
(zkCallback-2094-thread-1-processing-n:127.0.0.1:33402_solr)
[n:127.0.0.1:33402_solr c:testNodeWithMultipleReplicasLost s:shard2
r:core_node9 x:testNodeWithMultipleReplicasLost_shard2_replica_n6]
o.a.s.m.r.SolrJmxReporter Closing reporter
[org.apache.solr.metrics.reporters.SolrJmxReporter@25efd08f: rootName =
solr_33402, domain =
solr.core.testNodeWithMultipleReplicasLost.shard2.replica_n6, service url =
null, agent id = null] for registry
solr.core.testNodeWithMultipleReplicasLost.shard2.replica_n6 /
com.codahale.metrics.MetricRegistry@30732113
[junit4] 2> 2352519 INFO
(zkCallback-2094-thread-1-processing-n:127.0.0.1:33402_solr)
[n:127.0.0.1:33402_solr c:testNodeWithMultipleReplicasLost s:shard2
r:core_node9 x:testNodeWithMultipleReplicasLost_shard2_replica_n6]
o.a.s.m.SolrMetricManager Closing metric reporters for
registry=solr.collection.testNodeWithMultipleReplicasLost.shard2.leader,
tag=63592287
[junit4] 2> 2352520 INFO (jetty-closer-2020-thread-1) [ ]
o.e.j.s.h.ContextHandler Stopped
o.e.j.s.ServletContextHandler@73810620{/solr,null,UNAVAILABLE}
[junit4] 2> 2352521 INFO (jetty-closer-2020-thread-1) [ ]
o.e.j.s.session Stopped scavenging
[junit4] 2> 2352521 ERROR
(SUITE-ComputePlanActionTest-seed#[DB3957B6117D9155]-worker) [ ]
o.a.z.s.ZooKeeperServer ZKShutdownHandler is not registered, so ZooKeeper
server won't take any action on ERROR or SHUTDOWN server state changes
[junit4] 2> 2352522 INFO
(SUITE-ComputePlanActionTest-seed#[DB3957B6117D9155]-worker) [ ]
o.a.s.c.ZkTestServer connecting to 127.0.0.1:41341 41341
[junit4] 2> 2352621 INFO (Thread-2620) [ ] o.a.s.c.ZkTestServer
connecting to 127.0.0.1:41341 41341
[junit4] 2> 2352622 WARN (Thread-2620) [ ] o.a.s.c.ZkTestServer Watch
limit violations:
[junit4] 2> Maximum concurrent create/delete watches above limit:
[junit4] 2>
[junit4] 2> 21 /solr/aliases.json
[junit4] 2> 9
/solr/collections/testNodeWithMultipleReplicasLost/terms/shard2
[junit4] 2> 9
/solr/collections/testNodeWithMultipleReplicasLost/terms/shard1
[junit4] 2> 7 /solr/security.json
[junit4] 2> 7 /solr/configs/conf
[junit4] 2> 6 /solr/collections/testNodeLost/terms/shard1
[junit4] 2> 4
/solr/collections/testNodeWithMultipleReplicasLost/collectionprops.json
[junit4] 2> 3 /solr/collections/testNodeAdded/terms/shard1
[junit4] 2> 2
/solr/collections/testNodeLost/collectionprops.json
[junit4] 2>
[junit4] 2> Maximum concurrent data watches above limit:
[junit4] 2>
[junit4] 2> 24
/solr/collections/testNodeWithMultipleReplicasLost/state.json
[junit4] 2> 21 /solr/clusterprops.json
[junit4] 2> 21 /solr/clusterstate.json
[junit4] 2> 16 /solr/collections/testNodeLost/state.json
[junit4] 2> 7 /solr/collections/testNodeAdded/state.json
[junit4] 2> 3 /solr/autoscaling.json
[junit4] 2> 3
/solr/overseer_elect/election/72279465483698185-127.0.0.1:38800_solr-n_0000000001
[junit4] 2>
[junit4] 2> Maximum concurrent children watches above limit:
[junit4] 2>
[junit4] 2> 29 /solr/live_nodes
[junit4] 2> 28 /solr/collections
[junit4] 2> 3 /solr/overseer/queue
[junit4] 2> 3 /solr/autoscaling/events/.scheduled_maintenance
[junit4] 2> 3 /solr/autoscaling/events/.auto_add_replicas
[junit4] 2> 3 /solr/overseer/collection-queue-work
[junit4] 2> 3 /solr/overseer/queue-work
[junit4] 2>
[junit4] 2> NOTE: leaving temporary files on disk at:
/home/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-master/solr/build/solr-core/test/J0/temp/solr.cloud.autoscaling.ComputePlanActionTest_DB3957B6117D9155-001
[junit4] 2> Mar 14, 2018 5:22:20 PM
com.carrotsearch.randomizedtesting.ThreadLeakControl checkThreadLeaks
[junit4] 2> WARNING: Will linger awaiting termination of 1 leaked
thread(s).
[junit4] 2> NOTE: test params are: codec=CheapBastard,
sim=Asserting(org.apache.lucene.search.similarities.AssertingSimilarity@21b18dd5),
locale=sr-ME, timezone=Africa/Bangui
[junit4] 2> NOTE: Linux 4.4.0-112-generic amd64/Oracle Corporation
1.8.0_152 (64-bit)/cpus=4,threads=1,free=263448656,total=518520832
[junit4] 2> NOTE: All tests run in this JVM: [UpdateLogTest,
TestManagedSchemaThreadSafety, SolrCoreCheckLockOnStartupTest,
TestLocalFSCloudBackupRestore, RequestLoggingTest, CdcrVersionReplicationTest,
DocExpirationUpdateProcessorFactoryTest,
ClassificationUpdateProcessorIntegrationTest, MergeStrategyTest,
AutoAddReplicasIntegrationTest, FullSolrCloudDistribCmdsTest,
TestEmbeddedSolrServerConstructors, TestPerFieldSimilarityWithDefaultOverride,
TestBinaryField, TestStressLucene, TestHalfAndHalfDocValues,
TestComplexPhraseQParserPlugin, DistributedFacetPivotWhiteBoxTest,
UUIDFieldTest, TestDeleteCollectionOnDownNodes,
DocumentAnalysisRequestHandlerTest, SolrPluginUtilsTest,
TestDynamicFieldResource, UpdateParamsTest, TestRandomFaceting,
TestApiFramework, SearchRateTriggerTest, TokenizerChainTest, TestBlobHandler,
SolrXmlInZkTest, BaseCdcrDistributedZkTest, TestHdfsUpdateLog,
AliasIntegrationTest, TestQuerySenderNoQuery, V2ApiIntegrationTest,
ConnectionReuseTest, SharedFSAutoReplicaFailoverTest, SolrIndexConfigTest,
DistributedFacetPivotLongTailTest, RAMDirectoryFactoryTest,
TestLegacyFieldReuse, TestSort, TestRuleBasedAuthorizationPlugin,
TestHashPartitioner, HLLSerializationTest, TestMergePolicyConfig,
ExternalFileFieldSortTest, TestDocSet, TestBulkSchemaAPI,
WrapperMergePolicyFactoryTest, HttpSolrCallGetCoreTest,
DocValuesNotIndexedTest, HttpPartitionOnCommitTest, TestStandardQParsers,
SuggestComponentContextFilterQueryTest, RegexBytesRefFilterTest,
TestInitQParser, TestNestedDocsSort, TestDistributedSearch,
TestExpandComponent, TestInitParams, DateRangeFieldTest,
ChaosMonkeyNothingIsSafeWithPullReplicasTest, NodeMutatorTest,
BasicDistributedZkTest, TestRemoteStreaming, TestWriterPerf,
TestSerializedLuceneMatchVersion, TestFileDictionaryLookup, MetricsConfigTest,
TestAddFieldRealTimeGet, TestStressInPlaceUpdates, CreateRoutedAliasTest,
TestFieldCache, TestPullReplica, TestOmitPositions,
TestTolerantUpdateProcessorCloud, AtomicUpdateProcessorFactoryTest,
CollectionsAPIDistributedZkTest, TestIndexingPerformance,
TestPhraseSuggestions, TestCloudPivotFacet, TestLargeCluster, InfoHandlerTest,
MigrateRouteKeyTest, TestRandomRequestDistribution,
TestSchemalessBufferedUpdates, TestCloudDeleteByQuery, TestMissingGroups,
PluginInfoTest, TestGroupingSearch, TestSolrXml, TestConfigSetImmutable,
TestUseDocValuesAsStored2, TestTrackingShardHandlerFactory,
OpenCloseCoreStressTest, TestManagedResource, HdfsRestartWhileUpdatingTest,
NodeLostTriggerTest, TestIndexSearcher, DirectoryFactoryTest,
TestMultiValuedNumericRangeQuery, TestDynamicLoading, TestRestoreCore,
TestCoreAdminApis, TestPolicyCloud, TestMacros,
TestLMDirichletSimilarityFactory, SpellCheckCollatorWithCollapseTest,
TestMaxTokenLenTokenizer, ComputePlanActionTest]
[junit4] Completed [510/785 (1!)] on J0 in 52.58s, 4 tests, 1 failure, 1
skipped <<< FAILURES!
[...truncated 50545 lines...]
---------------------------------------------------------------------
To unsubscribe, e-mail: dev-unsubscr...@lucene.apache.org
For additional commands, e-mail: dev-h...@lucene.apache.org
