Build: https://jenkins.thetaphi.de/job/Lucene-Solr-7.x-Linux/1422/
Java: 64bit/jdk1.8.0_162 -XX:+UseCompressedOops -XX:+UseSerialGC
2 tests failed.
FAILED: org.apache.solr.cloud.TestUtilizeNode.test
Error Message:
no replica should be present in 127.0.0.1:36897_solr
Stack Trace:
java.lang.AssertionError: no replica should be present in 127.0.0.1:36897_solr
at
__randomizedtesting.SeedInfo.seed([2517DF000B47CC7A:AD43E0DAA5BBA182]:0)
at org.junit.Assert.fail(Assert.java:93)
at org.junit.Assert.assertTrue(Assert.java:43)
at org.apache.solr.cloud.TestUtilizeNode.test(TestUtilizeNode.java:99)
at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
at
sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
at
sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
at java.lang.reflect.Method.invoke(Method.java:498)
at
com.carrotsearch.randomizedtesting.RandomizedRunner.invoke(RandomizedRunner.java:1737)
at
com.carrotsearch.randomizedtesting.RandomizedRunner$8.evaluate(RandomizedRunner.java:934)
at
com.carrotsearch.randomizedtesting.RandomizedRunner$9.evaluate(RandomizedRunner.java:970)
at
com.carrotsearch.randomizedtesting.RandomizedRunner$10.evaluate(RandomizedRunner.java:984)
at
com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:57)
at
org.apache.lucene.util.TestRuleSetupTeardownChained$1.evaluate(TestRuleSetupTeardownChained.java:49)
at
org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:45)
at
org.apache.lucene.util.TestRuleThreadAndTestName$1.evaluate(TestRuleThreadAndTestName.java:48)
at
org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:64)
at
org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:47)
at
com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at
com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:368)
at
com.carrotsearch.randomizedtesting.ThreadLeakControl.forkTimeoutingTask(ThreadLeakControl.java:817)
at
com.carrotsearch.randomizedtesting.ThreadLeakControl$3.evaluate(ThreadLeakControl.java:468)
at
com.carrotsearch.randomizedtesting.RandomizedRunner.runSingleTest(RandomizedRunner.java:943)
at
com.carrotsearch.randomizedtesting.RandomizedRunner$5.evaluate(RandomizedRunner.java:829)
at
com.carrotsearch.randomizedtesting.RandomizedRunner$6.evaluate(RandomizedRunner.java:879)
at
com.carrotsearch.randomizedtesting.RandomizedRunner$7.evaluate(RandomizedRunner.java:890)
at
com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at
com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:57)
at
org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:45)
at
com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at
org.apache.lucene.util.TestRuleStoreClassName$1.evaluate(TestRuleStoreClassName.java:41)
at
com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:40)
at
com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:40)
at
com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at
com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at
com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at
org.apache.lucene.util.TestRuleAssertionsRequired$1.evaluate(TestRuleAssertionsRequired.java:53)
at
org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:47)
at
org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:64)
at
org.apache.lucene.util.TestRuleIgnoreTestSuites$1.evaluate(TestRuleIgnoreTestSuites.java:54)
at
com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at
com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:368)
at java.lang.Thread.run(Thread.java:748)
FAILED:
org.apache.solr.cloud.autoscaling.ComputePlanActionTest.testSelectedCollections
Error Message:
The operations computed by ComputePlanAction should not be
nullSolrClientNodeStateProvider.DEBUG{AFTER_ACTION=[compute_plan, null],
BEFORE_ACTION=[compute_plan, null]}
Stack Trace:
java.lang.AssertionError: The operations computed by ComputePlanAction should
not be nullSolrClientNodeStateProvider.DEBUG{AFTER_ACTION=[compute_plan, null],
BEFORE_ACTION=[compute_plan, null]}
at
__randomizedtesting.SeedInfo.seed([2517DF000B47CC7A:1FB93AD935231514]: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.testSelectedCollections(ComputePlanActionTest.java:469)
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 12435 lines...]
[junit4] Suite: org.apache.solr.cloud.autoscaling.ComputePlanActionTest
[junit4] 2> 300116 INFO
(SUITE-ComputePlanActionTest-seed#[2517DF000B47CC7A]-worker) [ ]
o.a.s.SolrTestCaseJ4 SecureRandom sanity checks:
test.solr.allowed.securerandom=null & java.security.egd=file:/dev/./urandom
[junit4] 2> Creating dataDir:
/home/jenkins/workspace/Lucene-Solr-7.x-Linux/solr/build/solr-core/test/J1/temp/solr.cloud.autoscaling.ComputePlanActionTest_2517DF000B47CC7A-001/init-core-data-001
[junit4] 2> 300117 WARN
(SUITE-ComputePlanActionTest-seed#[2517DF000B47CC7A]-worker) [ ]
o.a.s.SolrTestCaseJ4 startTrackingSearchers: numOpens=4 numCloses=4
[junit4] 2> 300117 INFO
(SUITE-ComputePlanActionTest-seed#[2517DF000B47CC7A]-worker) [ ]
o.a.s.SolrTestCaseJ4 Using PointFields (NUMERIC_POINTS_SYSPROP=true)
w/NUMERIC_DOCVALUES_SYSPROP=true
[junit4] 2> 300118 INFO
(SUITE-ComputePlanActionTest-seed#[2517DF000B47CC7A]-worker) [ ]
o.a.s.SolrTestCaseJ4 Randomized ssl (false) and clientAuth (true) via:
@org.apache.solr.util.RandomizeSSL(reason=, ssl=NaN, value=NaN, clientAuth=NaN)
[junit4] 2> 300118 INFO
(SUITE-ComputePlanActionTest-seed#[2517DF000B47CC7A]-worker) [ ]
o.a.s.c.MiniSolrCloudCluster Starting cluster of 1 servers in
/home/jenkins/workspace/Lucene-Solr-7.x-Linux/solr/build/solr-core/test/J1/temp/solr.cloud.autoscaling.ComputePlanActionTest_2517DF000B47CC7A-001/tempDir-001
[junit4] 2> 300118 INFO
(SUITE-ComputePlanActionTest-seed#[2517DF000B47CC7A]-worker) [ ]
o.a.s.c.ZkTestServer STARTING ZK TEST SERVER
[junit4] 2> 300118 INFO (Thread-657) [ ] o.a.s.c.ZkTestServer client
port:0.0.0.0/0.0.0.0:0
[junit4] 2> 300118 INFO (Thread-657) [ ] o.a.s.c.ZkTestServer Starting
server
[junit4] 2> 300120 ERROR (Thread-657) [ ] 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> 300218 INFO
(SUITE-ComputePlanActionTest-seed#[2517DF000B47CC7A]-worker) [ ]
o.a.s.c.ZkTestServer start zk server on port:36953
[junit4] 2> 300220 INFO (zkConnectionManagerCallback-580-thread-1) [ ]
o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 300224 INFO (jetty-launcher-577-thread-1) [ ]
o.e.j.s.Server jetty-9.4.8.v20171121, build timestamp:
2017-11-21T23:27:37+02:00, git hash: 82b8fb23f757335bb3329d540ce37a2a2615f0a8
[junit4] 2> 300225 INFO (jetty-launcher-577-thread-1) [ ]
o.e.j.s.session DefaultSessionIdManager workerName=node0
[junit4] 2> 300225 INFO (jetty-launcher-577-thread-1) [ ]
o.e.j.s.session No SessionScavenger set, using defaults
[junit4] 2> 300225 INFO (jetty-launcher-577-thread-1) [ ]
o.e.j.s.session Scavenging every 600000ms
[junit4] 2> 300225 INFO (jetty-launcher-577-thread-1) [ ]
o.e.j.s.h.ContextHandler Started
o.e.j.s.ServletContextHandler@43220710{/solr,null,AVAILABLE}
[junit4] 2> 300227 INFO (jetty-launcher-577-thread-1) [ ]
o.e.j.s.AbstractConnector Started
ServerConnector@78af42d8{HTTP/1.1,[http/1.1]}{127.0.0.1:42365}
[junit4] 2> 300227 INFO (jetty-launcher-577-thread-1) [ ]
o.e.j.s.Server Started @301961ms
[junit4] 2> 300227 INFO (jetty-launcher-577-thread-1) [ ]
o.a.s.c.s.e.JettySolrRunner Jetty properties: {hostContext=/solr,
hostPort=42365}
[junit4] 2> 300227 ERROR (jetty-launcher-577-thread-1) [ ]
o.a.s.u.StartupLoggingUtils Missing Java Option solr.log.dir. Logging may be
missing or incomplete.
[junit4] 2> 300227 INFO (jetty-launcher-577-thread-1) [ ]
o.a.s.s.SolrDispatchFilter ___ _ Welcome to Apache Solr™ version
7.3.0
[junit4] 2> 300227 INFO (jetty-launcher-577-thread-1) [ ]
o.a.s.s.SolrDispatchFilter / __| ___| |_ _ Starting in cloud mode on port null
[junit4] 2> 300227 INFO (jetty-launcher-577-thread-1) [ ]
o.a.s.s.SolrDispatchFilter \__ \/ _ \ | '_| Install dir: null
[junit4] 2> 300227 INFO (jetty-launcher-577-thread-1) [ ]
o.a.s.s.SolrDispatchFilter |___/\___/_|_| Start time:
2018-02-24T22:15:37.123Z
[junit4] 2> 300228 INFO (zkConnectionManagerCallback-582-thread-1) [ ]
o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 300228 INFO (jetty-launcher-577-thread-1) [ ]
o.a.s.s.SolrDispatchFilter solr.xml found in ZooKeeper. Loading...
[junit4] 2> 300233 INFO (jetty-launcher-577-thread-1) [ ]
o.a.s.c.ZkContainer Zookeeper client=127.0.0.1:36953/solr
[junit4] 2> 300234 INFO (zkConnectionManagerCallback-586-thread-1) [ ]
o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 300236 INFO
(zkConnectionManagerCallback-588-thread-1-processing-n:127.0.0.1:42365_solr)
[n:127.0.0.1:42365_solr ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 300264 INFO (jetty-launcher-577-thread-1)
[n:127.0.0.1:42365_solr ] o.a.s.c.Overseer Overseer (id=null) closing
[junit4] 2> 300265 INFO (jetty-launcher-577-thread-1)
[n:127.0.0.1:42365_solr ] o.a.s.c.OverseerElectionContext I am going to be
the leader 127.0.0.1:42365_solr
[junit4] 2> 300265 INFO (jetty-launcher-577-thread-1)
[n:127.0.0.1:42365_solr ] o.a.s.c.Overseer Overseer
(id=72206603074142211-127.0.0.1:42365_solr-n_0000000000) starting
[junit4] 2> 300267 DEBUG
(OverseerStateUpdate-72206603074142211-127.0.0.1:42365_solr-n_0000000000)
[n:127.0.0.1:42365_solr ] o.a.s.c.Overseer Starting to work on the main queue
[junit4] 2> 300267 INFO (jetty-launcher-577-thread-1)
[n:127.0.0.1:42365_solr ] o.a.s.c.ZkController Register node as live in
ZooKeeper:/live_nodes/127.0.0.1:42365_solr
[junit4] 2> 300267 DEBUG
(OverseerAutoScalingTriggerThread-72206603074142211-127.0.0.1:42365_solr-n_0000000000)
[n:127.0.0.1:42365_solr ] o.a.s.c.a.OverseerTriggerThread Adding
.autoAddReplicas trigger
[junit4] 2> 300268 INFO
(OverseerStateUpdate-72206603074142211-127.0.0.1:42365_solr-n_0000000000)
[n:127.0.0.1:42365_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from
ZooKeeper... (0) -> (1)
[junit4] 2> 300268 DEBUG
(OverseerAutoScalingTriggerThread-72206603074142211-127.0.0.1:42365_solr-n_0000000000)
[n:127.0.0.1:42365_solr ] o.a.s.c.a.OverseerTriggerThread Refreshing
/autoscaling.json with znode version 1
[junit4] 2> 300269 DEBUG
(OverseerAutoScalingTriggerThread-72206603074142211-127.0.0.1:42365_solr-n_0000000000)
[n:127.0.0.1:42365_solr ] o.a.s.c.a.NodeLostTrigger Initial livenodes:
[127.0.0.1:42365_solr]
[junit4] 2> 300269 DEBUG
(OverseerAutoScalingTriggerThread-72206603074142211-127.0.0.1:42365_solr-n_0000000000)
[n:127.0.0.1:42365_solr ] o.a.s.c.a.OverseerTriggerThread Current
znodeVersion 1, lastZnodeVersion -1
[junit4] 2> 300269 DEBUG
(OverseerAutoScalingTriggerThread-72206603074142211-127.0.0.1:42365_solr-n_0000000000)
[n:127.0.0.1:42365_solr ] o.a.s.c.a.OverseerTriggerThread Processed trigger
updates upto znodeVersion 1
[junit4] 2> 300270 DEBUG
(OverseerAutoScalingTriggerThread-72206603074142211-127.0.0.1:42365_solr-n_0000000000)
[n:127.0.0.1:42365_solr ] o.a.s.c.a.OverseerTriggerThread -- clean old
nodeAdded markers
[junit4] 2> 300270 DEBUG
(OverseerAutoScalingTriggerThread-72206603074142211-127.0.0.1:42365_solr-n_0000000000)
[n:127.0.0.1:42365_solr ] o.a.s.c.a.OverseerTriggerThread Current
znodeVersion 1, lastZnodeVersion 1
[junit4] 2> 300270 DEBUG (ScheduledTrigger-1207-thread-1)
[n:127.0.0.1:42365_solr ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger:
.auto_add_replicas with currently live nodes: 1
[junit4] 2> 300302 INFO (jetty-launcher-577-thread-1)
[n:127.0.0.1:42365_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for
'solr_42365.solr.node' (registry 'solr.node') enabled at server:
com.sun.jmx.mbeanserver.JmxMBeanServer@40193ce4
[junit4] 2> 300307 INFO (jetty-launcher-577-thread-1)
[n:127.0.0.1:42365_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for
'solr_42365.solr.jvm' (registry 'solr.jvm') enabled at server:
com.sun.jmx.mbeanserver.JmxMBeanServer@40193ce4
[junit4] 2> 300307 INFO (jetty-launcher-577-thread-1)
[n:127.0.0.1:42365_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for
'solr_42365.solr.jetty' (registry 'solr.jetty') enabled at server:
com.sun.jmx.mbeanserver.JmxMBeanServer@40193ce4
[junit4] 2> 300308 INFO (jetty-launcher-577-thread-1)
[n:127.0.0.1:42365_solr ] o.a.s.c.CorePropertiesLocator Found 0 core
definitions underneath
/home/jenkins/workspace/Lucene-Solr-7.x-Linux/solr/build/solr-core/test/J1/temp/solr.cloud.autoscaling.ComputePlanActionTest_2517DF000B47CC7A-001/tempDir-001/node1/.
[junit4] 2> 300319 INFO (zkConnectionManagerCallback-592-thread-1) [ ]
o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 300322 INFO (zkConnectionManagerCallback-596-thread-1) [ ]
o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 300323 INFO
(SUITE-ComputePlanActionTest-seed#[2517DF000B47CC7A]-worker) [ ]
o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (1)
[junit4] 2> 300323 INFO
(SUITE-ComputePlanActionTest-seed#[2517DF000B47CC7A]-worker) [ ]
o.a.s.c.s.i.ZkClientClusterStateProvider Cluster at 127.0.0.1:36953/solr ready
[junit4] 2> 300330 INFO
(TEST-ComputePlanActionTest.testNodeAdded-seed#[2517DF000B47CC7A]) [ ]
o.a.s.SolrTestCaseJ4 ###Starting testNodeAdded
[junit4] 2> 300330 DEBUG
(zkCallback-587-thread-1-processing-n:127.0.0.1:42365_solr)
[n:127.0.0.1:42365_solr ] o.a.s.c.a.OverseerTriggerThread Refreshing
/autoscaling.json with znode version 2
[junit4] 2> 300330 DEBUG
(OverseerAutoScalingTriggerThread-72206603074142211-127.0.0.1:42365_solr-n_0000000000)
[n:127.0.0.1:42365_solr ] o.a.s.c.a.OverseerTriggerThread Processed trigger
updates upto znodeVersion 2
[junit4] 2> 300330 INFO
(TEST-ComputePlanActionTest.testNodeAdded-seed#[2517DF000B47CC7A]) [ ]
o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (1)
[junit4] 2> 300331 DEBUG
(OverseerAutoScalingTriggerThread-72206603074142211-127.0.0.1:42365_solr-n_0000000000)
[n:127.0.0.1:42365_solr ] o.a.s.c.a.OverseerTriggerThread -- clean old
nodeLost markers
[junit4] 2> 300331 DEBUG
(OverseerAutoScalingTriggerThread-72206603074142211-127.0.0.1:42365_solr-n_0000000000)
[n:127.0.0.1:42365_solr ] o.a.s.c.a.OverseerTriggerThread -- clean old
nodeAdded markers
[junit4] 2> 300331 DEBUG
(OverseerAutoScalingTriggerThread-72206603074142211-127.0.0.1:42365_solr-n_0000000000)
[n:127.0.0.1:42365_solr ] o.a.s.c.a.OverseerTriggerThread Current
znodeVersion 2, lastZnodeVersion 2
[junit4] 2> 300353 INFO (qtp512600927-2899) [n:127.0.0.1:42365_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=7
[junit4] 2> 300355 DEBUG (qtp512600927-2862) [n:127.0.0.1:42365_solr ]
o.a.s.c.a.AutoScalingHandler Verified autoscaling configuration
[junit4] 2> 300355 INFO (qtp512600927-2862) [n:127.0.0.1:42365_solr ]
o.a.s.s.HttpSolrCall [admin] webapp=null path=/cluster/autoscaling
params={wt=javabin&version=2} status=0 QTime=23
[junit4] 2> 300356 DEBUG
(zkCallback-587-thread-1-processing-n:127.0.0.1:42365_solr)
[n:127.0.0.1:42365_solr ] o.a.s.c.a.OverseerTriggerThread Refreshing
/autoscaling.json with znode version 3
[junit4] 2> 300356 DEBUG
(OverseerAutoScalingTriggerThread-72206603074142211-127.0.0.1:42365_solr-n_0000000000)
[n:127.0.0.1:42365_solr ] o.a.s.c.a.OverseerTriggerThread Processed trigger
updates upto znodeVersion 3
[junit4] 2> 300356 DEBUG
(OverseerAutoScalingTriggerThread-72206603074142211-127.0.0.1:42365_solr-n_0000000000)
[n:127.0.0.1:42365_solr ] o.a.s.c.a.OverseerTriggerThread -- clean old
nodeLost markers
[junit4] 2> 300356 DEBUG
(OverseerAutoScalingTriggerThread-72206603074142211-127.0.0.1:42365_solr-n_0000000000)
[n:127.0.0.1:42365_solr ] o.a.s.c.a.OverseerTriggerThread -- clean old
nodeAdded markers
[junit4] 2> 300356 DEBUG
(OverseerAutoScalingTriggerThread-72206603074142211-127.0.0.1:42365_solr-n_0000000000)
[n:127.0.0.1:42365_solr ] o.a.s.c.a.OverseerTriggerThread Current
znodeVersion 3, lastZnodeVersion 3
[junit4] 2> 300358 INFO (qtp512600927-2868) [n:127.0.0.1:42365_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> 300359 DEBUG (qtp512600927-2866) [n:127.0.0.1:42365_solr ]
o.a.s.c.a.AutoScalingHandler Verified autoscaling configuration
[junit4] 2> 300359 INFO (qtp512600927-2866) [n:127.0.0.1:42365_solr ]
o.a.s.s.HttpSolrCall [admin] webapp=null path=/cluster/autoscaling
params={wt=javabin&version=2} status=0 QTime=3
[junit4] 2> 300359 DEBUG
(zkCallback-587-thread-1-processing-n:127.0.0.1:42365_solr)
[n:127.0.0.1:42365_solr ] o.a.s.c.a.OverseerTriggerThread Refreshing
/autoscaling.json with znode version 4
[junit4] 2> 300359 DEBUG
(OverseerAutoScalingTriggerThread-72206603074142211-127.0.0.1:42365_solr-n_0000000000)
[n:127.0.0.1:42365_solr ] o.a.s.c.a.OverseerTriggerThread Processed trigger
updates upto znodeVersion 4
[junit4] 2> 300359 DEBUG
(OverseerAutoScalingTriggerThread-72206603074142211-127.0.0.1:42365_solr-n_0000000000)
[n:127.0.0.1:42365_solr ] o.a.s.c.a.OverseerTriggerThread -- clean old
nodeLost markers
[junit4] 2> 300360 DEBUG
(OverseerAutoScalingTriggerThread-72206603074142211-127.0.0.1:42365_solr-n_0000000000)
[n:127.0.0.1:42365_solr ] o.a.s.c.a.OverseerTriggerThread -- clean old
nodeAdded markers
[junit4] 2> 300360 DEBUG
(OverseerAutoScalingTriggerThread-72206603074142211-127.0.0.1:42365_solr-n_0000000000)
[n:127.0.0.1:42365_solr ] o.a.s.c.a.OverseerTriggerThread Current
znodeVersion 4, lastZnodeVersion 4
[junit4] 2> 300380 INFO (qtp512600927-2867) [n:127.0.0.1:42365_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> 300381 DEBUG (qtp512600927-2898) [n:127.0.0.1:42365_solr ]
o.a.s.c.a.AutoScalingHandler Verified autoscaling configuration
[junit4] 2> 300381 INFO (qtp512600927-2898) [n:127.0.0.1:42365_solr ]
o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/autoscaling
params={wt=javabin&version=2} status=0 QTime=20
[junit4] 2> 300381 DEBUG
(zkCallback-587-thread-1-processing-n:127.0.0.1:42365_solr)
[n:127.0.0.1:42365_solr ] o.a.s.c.a.OverseerTriggerThread Refreshing
/autoscaling.json with znode version 5
[junit4] 2> 300382 DEBUG
(zkCallback-587-thread-1-processing-n:127.0.0.1:42365_solr)
[n:127.0.0.1:42365_solr ] o.a.s.c.a.NodeAddedTrigger Initial livenodes:
[127.0.0.1:42365_solr]
[junit4] 2> 300382 DEBUG
(zkCallback-587-thread-1-processing-n:127.0.0.1:42365_solr)
[n:127.0.0.1:42365_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> 300382 DEBUG
(OverseerAutoScalingTriggerThread-72206603074142211-127.0.0.1:42365_solr-n_0000000000)
[n:127.0.0.1:42365_solr ] o.a.s.c.a.OverseerTriggerThread Processed trigger
updates upto znodeVersion 5
[junit4] 2> 300383 DEBUG
(OverseerAutoScalingTriggerThread-72206603074142211-127.0.0.1:42365_solr-n_0000000000)
[n:127.0.0.1:42365_solr ] o.a.s.c.a.OverseerTriggerThread -- clean old
nodeLost markers
[junit4] 2> 300383 DEBUG
(OverseerAutoScalingTriggerThread-72206603074142211-127.0.0.1:42365_solr-n_0000000000)
[n:127.0.0.1:42365_solr ] o.a.s.c.a.OverseerTriggerThread Current
znodeVersion 5, lastZnodeVersion 5
[junit4] 2> 300383 DEBUG (ScheduledTrigger-1207-thread-1)
[n:127.0.0.1:42365_solr ] o.a.s.c.a.NodeAddedTrigger Running
NodeAddedTrigger node_added_trigger
[junit4] 2> 300383 DEBUG (ScheduledTrigger-1207-thread-1)
[n:127.0.0.1:42365_solr ] o.a.s.c.a.NodeAddedTrigger Found livenodes: 1
[junit4] 2> 300383 INFO (qtp512600927-2868) [n:127.0.0.1:42365_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> 300384 DEBUG (qtp512600927-2866) [n:127.0.0.1:42365_solr ]
o.a.s.c.a.AutoScalingHandler Verified autoscaling configuration
[junit4] 2> 300384 INFO (qtp512600927-2866) [n:127.0.0.1:42365_solr ]
o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/autoscaling
params={wt=javabin&version=2} status=0 QTime=2
[junit4] 2> 300384 DEBUG
(zkCallback-587-thread-1-processing-n:127.0.0.1:42365_solr)
[n:127.0.0.1:42365_solr ] o.a.s.c.a.OverseerTriggerThread Refreshing
/autoscaling.json with znode version 6
[junit4] 2> 300384 DEBUG
(zkCallback-587-thread-1-processing-n:127.0.0.1:42365_solr)
[n:127.0.0.1:42365_solr ] o.a.s.c.a.NodeAddedTrigger Initial livenodes:
[127.0.0.1:42365_solr]
[junit4] 2> 300384 DEBUG
(zkCallback-587-thread-1-processing-n:127.0.0.1:42365_solr)
[n:127.0.0.1:42365_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> 300384 DEBUG
(OverseerAutoScalingTriggerThread-72206603074142211-127.0.0.1:42365_solr-n_0000000000)
[n:127.0.0.1:42365_solr ] o.a.s.c.a.OverseerTriggerThread Processed trigger
updates upto znodeVersion 6
[junit4] 2> 300385 INFO (qtp512600927-2898) [n:127.0.0.1:42365_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> 300385 DEBUG
(OverseerAutoScalingTriggerThread-72206603074142211-127.0.0.1:42365_solr-n_0000000000)
[n:127.0.0.1:42365_solr ] o.a.s.c.a.OverseerTriggerThread -- clean old
nodeLost markers
[junit4] 2> 300385 DEBUG
(OverseerAutoScalingTriggerThread-72206603074142211-127.0.0.1:42365_solr-n_0000000000)
[n:127.0.0.1:42365_solr ] o.a.s.c.a.OverseerTriggerThread Current
znodeVersion 6, lastZnodeVersion 6
[junit4] 2> 300386 INFO
(OverseerThreadFactory-1209-thread-1-processing-n:127.0.0.1:42365_solr)
[n:127.0.0.1:42365_solr ] o.a.s.c.a.c.CreateCollectionCmd Create collection
testNodeAdded
[junit4] 2> 300386 WARN
(OverseerThreadFactory-1209-thread-1-processing-n:127.0.0.1:42365_solr)
[n:127.0.0.1:42365_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> 300393 INFO (qtp512600927-2867) [n:127.0.0.1:42365_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> 300396 INFO
(OverseerThreadFactory-1209-thread-1-processing-n:127.0.0.1:42365_solr)
[n:127.0.0.1:42365_solr ] o.a.s.c.s.c.a.PolicyHelper returnSession,
curr-time 2273697730 sessionWrapper.createTime 2273697727435594,
this.sessionWrapper.createTime 2273697727435594
[junit4] 2> 300399 DEBUG
(OverseerStateUpdate-72206603074142211-127.0.0.1:42365_solr-n_0000000000)
[n:127.0.0.1:42365_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> 300399 DEBUG
(OverseerStateUpdate-72206603074142211-127.0.0.1:42365_solr-n_0000000000)
[n:127.0.0.1:42365_solr ] o.a.s.c.o.ClusterStateMutator building a new
cName: testNodeAdded
[junit4] 2> 300399 DEBUG
(OverseerStateUpdate-72206603074142211-127.0.0.1:42365_solr-n_0000000000)
[n:127.0.0.1:42365_solr ] o.a.s.c.o.ZkStateWriter going to create_collection
/collections/testNodeAdded/state.json
[junit4] 2> 300502 DEBUG
(OverseerStateUpdate-72206603074142211-127.0.0.1:42365_solr-n_0000000000)
[n:127.0.0.1:42365_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":"http://127.0.0.1:42365/solr";,
[junit4] 2> "type":"NRT",
[junit4] 2> "waitForFinalState":"false"} current state version: 0
[junit4] 2> 300502 INFO
(OverseerStateUpdate-72206603074142211-127.0.0.1:42365_solr-n_0000000000)
[n:127.0.0.1:42365_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":"http://127.0.0.1:42365/solr";,
[junit4] 2> "type":"NRT",
[junit4] 2> "waitForFinalState":"false"}
[junit4] 2> 300503 DEBUG
(OverseerStateUpdate-72206603074142211-127.0.0.1:42365_solr-n_0000000000)
[n:127.0.0.1:42365_solr ] o.a.s.c.o.SliceMutator Old Slice: shard1:{
[junit4] 2> "range":"80000000-7fffffff",
[junit4] 2> "state":"active",
[junit4] 2> "replicas":{}}
[junit4] 2> 300503 DEBUG
(OverseerStateUpdate-72206603074142211-127.0.0.1:42365_solr-n_0000000000)
[n:127.0.0.1:42365_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":"http://127.0.0.1:42365/solr";,
[junit4] 2> "state":"down",
[junit4] 2> "node_name":null,
[junit4] 2> "type":"NRT"}}}
[junit4] 2> 300503 DEBUG
(OverseerStateUpdate-72206603074142211-127.0.0.1:42365_solr-n_0000000000)
[n:127.0.0.1:42365_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":"http://127.0.0.1:42365/solr";,
[junit4] 2> "type":"NRT",
[junit4] 2> "waitForFinalState":"false"} current state version: 0
[junit4] 2> 300503 INFO
(OverseerStateUpdate-72206603074142211-127.0.0.1:42365_solr-n_0000000000)
[n:127.0.0.1:42365_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":"http://127.0.0.1:42365/solr";,
[junit4] 2> "type":"NRT",
[junit4] 2> "waitForFinalState":"false"}
[junit4] 2> 300503 DEBUG
(OverseerStateUpdate-72206603074142211-127.0.0.1:42365_solr-n_0000000000)
[n:127.0.0.1:42365_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":"http://127.0.0.1:42365/solr";,
[junit4] 2> "state":"down",
[junit4] 2> "node_name":null,
[junit4] 2> "type":"NRT"}}}
[junit4] 2> 300503 DEBUG
(OverseerStateUpdate-72206603074142211-127.0.0.1:42365_solr-n_0000000000)
[n:127.0.0.1:42365_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":"http://127.0.0.1:42365/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":"http://127.0.0.1:42365/solr";,
[junit4] 2> "state":"down",
[junit4] 2> "node_name":null,
[junit4] 2> "type":"NRT"}}}
[junit4] 2> 300604 DEBUG
(OverseerStateUpdate-72206603074142211-127.0.0.1:42365_solr-n_0000000000)
[n:127.0.0.1:42365_solr ] o.a.s.c.o.ZkStateWriter going to update_collection
/collections/testNodeAdded/state.json version: 0
[junit4] 2> 300705 INFO (qtp512600927-2900) [n:127.0.0.1:42365_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> 300706 INFO (qtp512600927-2900) [n:127.0.0.1:42365_solr ]
o.a.s.c.TransientSolrCoreCacheDefault Allocating transient cache for 2147483647
transient cores
[junit4] 2> 300706 INFO (qtp512600927-2867) [n:127.0.0.1:42365_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> 300709 DEBUG
(OverseerStateUpdate-72206603074142211-127.0.0.1:42365_solr-n_0000000000)
[n:127.0.0.1:42365_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":"http://127.0.0.1:42365/solr";,
[junit4] 2> "node_name":"127.0.0.1:42365_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> 300709 DEBUG
(OverseerStateUpdate-72206603074142211-127.0.0.1:42365_solr-n_0000000000)
[n:127.0.0.1:42365_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":"http://127.0.0.1:42365/solr";,
[junit4] 2> "node_name":"127.0.0.1:42365_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> 300709 DEBUG
(OverseerStateUpdate-72206603074142211-127.0.0.1:42365_solr-n_0000000000)
[n:127.0.0.1:42365_solr ] o.a.s.c.o.ReplicaMutator Will update state for
replica:
core_node4:{"core":"testNodeAdded_shard1_replica_n2","base_url":"http://127.0.0.1:42365/solr","node_name":"127.0.0.1:42365_solr","state":"down","type":"NRT"}
[junit4] 2> 300709 DEBUG
(OverseerStateUpdate-72206603074142211-127.0.0.1:42365_solr-n_0000000000)
[n:127.0.0.1:42365_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":"http://127.0.0.1:42365/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":"http://127.0.0.1:42365/solr";,
[junit4] 2> "node_name":"127.0.0.1:42365_solr",
[junit4] 2> "state":"down",
[junit4] 2> "type":"NRT"}}}}}
[junit4] 2> 300709 DEBUG
(OverseerStateUpdate-72206603074142211-127.0.0.1:42365_solr-n_0000000000)
[n:127.0.0.1:42365_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":"http://127.0.0.1:42365/solr";,
[junit4] 2> "node_name":"127.0.0.1:42365_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> 300709 DEBUG
(OverseerStateUpdate-72206603074142211-127.0.0.1:42365_solr-n_0000000000)
[n:127.0.0.1:42365_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":"http://127.0.0.1:42365/solr";,
[junit4] 2> "node_name":"127.0.0.1:42365_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> 300709 DEBUG
(OverseerStateUpdate-72206603074142211-127.0.0.1:42365_solr-n_0000000000)
[n:127.0.0.1:42365_solr ] o.a.s.c.o.ReplicaMutator Will update state for
replica:
core_node3:{"core":"testNodeAdded_shard1_replica_n1","base_url":"http://127.0.0.1:42365/solr","node_name":"127.0.0.1:42365_solr","state":"down","type":"NRT"}
[junit4] 2> 300709 DEBUG
(OverseerStateUpdate-72206603074142211-127.0.0.1:42365_solr-n_0000000000)
[n:127.0.0.1:42365_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":"http://127.0.0.1:42365/solr";,
[junit4] 2> "node_name":"127.0.0.1:42365_solr",
[junit4] 2> "state":"down",
[junit4] 2> "type":"NRT"},
[junit4] 2> "core_node4":{
[junit4] 2> "core":"testNodeAdded_shard1_replica_n2",
[junit4] 2> "base_url":"http://127.0.0.1:42365/solr";,
[junit4] 2> "node_name":"127.0.0.1:42365_solr",
[junit4] 2> "state":"down",
[junit4] 2> "type":"NRT"}}}}}
[junit4] 2> 300810 DEBUG
(OverseerStateUpdate-72206603074142211-127.0.0.1:42365_solr-n_0000000000)
[n:127.0.0.1:42365_solr ] o.a.s.c.o.ZkStateWriter going to update_collection
/collections/testNodeAdded/state.json version: 1
[junit4] 2> 300810 INFO
(zkCallback-587-thread-1-processing-n:127.0.0.1:42365_solr)
[n:127.0.0.1:42365_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> 300810 INFO
(zkCallback-587-thread-2-processing-n:127.0.0.1:42365_solr)
[n:127.0.0.1:42365_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> 301384 DEBUG (ScheduledTrigger-1207-thread-2)
[n:127.0.0.1:42365_solr ] o.a.s.c.a.NodeAddedTrigger Running
NodeAddedTrigger node_added_trigger
[junit4] 2> 301384 DEBUG (ScheduledTrigger-1207-thread-2)
[n:127.0.0.1:42365_solr ] o.a.s.c.a.NodeAddedTrigger Found livenodes: 1
[junit4] 2> 301717 INFO (qtp512600927-2867) [n:127.0.0.1:42365_solr
c:testNodeAdded s:shard1 r:core_node4 x:testNodeAdded_shard1_replica_n2]
o.a.s.c.SolrConfig Using Lucene MatchVersion: 7.3.0
[junit4] 2> 301717 INFO (qtp512600927-2900) [n:127.0.0.1:42365_solr
c:testNodeAdded s:shard1 r:core_node3 x:testNodeAdded_shard1_replica_n1]
o.a.s.c.SolrConfig Using Lucene MatchVersion: 7.3.0
[junit4] 2> 301721 INFO (qtp512600927-2900) [n:127.0.0.1:42365_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> 301721 INFO (qtp512600927-2867) [n:127.0.0.1:42365_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> 301723 INFO (qtp512600927-2900) [n:127.0.0.1:42365_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> 301723 INFO (qtp512600927-2867) [n:127.0.0.1:42365_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> 301723 INFO (qtp512600927-2900) [n:127.0.0.1:42365_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> 301723 INFO (qtp512600927-2867) [n:127.0.0.1:42365_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> 301738 INFO (qtp512600927-2867) [n:127.0.0.1:42365_solr
c:testNodeAdded s:shard1 r:core_node4 x:testNodeAdded_shard1_replica_n2]
o.a.s.m.r.SolrJmxReporter JMX monitoring for
'solr_42365.solr.core.testNodeAdded.shard1.replica_n2' (registry
'solr.core.testNodeAdded.shard1.replica_n2') enabled at server:
com.sun.jmx.mbeanserver.JmxMBeanServer@40193ce4
[junit4] 2> 301738 INFO (qtp512600927-2900) [n:127.0.0.1:42365_solr
c:testNodeAdded s:shard1 r:core_node3 x:testNodeAdded_shard1_replica_n1]
o.a.s.m.r.SolrJmxReporter JMX monitoring for
'solr_42365.solr.core.testNodeAdded.shard1.replica_n1' (registry
'solr.core.testNodeAdded.shard1.replica_n1') enabled at server:
com.sun.jmx.mbeanserver.JmxMBeanServer@40193ce4
[junit4] 2> 301739 INFO (qtp512600927-2900) [n:127.0.0.1:42365_solr
c:testNodeAdded s:shard1 r:core_node3 x:testNodeAdded_shard1_replica_n1]
o.a.s.c.SolrCore solr.RecoveryStrategy.Builder
[junit4] 2> 301739 INFO (qtp512600927-2867) [n:127.0.0.1:42365_solr
c:testNodeAdded s:shard1 r:core_node4 x:testNodeAdded_shard1_replica_n2]
o.a.s.c.SolrCore solr.RecoveryStrategy.Builder
[junit4] 2> 301739 INFO (qtp512600927-2900) [n:127.0.0.1:42365_solr
c:testNodeAdded s:shard1 r:core_node3 x:testNodeAdded_shard1_replica_n1]
o.a.s.c.SolrCore [[testNodeAdded_shard1_replica_n1] ] Opening new SolrCore at
[/home/jenkins/workspace/Lucene-Solr-7.x-Linux/solr/build/solr-core/test/J1/temp/solr.cloud.autoscaling.ComputePlanActionTest_2517DF000B47CC7A-001/tempDir-001/node1/testNodeAdded_shard1_replica_n1],
dataDir=[/home/jenkins/workspace/Lucene-Solr-7.x-Linux/solr/build/solr-core/test/J1/temp/solr.cloud.autoscaling.ComputePlanActionTest_2517DF000B47CC7A-001/tempDir-001/node1/./testNodeAdded_shard1_replica_n1/data/]
[junit4] 2> 301739 INFO (qtp512600927-2867) [n:127.0.0.1:42365_solr
c:testNodeAdded s:shard1 r:core_node4 x:testNodeAdded_shard1_replica_n2]
o.a.s.c.SolrCore [[testNodeAdded_shard1_replica_n2] ] Opening new SolrCore at
[/home/jenkins/workspace/Lucene-Solr-7.x-Linux/solr/build/solr-core/test/J1/temp/solr.cloud.autoscaling.ComputePlanActionTest_2517DF000B47CC7A-001/tempDir-001/node1/testNodeAdded_shard1_replica_n2],
dataDir=[/home/jenkins/workspace/Lucene-Solr-7.x-Linux/solr/build/solr-core/test/J1/temp/solr.cloud.autoscaling.ComputePlanActionTest_2517DF000B47CC7A-001/tempDir-001/node1/./testNodeAdded_shard1_replica_n2/data/]
[junit4] 2> 301772 INFO (qtp512600927-2867) [n:127.0.0.1:42365_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> 301772 INFO (qtp512600927-2867) [n:127.0.0.1:42365_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> 301773 INFO (qtp512600927-2900) [n:127.0.0.1:42365_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> 301773 INFO (qtp512600927-2900) [n:127.0.0.1:42365_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> 301773 INFO (qtp512600927-2867) [n:127.0.0.1:42365_solr
c:testNodeAdded s:shard1 r:core_node4 x:testNodeAdded_shard1_replica_n2]
o.a.s.u.CommitTracker Hard AutoCommit: disabled
[junit4] 2> 301773 INFO (qtp512600927-2867) [n:127.0.0.1:42365_solr
c:testNodeAdded s:shard1 r:core_node4 x:testNodeAdded_shard1_replica_n2]
o.a.s.u.CommitTracker Soft AutoCommit: disabled
[junit4] 2> 301773 INFO (qtp512600927-2900) [n:127.0.0.1:42365_solr
c:testNodeAdded s:shard1 r:core_node3 x:testNodeAdded_shard1_replica_n1]
o.a.s.u.CommitTracker Hard AutoCommit: disabled
[junit4] 2> 301773 INFO (qtp512600927-2900) [n:127.0.0.1:42365_solr
c:testNodeAdded s:shard1 r:core_node3 x:testNodeAdded_shard1_replica_n1]
o.a.s.u.CommitTracker Soft AutoCommit: disabled
[junit4] 2> 301774 INFO (qtp512600927-2867) [n:127.0.0.1:42365_solr
c:testNodeAdded s:shard1 r:core_node4 x:testNodeAdded_shard1_replica_n2]
o.a.s.s.SolrIndexSearcher Opening
[Searcher@72d498e8[testNodeAdded_shard1_replica_n2] main]
[junit4] 2> 301774 INFO (qtp512600927-2900) [n:127.0.0.1:42365_solr
c:testNodeAdded s:shard1 r:core_node3 x:testNodeAdded_shard1_replica_n1]
o.a.s.s.SolrIndexSearcher Opening
[Searcher@3fb03c83[testNodeAdded_shard1_replica_n1] main]
[junit4] 2> 301775 INFO (qtp512600927-2867) [n:127.0.0.1:42365_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> 301775 INFO (qtp512600927-2900) [n:127.0.0.1:42365_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> 301775 INFO (qtp512600927-2867) [n:127.0.0.1:42365_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> 301775 INFO (qtp512600927-2900) [n:127.0.0.1:42365_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> 301776 INFO (qtp512600927-2867) [n:127.0.0.1:42365_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> 301776 INFO (qtp512600927-2900) [n:127.0.0.1:42365_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> 301776 INFO
(searcherExecutor-1213-thread-1-processing-n:127.0.0.1:42365_solr
x:testNodeAdded_shard1_replica_n2 s:shard1 c:testNodeAdded r:core_node4)
[n:127.0.0.1:42365_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@72d498e8[testNodeAdded_shard1_replica_n2]
main{ExitableDirectoryReader(UninvertingDirectoryReader())}
[junit4] 2> 301776 INFO
(searcherExecutor-1212-thread-1-processing-n:127.0.0.1:42365_solr
x:testNodeAdded_shard1_replica_n1 s:shard1 c:testNodeAdded r:core_node3)
[n:127.0.0.1:42365_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@3fb03c83[testNodeAdded_shard1_replica_n1]
main{ExitableDirectoryReader(UninvertingDirectoryReader())}
[junit4] 2> 301776 INFO (qtp512600927-2867) [n:127.0.0.1:42365_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 1593322282598531072
[junit4] 2> 301776 INFO (qtp512600927-2900) [n:127.0.0.1:42365_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 1593322282598531072
[junit4] 2> 301779 INFO (qtp512600927-2900) [n:127.0.0.1:42365_solr
c:testNodeAdded s:shard1 r:core_node3 x:testNodeAdded_shard1_replica_n1]
o.a.s.c.ZkShardTerms Failed to save terms, version is not match, retrying
[junit4] 2> 301781 INFO (qtp512600927-2867) [n:127.0.0.1:42365_solr
c:testNodeAdded s:shard1 r:core_node4 x:testNodeAdded_shard1_replica_n2]
o.a.s.c.ShardLeaderElectionContext Enough replicas found to continue.
[junit4] 2> 301781 INFO (qtp512600927-2867) [n:127.0.0.1:42365_solr
c:testNodeAdded s:shard1 r:core_node4 x:testNodeAdded_shard1_replica_n2]
o.a.s.c.ShardLeaderElectionContext I may be the new leader - try and sync
[junit4] 2> 301781 INFO (qtp512600927-2867) [n:127.0.0.1:42365_solr
c:testNodeAdded s:shard1 r:core_node4 x:testNodeAdded_shard1_replica_n2]
o.a.s.c.SyncStrategy Sync replicas to
http://127.0.0.1:42365/solr/testNodeAdded_shard1_replica_n2/
[junit4] 2> 301781 DEBUG
(OverseerStateUpdate-72206603074142211-127.0.0.1:42365_solr-n_0000000000)
[n:127.0.0.1:42365_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> 301781 INFO (qtp512600927-2867) [n:127.0.0.1:42365_solr
c:testNodeAdded s:shard1 r:core_node4 x:testNodeAdded_shard1_replica_n2]
o.a.s.u.PeerSync PeerSync: core=testNodeAdded_shard1_replica_n2
url=http://127.0.0.1:42365/solr START
replicas=[http://127.0.0.1:42365/solr/testNodeAdded_shard1_replica_n1/]
nUpdates=100
[junit4] 2> 301782 INFO (qtp512600927-2862) [n:127.0.0.1:42365_solr
c:testNodeAdded s:shard1 r:core_node3 x:testNodeAdded_shard1_replica_n1]
o.a.s.c.S.Request [testNodeAdded_shard1_replica_n1] webapp=/solr path=/get
params={distrib=false&qt=/get&fingerprint=false&getVersions=100&wt=javabin&version=2}
status=0 QTime=0
[junit4] 2> 301882 DEBUG
(OverseerStateUpdate-72206603074142211-127.0.0.1:42365_solr-n_0000000000)
[n:127.0.0.1:42365_solr ] o.a.s.c.o.ZkStateWriter going to update_collection
/collections/testNodeAdded/state.json version: 2
[junit4] 2> 301882 INFO
(zkCallback-587-thread-2-processing-n:127.0.0.1:42365_solr)
[n:127.0.0.1:42365_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> 301882 INFO
(zkCallback-587-thread-1-processing-n:127.0.0.1:42365_solr)
[n:127.0.0.1:42365_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> 302081 INFO (qtp512600927-2867) [n:127.0.0.1:42365_solr
c:testNodeAdded s:shard1 r:core_node4 x:testNodeAdded_shard1_replica_n2]
o.a.s.u.PeerSync PeerSync: core=testNodeAdded_shard1_replica_n2
url=http://127.0.0.1:42365/solr DONE. We have no versions. sync failed.
[junit4] 2> 302081 INFO (qtp512600927-2867) [n:127.0.0.1:42365_solr
c:testNodeAdded s:shard1 r:core_node4 x:testNodeAdded_shard1_replica_n2]
o.a.s.c.SyncStrategy Leader's attempt to sync with shard failed, moving to the
next candidate
[junit4] 2> 302081 INFO (qtp512600927-2867) [n:127.0.0.1:42365_solr
c:testNodeAdded s:shard1 r:core_node4 x:testNodeAdded_shard1_replica_n2]
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> 302081 INFO (qtp512600927-2867) [n:127.0.0.1:42365_solr
c:testNodeAdded s:shard1 r:core_node4 x:testNodeAdded_shard1_replica_n2]
o.a.s.c.ShardLeaderElectionContext Found all replicas participating in
election, clear LIR
[junit4] 2> 302086 INFO (qtp512600927-2867) [n:127.0.0.1:42365_solr
c:testNodeAdded s:shard1 r:core_node4 x:testNodeAdded_shard1_replica_n2]
o.a.s.c.ShardLeaderElectionContext I am the new leader:
http://127.0.0.1:42365/solr/testNodeAdded_shard1_replica_n2/ shard1
[junit4] 2> 302086 DEBUG
(OverseerStateUpdate-72206603074142211-127.0.0.1:42365_solr-n_0000000000)
[n:127.0.0.1:42365_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":"http://127.0.0.1:42365/solr";,
[junit4] 2> "core":"testNodeAdded_shard1_replica_n2",
[junit4] 2> "state":"active"} current state version: 0
[junit4] 2> 302187 DEBUG
(OverseerStateUpdate-72206603074142211-127.0.0.1:42365_solr-n_0000000000)
[n:127.0.0.1:42365_solr ] o.a.s.c.o.ZkStateWriter going to update_collection
/collections/testNodeAdded/state.json version: 3
[junit4] 2> 302187 INFO
(zkCallback-587-thread-2-processing-n:127.0.0.1:42365_solr)
[n:127.0.0.1:42365_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> 302187 INFO
(zkCallback-587-thread-1-processing-n:127.0.0.1:42365_solr)
[n:127.0.0.1:42365_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> 302237 INFO (qtp512600927-2867) [n:127.0.0.1:42365_solr
c:testNodeAdded s:shard1 r:core_node4 x:testNodeAdded_shard1_replica_n2]
o.a.s.c.ZkController I am the leader, no recovery necessary
[junit4] 2> 302238 DEBUG
(OverseerStateUpdate-72206603074142211-127.0.0.1:42365_solr-n_0000000000)
[n:127.0.0.1:42365_solr ] o.a.s.c.Overseer processMessage: queueSize: 1,
message = {
[junit4] 2> "core":"testNodeAdded_shard1_replica_n2",
[junit4] 2> "core_node_name":"core_node4",
[junit4] 2> "roles":null,
[junit4] 2> "base_url":"http://127.0.0.1:42365/solr";,
[junit4] 2> "node_name":"127.0.0.1:42365_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> 302238 DEBUG
(OverseerStateUpdate-72206603074142211-127.0.0.1:42365_solr-n_0000000000)
[n:127.0.0.1:42365_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":"http://127.0.0.1:42365/solr";,
[junit4] 2> "node_name":"127.0.0.1:42365_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> 302238 DEBUG
(OverseerStateUpdate-72206603074142211-127.0.0.1:42365_solr-n_0000000000)
[n:127.0.0.1:42365_solr ] o.a.s.c.o.ReplicaMutator Will update state for
replica:
core_node4:{"core":"testNodeAdded_shard1_replica_n2","base_url":"http://127.0.0.1:42365/solr","node_name":"127.0.0.1:42365_solr","state":"active","type":"NRT","leader":"true"}
[junit4] 2> 302238 DEBUG
(OverseerStateUpdate-72206603074142211-127.0.0.1:42365_solr-n_0000000000)
[n:127.0.0.1:42365_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":"http://127.0.0.1:42365/solr";,
[junit4] 2> "node_name":"127.0.0.1:42365_solr",
[junit4] 2> "state":"down",
[junit4] 2> "type":"NRT"},
[junit4] 2> "core_node4":{
[junit4] 2> "core":"testNodeAdded_shard1_replica_n2",
[junit4] 2> "base_url":"http://127.0.0.1:42365/solr";,
[junit4] 2> "node_name":"127.0.0.1:42365_solr",
[junit4] 2> "state":"active",
[junit4] 2> "type":"NRT",
[junit4] 2> "leader":"true"}}}}}
[junit4] 2> 302339 DEBUG
(OverseerStateUpdate-72206603074142211-127.0.0.1:42365_solr-n_0000000000)
[n:127.0.0.1:42365_solr ] o.a.s.c.o.ZkStateWriter going to update_collection
/collections/testNodeAdded/state.json version: 4
[junit4] 2> 302339 INFO
(zkCallback-587-thread-1-processing-n:127.0.0.1:42365_solr)
[n:127.0.0.1:42365_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> 302339 INFO
(zkCallback-587-thread-2-processing-n:127.0.0.1:42365_solr)
[n:127.0.0.1:42365_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> 302385 DEBUG (ScheduledTrigger-1207-thread-2)
[n:127.0.0.1:42365_solr ] o.a.s.c.a.NodeAddedTrigger Running
NodeAddedTrigger node_added_trigger
[junit4] 2> 302385 DEBUG (ScheduledTrigger-1207-thread-2)
[n:127.0.0.1:42365_solr ] o.a.s.c.a.NodeAddedTrigger Found livenodes: 1
[junit4] 2> 302737 INFO (qtp512600927-2867) [n:127.0.0.1:42365_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=2030
[junit4] 2> 302782 DEBUG
(OverseerStateUpdate-72206603074142211-127.0.0.1:42365_solr-n_0000000000)
[n:127.0.0.1:42365_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":"http://127.0.0.1:42365/solr";,
[junit4] 2> "node_name":"127.0.0.1:42365_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> 302782 DEBUG
(OverseerStateUpdate-72206603074142211-127.0.0.1:42365_solr-n_0000000000)
[n:127.0.0.1:42365_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":"http://127.0.0.1:42365/solr";,
[junit4] 2> "node_name":"127.0.0.1:42365_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> 302782 DEBUG
(OverseerStateUpdate-72206603074142211-127.0.0.1:42365_solr-n_0000000000)
[n:127.0.0.1:42365_solr ] o.a.s.c.o.ReplicaMutator Will update state for
replica:
core_node3:{"core":"testNodeAdded_shard1_replica_n1","base_url":"http://127.0.0.1:42365/solr","node_name":"127.0.0.1:42365_solr","state":"active","type":"NRT"}
[junit4] 2> 302782 DEBUG
(OverseerStateUpdate-72206603074142211-127.0.0.1:42365_solr-n_0000000000)
[n:127.0.0.1:42365_solr ] o.a.s.c.o.ReplicaMutator Collection is now:
DocCollection(testNodeAdded//collections/testNodeAdded/state.json/5)={
[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":"http://127.0.0.1:42365/solr";,
[junit4] 2> "node_name":"127.0.0.1:42365_solr",
[junit4] 2> "state":"active",
[junit4] 2> "type":"NRT"},
[junit4] 2> "core_node4":{
[junit4] 2> "core":"testNodeAdded_shard1_replica_n2",
[junit4] 2> "base_url":"http://127.0.0.1:42365/solr";,
[junit4] 2> "node_name":"127.0.0.1:42365_solr",
[junit4] 2> "state":"active",
[junit4] 2> "type":"NRT",
[junit4] 2> "leader":"true"}}}}}
[junit4] 2> 302783 INFO (qtp512600927-2900) [n:127.0.0.1:42365_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=2077
[junit4] 2> 302785 INFO (qtp512600927-2898) [n:127.0.0.1:42365_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> 302883 DEBUG
(OverseerStateUpdate-72206603074142211-127.0.0.1:42365_solr-n_0000000000)
[n:127.0.0.1:42365_solr ] o.a.s.c.o.ZkStateWriter going to update_collection
/collections/testNodeAdded/state.json version: 5
[junit4] 2> 302883 INFO
(zkCallback-587-thread-2-processing-n:127.0.0.1:42365_solr)
[n:127.0.0.1:42365_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> 302883 INFO
(zkCallback-587-thread-1-processing-n:127.0.0.1:42365_solr)
[n:127.0.0.1:42365_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> 303385 DEBUG (ScheduledTrigger-1207-thread-2)
[n:127.0.0.1:42365_solr ] o.a.s.c.a.NodeAddedTrigger Running
NodeAddedTrigger node_added_trigger
[junit4] 2> 303385 DEBUG (ScheduledTrigger-1207-thread-2)
[n:127.0.0.1:42365_solr ] o.a.s.c.a.NodeAddedTrigger Found livenodes: 1
[junit4] 2> 303785 INFO (qtp512600927-2898) [n:127.0.0.1:42365_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=3400
[junit4] 2> 303792 INFO (qtp512600927-2868) [n:127.0.0.1:42365_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=1
[junit4] 2> 303795 INFO (qtp512600927-2900) [n:127.0.0.1:42365_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> 303797 DEBUG (qtp512600927-2866) [n:127.0.0.1:42365_solr ]
o.a.s.c.a.AutoScalingHandler Verified autoscaling configuration
[junit4] 2> 303798 INFO (qtp512600927-2866) [n:127.0.0.1:42365_solr ]
o.a.s.s.HttpSolrCall [admin] webapp=null path=/cluster/autoscaling
params={wt=javabin&version=2} status=0 QTime=10
[junit4] 2> 303798 DEBUG
(zkCallback-587-thread-1-processing-n:127.0.0.1:42365_solr)
[n:127.0.0.1:42365_solr ] o.a.s.c.a.OverseerTriggerThread Refreshing
/autoscaling.json with znode version 7
[junit4] 2> 303798 DEBUG
(zkCallback-587-thread-1-processing-n:127.0.0.1:42365_solr)
[n:127.0.0.1:42365_solr ] o.a.s.c.a.NodeAddedTrigger Initial livenodes:
[127.0.0.1:42365_solr]
[junit4] 2> 303798 DEBUG
(zkCallback-587-thread-1-processing-n:127.0.0.1:42365_solr)
[n:127.0.0.1:42365_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> 303799 DEBUG
(OverseerAutoScalingTriggerThread-72206603074142211-127.0.0.1:42365_solr-n_0000000000)
[n:127.0.0.1:42365_solr ] o.a.s.c.a.OverseerTriggerThread Processed trigger
updates upto znodeVersion 7
[junit4] 2> 303799 INFO
(TEST-ComputePlanActionTest.testNodeAdded-seed#[2517DF000B47CC7A]) [ ]
o.e.j.s.Server jetty-9.4.8.v20171121, build timestamp:
2017-11-21T23:27:37+02:00, git hash: 82b8fb23f757335bb3329d540ce37a2a2615f0a8
[junit4] 2> 303799 DEBUG
(OverseerAutoScalingTriggerThread-72206603074142211-127.0.0.1:42365_solr-n_0000000000)
[n:127.0.0.1:42365_solr ] o.a.s.c.a.OverseerTriggerThread -- clean old
nodeLost markers
[junit4] 2> 303799 DEBUG
(OverseerAutoScalingTriggerThread-72206603074142211-127.0.0.1:42365_solr-n_0000000000)
[n:127.0.0.1:42365_solr ] o.a.s.c.a.OverseerTriggerThread Current
znodeVersion 7, lastZnodeVersion 7
[junit4] 2> 303799 INFO
(TEST-ComputePlanActionTest.testNodeAdded-seed#[2517DF000B47CC7A]) [ ]
o.e.j.s.session DefaultSessionIdManager workerName=node0
[junit4] 2> 303799 INFO
(TEST-ComputePlanActionTest.testNodeAdded-seed#[2517DF000B47CC7A]) [ ]
o.e.j.s.session No SessionScavenger set, using defaults
[junit4] 2> 303799 INFO
(TEST-ComputePlanActionTest.testNodeAdded-seed#[2517DF000B47CC7A]) [ ]
o.e.j.s.session Scavenging every 600000ms
[junit4] 2> 303800 INFO
(TEST-ComputePlanActionTest.testNodeAdded-seed#[2517DF000B47CC7A]) [ ]
o.e.j.s.h.ContextHandler Started
o.e.j.s.ServletContextHandler@3f727757{/solr,null,AVAILABLE}
[junit4] 2> 303800 INFO
(TEST-ComputePlanActionTest.testNodeAdded-seed#[2517DF000B47CC7A]) [ ]
o.e.j.s.AbstractConnector Started
ServerConnector@1a10d382{HTTP/1.1,[http/1.1]}{127.0.0.1:44583}
[junit4] 2> 303800 INFO
(TEST-ComputePlanActionTest.testNodeAdded-seed#[2517DF000B47CC7A]) [ ]
o.e.j.s.Server Started @305534ms
[junit4] 2> 303800 INFO
(TEST-ComputePlanActionTest.testNodeAdded-seed#[2517DF000B47CC7A]) [ ]
o.a.s.c.s.e.JettySolrRunner Jetty properties: {hostContext=/solr,
hostPort=44583}
[junit4] 2> 303800 ERROR
(TEST-ComputePlanActionTest.testNodeAdded-seed#[2517DF000B47CC7A]) [ ]
o.a.s.u.StartupLoggingUtils Missing Java Option solr.log.dir. Logging may be
missing or incomplete.
[junit4] 2> 303801 INFO
(TEST-ComputePlanActionTest.testNodeAdded-seed#[2517DF000B47CC7A]) [ ]
o.a.s.s.SolrDispatchFilter ___ _ Welcome to Apache Solr™ version
7.3.0
[junit4] 2> 303801 INFO
(TEST-ComputePlanActionTest.testNodeAdded-seed#[2517DF000B47CC7A]) [ ]
o.a.s.s.SolrDispatchFilter / __| ___| |_ _ Starting in cloud mode on port null
[junit4] 2> 303801 INFO
(TEST-ComputePlanActionTest.testNodeAdded-seed#[2517DF000B47CC7A]) [ ]
o.a.s.s.SolrDispatchFilter \__ \/ _ \ | '_| Install dir: null
[junit4] 2> 303801 INFO
(TEST-ComputePlanActionTest.testNodeAdded-seed#[2517DF000B47CC7A]) [ ]
o.a.s.s.SolrDispatchFilter |___/\___/_|_| Start time:
2018-02-24T22:15:40.697Z
[junit4] 2> 303802 INFO (zkConnectionManagerCallback-599-thread-1) [ ]
o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 303802 INFO
(TEST-ComputePlanActionTest.testNodeAdded-seed#[2517DF000B47CC7A]) [ ]
o.a.s.s.SolrDispatchFilter solr.xml found in ZooKeeper. Loading...
[junit4] 2> 303808 INFO
(TEST-ComputePlanActionTest.testNodeAdded-seed#[2517DF000B47CC7A]) [ ]
o.a.s.c.ZkContainer Zookeeper client=127.0.0.1:36953/solr
[junit4] 2> 303809 INFO (zkConnectionManagerCallback-603-thread-1) [ ]
o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 303811 INFO
(zkConnectionManagerCallback-605-thread-1-processing-n:127.0.0.1:44583_solr)
[n:127.0.0.1:44583_solr ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 303813 INFO
(TEST-ComputePlanActionTest.testNodeAdded-seed#[2517DF000B47CC7A])
[n:127.0.0.1:44583_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from
ZooKeeper... (0) -> (1)
[junit4] 2> 303814 INFO
(TEST-ComputePlanActionTest.testNodeAdded-seed#[2517DF000B47CC7A])
[n:127.0.0.1:44583_solr ] o.a.s.c.Overseer Overseer (id=null) closing
[junit4] 2> 303814 INFO
(TEST-ComputePlanActionTest.testNodeAdded-seed#[2517DF000B47CC7A])
[n:127.0.0.1:44583_solr ] o.a.s.c.ZkController Register node as live in
ZooKeeper:/live_nodes/127.0.0.1:44583_solr
[junit4] 2> 303814 DEBUG
(OverseerStateUpdate-72206603074142211-127.0.0.1:42365_solr-n_0000000000)
[n:127.0.0.1:42365_solr ] o.a.s.c.Overseer processMessage: queueSize: 1,
message = {
[junit4] 2> "operation":"downnode",
[junit4] 2> "node_name":"127.0.0.1:44583_solr"} current state version: 0
[junit4] 2> 303814 DEBUG
(OverseerStateUpdate-72206603074142211-127.0.0.1:42365_solr-n_0000000000)
[n:127.0.0.1:42365_solr ] o.a.s.c.o.NodeMutator DownNode state invoked for
node: 127.0.0.1:44583_solr
[junit4] 2> 303815 INFO
(zkCallback-587-thread-1-processing-n:127.0.0.1:42365_solr)
[n:127.0.0.1:42365_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from
ZooKeeper... (1) -> (2)
[junit4] 2> 303815 INFO (zkCallback-595-thread-2) [ ]
o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (1) -> (2)
[junit4] 2> 303815 INFO (zkCallback-595-thread-1) [ ]
o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (1) -> (2)
[junit4] 2> 303815 INFO
(zkCallback-604-thread-1-processing-n:127.0.0.1:44583_solr)
[n:127.0.0.1:44583_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from
ZooKeeper... (1) -> (2)
[junit4] 2> 303851 INFO
(TEST-ComputePlanActionTest.testNodeAdded-seed#[2517DF000B47CC7A])
[n:127.0.0.1:44583_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for
'solr_44583.solr.node' (registry 'solr.node') enabled at server:
com.sun.jmx.mbeanserver.JmxMBeanServer@40193ce4
[junit4] 2> 303857 INFO
(TEST-ComputePlanActionTest.testNodeAdded-seed#[2517DF000B47CC7A])
[n:127.0.0.1:44583_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for
'solr_44583.solr.jvm' (registry 'solr.jvm') enabled at server:
com.sun.jmx.mbeanserver.JmxMBeanServer@40193ce4
[junit4] 2> 303857 INFO
(TEST-ComputePlanActionTest.testNodeAdded-seed#[2517DF000B47CC7A])
[n:127.0.0.1:44583_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for
'solr_44583.solr.jetty' (registry 'solr.jetty') enabled at server:
com.sun.jmx.mbeanserver.JmxMBeanServer@40193ce4
[junit4] 2> 303858 INFO
(TEST-ComputePlanActionTest.testNodeAdded-seed#[2517DF000B47CC7A])
[n:127.0.0.1:44583_solr ] o.a.s.c.CorePropertiesLocator Found 0 core
definitions underneath
/home/jenkins/workspace/Lucene-Solr-7.x-Linux/solr/build/solr-core/test/J1/temp/solr.cloud.autoscaling.ComputePlanActionTest_2517DF000B47CC7A-001/tempDir-001/node2/.
[junit4] 2> 304385 DEBUG (ScheduledTrigger-1207-thread-2)
[n:127.0.0.1:42365_solr ] o.a.s.c.a.NodeAddedTrigger Running
NodeAddedTrigger node_added_trigger
[junit4] 2> 304385 DEBUG (ScheduledTrigger-1207-thread-2)
[n:127.0.0.1:42365_solr ] o.a.s.c.a.NodeAddedTrigger Found livenodes: 2
[junit4] 2> 304385 DEBUG (ScheduledTrigger-1207-thread-2)
[n:127.0.0.1:42365_solr ] o.a.s.c.a.NodeAddedTrigger Tracking new node:
127.0.0.1:44583_solr at time 2273701719205810
[junit4] 2> 304388 INFO
(OverseerCollectionConfigSetProcessor-72206603074142211-127.0.0.1:42365_solr-n_0000000000)
[n:127.0.0.1:42365_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> 305386 DEBUG (ScheduledTrigger-1207-thread-2)
[n:127.0.0.1:42365_solr ] o.a.s.c.a.NodeAddedTrigger Running
NodeAddedTrigger node_added_trigger
[junit4] 2> 305386 DEBUG (ScheduledTrigger-1207-thread-2)
[n:127.0.0.1:42365_solr ] o.a.s.c.a.NodeAddedTrigger Found livenodes: 2
[junit4] 2> 305387 DEBUG (ScheduledTrigger-1207-thread-2)
[n:127.0.0.1:42365_solr ] o.a.s.c.a.NodeAddedTrigger NodeAddedTrigger
node_added_trigger firing registered processor for nodes:
[127.0.0.1:44583_solr] added at times [2273701719205810], now=2273702720466880
[junit4] 2> 305387 DEBUG (ScheduledTrigger-1207-thread-2)
[n:127.0.0.1:42365_solr ] o.a.s.c.a.ScheduledTriggers ++++++++ Cooldown
inactive - processing event: {
[junit4] 2> "id":"813eb6f4c67b2T44wsk2vv3cjo7iar6zyyfnsw9",
[junit4] 2> "source":"node_added_trigger",
[junit4] 2> "eventTime":2273701719205810,
[junit4] 2> "eventType":"NODEADDED",
[junit4] 2> "properties":{
[junit4] 2> "eventTimes":[2273701719205810],
[junit4] 2> "nodeNames":["127.0.0.1:44583_solr"]}}
[junit4] 2> 305387 DEBUG (ScheduledTrigger-1207-thread-2)
[n:127.0.0.1:42365_solr ] o.a.s.c.a.ScheduledTriggers Pausing all triggers:
[node_added_trigger]
[junit4] 2> 305388 INFO (ScheduledTrigger-1207-thread-2)
[n:127.0.0.1:42365_solr ] o.a.s.c.a.SystemLogListener Collection .system
does not exist, disabling logging.
[junit4] 2> 305388 DEBUG
(AutoscalingActionExecutor-1208-thread-1-processing-n:127.0.0.1:42365_solr)
[n:127.0.0.1:42365_solr ] o.a.s.c.a.ScheduledTriggers -- processing actions
for {
[junit4] 2> "id":"813eb6f4c67b2T44wsk2vv3cjo7iar6zyyfnsw9",
[junit4] 2> "source":"node_added_trigger",
[junit4] 2> "eventTime":2273701719205810,
[junit4] 2> "eventType":"NODEADDED",
[junit4] 2> "properties":{
[junit4] 2> "eventTimes":[2273701719205810],
[junit4] 2> "_enqueue_time_":2273702720913682,
[junit4] 2> "nodeNames":["127.0.0.1:44583_solr"]}}
[junit4] 2> 305388 DEBUG
(AutoscalingActionExecutor-1208-thread-1-processing-n:127.0.0.1:42365_solr)
[n:127.0.0.1:42365_solr ] o.a.s.c.a.ComputePlanAction -- processing event: {
[junit4] 2> "id":"813eb6f4c67b2T44wsk2vv3cjo7iar6zyyfnsw9",
[junit4] 2> "source":"node_added_trigger",
[junit4] 2> "eventTime":2273701719205810,
[junit4] 2> "eventType":"NODEADDED",
[junit4] 2> "properties":{
[junit4] 2> "eventTimes":[2273701719205810],
[junit4] 2> "_enqueue_time_":2273702720913682,
[junit4] 2> "nodeNames":["127.0.0.1:44583_solr"]}} with context
properties: {BEFORE_ACTION=[compute_plan]}
[junit4] 2> 305390 INFO (qtp512600927-2868) [n:127.0.0.1:42365_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> 305392 INFO (qtp512600927-2866) [n:127.0.0.1:42365_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> 305393 INFO (qtp374328738-2919) [n:127.0.0.1:44583_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> 305395 INFO
(AutoscalingActionExecutor-1208-thread-1-processing-n:127.0.0.1:42365_solr)
[n:127.0.0.1:42365_solr ] o.a.s.c.a.ComputePlanAction Computed Plan:
action=MOVEREPLICA&collection=testNodeAdded&targetNode=127.0.0.1:44583_solr&inPlaceMove=true&replica=core_node3
[junit4] 2> 305395 INFO
(AutoscalingActionExecutor-1208-thread-1-processing-n:127.0.0.1:42365_solr)
[n:127.0.0.1:42365_solr ] o.a.s.c.s.c.a.PolicyHelper returnSession,
curr-time 2273702729 sessionWrapper.createTime 2273702727278666,
this.sessionWrapper.createTime 2273702727278666
[junit4] 2> 305396 DEBUG
(TEST-ComputePlanActionTest.testNodeAdded-seed#[2517DF000B47CC7A]) [ ]
o.a.s.c.a.ComputePlanActionTest -------------_ FINAL STATE --------------
[junit4] 2> 305397 DEBUG
(AutoscalingActionExecutor-1208-thread-1-processing-n:127.0.0.1:42365_solr)
[n:127.0.0.1:42365_solr ] o.a.s.c.a.ScheduledTriggers Resuming trigger:
node_added_trigger after 5000ms
[junit4] 2> 305397 DEBUG
(AutoscalingActionExecutor-1208-thread-1-processing-n:127.0.0.1:42365_solr)
[n:127.0.0.1:42365_solr ] o.a.s.c.a.ScheduledTriggers -- processing took 8
ms for event id=813eb6f4c67b2T44wsk2vv3cjo7iar6zyyfnsw9
[junit4] 2> 305398 INFO (qtp512600927-2868) [n:127.0.0.1:42365_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> 305398 DEBUG
(TEST-ComputePlanActionTest.testNodeAdded-seed#[2517DF000B47CC7A]) [ ]
o.a.s.c.a.ComputePlanActionTest * Node values: 127.0.0.1:42365_solr
[junit4] 2> {
[junit4] 2> "node":"127.0.0.1:42365_solr",
[junit4] 2> "cores":2,
[junit4] 2> "port":"42365",
[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":217.19066619873047}
[junit4] 2> 305399 INFO (qtp374328738-2923) [n:127.0.0.1:44583_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> 305399 DEBUG
(TEST-ComputePlanActionTest.testNodeAdded-seed#[2517DF000B47CC7A]) [ ]
o.a.s.c.a.ComputePlanActionTest * Node values: 127.0.0.1:44583_solr
[junit4] 2> {
[junit4] 2> "node":"127.0.0.1:44583_solr",
[junit4] 2> "cores":0,
[junit4] 2> "port":"44583",
[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":217.19066619873047}
[junit4] 2> 305399 DEBUG
(TEST-ComputePlanActionTest.testNodeAdded-seed#[2517DF000B47CC7A]) [ ]
o.a.s.c.a.ComputePlanActionTest * Live nodes: [127.0.0.1:42365_solr,
127.0.0.1:44583_solr]
[junit4] 2> 305399 DEBUG
(TEST-ComputePlanActionTest.testNodeAdded-seed#[2517DF000B47CC7A]) [ ]
o.a.s.c.a.ComputePlanActionTest * Collection testNodeAdded state:
DocCollection(testNodeAdded//collections/testNodeAdded/state.json/6)={
[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":"http://127.0.0.1:42365/solr";,
[junit4] 2> "node_name":"127.0.0.1:42365_solr",
[junit4] 2> "state":"active",
[junit4] 2> "type":"NRT"},
[junit4] 2> "core_node4":{
[junit4] 2> "core":"testNodeAdded_shard1_replica_n2",
[junit4] 2> "base_url":"http://127.0.0.1:42365/solr";,
[junit4] 2> "node_name":"127.0.0.1:42365_solr",
[junit4] 2> "state":"active",
[junit4] 2> "type":"NRT",
[junit4] 2> "leader":"true"}}}},
[junit4] 2> "router":{"name":"compositeId"},
[junit4] 2> "maxShardsPerNode":"1",
[junit4] 2> "autoAddReplicas":"false",
[junit4] 2> "nrtReplicas":"2",
[junit4] 2> "tlogReplicas":"0"}
[junit4] 2> 305399 INFO
(TEST-ComputePlanActionTest.testNodeAdded-seed#[2517DF000B47CC7A]) [ ]
o.a.s.SolrTestCaseJ4 ###Ending testNodeAdded
[junit4] 2> 305411 INFO
(TEST-ComputePlanActionTest.testNodeWithMultipleReplicasLost-seed#[2517DF000B47CC7A])
[ ] o.a.s.SolrTestCaseJ4 ###Starting testNodeWithMultipleReplicasLost
[junit4] 2> 305412 DEBUG
(zkCallback-587-thread-1-processing-n:127.0.0.1:42365_solr)
[n:127.0.0.1:42365_solr ] o.a.s.c.a.OverseerTriggerThread Refreshing
/autoscaling.json with znode version 8
[junit4] 2> 305412 DEBUG
(OverseerAutoScalingTriggerThread-72206603074142211-127.0.0.1:42365_solr-n_0000000000)
[n:127.0.0.1:42365_solr ] o.a.s.c.a.OverseerTriggerThread Processed trigger
updates upto znodeVersion 8
[junit4] 2> 305412 INFO
(TEST-ComputePlanActionTest.testNodeWithMultipleReplicasLost-seed#[2517DF000B47CC7A])
[ ] o.e.j.s.AbstractConnector Stopped
ServerConnector@78af42d8{HTTP/1.1,[http/1.1]}{127.0.0.1:0}
[junit4] 2> 305413 INFO
(TEST-ComputePlanActionTest.testNodeWithMultipleReplicasLost-seed#[2517DF000B47CC7A])
[ ] o.a.s.c.CoreContainer Shutting down CoreContainer instance=1024288738
[junit4] 2> 305413 DEBUG
(OverseerAutoScalingTriggerThread-72206603074142211-127.0.0.1:42365_solr-n_0000000000)
[n:127.0.0.1:42365_solr ] o.a.s.c.a.OverseerTriggerThread -- clean old
nodeLost markers
[junit4] 2> 305413 INFO
(TEST-ComputePlanActionTest.testNodeWithMultipleReplicasLost-seed#[2517DF000B47CC7A])
[ ] o.a.s.m.SolrMetricManager Closing metric reporters for
registry=solr.node, tag=null
[junit4] 2> 305413 INFO
(TEST-ComputePlanActionTest.testNodeWithMultipleReplicasLost-seed#[2517DF000B47CC7A])
[ ] o.a.s.m.r.SolrJmxReporter Closing reporter
[org.apache.solr.metrics.reporters.SolrJmxReporter@428977ae: rootName =
solr_42365, domain = solr.node, service url = null, agent id = null] for
registry solr.node / com.codahale.metrics.MetricRegistry@fa2a440
[junit4] 2> 305413 DEBUG
(OverseerAutoScalingTriggerThread-72206603074142211-127.0.0.1:42365_solr-n_0000000000)
[n:127.0.0.1:42365_solr ] o.a.s.c.a.OverseerTriggerThread -- clean old
nodeAdded markers
[junit4] 2> 305413 DEBUG
(OverseerAutoScalingTriggerThread-72206603074142211-127.0.0.1:42365_solr-n_0000000000)
[n:127.0.0.1:42365_solr ] o.a.s.c.a.OverseerTriggerThread Current
znodeVersion 8, lastZnodeVersion 8
[junit4] 2> 305417 INFO
(TEST-ComputePlanActionTest.testNodeWithMultipleReplicasLost-seed#[2517DF000B47CC7A])
[ ] o.a.s.m.SolrMetricManager Closing metric reporters for
registry=solr.jvm, tag=null
[junit4] 2> 305417 INFO
(TEST-ComputePlanActionTest.testNodeWithMultipleReplicasLost-seed#[2517DF000B47CC7A])
[ ] o.a.s.m.r.SolrJmxReporter Closing reporter
[org.apache.solr.metrics.reporters.SolrJmxReporter@3dc676b9: rootName =
solr_42365, domain = solr.jvm, service url = null, agent id = null] for
registry solr.jvm / com.codahale.metrics.MetricRegistry@8dc7c9
[junit4] 2> 305420 INFO
(TEST-ComputePlanActionTest.testNodeWithMultipleReplicasLost-seed#[2517DF000B47CC7A])
[ ] o.a.s.m.SolrMetricManager Closing metric reporters for
registry=solr.jetty, tag=null
[junit4] 2> 305420 INFO
(TEST-ComputePlanActionTest.testNodeWithMultipleReplicasLost-seed#[2517DF000B47CC7A])
[ ] o.a.s.m.r.SolrJmxReporter Closing reporter
[org.apache.solr.metrics.reporters.SolrJmxReporter@2a50d915: rootName =
solr_42365, domain = solr.jetty, service url = null, agent id = null] for
registry solr.jetty / com.codahale.metrics.MetricRegistry@3c5f04cc
[junit4] 2> 305421 INFO
(TEST-ComputePlanActionTest.testNodeWithMultipleReplicasLost-seed#[2517DF000B47CC7A])
[ ] o.a.s.c.ZkController Remove node as live in
ZooKeeper:/live_nodes/127.0.0.1:42365_solr
[junit4] 2> 305421 DEBUG
(OverseerStateUpdate-72206603074142211-127.0.0.1:42365_solr-n_0000000000)
[n:127.0.0.1:42365_solr ] o.a.s.c.Overseer processMessage: queueSize: 1,
message = {
[junit4] 2> "operation":"downnode",
[junit4] 2> "node_name":"127.0.0.1:42365_solr"} current state version: 0
[junit4] 2> 305421 DEBUG
(OverseerStateUpdate-72206603074142211-127.0.0.1:42365_solr-n_0000000000)
[n:127.0.0.1:42365_solr ] o.a.s.c.o.NodeMutator DownNode state invoked for
node: 127.0.0.1:42365_solr
[junit4] 2> 305421 DEBUG
(OverseerStateUpdate-72206603074142211-127.0.0.1:42365_solr-n_0000000000)
[n:127.0.0.1:42365_solr ] o.a.s.c.o.NodeMutator Update replica state for
core_node3:{"core":"testNodeAdded_shard1_replica_n1","base_url":"http://127.0.0.1:4
[...truncated too long message...]
solr.cluster, tag=null
[junit4] 2> 115933 DEBUG
(OverseerStateUpdate-72206834951061526-127.0.0.1:44685_solr-n_0000000005)
[n:127.0.0.1:44685_solr ] o.a.s.c.Overseer processMessage: queueSize: 1,
message = {
[junit4] 2> "operation":"downnode",
[junit4] 2> "node_name":"127.0.0.1:44685_solr"} current state version: 0
[junit4] 2> 115933 INFO
(zkCallback-277-thread-2-processing-n:127.0.0.1:44685_solr)
[n:127.0.0.1:44685_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from
ZooKeeper... (1) -> (0)
[junit4] 2> 115933 DEBUG
(OverseerStateUpdate-72206834951061526-127.0.0.1:44685_solr-n_0000000005)
[n:127.0.0.1:44685_solr ] o.a.s.c.o.NodeMutator DownNode state invoked for
node: 127.0.0.1:44685_solr
[junit4] 2> 115933 DEBUG
(OverseerStateUpdate-72206834951061526-127.0.0.1:44685_solr-n_0000000005)
[n:127.0.0.1:44685_solr ] o.a.s.c.o.NodeMutator Update replica state for
core_node4:{"core":"testNodeLost_shard1_replica_n2","base_url":"http://127.0.0.1:44685/solr","node_name":"127.0.0.1:44685_solr","state":"active","type":"NRT","leader":"true"}
to down
[junit4] 2> 115933 INFO (coreCloseExecutor-489-thread-1)
[n:127.0.0.1:44685_solr c:testNodeLost s:shard1 r:core_node4
x:testNodeLost_shard1_replica_n2] o.a.s.c.SolrCore
[testNodeLost_shard1_replica_n2] CLOSING SolrCore
org.apache.solr.core.SolrCore@c75cd4a
[junit4] 2> 115933 INFO (coreCloseExecutor-489-thread-1)
[n:127.0.0.1:44685_solr c:testNodeLost s:shard1 r:core_node4
x:testNodeLost_shard1_replica_n2] o.a.s.m.SolrMetricManager Closing metric
reporters for registry=solr.core.testNodeLost.shard1.replica_n2, tag=209046858
[junit4] 2> 115933 INFO (coreCloseExecutor-489-thread-1)
[n:127.0.0.1:44685_solr c:testNodeLost s:shard1 r:core_node4
x:testNodeLost_shard1_replica_n2] o.a.s.m.r.SolrJmxReporter Closing reporter
[org.apache.solr.metrics.reporters.SolrJmxReporter@209cbeb5: rootName =
solr_44685, domain = solr.core.testNodeLost.shard1.replica_n2, service url =
null, agent id = null] for registry solr.core.testNodeLost.shard1.replica_n2 /
com.codahale.metrics.MetricRegistry@71cafb66
[junit4] 2> 115933 DEBUG
(OverseerStateUpdate-72206834951061526-127.0.0.1:44685_solr-n_0000000005)
[n:127.0.0.1:44685_solr ] o.a.s.c.o.ZkStateWriter going to update_collection
/collections/testNodeLost/state.json version: 7
[junit4] 2> 115934 INFO
(zkCallback-277-thread-2-processing-n:127.0.0.1:44685_solr)
[n:127.0.0.1:44685_solr ] o.a.s.c.c.ZkStateReader A cluster state change:
[WatchedEvent state:SyncConnected type:NodeDataChanged
path:/collections/testNodeLost/state.json] for collection [testNodeLost] has
occurred - updating... (live nodes size: [0])
[junit4] 2> 115934 INFO
(zkCallback-277-thread-3-processing-n:127.0.0.1:44685_solr)
[n:127.0.0.1:44685_solr ] o.a.s.c.c.ZkStateReader A cluster state change:
[WatchedEvent state:SyncConnected type:NodeDataChanged
path:/collections/testNodeLost/state.json] for collection [testNodeLost] has
occurred - updating... (live nodes size: [0])
[junit4] 2> 115939 INFO (coreCloseExecutor-489-thread-1)
[n:127.0.0.1:44685_solr c:testNodeLost s:shard1 r:core_node4
x:testNodeLost_shard1_replica_n2] o.a.s.m.SolrMetricManager Closing metric
reporters for registry=solr.collection.testNodeLost.shard1.leader, tag=209046858
[junit4] 2> 115941 INFO (jetty-closer-205-thread-1) [ ]
o.a.s.c.Overseer Overseer
(id=72206834951061526-127.0.0.1:44685_solr-n_0000000005) closing
[junit4] 2> 115941 INFO
(OverseerStateUpdate-72206834951061526-127.0.0.1:44685_solr-n_0000000005)
[n:127.0.0.1:44685_solr ] o.a.s.c.Overseer Overseer Loop exiting :
127.0.0.1:44685_solr
[junit4] 2> 115941 WARN
(OverseerAutoScalingTriggerThread-72206834951061526-127.0.0.1:44685_solr-n_0000000005)
[n:127.0.0.1:44685_solr ] o.a.s.c.a.OverseerTriggerThread
OverseerTriggerThread woken up but we are closed, exiting.
[junit4] 2> 115942 DEBUG (jetty-closer-205-thread-1) [ ]
o.a.s.c.a.OverseerTriggerThread OverseerTriggerThread has been closed explicitly
[junit4] 2> 115943 INFO (jetty-closer-205-thread-1) [ ]
o.e.j.s.h.ContextHandler Stopped
o.e.j.s.ServletContextHandler@356d44d9{/solr,null,UNAVAILABLE}
[junit4] 2> 115943 INFO (jetty-closer-205-thread-1) [ ]
o.e.j.s.session Stopped scavenging
[junit4] 2> 115943 ERROR
(SUITE-ComputePlanActionTest-seed#[2517DF000B47CC7A]-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> 115943 INFO
(SUITE-ComputePlanActionTest-seed#[2517DF000B47CC7A]-worker) [ ]
o.a.s.c.ZkTestServer connecting to 127.0.0.1:46211 46211
[junit4] 2> 121058 INFO (Thread-199) [ ] o.a.s.c.ZkTestServer
connecting to 127.0.0.1:46211 46211
[junit4] 2> 121058 WARN (Thread-199) [ ] o.a.s.c.ZkTestServer Watch
limit violations:
[junit4] 2> Maximum concurrent create/delete watches above limit:
[junit4] 2>
[junit4] 2> 15 /solr/aliases.json
[junit4] 2> 15 /solr/clusterprops.json
[junit4] 2> 11 /solr/configs/conf
[junit4] 2> 10 /solr/security.json
[junit4] 2> 9
/solr/collections/testNodeWithMultipleReplicasLost/terms/shard2
[junit4] 2> 9
/solr/collections/testNodeWithMultipleReplicasLost/terms/shard1
[junit4] 2> 6 /solr/collections/testNodeLost/terms/shard1
[junit4] 2> 5 /solr/collections/testSelected1/terms/shard2
[junit4] 2> 5 /solr/collections/testSelected2/terms/shard1
[junit4] 2> 5 /solr/collections/testSelected1/terms/shard1
[junit4] 2> 5 /solr/collections/testSelected2/terms/shard2
[junit4] 2> 5 /solr/collections/testSelected3/terms/shard2
[junit4] 2> 5 /solr/collections/testSelected3/terms/shard1
[junit4] 2> 3 /solr/collections/testNodeAdded/terms/shard1
[junit4] 2>
[junit4] 2> Maximum concurrent data watches above limit:
[junit4] 2>
[junit4] 2> 35 /solr/collections/testSelected2/state.json
[junit4] 2> 34 /solr/collections/testSelected3/state.json
[junit4] 2> 27 /solr/collections/testSelected1/state.json
[junit4] 2> 23
/solr/collections/testNodeWithMultipleReplicasLost/state.json
[junit4] 2> 16 /solr/collections/testNodeLost/state.json
[junit4] 2> 15 /solr/clusterstate.json
[junit4] 2> 4 /solr/autoscaling.json
[junit4] 2> 3
/solr/overseer_elect/election/72206834951061526-127.0.0.1:44685_solr-n_0000000005
[junit4] 2> 3
/solr/overseer_elect/election/72206834951061515-127.0.0.1:39507_solr-n_0000000002
[junit4] 2> 2 /solr/collections/testNodeAdded/state.json
[junit4] 2> 2
/solr/collections/testNodeWithMultipleReplicasLost/leader_elect/shard1/election/72206834951061521-core_node5-n_0000000000
[junit4] 2>
[junit4] 2> Maximum concurrent children watches above limit:
[junit4] 2>
[junit4] 2> 63 /solr/live_nodes
[junit4] 2> 48 /solr/collections
[junit4] 2> 4 /solr/overseer/queue
[junit4] 2> 4 /solr/autoscaling/events/.auto_add_replicas
[junit4] 2> 4 /solr/overseer/collection-queue-work
[junit4] 2> 4 /solr/overseer/queue-work
[junit4] 2>
[junit4] 2> NOTE: leaving temporary files on disk at:
/home/jenkins/workspace/Lucene-Solr-7.x-Linux/solr/build/solr-core/test/J0/temp/solr.cloud.autoscaling.ComputePlanActionTest_2517DF000B47CC7A-001
[junit4] 2> NOTE: test params are: codec=Asserting(Lucene70): {},
docValues:{}, maxPointsInLeafNode=526, maxMBSortInHeap=7.079047275862642,
sim=RandomSimilarity(queryNorm=false): {}, locale=es-NI,
timezone=America/Kentucky/Monticello
[junit4] 2> NOTE: Linux 4.13.0-32-generic amd64/Oracle Corporation
1.8.0_162 (64-bit)/cpus=8,threads=1,free=339457776,total=518979584
[junit4] 2> NOTE: All tests run in this JVM: [ComputePlanActionTest,
TestUtilizeNode, ComputePlanActionTest]
[junit4] Completed [10/10 (4!)] on J0 in 47.18s, 4 tests, 1 failure <<<
FAILURES!
[...truncated 14 lines...]
BUILD FAILED
/home/jenkins/workspace/Lucene-Solr-7.x-Linux/lucene/common-build.xml:1560: The
following error occurred while executing this line:
/home/jenkins/workspace/Lucene-Solr-7.x-Linux/lucene/common-build.xml:1085:
There were test failures: 10 suites, 25 tests, 4 failures [seed:
2517DF000B47CC7A]
Total time: 2 minutes 5 seconds
[repro] Setting last failure code to 256
[repro] Failures:
[repro] 0/5 failed: org.apache.solr.cloud.TestUtilizeNode
[repro] 4/5 failed: org.apache.solr.cloud.autoscaling.ComputePlanActionTest
[repro] Exiting with code 256
+ mv lucene/build lucene/build.repro
+ mv solr/build solr/build.repro
+ mv lucene/build.orig lucene/build
+ mv solr/build.orig solr/build
Archiving artifacts
Setting
ANT_1_8_2_HOME=/var/lib/jenkins/tools/hudson.tasks.Ant_AntInstallation/ANT_1.8.2
[WARNINGS] Parsing warnings in console log with parser Java Compiler (javac)
Setting
ANT_1_8_2_HOME=/var/lib/jenkins/tools/hudson.tasks.Ant_AntInstallation/ANT_1.8.2
Setting
ANT_1_8_2_HOME=/var/lib/jenkins/tools/hudson.tasks.Ant_AntInstallation/ANT_1.8.2
<Git Blamer> Using GitBlamer to create author and commit information for all
warnings.
<Git Blamer> GIT_COMMIT=d7f6cb93837e1bde1066c96606845c4ab04e50cf,
workspace=/var/lib/jenkins/workspace/Lucene-Solr-7.x-Linux
[WARNINGS] Computing warning deltas based on reference build #1421
Recording test results
Setting
ANT_1_8_2_HOME=/var/lib/jenkins/tools/hudson.tasks.Ant_AntInstallation/ANT_1.8.2
Build step 'Publish JUnit test result report' changed build result to UNSTABLE
Email was triggered for: Unstable (Test Failures)
Sending email for trigger: Unstable (Test Failures)
Setting
ANT_1_8_2_HOME=/var/lib/jenkins/tools/hudson.tasks.Ant_AntInstallation/ANT_1.8.2
Setting
ANT_1_8_2_HOME=/var/lib/jenkins/tools/hudson.tasks.Ant_AntInstallation/ANT_1.8.2
Setting
ANT_1_8_2_HOME=/var/lib/jenkins/tools/hudson.tasks.Ant_AntInstallation/ANT_1.8.2
Setting
ANT_1_8_2_HOME=/var/lib/jenkins/tools/hudson.tasks.Ant_AntInstallation/ANT_1.8.2
---------------------------------------------------------------------
To unsubscribe, e-mail: dev-unsubscr...@lucene.apache.org
For additional commands, e-mail: dev-h...@lucene.apache.org
