Build: https://jenkins.thetaphi.de/job/Lucene-Solr-master-MacOSX/4435/
Java: 64bit/jdk1.8.0 -XX:-UseCompressedOops -XX:+UseConcMarkSweepGC
1 tests failed.
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([8E7BBC17670D81CA:B4D559CE596958A4]: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 12540 lines...]
[junit4] Suite: org.apache.solr.cloud.autoscaling.ComputePlanActionTest
[junit4] 2> Creating dataDir:
/Users/jenkins/workspace/Lucene-Solr-master-MacOSX/solr/build/solr-core/test/J1/temp/solr.cloud.autoscaling.ComputePlanActionTest_8E7BBC17670D81CA-001/init-core-data-001
[junit4] 2> 1077642 WARN
(SUITE-ComputePlanActionTest-seed#[8E7BBC17670D81CA]-worker) [ ]
o.a.s.SolrTestCaseJ4 startTrackingSearchers: numOpens=7 numCloses=7
[junit4] 2> 1077642 INFO
(SUITE-ComputePlanActionTest-seed#[8E7BBC17670D81CA]-worker) [ ]
o.a.s.SolrTestCaseJ4 Using PointFields (NUMERIC_POINTS_SYSPROP=true)
w/NUMERIC_DOCVALUES_SYSPROP=false
[junit4] 2> 1077646 INFO
(SUITE-ComputePlanActionTest-seed#[8E7BBC17670D81CA]-worker) [ ]
o.a.s.SolrTestCaseJ4 Randomized ssl (false) and clientAuth (false) via:
@org.apache.solr.util.RandomizeSSL(reason=, value=NaN, ssl=NaN, clientAuth=NaN)
w/ MAC_OS_X supressed clientAuth
[junit4] 2> 1077646 INFO
(SUITE-ComputePlanActionTest-seed#[8E7BBC17670D81CA]-worker) [ ]
o.a.s.SolrTestCaseJ4 SecureRandom sanity checks:
test.solr.allowed.securerandom=null & java.security.egd=file:/dev/./urandom
[junit4] 2> 1077647 INFO
(SUITE-ComputePlanActionTest-seed#[8E7BBC17670D81CA]-worker) [ ]
o.a.s.c.MiniSolrCloudCluster Starting cluster of 1 servers in
/Users/jenkins/workspace/Lucene-Solr-master-MacOSX/solr/build/solr-core/test/J1/temp/solr.cloud.autoscaling.ComputePlanActionTest_8E7BBC17670D81CA-001/tempDir-001
[junit4] 2> 1077647 INFO
(SUITE-ComputePlanActionTest-seed#[8E7BBC17670D81CA]-worker) [ ]
o.a.s.c.ZkTestServer STARTING ZK TEST SERVER
[junit4] 2> 1077648 INFO (Thread-1680) [ ] o.a.s.c.ZkTestServer client
port:0.0.0.0/0.0.0.0:0
[junit4] 2> 1077648 INFO (Thread-1680) [ ] o.a.s.c.ZkTestServer
Starting server
[junit4] 2> 1077652 ERROR (Thread-1680) [ ] 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> 1077757 INFO
(SUITE-ComputePlanActionTest-seed#[8E7BBC17670D81CA]-worker) [ ]
o.a.s.c.ZkTestServer start zk server on port:51352
[junit4] 2> 1077769 INFO (zkConnectionManagerCallback-2400-thread-1) [
] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 1077775 INFO (jetty-launcher-2397-thread-1) [ ]
o.e.j.s.Server jetty-9.4.8.v20171121, build timestamp:
2017-11-22T06:57:37+09:30, git hash: 82b8fb23f757335bb3329d540ce37a2a2615f0a8
[junit4] 2> 1077776 INFO (jetty-launcher-2397-thread-1) [ ]
o.e.j.s.session DefaultSessionIdManager workerName=node0
[junit4] 2> 1077776 INFO (jetty-launcher-2397-thread-1) [ ]
o.e.j.s.session No SessionScavenger set, using defaults
[junit4] 2> 1077776 INFO (jetty-launcher-2397-thread-1) [ ]
o.e.j.s.session Scavenging every 660000ms
[junit4] 2> 1077776 INFO (jetty-launcher-2397-thread-1) [ ]
o.e.j.s.h.ContextHandler Started
o.e.j.s.ServletContextHandler@17949134{/solr,null,AVAILABLE}
[junit4] 2> 1077778 INFO (jetty-launcher-2397-thread-1) [ ]
o.e.j.s.AbstractConnector Started
ServerConnector@57682d91{HTTP/1.1,[http/1.1]}{127.0.0.1:51354}
[junit4] 2> 1077778 INFO (jetty-launcher-2397-thread-1) [ ]
o.e.j.s.Server Started @1086034ms
[junit4] 2> 1077778 INFO (jetty-launcher-2397-thread-1) [ ]
o.a.s.c.s.e.JettySolrRunner Jetty properties: {hostContext=/solr,
hostPort=51354}
[junit4] 2> 1077778 ERROR (jetty-launcher-2397-thread-1) [ ]
o.a.s.u.StartupLoggingUtils Missing Java Option solr.log.dir. Logging may be
missing or incomplete.
[junit4] 2> 1077778 INFO (jetty-launcher-2397-thread-1) [ ]
o.a.s.s.SolrDispatchFilter ___ _ Welcome to Apache Solr? version
8.0.0
[junit4] 2> 1077778 INFO (jetty-launcher-2397-thread-1) [ ]
o.a.s.s.SolrDispatchFilter / __| ___| |_ _ Starting in cloud mode on port null
[junit4] 2> 1077778 INFO (jetty-launcher-2397-thread-1) [ ]
o.a.s.s.SolrDispatchFilter \__ \/ _ \ | '_| Install dir: null
[junit4] 2> 1077778 INFO (jetty-launcher-2397-thread-1) [ ]
o.a.s.s.SolrDispatchFilter |___/\___/_|_| Start time:
2018-02-12T00:37:06.406Z
[junit4] 2> 1077781 INFO (zkConnectionManagerCallback-2402-thread-1) [
] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 1077781 INFO (jetty-launcher-2397-thread-1) [ ]
o.a.s.s.SolrDispatchFilter solr.xml found in ZooKeeper. Loading...
[junit4] 2> 1077797 INFO (jetty-launcher-2397-thread-1) [ ]
o.a.s.c.ZkContainer Zookeeper client=127.0.0.1:51352/solr
[junit4] 2> 1077799 INFO (zkConnectionManagerCallback-2406-thread-1) [
] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 1077802 INFO
(zkConnectionManagerCallback-2408-thread-1-processing-n:127.0.0.1:51354_solr)
[n:127.0.0.1:51354_solr ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 1077996 INFO (jetty-launcher-2397-thread-1)
[n:127.0.0.1:51354_solr ] o.a.s.c.Overseer Overseer (id=null) closing
[junit4] 2> 1077997 INFO (jetty-launcher-2397-thread-1)
[n:127.0.0.1:51354_solr ] o.a.s.c.OverseerElectionContext I am going to be
the leader 127.0.0.1:51354_solr
[junit4] 2> 1077999 INFO (jetty-launcher-2397-thread-1)
[n:127.0.0.1:51354_solr ] o.a.s.c.Overseer Overseer
(id=72077351691354115-127.0.0.1:51354_solr-n_0000000000) starting
[junit4] 2> 1078011 DEBUG
(OverseerStateUpdate-72077351691354115-127.0.0.1:51354_solr-n_0000000000)
[n:127.0.0.1:51354_solr ] o.a.s.c.Overseer Starting to work on the main queue
[junit4] 2> 1078011 INFO (jetty-launcher-2397-thread-1)
[n:127.0.0.1:51354_solr ] o.a.s.c.ZkController Register node as live in
ZooKeeper:/live_nodes/127.0.0.1:51354_solr
[junit4] 2> 1078012 DEBUG
(OverseerAutoScalingTriggerThread-72077351691354115-127.0.0.1:51354_solr-n_0000000000)
[n:127.0.0.1:51354_solr ] o.a.s.c.a.OverseerTriggerThread Adding
.autoAddReplicas trigger
[junit4] 2> 1078013 INFO
(OverseerStateUpdate-72077351691354115-127.0.0.1:51354_solr-n_0000000000)
[n:127.0.0.1:51354_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from
ZooKeeper... (0) -> (1)
[junit4] 2> 1078013 DEBUG
(OverseerAutoScalingTriggerThread-72077351691354115-127.0.0.1:51354_solr-n_0000000000)
[n:127.0.0.1:51354_solr ] o.a.s.c.a.OverseerTriggerThread Refreshing
/autoscaling.json with znode version 1
[junit4] 2> 1078014 DEBUG
(OverseerAutoScalingTriggerThread-72077351691354115-127.0.0.1:51354_solr-n_0000000000)
[n:127.0.0.1:51354_solr ] o.a.s.c.a.NodeLostTrigger Initial livenodes:
[127.0.0.1:51354_solr]
[junit4] 2> 1078014 DEBUG
(OverseerAutoScalingTriggerThread-72077351691354115-127.0.0.1:51354_solr-n_0000000000)
[n:127.0.0.1:51354_solr ] o.a.s.c.a.OverseerTriggerThread Current
znodeVersion 1, lastZnodeVersion -1
[junit4] 2> 1078014 DEBUG
(OverseerAutoScalingTriggerThread-72077351691354115-127.0.0.1:51354_solr-n_0000000000)
[n:127.0.0.1:51354_solr ] o.a.s.c.a.OverseerTriggerThread Processed trigger
updates upto znodeVersion 1
[junit4] 2> 1078018 DEBUG
(OverseerAutoScalingTriggerThread-72077351691354115-127.0.0.1:51354_solr-n_0000000000)
[n:127.0.0.1:51354_solr ] o.a.s.c.a.OverseerTriggerThread -- clean old
nodeAdded markers
[junit4] 2> 1078018 DEBUG
(OverseerAutoScalingTriggerThread-72077351691354115-127.0.0.1:51354_solr-n_0000000000)
[n:127.0.0.1:51354_solr ] o.a.s.c.a.OverseerTriggerThread Current
znodeVersion 1, lastZnodeVersion 1
[junit4] 2> 1078019 DEBUG (ScheduledTrigger-4063-thread-1)
[n:127.0.0.1:51354_solr ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger:
.auto_add_replicas with currently live nodes: 1
[junit4] 2> 1078111 INFO (jetty-launcher-2397-thread-1)
[n:127.0.0.1:51354_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for
'solr_51354.solr.node' (registry 'solr.node') enabled at server:
com.sun.jmx.mbeanserver.JmxMBeanServer@39954ebe
[junit4] 2> 1078118 INFO (jetty-launcher-2397-thread-1)
[n:127.0.0.1:51354_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for
'solr_51354.solr.jvm' (registry 'solr.jvm') enabled at server:
com.sun.jmx.mbeanserver.JmxMBeanServer@39954ebe
[junit4] 2> 1078118 INFO (jetty-launcher-2397-thread-1)
[n:127.0.0.1:51354_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for
'solr_51354.solr.jetty' (registry 'solr.jetty') enabled at server:
com.sun.jmx.mbeanserver.JmxMBeanServer@39954ebe
[junit4] 2> 1078119 INFO (jetty-launcher-2397-thread-1)
[n:127.0.0.1:51354_solr ] o.a.s.c.CorePropertiesLocator Found 0 core
definitions underneath
/Users/jenkins/workspace/Lucene-Solr-master-MacOSX/solr/build/solr-core/test/J1/temp/solr.cloud.autoscaling.ComputePlanActionTest_8E7BBC17670D81CA-001/tempDir-001/node1/.
[junit4] 2> 1078147 INFO (zkConnectionManagerCallback-2412-thread-1) [
] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 1078152 INFO (zkConnectionManagerCallback-2416-thread-1) [
] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 1078154 INFO
(SUITE-ComputePlanActionTest-seed#[8E7BBC17670D81CA]-worker) [ ]
o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (1)
[junit4] 2> 1078156 INFO
(SUITE-ComputePlanActionTest-seed#[8E7BBC17670D81CA]-worker) [ ]
o.a.s.c.s.i.ZkClientClusterStateProvider Cluster at 127.0.0.1:51352/solr ready
[junit4] 2> 1078171 INFO
(TEST-ComputePlanActionTest.testNodeAdded-seed#[8E7BBC17670D81CA]) [ ]
o.a.s.SolrTestCaseJ4 ###Starting testNodeAdded
[junit4] 2> 1078172 DEBUG
(zkCallback-2407-thread-1-processing-n:127.0.0.1:51354_solr)
[n:127.0.0.1:51354_solr ] o.a.s.c.a.OverseerTriggerThread Refreshing
/autoscaling.json with znode version 2
[junit4] 2> 1078172 DEBUG
(OverseerAutoScalingTriggerThread-72077351691354115-127.0.0.1:51354_solr-n_0000000000)
[n:127.0.0.1:51354_solr ] o.a.s.c.a.OverseerTriggerThread Processed trigger
updates upto znodeVersion 2
[junit4] 2> 1078174 INFO
(TEST-ComputePlanActionTest.testNodeAdded-seed#[8E7BBC17670D81CA]) [ ]
o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (1)
[junit4] 2> 1078175 DEBUG
(OverseerAutoScalingTriggerThread-72077351691354115-127.0.0.1:51354_solr-n_0000000000)
[n:127.0.0.1:51354_solr ] o.a.s.c.a.OverseerTriggerThread -- clean old
nodeLost markers
[junit4] 2> 1078176 DEBUG
(OverseerAutoScalingTriggerThread-72077351691354115-127.0.0.1:51354_solr-n_0000000000)
[n:127.0.0.1:51354_solr ] o.a.s.c.a.OverseerTriggerThread -- clean old
nodeAdded markers
[junit4] 2> 1078176 DEBUG
(OverseerAutoScalingTriggerThread-72077351691354115-127.0.0.1:51354_solr-n_0000000000)
[n:127.0.0.1:51354_solr ] o.a.s.c.a.OverseerTriggerThread Current
znodeVersion 2, lastZnodeVersion 2
[junit4] 2> 1078201 INFO (qtp1515177652-10602) [n:127.0.0.1:51354_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> 1078207 DEBUG (qtp1515177652-10598) [n:127.0.0.1:51354_solr
] o.a.s.c.a.AutoScalingHandler Verified autoscaling configuration
[junit4] 2> 1078208 INFO (qtp1515177652-10598) [n:127.0.0.1:51354_solr
] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/autoscaling
params={wt=javabin&version=2} status=0 QTime=30
[junit4] 2> 1078208 DEBUG
(zkCallback-2407-thread-1-processing-n:127.0.0.1:51354_solr)
[n:127.0.0.1:51354_solr ] o.a.s.c.a.OverseerTriggerThread Refreshing
/autoscaling.json with znode version 3
[junit4] 2> 1078208 DEBUG
(OverseerAutoScalingTriggerThread-72077351691354115-127.0.0.1:51354_solr-n_0000000000)
[n:127.0.0.1:51354_solr ] o.a.s.c.a.OverseerTriggerThread Processed trigger
updates upto znodeVersion 3
[junit4] 2> 1078208 DEBUG
(OverseerAutoScalingTriggerThread-72077351691354115-127.0.0.1:51354_solr-n_0000000000)
[n:127.0.0.1:51354_solr ] o.a.s.c.a.OverseerTriggerThread -- clean old
nodeLost markers
[junit4] 2> 1078209 DEBUG
(OverseerAutoScalingTriggerThread-72077351691354115-127.0.0.1:51354_solr-n_0000000000)
[n:127.0.0.1:51354_solr ] o.a.s.c.a.OverseerTriggerThread -- clean old
nodeAdded markers
[junit4] 2> 1078209 DEBUG
(OverseerAutoScalingTriggerThread-72077351691354115-127.0.0.1:51354_solr-n_0000000000)
[n:127.0.0.1:51354_solr ] o.a.s.c.a.OverseerTriggerThread Current
znodeVersion 3, lastZnodeVersion 3
[junit4] 2> 1078211 INFO (qtp1515177652-10602) [n:127.0.0.1:51354_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> 1078211 DEBUG (qtp1515177652-10600) [n:127.0.0.1:51354_solr
] o.a.s.c.a.AutoScalingHandler Verified autoscaling configuration
[junit4] 2> 1078211 INFO (qtp1515177652-10600) [n:127.0.0.1:51354_solr
] o.a.s.s.HttpSolrCall [admin] webapp=null path=/cluster/autoscaling
params={wt=javabin&version=2} status=0 QTime=2
[junit4] 2> 1078212 DEBUG
(zkCallback-2407-thread-1-processing-n:127.0.0.1:51354_solr)
[n:127.0.0.1:51354_solr ] o.a.s.c.a.OverseerTriggerThread Refreshing
/autoscaling.json with znode version 4
[junit4] 2> 1078212 DEBUG
(OverseerAutoScalingTriggerThread-72077351691354115-127.0.0.1:51354_solr-n_0000000000)
[n:127.0.0.1:51354_solr ] o.a.s.c.a.OverseerTriggerThread Processed trigger
updates upto znodeVersion 4
[junit4] 2> 1078212 DEBUG
(OverseerAutoScalingTriggerThread-72077351691354115-127.0.0.1:51354_solr-n_0000000000)
[n:127.0.0.1:51354_solr ] o.a.s.c.a.OverseerTriggerThread -- clean old
nodeLost markers
[junit4] 2> 1078212 DEBUG
(OverseerAutoScalingTriggerThread-72077351691354115-127.0.0.1:51354_solr-n_0000000000)
[n:127.0.0.1:51354_solr ] o.a.s.c.a.OverseerTriggerThread -- clean old
nodeAdded markers
[junit4] 2> 1078213 DEBUG
(OverseerAutoScalingTriggerThread-72077351691354115-127.0.0.1:51354_solr-n_0000000000)
[n:127.0.0.1:51354_solr ] o.a.s.c.a.OverseerTriggerThread Current
znodeVersion 4, lastZnodeVersion 4
[junit4] 2> 1078215 INFO (qtp1515177652-10600) [n:127.0.0.1:51354_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> 1078215 DEBUG (qtp1515177652-10603) [n:127.0.0.1:51354_solr
] o.a.s.c.a.AutoScalingHandler Verified autoscaling configuration
[junit4] 2> 1078216 INFO (qtp1515177652-10603) [n:127.0.0.1:51354_solr
] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/autoscaling
params={wt=javabin&version=2} status=0 QTime=2
[junit4] 2> 1078216 DEBUG
(zkCallback-2407-thread-1-processing-n:127.0.0.1:51354_solr)
[n:127.0.0.1:51354_solr ] o.a.s.c.a.OverseerTriggerThread Refreshing
/autoscaling.json with znode version 5
[junit4] 2> 1078217 DEBUG
(zkCallback-2407-thread-1-processing-n:127.0.0.1:51354_solr)
[n:127.0.0.1:51354_solr ] o.a.s.c.a.NodeAddedTrigger Initial livenodes:
[127.0.0.1:51354_solr]
[junit4] 2> 1078217 DEBUG
(zkCallback-2407-thread-1-processing-n:127.0.0.1:51354_solr)
[n:127.0.0.1:51354_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> 1078217 DEBUG
(OverseerAutoScalingTriggerThread-72077351691354115-127.0.0.1:51354_solr-n_0000000000)
[n:127.0.0.1:51354_solr ] o.a.s.c.a.OverseerTriggerThread Processed trigger
updates upto znodeVersion 5
[junit4] 2> 1078218 INFO (qtp1515177652-10603) [n:127.0.0.1:51354_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> 1078218 DEBUG (qtp1515177652-10602) [n:127.0.0.1:51354_solr
] o.a.s.c.a.AutoScalingHandler Verified autoscaling configuration
[junit4] 2> 1078219 INFO (qtp1515177652-10602) [n:127.0.0.1:51354_solr
] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/autoscaling
params={wt=javabin&version=2} status=0 QTime=2
[junit4] 2> 1078220 INFO (qtp1515177652-10600) [n:127.0.0.1:51354_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> 1078220 DEBUG
(zkCallback-2407-thread-1-processing-n:127.0.0.1:51354_solr)
[n:127.0.0.1:51354_solr ] o.a.s.c.a.OverseerTriggerThread Refreshing
/autoscaling.json with znode version 6
[junit4] 2> 1078221 DEBUG
(zkCallback-2407-thread-1-processing-n:127.0.0.1:51354_solr)
[n:127.0.0.1:51354_solr ] o.a.s.c.a.NodeAddedTrigger Initial livenodes:
[127.0.0.1:51354_solr]
[junit4] 2> 1078221 DEBUG
(zkCallback-2407-thread-1-processing-n:127.0.0.1:51354_solr)
[n:127.0.0.1:51354_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> 1078222 DEBUG
(OverseerAutoScalingTriggerThread-72077351691354115-127.0.0.1:51354_solr-n_0000000000)
[n:127.0.0.1:51354_solr ] o.a.s.c.a.OverseerTriggerThread -- clean old
nodeLost markers
[junit4] 2> 1078222 DEBUG
(OverseerAutoScalingTriggerThread-72077351691354115-127.0.0.1:51354_solr-n_0000000000)
[n:127.0.0.1:51354_solr ] o.a.s.c.a.OverseerTriggerThread Current
znodeVersion 6, lastZnodeVersion 5
[junit4] 2> 1078222 DEBUG
(OverseerAutoScalingTriggerThread-72077351691354115-127.0.0.1:51354_solr-n_0000000000)
[n:127.0.0.1:51354_solr ] o.a.s.c.a.OverseerTriggerThread Processed trigger
updates upto znodeVersion 6
[junit4] 2> 1078223 DEBUG (ScheduledTrigger-4063-thread-1)
[n:127.0.0.1:51354_solr ] o.a.s.c.a.NodeAddedTrigger Running
NodeAddedTrigger node_added_trigger
[junit4] 2> 1078223 DEBUG (ScheduledTrigger-4063-thread-1)
[n:127.0.0.1:51354_solr ] o.a.s.c.a.NodeAddedTrigger Found livenodes: 1
[junit4] 2> 1078223 DEBUG
(OverseerAutoScalingTriggerThread-72077351691354115-127.0.0.1:51354_solr-n_0000000000)
[n:127.0.0.1:51354_solr ] o.a.s.c.a.OverseerTriggerThread -- clean old
nodeLost markers
[junit4] 2> 1078223 INFO
(OverseerThreadFactory-4065-thread-1-processing-n:127.0.0.1:51354_solr)
[n:127.0.0.1:51354_solr ] o.a.s.c.a.c.CreateCollectionCmd Create collection
testNodeAdded
[junit4] 2> 1078224 DEBUG
(OverseerAutoScalingTriggerThread-72077351691354115-127.0.0.1:51354_solr-n_0000000000)
[n:127.0.0.1:51354_solr ] o.a.s.c.a.OverseerTriggerThread Current
znodeVersion 6, lastZnodeVersion 6
[junit4] 2> 1078224 WARN
(OverseerThreadFactory-4065-thread-1-processing-n:127.0.0.1:51354_solr)
[n:127.0.0.1:51354_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> 1078240 INFO (qtp1515177652-10602) [n:127.0.0.1:51354_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> 1078248 INFO
(OverseerThreadFactory-4065-thread-1-processing-n:127.0.0.1:51354_solr)
[n:127.0.0.1:51354_solr ] o.a.s.c.s.c.a.PolicyHelper returnSession,
curr-time 301478463 sessionWrapper.createTime 301478456655176,
this.sessionWrapper.createTime 301478456655176
[junit4] 2> 1078255 DEBUG
(OverseerStateUpdate-72077351691354115-127.0.0.1:51354_solr-n_0000000000)
[n:127.0.0.1:51354_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> 1078255 DEBUG
(OverseerStateUpdate-72077351691354115-127.0.0.1:51354_solr-n_0000000000)
[n:127.0.0.1:51354_solr ] o.a.s.c.o.ClusterStateMutator building a new
cName: testNodeAdded
[junit4] 2> 1078256 DEBUG
(OverseerStateUpdate-72077351691354115-127.0.0.1:51354_solr-n_0000000000)
[n:127.0.0.1:51354_solr ] o.a.s.c.o.ZkStateWriter going to create_collection
/collections/testNodeAdded/state.json
[junit4] 2> 1078370 DEBUG
(OverseerStateUpdate-72077351691354115-127.0.0.1:51354_solr-n_0000000000)
[n:127.0.0.1:51354_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:51354/solr";,
[junit4] 2> "type":"NRT",
[junit4] 2> "waitForFinalState":"false"} current state version: 0
[junit4] 2> 1078370 INFO
(OverseerStateUpdate-72077351691354115-127.0.0.1:51354_solr-n_0000000000)
[n:127.0.0.1:51354_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:51354/solr";,
[junit4] 2> "type":"NRT",
[junit4] 2> "waitForFinalState":"false"}
[junit4] 2> 1078372 DEBUG
(OverseerStateUpdate-72077351691354115-127.0.0.1:51354_solr-n_0000000000)
[n:127.0.0.1:51354_solr ] o.a.s.c.o.SliceMutator Old Slice: shard1:{
[junit4] 2> "range":"80000000-7fffffff",
[junit4] 2> "state":"active",
[junit4] 2> "replicas":{}}
[junit4] 2> 1078372 DEBUG
(OverseerStateUpdate-72077351691354115-127.0.0.1:51354_solr-n_0000000000)
[n:127.0.0.1:51354_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:51354/solr";,
[junit4] 2> "state":"down",
[junit4] 2> "node_name":null,
[junit4] 2> "type":"NRT"}}}
[junit4] 2> 1078374 DEBUG
(OverseerStateUpdate-72077351691354115-127.0.0.1:51354_solr-n_0000000000)
[n:127.0.0.1:51354_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:51354/solr";,
[junit4] 2> "type":"NRT",
[junit4] 2> "waitForFinalState":"false"} current state version: 0
[junit4] 2> 1078374 INFO
(OverseerStateUpdate-72077351691354115-127.0.0.1:51354_solr-n_0000000000)
[n:127.0.0.1:51354_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:51354/solr";,
[junit4] 2> "type":"NRT",
[junit4] 2> "waitForFinalState":"false"}
[junit4] 2> 1078376 DEBUG
(OverseerStateUpdate-72077351691354115-127.0.0.1:51354_solr-n_0000000000)
[n:127.0.0.1:51354_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:51354/solr";,
[junit4] 2> "state":"down",
[junit4] 2> "node_name":null,
[junit4] 2> "type":"NRT"}}}
[junit4] 2> 1078376 DEBUG
(OverseerStateUpdate-72077351691354115-127.0.0.1:51354_solr-n_0000000000)
[n:127.0.0.1:51354_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:51354/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:51354/solr";,
[junit4] 2> "state":"down",
[junit4] 2> "node_name":null,
[junit4] 2> "type":"NRT"}}}
[junit4] 2> 1078485 DEBUG
(OverseerStateUpdate-72077351691354115-127.0.0.1:51354_solr-n_0000000000)
[n:127.0.0.1:51354_solr ] o.a.s.c.o.ZkStateWriter going to update_collection
/collections/testNodeAdded/state.json version: 0
[junit4] 2> 1078597 INFO (qtp1515177652-10604) [n:127.0.0.1:51354_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> 1078597 INFO (qtp1515177652-10602) [n:127.0.0.1:51354_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> 1078598 INFO (qtp1515177652-10604) [n:127.0.0.1:51354_solr
] o.a.s.c.TransientSolrCoreCacheDefault Allocating transient cache for
2147483647 transient cores
[junit4] 2> 1078603 DEBUG
(OverseerStateUpdate-72077351691354115-127.0.0.1:51354_solr-n_0000000000)
[n:127.0.0.1:51354_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:51354/solr";,
[junit4] 2> "node_name":"127.0.0.1:51354_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> 1078603 DEBUG
(OverseerStateUpdate-72077351691354115-127.0.0.1:51354_solr-n_0000000000)
[n:127.0.0.1:51354_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:51354/solr";,
[junit4] 2> "node_name":"127.0.0.1:51354_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> 1078603 DEBUG
(OverseerStateUpdate-72077351691354115-127.0.0.1:51354_solr-n_0000000000)
[n:127.0.0.1:51354_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:51354/solr","node_name":"127.0.0.1:51354_solr","state":"down","type":"NRT"}
[junit4] 2> 1078603 DEBUG
(OverseerStateUpdate-72077351691354115-127.0.0.1:51354_solr-n_0000000000)
[n:127.0.0.1:51354_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:51354/solr";,
[junit4] 2> "node_name":"127.0.0.1:51354_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:51354/solr";,
[junit4] 2> "state":"down",
[junit4] 2> "node_name":null,
[junit4] 2> "type":"NRT"}}}}}
[junit4] 2> 1078603 DEBUG
(OverseerStateUpdate-72077351691354115-127.0.0.1:51354_solr-n_0000000000)
[n:127.0.0.1:51354_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:51354/solr";,
[junit4] 2> "node_name":"127.0.0.1:51354_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> 1078603 DEBUG
(OverseerStateUpdate-72077351691354115-127.0.0.1:51354_solr-n_0000000000)
[n:127.0.0.1:51354_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:51354/solr";,
[junit4] 2> "node_name":"127.0.0.1:51354_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> 1078603 DEBUG
(OverseerStateUpdate-72077351691354115-127.0.0.1:51354_solr-n_0000000000)
[n:127.0.0.1:51354_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:51354/solr","node_name":"127.0.0.1:51354_solr","state":"down","type":"NRT"}
[junit4] 2> 1078603 DEBUG
(OverseerStateUpdate-72077351691354115-127.0.0.1:51354_solr-n_0000000000)
[n:127.0.0.1:51354_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:51354/solr";,
[junit4] 2> "node_name":"127.0.0.1:51354_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:51354/solr";,
[junit4] 2> "node_name":"127.0.0.1:51354_solr",
[junit4] 2> "state":"down",
[junit4] 2> "type":"NRT"}}}}}
[junit4] 2> 1078707 DEBUG
(OverseerStateUpdate-72077351691354115-127.0.0.1:51354_solr-n_0000000000)
[n:127.0.0.1:51354_solr ] o.a.s.c.o.ZkStateWriter going to update_collection
/collections/testNodeAdded/state.json version: 1
[junit4] 2> 1078707 INFO
(zkCallback-2407-thread-1-processing-n:127.0.0.1:51354_solr)
[n:127.0.0.1:51354_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> 1078707 INFO
(zkCallback-2407-thread-2-processing-n:127.0.0.1:51354_solr)
[n:127.0.0.1:51354_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> 1079235 DEBUG (ScheduledTrigger-4063-thread-2)
[n:127.0.0.1:51354_solr ] o.a.s.c.a.NodeAddedTrigger Running
NodeAddedTrigger node_added_trigger
[junit4] 2> 1079235 DEBUG (ScheduledTrigger-4063-thread-2)
[n:127.0.0.1:51354_solr ] o.a.s.c.a.NodeAddedTrigger Found livenodes: 1
[junit4] 2> 1079620 INFO (qtp1515177652-10604) [n:127.0.0.1:51354_solr
c:testNodeAdded s:shard1 r:core_node3 x:testNodeAdded_shard1_replica_n1]
o.a.s.c.SolrConfig Using Lucene MatchVersion: 8.0.0
[junit4] 2> 1079620 INFO (qtp1515177652-10602) [n:127.0.0.1:51354_solr
c:testNodeAdded s:shard1 r:core_node4 x:testNodeAdded_shard1_replica_n2]
o.a.s.c.SolrConfig Using Lucene MatchVersion: 8.0.0
[junit4] 2> 1079631 INFO (qtp1515177652-10602) [n:127.0.0.1:51354_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> 1079631 INFO (qtp1515177652-10604) [n:127.0.0.1:51354_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> 1079635 INFO (qtp1515177652-10602) [n:127.0.0.1:51354_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> 1079635 INFO (qtp1515177652-10604) [n:127.0.0.1:51354_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> 1079635 INFO (qtp1515177652-10602) [n:127.0.0.1:51354_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> 1079635 INFO (qtp1515177652-10604) [n:127.0.0.1:51354_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> 1079637 INFO (qtp1515177652-10602) [n:127.0.0.1:51354_solr
c:testNodeAdded s:shard1 r:core_node4 x:testNodeAdded_shard1_replica_n2]
o.a.s.m.r.SolrJmxReporter JMX monitoring for
'solr_51354.solr.core.testNodeAdded.shard1.replica_n2' (registry
'solr.core.testNodeAdded.shard1.replica_n2') enabled at server:
com.sun.jmx.mbeanserver.JmxMBeanServer@39954ebe
[junit4] 2> 1079637 INFO (qtp1515177652-10604) [n:127.0.0.1:51354_solr
c:testNodeAdded s:shard1 r:core_node3 x:testNodeAdded_shard1_replica_n1]
o.a.s.m.r.SolrJmxReporter JMX monitoring for
'solr_51354.solr.core.testNodeAdded.shard1.replica_n1' (registry
'solr.core.testNodeAdded.shard1.replica_n1') enabled at server:
com.sun.jmx.mbeanserver.JmxMBeanServer@39954ebe
[junit4] 2> 1079637 INFO (qtp1515177652-10602) [n:127.0.0.1:51354_solr
c:testNodeAdded s:shard1 r:core_node4 x:testNodeAdded_shard1_replica_n2]
o.a.s.c.SolrCore solr.RecoveryStrategy.Builder
[junit4] 2> 1079637 INFO (qtp1515177652-10604) [n:127.0.0.1:51354_solr
c:testNodeAdded s:shard1 r:core_node3 x:testNodeAdded_shard1_replica_n1]
o.a.s.c.SolrCore solr.RecoveryStrategy.Builder
[junit4] 2> 1079637 INFO (qtp1515177652-10602) [n:127.0.0.1:51354_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
[/Users/jenkins/workspace/Lucene-Solr-master-MacOSX/solr/build/solr-core/test/J1/temp/solr.cloud.autoscaling.ComputePlanActionTest_8E7BBC17670D81CA-001/tempDir-001/node1/testNodeAdded_shard1_replica_n2],
dataDir=[/Users/jenkins/workspace/Lucene-Solr-master-MacOSX/solr/build/solr-core/test/J1/temp/solr.cloud.autoscaling.ComputePlanActionTest_8E7BBC17670D81CA-001/tempDir-001/node1/./testNodeAdded_shard1_replica_n2/data/]
[junit4] 2> 1079637 INFO (qtp1515177652-10604) [n:127.0.0.1:51354_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
[/Users/jenkins/workspace/Lucene-Solr-master-MacOSX/solr/build/solr-core/test/J1/temp/solr.cloud.autoscaling.ComputePlanActionTest_8E7BBC17670D81CA-001/tempDir-001/node1/testNodeAdded_shard1_replica_n1],
dataDir=[/Users/jenkins/workspace/Lucene-Solr-master-MacOSX/solr/build/solr-core/test/J1/temp/solr.cloud.autoscaling.ComputePlanActionTest_8E7BBC17670D81CA-001/tempDir-001/node1/./testNodeAdded_shard1_replica_n1/data/]
[junit4] 2> 1079713 INFO (qtp1515177652-10602) [n:127.0.0.1:51354_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> 1079713 INFO (qtp1515177652-10602) [n:127.0.0.1:51354_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> 1079713 INFO (qtp1515177652-10604) [n:127.0.0.1:51354_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> 1079713 INFO (qtp1515177652-10604) [n:127.0.0.1:51354_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> 1079714 INFO (qtp1515177652-10604) [n:127.0.0.1:51354_solr
c:testNodeAdded s:shard1 r:core_node3 x:testNodeAdded_shard1_replica_n1]
o.a.s.u.CommitTracker Hard AutoCommit: disabled
[junit4] 2> 1079714 INFO (qtp1515177652-10602) [n:127.0.0.1:51354_solr
c:testNodeAdded s:shard1 r:core_node4 x:testNodeAdded_shard1_replica_n2]
o.a.s.u.CommitTracker Hard AutoCommit: disabled
[junit4] 2> 1079715 INFO (qtp1515177652-10604) [n:127.0.0.1:51354_solr
c:testNodeAdded s:shard1 r:core_node3 x:testNodeAdded_shard1_replica_n1]
o.a.s.u.CommitTracker Soft AutoCommit: disabled
[junit4] 2> 1079715 INFO (qtp1515177652-10602) [n:127.0.0.1:51354_solr
c:testNodeAdded s:shard1 r:core_node4 x:testNodeAdded_shard1_replica_n2]
o.a.s.u.CommitTracker Soft AutoCommit: disabled
[junit4] 2> 1079716 INFO (qtp1515177652-10604) [n:127.0.0.1:51354_solr
c:testNodeAdded s:shard1 r:core_node3 x:testNodeAdded_shard1_replica_n1]
o.a.s.s.SolrIndexSearcher Opening
[Searcher@7cf50e0b[testNodeAdded_shard1_replica_n1] main]
[junit4] 2> 1079717 INFO (qtp1515177652-10602) [n:127.0.0.1:51354_solr
c:testNodeAdded s:shard1 r:core_node4 x:testNodeAdded_shard1_replica_n2]
o.a.s.s.SolrIndexSearcher Opening
[Searcher@17ff2dcf[testNodeAdded_shard1_replica_n2] main]
[junit4] 2> 1079718 INFO (qtp1515177652-10604) [n:127.0.0.1:51354_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> 1079719 INFO (qtp1515177652-10602) [n:127.0.0.1:51354_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> 1079719 INFO (qtp1515177652-10604) [n:127.0.0.1:51354_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> 1079719 INFO (qtp1515177652-10602) [n:127.0.0.1:51354_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> 1079719 INFO (qtp1515177652-10604) [n:127.0.0.1:51354_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> 1079719 INFO (qtp1515177652-10604) [n:127.0.0.1:51354_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 1592153424104783872
[junit4] 2> 1079719 INFO (qtp1515177652-10602) [n:127.0.0.1:51354_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> 1079720 INFO (qtp1515177652-10602) [n:127.0.0.1:51354_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 1592153424105832448
[junit4] 2> 1079721 INFO
(searcherExecutor-4069-thread-1-processing-n:127.0.0.1:51354_solr
x:testNodeAdded_shard1_replica_n1 s:shard1 c:testNodeAdded r:core_node3)
[n:127.0.0.1:51354_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@7cf50e0b[testNodeAdded_shard1_replica_n1]
main{ExitableDirectoryReader(UninvertingDirectoryReader())}
[junit4] 2> 1079721 INFO
(searcherExecutor-4068-thread-1-processing-n:127.0.0.1:51354_solr
x:testNodeAdded_shard1_replica_n2 s:shard1 c:testNodeAdded r:core_node4)
[n:127.0.0.1:51354_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@17ff2dcf[testNodeAdded_shard1_replica_n2]
main{ExitableDirectoryReader(UninvertingDirectoryReader())}
[junit4] 2> 1079726 INFO (qtp1515177652-10602) [n:127.0.0.1:51354_solr
c:testNodeAdded s:shard1 r:core_node4 x:testNodeAdded_shard1_replica_n2]
o.a.s.c.ZkShardTerms Failed to save terms, version is not match, retrying
[junit4] 2> 1079734 INFO (qtp1515177652-10604) [n:127.0.0.1:51354_solr
c:testNodeAdded s:shard1 r:core_node3 x:testNodeAdded_shard1_replica_n1]
o.a.s.c.ShardLeaderElectionContext Enough replicas found to continue.
[junit4] 2> 1079734 INFO (qtp1515177652-10604) [n:127.0.0.1:51354_solr
c:testNodeAdded s:shard1 r:core_node3 x:testNodeAdded_shard1_replica_n1]
o.a.s.c.ShardLeaderElectionContext I may be the new leader - try and sync
[junit4] 2> 1079734 INFO (qtp1515177652-10604) [n:127.0.0.1:51354_solr
c:testNodeAdded s:shard1 r:core_node3 x:testNodeAdded_shard1_replica_n1]
o.a.s.c.SyncStrategy Sync replicas to
http://127.0.0.1:51354/solr/testNodeAdded_shard1_replica_n1/
[junit4] 2> 1079734 DEBUG
(OverseerStateUpdate-72077351691354115-127.0.0.1:51354_solr-n_0000000000)
[n:127.0.0.1:51354_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> 1079734 INFO (qtp1515177652-10604) [n:127.0.0.1:51354_solr
c:testNodeAdded s:shard1 r:core_node3 x:testNodeAdded_shard1_replica_n1]
o.a.s.u.PeerSync PeerSync: core=testNodeAdded_shard1_replica_n1
url=http://127.0.0.1:51354/solr START
replicas=[http://127.0.0.1:51354/solr/testNodeAdded_shard1_replica_n2/]
nUpdates=100
[junit4] 2> 1079736 INFO (qtp1515177652-10603) [n:127.0.0.1:51354_solr
c:testNodeAdded s:shard1 r:core_node4 x:testNodeAdded_shard1_replica_n2]
o.a.s.c.S.Request [testNodeAdded_shard1_replica_n2] webapp=/solr path=/get
params={distrib=false&qt=/get&fingerprint=false&getVersions=100&wt=javabin&version=2}
status=0 QTime=0
[junit4] 2> 1079835 DEBUG
(OverseerStateUpdate-72077351691354115-127.0.0.1:51354_solr-n_0000000000)
[n:127.0.0.1:51354_solr ] o.a.s.c.o.ZkStateWriter going to update_collection
/collections/testNodeAdded/state.json version: 2
[junit4] 2> 1079836 INFO
(zkCallback-2407-thread-2-processing-n:127.0.0.1:51354_solr)
[n:127.0.0.1:51354_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> 1079836 INFO
(zkCallback-2407-thread-3-processing-n:127.0.0.1:51354_solr)
[n:127.0.0.1:51354_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> 1080035 INFO (qtp1515177652-10604) [n:127.0.0.1:51354_solr
c:testNodeAdded s:shard1 r:core_node3 x:testNodeAdded_shard1_replica_n1]
o.a.s.u.PeerSync PeerSync: core=testNodeAdded_shard1_replica_n1
url=http://127.0.0.1:51354/solr DONE. We have no versions. sync failed.
[junit4] 2> 1080035 INFO (qtp1515177652-10604) [n:127.0.0.1:51354_solr
c:testNodeAdded s:shard1 r:core_node3 x:testNodeAdded_shard1_replica_n1]
o.a.s.c.SyncStrategy Leader's attempt to sync with shard failed, moving to the
next candidate
[junit4] 2> 1080035 INFO (qtp1515177652-10604) [n:127.0.0.1:51354_solr
c:testNodeAdded s:shard1 r:core_node3 x:testNodeAdded_shard1_replica_n1]
o.a.s.c.ShardLeaderElectionContext We failed sync, but we have no versions - we
can't sync in that case - we were active before, so become leader anyway
[junit4] 2> 1080035 INFO (qtp1515177652-10604) [n:127.0.0.1:51354_solr
c:testNodeAdded s:shard1 r:core_node3 x:testNodeAdded_shard1_replica_n1]
o.a.s.c.ShardLeaderElectionContext Found all replicas participating in
election, clear LIR
[junit4] 2> 1080041 INFO (qtp1515177652-10604) [n:127.0.0.1:51354_solr
c:testNodeAdded s:shard1 r:core_node3 x:testNodeAdded_shard1_replica_n1]
o.a.s.c.ShardLeaderElectionContext I am the new leader:
http://127.0.0.1:51354/solr/testNodeAdded_shard1_replica_n1/ shard1
[junit4] 2> 1080043 DEBUG
(OverseerStateUpdate-72077351691354115-127.0.0.1:51354_solr-n_0000000000)
[n:127.0.0.1:51354_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:51354/solr";,
[junit4] 2> "core":"testNodeAdded_shard1_replica_n1",
[junit4] 2> "state":"active"} current state version: 0
[junit4] 2> 1080145 DEBUG
(OverseerStateUpdate-72077351691354115-127.0.0.1:51354_solr-n_0000000000)
[n:127.0.0.1:51354_solr ] o.a.s.c.o.ZkStateWriter going to update_collection
/collections/testNodeAdded/state.json version: 3
[junit4] 2> 1080145 INFO
(zkCallback-2407-thread-2-processing-n:127.0.0.1:51354_solr)
[n:127.0.0.1:51354_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> 1080145 INFO
(zkCallback-2407-thread-3-processing-n:127.0.0.1:51354_solr)
[n:127.0.0.1:51354_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> 1080194 INFO (qtp1515177652-10604) [n:127.0.0.1:51354_solr
c:testNodeAdded s:shard1 r:core_node3 x:testNodeAdded_shard1_replica_n1]
o.a.s.c.ZkController I am the leader, no recovery necessary
[junit4] 2> 1080197 DEBUG
(OverseerStateUpdate-72077351691354115-127.0.0.1:51354_solr-n_0000000000)
[n:127.0.0.1:51354_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:51354/solr";,
[junit4] 2> "node_name":"127.0.0.1:51354_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> 1080197 DEBUG
(OverseerStateUpdate-72077351691354115-127.0.0.1:51354_solr-n_0000000000)
[n:127.0.0.1:51354_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:51354/solr";,
[junit4] 2> "node_name":"127.0.0.1:51354_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> 1080197 DEBUG
(OverseerStateUpdate-72077351691354115-127.0.0.1:51354_solr-n_0000000000)
[n:127.0.0.1:51354_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:51354/solr","node_name":"127.0.0.1:51354_solr","state":"active","type":"NRT","leader":"true"}
[junit4] 2> 1080197 DEBUG
(OverseerStateUpdate-72077351691354115-127.0.0.1:51354_solr-n_0000000000)
[n:127.0.0.1:51354_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:51354/solr";,
[junit4] 2> "node_name":"127.0.0.1:51354_solr",
[junit4] 2> "state":"active",
[junit4] 2> "type":"NRT",
[junit4] 2> "leader":"true"},
[junit4] 2> "core_node4":{
[junit4] 2> "core":"testNodeAdded_shard1_replica_n2",
[junit4] 2> "base_url":"http://127.0.0.1:51354/solr";,
[junit4] 2> "node_name":"127.0.0.1:51354_solr",
[junit4] 2> "state":"down",
[junit4] 2> "type":"NRT"}}}}}
[junit4] 2> 1080197 INFO (qtp1515177652-10604) [n:127.0.0.1:51354_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=1599
[junit4] 2> 1080236 DEBUG (ScheduledTrigger-4063-thread-2)
[n:127.0.0.1:51354_solr ] o.a.s.c.a.NodeAddedTrigger Running
NodeAddedTrigger node_added_trigger
[junit4] 2> 1080236 DEBUG (ScheduledTrigger-4063-thread-2)
[n:127.0.0.1:51354_solr ] o.a.s.c.a.NodeAddedTrigger Found livenodes: 1
[junit4] 2> 1080303 DEBUG
(OverseerStateUpdate-72077351691354115-127.0.0.1:51354_solr-n_0000000000)
[n:127.0.0.1:51354_solr ] o.a.s.c.o.ZkStateWriter going to update_collection
/collections/testNodeAdded/state.json version: 4
[junit4] 2> 1080304 INFO
(zkCallback-2407-thread-3-processing-n:127.0.0.1:51354_solr)
[n:127.0.0.1:51354_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> 1080304 INFO
(zkCallback-2407-thread-2-processing-n:127.0.0.1:51354_solr)
[n:127.0.0.1:51354_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> 1080743 DEBUG
(OverseerStateUpdate-72077351691354115-127.0.0.1:51354_solr-n_0000000000)
[n:127.0.0.1:51354_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:51354/solr";,
[junit4] 2> "node_name":"127.0.0.1:51354_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> 1080743 DEBUG
(OverseerStateUpdate-72077351691354115-127.0.0.1:51354_solr-n_0000000000)
[n:127.0.0.1:51354_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:51354/solr";,
[junit4] 2> "node_name":"127.0.0.1:51354_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> 1080743 DEBUG
(OverseerStateUpdate-72077351691354115-127.0.0.1:51354_solr-n_0000000000)
[n:127.0.0.1:51354_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:51354/solr","node_name":"127.0.0.1:51354_solr","state":"active","type":"NRT"}
[junit4] 2> 1080743 DEBUG
(OverseerStateUpdate-72077351691354115-127.0.0.1:51354_solr-n_0000000000)
[n:127.0.0.1:51354_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:51354/solr";,
[junit4] 2> "node_name":"127.0.0.1:51354_solr",
[junit4] 2> "state":"active",
[junit4] 2> "type":"NRT",
[junit4] 2> "leader":"true"},
[junit4] 2> "core_node4":{
[junit4] 2> "core":"testNodeAdded_shard1_replica_n2",
[junit4] 2> "base_url":"http://127.0.0.1:51354/solr";,
[junit4] 2> "node_name":"127.0.0.1:51354_solr",
[junit4] 2> "state":"active",
[junit4] 2> "type":"NRT"}}}}}
[junit4] 2> 1080743 INFO (qtp1515177652-10602) [n:127.0.0.1:51354_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=2146
[junit4] 2> 1080746 INFO (qtp1515177652-10600) [n:127.0.0.1:51354_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> 1080849 DEBUG
(OverseerStateUpdate-72077351691354115-127.0.0.1:51354_solr-n_0000000000)
[n:127.0.0.1:51354_solr ] o.a.s.c.o.ZkStateWriter going to update_collection
/collections/testNodeAdded/state.json version: 5
[junit4] 2> 1080850 INFO
(zkCallback-2407-thread-2-processing-n:127.0.0.1:51354_solr)
[n:127.0.0.1:51354_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> 1080850 INFO
(zkCallback-2407-thread-3-processing-n:127.0.0.1:51354_solr)
[n:127.0.0.1:51354_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> 1081246 DEBUG (ScheduledTrigger-4063-thread-2)
[n:127.0.0.1:51354_solr ] o.a.s.c.a.NodeAddedTrigger Running
NodeAddedTrigger node_added_trigger
[junit4] 2> 1081246 DEBUG (ScheduledTrigger-4063-thread-2)
[n:127.0.0.1:51354_solr ] o.a.s.c.a.NodeAddedTrigger Found livenodes: 1
[junit4] 2> 1081756 INFO (qtp1515177652-10600) [n:127.0.0.1:51354_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=3536
[junit4] 2> 1081762 INFO (qtp1515177652-10604) [n:127.0.0.1:51354_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> 1081763 INFO (qtp1515177652-10603) [n:127.0.0.1:51354_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> 1081771 DEBUG (qtp1515177652-10605) [n:127.0.0.1:51354_solr
] o.a.s.c.a.AutoScalingHandler Verified autoscaling configuration
[junit4] 2> 1081771 INFO (qtp1515177652-10605) [n:127.0.0.1:51354_solr
] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/autoscaling
params={wt=javabin&version=2} status=0 QTime=13
[junit4] 2> 1081772 DEBUG
(zkCallback-2407-thread-3-processing-n:127.0.0.1:51354_solr)
[n:127.0.0.1:51354_solr ] o.a.s.c.a.OverseerTriggerThread Refreshing
/autoscaling.json with znode version 7
[junit4] 2> 1081772 INFO
(TEST-ComputePlanActionTest.testNodeAdded-seed#[8E7BBC17670D81CA]) [ ]
o.e.j.s.Server jetty-9.4.8.v20171121, build timestamp:
2017-11-22T06:57:37+09:30, git hash: 82b8fb23f757335bb3329d540ce37a2a2615f0a8
[junit4] 2> 1081773 DEBUG
(zkCallback-2407-thread-3-processing-n:127.0.0.1:51354_solr)
[n:127.0.0.1:51354_solr ] o.a.s.c.a.NodeAddedTrigger Initial livenodes:
[127.0.0.1:51354_solr]
[junit4] 2> 1081773 DEBUG
(zkCallback-2407-thread-3-processing-n:127.0.0.1:51354_solr)
[n:127.0.0.1:51354_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> 1081773 DEBUG
(OverseerAutoScalingTriggerThread-72077351691354115-127.0.0.1:51354_solr-n_0000000000)
[n:127.0.0.1:51354_solr ] o.a.s.c.a.OverseerTriggerThread Processed trigger
updates upto znodeVersion 7
[junit4] 2> 1081773 DEBUG
(OverseerAutoScalingTriggerThread-72077351691354115-127.0.0.1:51354_solr-n_0000000000)
[n:127.0.0.1:51354_solr ] o.a.s.c.a.OverseerTriggerThread -- clean old
nodeLost markers
[junit4] 2> 1081774 DEBUG
(OverseerAutoScalingTriggerThread-72077351691354115-127.0.0.1:51354_solr-n_0000000000)
[n:127.0.0.1:51354_solr ] o.a.s.c.a.OverseerTriggerThread Current
znodeVersion 7, lastZnodeVersion 7
[junit4] 2> 1081774 INFO
(TEST-ComputePlanActionTest.testNodeAdded-seed#[8E7BBC17670D81CA]) [ ]
o.e.j.s.session DefaultSessionIdManager workerName=node0
[junit4] 2> 1081774 INFO
(TEST-ComputePlanActionTest.testNodeAdded-seed#[8E7BBC17670D81CA]) [ ]
o.e.j.s.session No SessionScavenger set, using defaults
[junit4] 2> 1081774 INFO
(TEST-ComputePlanActionTest.testNodeAdded-seed#[8E7BBC17670D81CA]) [ ]
o.e.j.s.session Scavenging every 660000ms
[junit4] 2> 1081774 INFO
(TEST-ComputePlanActionTest.testNodeAdded-seed#[8E7BBC17670D81CA]) [ ]
o.e.j.s.h.ContextHandler Started
o.e.j.s.ServletContextHandler@74ec3ff2{/solr,null,AVAILABLE}
[junit4] 2> 1081774 INFO
(TEST-ComputePlanActionTest.testNodeAdded-seed#[8E7BBC17670D81CA]) [ ]
o.e.j.s.AbstractConnector Started
ServerConnector@60b3253a{HTTP/1.1,[http/1.1]}{127.0.0.1:51365}
[junit4] 2> 1081775 INFO
(TEST-ComputePlanActionTest.testNodeAdded-seed#[8E7BBC17670D81CA]) [ ]
o.e.j.s.Server Started @1090030ms
[junit4] 2> 1081775 INFO
(TEST-ComputePlanActionTest.testNodeAdded-seed#[8E7BBC17670D81CA]) [ ]
o.a.s.c.s.e.JettySolrRunner Jetty properties: {hostContext=/solr,
hostPort=51365}
[junit4] 2> 1081775 ERROR
(TEST-ComputePlanActionTest.testNodeAdded-seed#[8E7BBC17670D81CA]) [ ]
o.a.s.u.StartupLoggingUtils Missing Java Option solr.log.dir. Logging may be
missing or incomplete.
[junit4] 2> 1081775 INFO
(TEST-ComputePlanActionTest.testNodeAdded-seed#[8E7BBC17670D81CA]) [ ]
o.a.s.s.SolrDispatchFilter ___ _ Welcome to Apache Solr? version
8.0.0
[junit4] 2> 1081775 INFO
(TEST-ComputePlanActionTest.testNodeAdded-seed#[8E7BBC17670D81CA]) [ ]
o.a.s.s.SolrDispatchFilter / __| ___| |_ _ Starting in cloud mode on port null
[junit4] 2> 1081775 INFO
(TEST-ComputePlanActionTest.testNodeAdded-seed#[8E7BBC17670D81CA]) [ ]
o.a.s.s.SolrDispatchFilter \__ \/ _ \ | '_| Install dir: null
[junit4] 2> 1081775 INFO
(TEST-ComputePlanActionTest.testNodeAdded-seed#[8E7BBC17670D81CA]) [ ]
o.a.s.s.SolrDispatchFilter |___/\___/_|_| Start time:
2018-02-12T00:37:10.403Z
[junit4] 2> 1081777 INFO (zkConnectionManagerCallback-2419-thread-1) [
] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 1081778 INFO
(TEST-ComputePlanActionTest.testNodeAdded-seed#[8E7BBC17670D81CA]) [ ]
o.a.s.s.SolrDispatchFilter solr.xml found in ZooKeeper. Loading...
[junit4] 2> 1081790 INFO
(TEST-ComputePlanActionTest.testNodeAdded-seed#[8E7BBC17670D81CA]) [ ]
o.a.s.c.ZkContainer Zookeeper client=127.0.0.1:51352/solr
[junit4] 2> 1081792 INFO (zkConnectionManagerCallback-2423-thread-1) [
] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 1081795 INFO
(zkConnectionManagerCallback-2425-thread-1-processing-n:127.0.0.1:51365_solr)
[n:127.0.0.1:51365_solr ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 1081805 INFO
(TEST-ComputePlanActionTest.testNodeAdded-seed#[8E7BBC17670D81CA])
[n:127.0.0.1:51365_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from
ZooKeeper... (0) -> (1)
[junit4] 2> 1081809 INFO
(TEST-ComputePlanActionTest.testNodeAdded-seed#[8E7BBC17670D81CA])
[n:127.0.0.1:51365_solr ] o.a.s.c.Overseer Overseer (id=null) closing
[junit4] 2> 1081812 INFO
(TEST-ComputePlanActionTest.testNodeAdded-seed#[8E7BBC17670D81CA])
[n:127.0.0.1:51365_solr ] o.a.s.c.ZkController Register node as live in
ZooKeeper:/live_nodes/127.0.0.1:51365_solr
[junit4] 2> 1081813 DEBUG
(OverseerStateUpdate-72077351691354115-127.0.0.1:51354_solr-n_0000000000)
[n:127.0.0.1:51354_solr ] o.a.s.c.Overseer processMessage: queueSize: 1,
message = {
[junit4] 2> "operation":"downnode",
[junit4] 2> "node_name":"127.0.0.1:51365_solr"} current state version: 0
[junit4] 2> 1081813 DEBUG
(OverseerStateUpdate-72077351691354115-127.0.0.1:51354_solr-n_0000000000)
[n:127.0.0.1:51354_solr ] o.a.s.c.o.NodeMutator DownNode state invoked for
node: 127.0.0.1:51365_solr
[junit4] 2> 1081815 INFO (zkCallback-2415-thread-2) [ ]
o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (1) -> (2)
[junit4] 2> 1081815 INFO (zkCallback-2415-thread-1) [ ]
o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (1) -> (2)
[junit4] 2> 1081815 INFO
(zkCallback-2407-thread-3-processing-n:127.0.0.1:51354_solr)
[n:127.0.0.1:51354_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from
ZooKeeper... (1) -> (2)
[junit4] 2> 1081816 INFO
(zkCallback-2424-thread-1-processing-n:127.0.0.1:51365_solr)
[n:127.0.0.1:51365_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from
ZooKeeper... (1) -> (2)
[junit4] 2> 1081894 INFO
(TEST-ComputePlanActionTest.testNodeAdded-seed#[8E7BBC17670D81CA])
[n:127.0.0.1:51365_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for
'solr_51365.solr.node' (registry 'solr.node') enabled at server:
com.sun.jmx.mbeanserver.JmxMBeanServer@39954ebe
[junit4] 2> 1081901 INFO
(TEST-ComputePlanActionTest.testNodeAdded-seed#[8E7BBC17670D81CA])
[n:127.0.0.1:51365_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for
'solr_51365.solr.jvm' (registry 'solr.jvm') enabled at server:
com.sun.jmx.mbeanserver.JmxMBeanServer@39954ebe
[junit4] 2> 1081901 INFO
(TEST-ComputePlanActionTest.testNodeAdded-seed#[8E7BBC17670D81CA])
[n:127.0.0.1:51365_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for
'solr_51365.solr.jetty' (registry 'solr.jetty') enabled at server:
com.sun.jmx.mbeanserver.JmxMBeanServer@39954ebe
[junit4] 2> 1081903 INFO
(TEST-ComputePlanActionTest.testNodeAdded-seed#[8E7BBC17670D81CA])
[n:127.0.0.1:51365_solr ] o.a.s.c.CorePropertiesLocator Found 0 core
definitions underneath
/Users/jenkins/workspace/Lucene-Solr-master-MacOSX/solr/build/solr-core/test/J1/temp/solr.cloud.autoscaling.ComputePlanActionTest_8E7BBC17670D81CA-001/tempDir-001/node2/.
[junit4] 2> 1082236 INFO
(OverseerCollectionConfigSetProcessor-72077351691354115-127.0.0.1:51354_solr-n_0000000000)
[n:127.0.0.1:51354_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> 1082251 DEBUG (ScheduledTrigger-4063-thread-2)
[n:127.0.0.1:51354_solr ] o.a.s.c.a.NodeAddedTrigger Running
NodeAddedTrigger node_added_trigger
[junit4] 2> 1082251 DEBUG (ScheduledTrigger-4063-thread-2)
[n:127.0.0.1:51354_solr ] o.a.s.c.a.NodeAddedTrigger Found livenodes: 2
[junit4] 2> 1082251 DEBUG (ScheduledTrigger-4063-thread-2)
[n:127.0.0.1:51354_solr ] o.a.s.c.a.NodeAddedTrigger Tracking new node:
127.0.0.1:51365_solr at time 301482467216655
[junit4] 2> 1083254 DEBUG (ScheduledTrigger-4063-thread-2)
[n:127.0.0.1:51354_solr ] o.a.s.c.a.NodeAddedTrigger Running
NodeAddedTrigger node_added_trigger
[junit4] 2> 1083254 DEBUG (ScheduledTrigger-4063-thread-2)
[n:127.0.0.1:51354_solr ] o.a.s.c.a.NodeAddedTrigger Found livenodes: 2
[junit4] 2> 1083254 DEBUG (ScheduledTrigger-4063-thread-2)
[n:127.0.0.1:51354_solr ] o.a.s.c.a.NodeAddedTrigger NodeAddedTrigger
node_added_trigger firing registered processor for nodes:
[127.0.0.1:51365_solr] added at times [301482467216655], now=301483469813889
[junit4] 2> 1083254 DEBUG (ScheduledTrigger-4063-thread-2)
[n:127.0.0.1:51354_solr ] o.a.s.c.a.ScheduledTriggers ++++++++ Cooldown
inactive - processing event: {
[junit4] 2> "id":"112325b5d4d0fT9n90wy5iw5yx8569pwwutcy42",
[junit4] 2> "source":"node_added_trigger",
[junit4] 2> "eventTime":301482467216655,
[junit4] 2> "eventType":"NODEADDED",
[junit4] 2> "properties":{
[junit4] 2> "eventTimes":[301482467216655],
[junit4] 2> "nodeNames":["127.0.0.1:51365_solr"]}}
[junit4] 2> 1083255 DEBUG (ScheduledTrigger-4063-thread-2)
[n:127.0.0.1:51354_solr ] o.a.s.c.a.ScheduledTriggers Pausing all triggers:
[node_added_trigger]
[junit4] 2> 1083256 INFO (ScheduledTrigger-4063-thread-2)
[n:127.0.0.1:51354_solr ] o.a.s.c.a.SystemLogListener Collection .system
does not exist, disabling logging.
[junit4] 2> 1083256 DEBUG
(AutoscalingActionExecutor-4064-thread-1-processing-n:127.0.0.1:51354_solr)
[n:127.0.0.1:51354_solr ] o.a.s.c.a.ScheduledTriggers -- processing actions
for {
[junit4] 2> "id":"112325b5d4d0fT9n90wy5iw5yx8569pwwutcy42",
[junit4] 2> "source":"node_added_trigger",
[junit4] 2> "eventTime":301482467216655,
[junit4] 2> "eventType":"NODEADDED",
[junit4] 2> "properties":{
[junit4] 2> "eventTimes":[301482467216655],
[junit4] 2> "_enqueue_time_":301483470536056,
[junit4] 2> "nodeNames":["127.0.0.1:51365_solr"]}}
[junit4] 2> 1083256 DEBUG
(AutoscalingActionExecutor-4064-thread-1-processing-n:127.0.0.1:51354_solr)
[n:127.0.0.1:51354_solr ] o.a.s.c.a.ComputePlanAction -- processing event: {
[junit4] 2> "id":"112325b5d4d0fT9n90wy5iw5yx8569pwwutcy42",
[junit4] 2> "source":"node_added_trigger",
[junit4] 2> "eventTime":301482467216655,
[junit4] 2> "eventType":"NODEADDED",
[junit4] 2> "properties":{
[junit4] 2> "eventTimes":[301482467216655],
[junit4] 2> "_enqueue_time_":301483470536056,
[junit4] 2> "nodeNames":["127.0.0.1:51365_solr"]}} with context
properties: {BEFORE_ACTION=[compute_plan]}
[junit4] 2> 1083258 INFO (qtp1515177652-10604) [n:127.0.0.1:51354_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> 1083260 INFO (qtp1515177652-10605) [n:127.0.0.1:51354_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> 1083263 INFO (qtp286241179-10652) [n:127.0.0.1:51365_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> 1083266 INFO
(AutoscalingActionExecutor-4064-thread-1-processing-n:127.0.0.1:51354_solr)
[n:127.0.0.1:51354_solr ] o.a.s.c.a.ComputePlanAction Computed Plan:
action=MOVEREPLICA&collection=testNodeAdded&targetNode=127.0.0.1:51365_solr&inPlaceMove=true&replica=core_node3
[junit4] 2> 1083266 INFO
(AutoscalingActionExecutor-4064-thread-1-processing-n:127.0.0.1:51354_solr)
[n:127.0.0.1:51354_solr ] o.a.s.c.s.c.a.PolicyHelper returnSession,
curr-time 301483481 sessionWrapper.createTime 301483480792294,
this.sessionWrapper.createTime 301483480792294
[junit4] 2> 1083268 DEBUG
(TEST-ComputePlanActionTest.testNodeAdded-seed#[8E7BBC17670D81CA]) [ ]
o.a.s.c.a.ComputePlanActionTest -------------_ FINAL STATE --------------
[junit4] 2> 1083271 INFO (qtp1515177652-10604) [n:127.0.0.1:51354_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> 1083272 DEBUG
(TEST-ComputePlanActionTest.testNodeAdded-seed#[8E7BBC17670D81CA]) [ ]
o.a.s.c.a.ComputePlanActionTest * Node values: 127.0.0.1:51354_solr
[junit4] 2> {
[junit4] 2> "node":"127.0.0.1:51354_solr",
[junit4] 2> "cores":2,
[junit4] 2> "port":"51354",
[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":13.22183609008789}
[junit4] 2> 1083273 DEBUG
(AutoscalingActionExecutor-4064-thread-1-processing-n:127.0.0.1:51354_solr)
[n:127.0.0.1:51354_solr ] o.a.s.c.a.ScheduledTriggers Resuming trigger:
node_added_trigger after 5000ms
[junit4] 2> 1083273 DEBUG
(AutoscalingActionExecutor-4064-thread-1-processing-n:127.0.0.1:51354_solr)
[n:127.0.0.1:51354_solr ] o.a.s.c.a.ScheduledTriggers -- processing took 16
ms for event id=112325b5d4d0fT9n90wy5iw5yx8569pwwutcy42
[junit4] 2> 1083274 INFO (qtp286241179-10654) [n:127.0.0.1:51365_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> 1083274 DEBUG
(TEST-ComputePlanActionTest.testNodeAdded-seed#[8E7BBC17670D81CA]) [ ]
o.a.s.c.a.ComputePlanActionTest * Node values: 127.0.0.1:51365_solr
[junit4] 2> {
[junit4] 2> "node":"127.0.0.1:51365_solr",
[junit4] 2> "cores":0,
[junit4] 2> "port":"51365",
[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":13.22183609008789}
[junit4] 2> 1083274 DEBUG
(TEST-ComputePlanActionTest.testNodeAdded-seed#[8E7BBC17670D81CA]) [ ]
o.a.s.c.a.ComputePlanActionTest * Live nodes: [127.0.0.1:51354_solr,
127.0.0.1:51365_solr]
[junit4] 2> 1083275 DEBUG
(TEST-ComputePlanActionTest.testNodeAdded-seed#[8E7BBC17670D81CA]) [ ]
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:51354/solr";,
[junit4] 2> "node_name":"127.0.0.1:51354_solr",
[junit4] 2> "state":"active",
[junit4] 2> "type":"NRT",
[junit4] 2> "leader":"true"},
[junit4] 2> "core_node4":{
[junit4] 2> "core":"testNodeAdded_shard1_replica_n2",
[junit4] 2> "base_url":"http://127.0.0.1:51354/solr";,
[junit4] 2> "node_name":"127.0.0.1:51354_solr",
[junit4] 2> "state":"active",
[junit4] 2> "type":"NRT"}}}},
[junit4] 2> "router":{"name":"compositeId"},
[junit4] 2> "maxShardsPerNode":"1",
[junit4] 2> "autoAddReplicas":"false",
[junit4] 2> "nrtReplicas":"2",
[junit4] 2> "tlogReplicas":"0"}
[junit4] 2> 1083275 INFO
(TEST-ComputePlanActionTest.testNodeAdded-seed#[8E7BBC17670D81CA]) [ ]
o.a.s.SolrTestCaseJ4 ###Ending testNodeAdded
[junit4] 2> 1083309 INFO
(TEST-ComputePlanActionTest.testNodeLost-seed#[8E7BBC17670D81CA]) [ ]
o.a.s.SolrTestCaseJ4 ###Starting testNodeLost
[junit4] 2> 1083311 DEBUG
(zkCallback-2407-thread-3-processing-n:127.0.0.1:51354_solr)
[n:127.0.0.1:51354_solr ] o.a.s.c.a.OverseerTriggerThread Refreshing
/autoscaling.json with znode version 8
[junit4] 2> 1083311 DEBUG
(OverseerAutoScalingTriggerThread-72077351691354115-127.0.0.1:51354_solr-n_0000000000)
[n:127.0.0.1:51354_solr ] o.a.s.c.a.OverseerTriggerThread Processed trigger
updates upto znodeVersion 8
[junit4] 2> 1083312 INFO
(TEST-ComputePlanActionTest.testNodeLost-seed#[8E7BBC17670D81CA]) [ ]
o.e.j.s.AbstractConnector Stopped
ServerConnector@57682d91{HTTP/1.1,[http/1.1]}{127.0.0.1:0}
[junit4] 2> 1083313 INFO
(TEST-ComputePlanActionTest.testNodeLost-seed#[8E7BBC17670D81CA]) [ ]
o.a.s.c.CoreContainer Shutting down CoreContainer instance=290538766
[junit4] 2> 1083313 INFO
(TEST-ComputePlanActionTest.testNodeLost-seed#[8E7BBC17670D81CA]) [ ]
o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.node,
tag=null
[junit4] 2> 1083313 INFO
(TEST-ComputePlanActionTest.testNodeLost-seed#[8E7BBC17670D81CA]) [ ]
o.a.s.m.r.SolrJmxReporter Closing reporter
[org.apache.solr.metrics.reporters.SolrJmxReporter@75a22d19: rootName =
solr_51354, domain = solr.node, service url = null, agent id = null] for
registry solr.node / com.codahale.metrics.MetricRegistry@7ead320c
[junit4] 2> 1083314 DEBUG
(OverseerAutoScalingTriggerThread-72077351691354115-127.0.0.1:51354_solr-n_0000000000)
[n:127.0.0.1:51354_solr ] o.a.s.c.a.OverseerTriggerThread -- clean old
nodeLost markers
[junit4] 2> 1083315 DEBUG
(OverseerAutoScalingTriggerThread-72077351691354115-127.0.0.1:51354_solr-n_0000000000)
[n:127.0.0.1:51354_solr ] o.a.s.c.a.OverseerTriggerThread -- clean old
nodeAdded markers
[junit4] 2> 1083315 DEBUG
(OverseerAutoScalingTriggerThread-72077351691354115-127.0.0.1:51354_solr-n_0000000000)
[n:127.0.0.1:51354_solr ] o.a.s.c.a.OverseerTriggerThread Current
znodeVersion 8, lastZnodeVersion 8
[junit4] 2> 1083324 INFO
(TEST-ComputePlanActionTest.testNodeLost-seed#[8E7BBC17670D81CA]) [ ]
o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.jvm,
tag=null
[junit4] 2> 1083324 INFO
(TEST-ComputePlanActionTest.testNodeLost-seed#[8E7BBC17670D81CA]) [ ]
o.a.s.m.r.SolrJmxReporter Closing reporter
[org.apache.solr.metrics.reporters.SolrJmxReporter@13bd57a6: rootName =
solr_51354, domain = solr.jvm, service url = null, agent id = null] for
registry solr.jvm / com.codahale.metrics.MetricRegistry@5698277b
[junit4] 2> 1083328 INFO
(TEST-ComputePlanActionTest.testNodeLost-seed#[8E7BBC17670D81CA]) [ ]
o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.jetty,
tag=null
[junit4] 2> 1083328 INFO
(TEST-ComputePlanActionTest.testNodeLost-seed#[8E7BBC17670D81CA]) [ ]
o.a.s.m.r.SolrJmxReporter Closing reporter
[org.apache.solr.metrics.reporters.SolrJmxReporter@a7482e5: rootName =
solr_51354, domain = solr.jetty, service url = null, agent id = null] for
registry solr.jetty / com.codahale.metrics.MetricRegistry@75229101
[junit4] 2> 1083330 INFO
(TEST-ComputePlanActionTest.testNodeLost-seed#[8E7BBC17670D81CA]) [ ]
o.a.s.c.ZkController Remove node as live in
ZooKeeper:/live_nodes/127.0.0.1:51354_solr
[junit4] 2> 1083331 DEBUG
(OverseerStateUpdate-72077351691354115-127.0.0.1:51354_solr-n_0000000000)
[n:127.0.0.1:51354_solr ] o.a.s.c.Overseer processMessage: queueSize: 1,
message = {
[junit4] 2> "operation":"downnode",
[junit4] 2> "node_name":"127.0.0.1:51354_solr"} current state version: 0
[junit4] 2> 1083332 DEBUG
(OverseerStateUpdate-72077351691354115-127.0.0.1:51354_solr-n_0000000000)
[n:127.0.0.1:51354_solr ] o.a.s.c.o.NodeMutator DownNode state invoked for
node: 127.0.0.1:51354_solr
[junit4] 2> 1083332 DEBUG
(OverseerStateUpdate-72077351691354115-127.0.0.1:51354_solr-n_0000000000)
[n:127.0.0.1:51354_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:51354/solr","node_name":"127.0.0.1:51354_solr","state":"active","type":"NRT","leader":"true"}
to down
[junit4] 2> 1083332 DEBUG
(OverseerStateUpdate-72077351691354115-127.0.0.1:51354_solr-n_0000000000)
[n:127.0.0.1:51354_solr ] o.a.s.c.o.NodeMutator Update replica state for
core_node4:{"core":"testNodeAdded_shard1_replica_n2","base_url":"http://127.0.0.1:51354/solr","node_name":"127.0.0.1:51354_solr","state":"active","type":"NRT"}
to down
[junit4] 2> 1083332 INFO
(TEST-ComputePlanActionTest.testNodeLost-seed#[8E7BBC17670D81CA]) [ ]
o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.cluster,
tag=null
[junit4] 2> 1083333 DEBUG
(OverseerStateUpdate-72077351691354115-127.0.0.1:51354_solr-n_0000000000)
[n:127.0.0.1:51354_solr ] o.a.s.c.o.ZkStateWriter going to update_collection
/collections/testNodeAdded/state.json version: 6
[junit4] 2> 1083334 INFO (zkCallback-2415-thread-1) [ ]
o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (2) -> (1)
[junit4] 2> 1083334 INFO
(zkCallback-2424-thread-1-processing-n:127.0.0.1:51365_solr)
[n:127.0.0.1:51365_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from
ZooKeeper... (2) -> (1)
[junit4] 2> 1083334 INFO (zkCallback-2415-thread-2) [ ]
o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (2) -> (1)
[junit4] 2> 1083334 INFO (coreCloseExecutor-4084-thread-1)
[n:127.0.0.1:51354_solr c:testNodeAdded s:shard1 r:core_node3
x:testNodeAdded_shard1_replica_n1] o.a.s.c.SolrCore
[testNodeAdded_shard1_replica_n1] CLOSING SolrCore
org.apache.solr.core.SolrCore@67bc6f44
[junit4] 2> 1083334 INFO (coreCloseExecutor-4084-thread-1)
[n:127.0.0.1:51354_solr c:testNodeAdded s:shard1 r:core_node3
x:testNodeAdded_shard1_replica_n1] o.a.s.m.SolrMetricManager Closing metric
reporters for registry=solr.core.testNodeAdded.shard1.replica_n1, tag=1740402500
[junit4] 2> 1083335 INFO (coreCloseExecutor-4084-thread-1)
[n:127.0.0.1:51354_solr c:testNodeAdded s:shard1 r:core_node3
x:testNodeAdded_shard1_replica_n1] o.a.s.m.r.SolrJmxReporter Closing reporter
[org.apache.solr.metrics.reporters.SolrJmxReporter@1773bf70: rootName =
solr_51354, domain = solr.core.testNodeAdded.shard1.replica_n1, service url =
null, agent id = null] for registry solr.core.testNodeAdded.shard1.replica_n1 /
com.codahale.metrics.MetricRegistry@3e9d7039
[junit4] 2> 1083335 INFO (coreCloseExecutor-4084-thread-2)
[n:127.0.0.1:51354_solr c:testNodeAdded s:shard1 r:core_node4
x:testNodeAdded_shard1_replica_n2] o.a.s.c.SolrCore
[testNodeAdded_shard1_replica_n2] CLOSING SolrCore
org.apache.solr.core.SolrCore@6c14a3a3
[junit4] 2> 1083335 INFO
(zkCallback-2407-thread-3-processing-n:127.0.0.1:51354_solr)
[n:127.0.0.1:51354_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from
ZooKeeper... (2) -> (1)
[junit4] 2> 1083336 INFO
(zkCallback-2407-thread-2-processing-n:127.0.0.1:51354_solr)
[n:127.0.0.1:51354_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> 1083337 INFO
(zkCallback-2407-thread-1-processing-n:127.0.0.1:51354_solr)
[n:127.0.0.1:51354_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> 1083345 INFO (coreCloseExecutor-4084-thread-1)
[n:127.0.0.1:51354_solr c:testNodeAdded s:shard1 r:core_node3
x:testNodeAdded_shard1_replica_n1] o.a.s.m.SolrMetricManager Closing metric
reporters for registry=solr.collection.testNodeAdded.shard1.leader,
tag=1740402500
[junit4] 2> 1083345 INFO (coreCloseExecutor-4084-thread
[...truncated too long message...]
x:testSelected3_shard1_replica_n2] o.a.s.m.SolrMetricManager Closing metric
reporters for registry=solr.collection.testSelected3.shard1.leader,
tag=1269263697
[junit4] 2> 1117867 INFO (jetty-closer-2398-thread-2) [ ]
o.e.j.s.h.ContextHandler Stopped
o.e.j.s.ServletContextHandler@7d789429{/solr,null,UNAVAILABLE}
[junit4] 2> 1117868 INFO (jetty-closer-2398-thread-2) [ ]
o.e.j.s.session Stopped scavenging
[junit4] 2> 1117869 INFO (jetty-closer-2398-thread-1) [ ]
o.a.s.c.Overseer Overseer
(id=72077351691354134-127.0.0.1:51418_solr-n_0000000005) closing
[junit4] 2> 1117869 INFO
(OverseerStateUpdate-72077351691354134-127.0.0.1:51418_solr-n_0000000005)
[n:127.0.0.1:51418_solr ] o.a.s.c.Overseer Overseer Loop exiting :
127.0.0.1:51418_solr
[junit4] 2> 1117871 WARN
(OverseerAutoScalingTriggerThread-72077351691354134-127.0.0.1:51418_solr-n_0000000005)
[n:127.0.0.1:51418_solr ] o.a.s.c.a.OverseerTriggerThread
OverseerTriggerThread woken up but we are closed, exiting.
[junit4] 2> 1117871 DEBUG (jetty-closer-2398-thread-1) [ ]
o.a.s.c.a.OverseerTriggerThread OverseerTriggerThread has been closed explicitly
[junit4] 2> 1117874 INFO (jetty-closer-2398-thread-1) [ ]
o.e.j.s.h.ContextHandler Stopped
o.e.j.s.ServletContextHandler@18c717b0{/solr,null,UNAVAILABLE}
[junit4] 2> 1117874 INFO (jetty-closer-2398-thread-1) [ ]
o.e.j.s.session Stopped scavenging
[junit4] 2> 1119902 WARN
(zkCallback-2505-thread-1-processing-n:127.0.0.1:51469_solr)
[n:127.0.0.1:51469_solr c:testSelected1 s:shard1 r:core_node5
x:testSelected1_shard1_replica_n2] o.a.s.c.SyncStrategy Closed, skipping sync
up.
[junit4] 2> 1119903 INFO
(zkCallback-2505-thread-1-processing-n:127.0.0.1:51469_solr)
[n:127.0.0.1:51469_solr c:testSelected1 s:shard1 r:core_node5
x:testSelected1_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> 1119903 INFO
(zkCallback-2505-thread-1-processing-n:127.0.0.1:51469_solr)
[n:127.0.0.1:51469_solr c:testSelected1 s:shard1 r:core_node5
x:testSelected1_shard1_replica_n2] o.a.s.c.SolrCore
[testSelected1_shard1_replica_n2] CLOSING SolrCore
org.apache.solr.core.SolrCore@15270c4e
[junit4] 2> 1119903 INFO
(zkCallback-2505-thread-1-processing-n:127.0.0.1:51469_solr)
[n:127.0.0.1:51469_solr c:testSelected1 s:shard1 r:core_node5
x:testSelected1_shard1_replica_n2] o.a.s.m.SolrMetricManager Closing metric
reporters for registry=solr.core.testSelected1.shard1.replica_n2, tag=354880590
[junit4] 2> 1119903 INFO
(zkCallback-2505-thread-1-processing-n:127.0.0.1:51469_solr)
[n:127.0.0.1:51469_solr c:testSelected1 s:shard1 r:core_node5
x:testSelected1_shard1_replica_n2] o.a.s.m.r.SolrJmxReporter Closing reporter
[org.apache.solr.metrics.reporters.SolrJmxReporter@2833f367: rootName =
solr_51469, domain = solr.core.testSelected1.shard1.replica_n2, service url =
null, agent id = null] for registry solr.core.testSelected1.shard1.replica_n2 /
com.codahale.metrics.MetricRegistry@6cbaf7b4
[junit4] 2> 1119917 INFO
(zkCallback-2505-thread-1-processing-n:127.0.0.1:51469_solr)
[n:127.0.0.1:51469_solr c:testSelected1 s:shard1 r:core_node5
x:testSelected1_shard1_replica_n2] o.a.s.m.SolrMetricManager Closing metric
reporters for registry=solr.collection.testSelected1.shard1.leader,
tag=354880590
[junit4] 2> 1119922 INFO (jetty-closer-2398-thread-3) [ ]
o.e.j.s.h.ContextHandler Stopped
o.e.j.s.ServletContextHandler@63d60d11{/solr,null,UNAVAILABLE}
[junit4] 2> 1119922 INFO (jetty-closer-2398-thread-3) [ ]
o.e.j.s.session Stopped scavenging
[junit4] 2> 1119925 ERROR
(SUITE-ComputePlanActionTest-seed#[8E7BBC17670D81CA]-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> 1119926 INFO
(SUITE-ComputePlanActionTest-seed#[8E7BBC17670D81CA]-worker) [ ]
o.a.s.c.ZkTestServer connecting to 127.0.0.1:51352 51352
[junit4] 2> 1120055 INFO (Thread-1680) [ ] o.a.s.c.ZkTestServer
connecting to 127.0.0.1:51352 51352
[junit4] 2> 1120225 WARN (Thread-1680) [ ] o.a.s.c.ZkTestServer Watch
limit violations:
[junit4] 2> Maximum concurrent create/delete watches above limit:
[junit4] 2>
[junit4] 2> 15 /solr/clusterprops.json
[junit4] 2> 15 /solr/aliases.json
[junit4] 2> 11 /solr/configs/conf
[junit4] 2> 10 /solr/security.json
[junit4] 2> 10
/solr/collections/testNodeWithMultipleReplicasLost/terms/shard2
[junit4] 2> 9
/solr/collections/testNodeWithMultipleReplicasLost/terms/shard1
[junit4] 2> 5 /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> 40
/solr/collections/testNodeWithMultipleReplicasLost/state.json
[junit4] 2> 39 /solr/collections/testSelected1/state.json
[junit4] 2> 39 /solr/collections/testSelected2/state.json
[junit4] 2> 31 /solr/collections/testSelected3/state.json
[junit4] 2> 15 /solr/collections/testNodeLost/state.json
[junit4] 2> 15 /solr/clusterstate.json
[junit4] 2> 8 /solr/collections/testNodeAdded/state.json
[junit4] 2> 4
/solr/overseer_elect/election/72077351691354120-127.0.0.1:51365_solr-n_0000000001
[junit4] 2> 3 /solr/autoscaling.json
[junit4] 2> 2
/solr/collections/testNodeWithMultipleReplicasLost/leader_elect/shard1/election/72077351691354137-core_node3-n_0000000000
[junit4] 2> 2
/solr/overseer_elect/election/72077351691354134-127.0.0.1:51418_solr-n_0000000005
[junit4] 2> 2
/solr/collections/testNodeWithMultipleReplicasLost/leader_elect/shard2/election/72077351691354120-core_node9-n_0000000000
[junit4] 2>
[junit4] 2> Maximum concurrent children watches above limit:
[junit4] 2>
[junit4] 2> 59 /solr/live_nodes
[junit4] 2> 42 /solr/collections
[junit4] 2> 3 /solr/overseer/queue
[junit4] 2> 3 /solr/autoscaling/events/.auto_add_replicas
[junit4] 2> 3 /solr/overseer/collection-queue-work
[junit4] 2> 3 /solr/overseer/queue-work
[junit4] 2>
[junit4] 2> NOTE: leaving temporary files on disk at:
/Users/jenkins/workspace/Lucene-Solr-master-MacOSX/solr/build/solr-core/test/J1/temp/solr.cloud.autoscaling.ComputePlanActionTest_8E7BBC17670D81CA-001
[junit4] 2> Feb 12, 2018 12:37:48 AM
com.carrotsearch.randomizedtesting.ThreadLeakControl checkThreadLeaks
[junit4] 2> WARNING: Will linger awaiting termination of 1 leaked
thread(s).
[junit4] 2> NOTE: test params are: codec=Asserting(Lucene70): {},
docValues:{}, maxPointsInLeafNode=327, maxMBSortInHeap=5.958217206471719,
sim=Asserting(org.apache.lucene.search.similarities.AssertingSimilarity@2b48fd04),
locale=ca-ES, timezone=Turkey
[junit4] 2> NOTE: Mac OS X 10.11.6 x86_64/Oracle Corporation 1.8.0_144
(64-bit)/cpus=3,threads=1,free=167169680,total=328880128
[junit4] 2> NOTE: All tests run in this JVM: [TestDynamicFieldResource,
TestFileDictionaryLookup, TestLargeCluster, SyncSliceTest, HdfsNNFailoverTest,
TestRequestStatusCollectionAPI, TestManagedResource, InfixSuggestersTest,
ConnectionManagerTest, DocValuesNotIndexedTest, TestXmlQParserPlugin,
TestManagedSynonymFilterFactory, TestRawResponseWriter,
BlobRepositoryCloudTest, TestDistributedMissingSort, HdfsRecoveryZkTest,
OverseerTaskQueueTest, TestChildDocTransformer, MultiThreadedOCPTest,
SuggesterWFSTTest, TestDFRSimilarityFactory, TestRTGBase, PreAnalyzedFieldTest,
TestLuceneIndexBackCompat, TestStressReorder, SolrCLIZkUtilsTest,
TestMiniSolrCloudClusterSSL, BlockJoinFacetDistribTest,
ConcurrentDeleteAndCreateCollectionTest, DocumentAnalysisRequestHandlerTest,
TestLegacyField, SuggesterTest, TestSortByMinMaxFunction, DocValuesTest,
SimpleCollectionCreateDeleteTest, MetricsConfigTest,
CachingDirectoryFactoryTest, AddSchemaFieldsUpdateProcessorFactoryTest,
UUIDUpdateProcessorFallbackTest, TestDocSet, DataDrivenBlockJoinTest,
IndexBasedSpellCheckerTest, StatsReloadRaceTest, RegexBoostProcessorTest,
TestSchemaResource, TestLegacyNumericUtils, TestReqParamsAPI,
TestShardHandlerFactory, ChaosMonkeyNothingIsSafeTest, ClusterStateUpdateTest,
SystemLogListenerTest, RuleEngineTest, TestRecoveryHdfs,
TestCustomDocTransformer, TestQuerySenderListener,
TestPayloadCheckQParserPlugin, HdfsBasicDistributedZk2Test,
HdfsTlogReplayBufferedWhileIndexingTest, TestSearcherReuse, AtomicUpdatesTest,
TestExactSharedStatsCache, TestLRUStatsCache, MetricTriggerTest,
DistributedFacetPivotLongTailTest, MinimalSchemaTest, TestCloudNestedDocsSort,
TestFieldCacheReopen, NoCacheHeaderTest, AnalysisErrorHandlingTest,
HttpPartitionTest, TestObjectReleaseTracker, TestTlogReplica,
TestSolrConfigHandlerCloud, TestRestManager, ZkShardTermsTest,
HttpSolrCallGetCoreTest, ChangedSchemaMergeTest,
TestDistributedStatsComponentCardinality, SoftAutoCommitTest,
SpellCheckComponentTest, SolrXmlInZkTest, DateRangeFieldTest,
DistributedSuggestComponentTest, ZkControllerTest, BadComponentTest,
DebugComponentTest, SolrCmdDistributorTest, BitVectorTest,
HdfsAutoAddReplicasIntegrationTest, HdfsChaosMonkeyNothingIsSafeTest,
TestSearchPerf, TestComplexPhraseLeadingWildcard, TestAuthorizationFramework,
TestWriterPerf, TestGeoJSONResponseWriter, ComputePlanActionTest]
[junit4] Completed [172/776 (1!)] on J1 in 43.36s, 4 tests, 1 failure <<<
FAILURES!
[...truncated 50473 lines...]
---------------------------------------------------------------------
To unsubscribe, e-mail: [email protected]
For additional commands, e-mail: [email protected]
