Build: https://jenkins.thetaphi.de/job/Lucene-Solr-7.x-Linux/1264/
Java: 64bit/jdk-9.0.1 -XX:-UseCompressedOops -XX:+UseSerialGC
2 tests failed.
FAILED:
org.apache.solr.cloud.autoscaling.ComputePlanActionTest.testNodeWithMultipleReplicasLost
Error Message:
The operations computed by ComputePlanAction should not be null
SolrClientNodeStateProvider.DEBUG{AFTER_ACTION=[compute_plan, null],
BEFORE_ACTION=[compute_plan, null]}
Stack Trace:
java.lang.AssertionError: The operations computed by ComputePlanAction should
not be null SolrClientNodeStateProvider.DEBUG{AFTER_ACTION=[compute_plan,
null], BEFORE_ACTION=[compute_plan, null]}
at
__randomizedtesting.SeedInfo.seed([8FA1EBE83DCC545B:BF610A6AB5BEB507]:0)
at org.junit.Assert.fail(Assert.java:93)
at org.junit.Assert.assertTrue(Assert.java:43)
at org.junit.Assert.assertNotNull(Assert.java:526)
at
org.apache.solr.cloud.autoscaling.ComputePlanActionTest.testNodeWithMultipleReplicasLost(ComputePlanActionTest.java:291)
at
java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
at
java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
at
java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
at java.base/java.lang.reflect.Method.invoke(Method.java:564)
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
org.apache.lucene.util.TestRuleAssertionsRequired$1.evaluate(TestRuleAssertionsRequired.java:53)
at
org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:47)
at
org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:64)
at
org.apache.lucene.util.TestRuleIgnoreTestSuites$1.evaluate(TestRuleIgnoreTestSuites.java:54)
at
com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at
com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:368)
at java.base/java.lang.Thread.run(Thread.java:844)
FAILED:
org.apache.solr.handler.admin.StatsReloadRaceTest.testParallelReloadAndStats
Error Message:
missing 'metrics' element in handler's output: {}
Stack Trace:
java.lang.AssertionError: missing 'metrics' element in handler's output: {}
at
__randomizedtesting.SeedInfo.seed([8FA1EBE83DCC545B:403F8ED1B23D3C04]:0)
at org.junit.Assert.fail(Assert.java:93)
at
org.apache.solr.handler.admin.StatsReloadRaceTest.requestMetrics(StatsReloadRaceTest.java:128)
at
org.apache.solr.handler.admin.StatsReloadRaceTest.testParallelReloadAndStats(StatsReloadRaceTest.java:77)
at
java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
at
java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
at
java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
at java.base/java.lang.reflect.Method.invoke(Method.java:564)
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
org.apache.lucene.util.TestRuleAssertionsRequired$1.evaluate(TestRuleAssertionsRequired.java:53)
at
org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:47)
at
org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:64)
at
org.apache.lucene.util.TestRuleIgnoreTestSuites$1.evaluate(TestRuleIgnoreTestSuites.java:54)
at
com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at
com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:368)
at java.base/java.lang.Thread.run(Thread.java:844)
Build Log:
[...truncated 12837 lines...]
[junit4] Suite: org.apache.solr.cloud.autoscaling.ComputePlanActionTest
[junit4] 2> 1165005 INFO
(SUITE-ComputePlanActionTest-seed#[8FA1EBE83DCC545B]-worker) [ ]
o.a.s.SolrTestCaseJ4 SecureRandom sanity checks:
test.solr.allowed.securerandom=null & java.security.egd=file:/dev/./urandom
[junit4] 2> Creating dataDir:
/home/jenkins/workspace/Lucene-Solr-7.x-Linux/solr/build/solr-core/test/J2/temp/solr.cloud.autoscaling.ComputePlanActionTest_8FA1EBE83DCC545B-001/init-core-data-001
[junit4] 2> 1165005 WARN
(SUITE-ComputePlanActionTest-seed#[8FA1EBE83DCC545B]-worker) [ ]
o.a.s.SolrTestCaseJ4 startTrackingSearchers: numOpens=3 numCloses=3
[junit4] 2> 1165005 INFO
(SUITE-ComputePlanActionTest-seed#[8FA1EBE83DCC545B]-worker) [ ]
o.a.s.SolrTestCaseJ4 Using PointFields (NUMERIC_POINTS_SYSPROP=true)
w/NUMERIC_DOCVALUES_SYSPROP=true
[junit4] 2> 1165006 INFO
(SUITE-ComputePlanActionTest-seed#[8FA1EBE83DCC545B]-worker) [ ]
o.a.s.SolrTestCaseJ4 Randomized ssl (true) and clientAuth (true) via:
@org.apache.solr.util.RandomizeSSL(reason="", ssl=0.0/0.0, value=0.0/0.0,
clientAuth=0.0/0.0)
[junit4] 2> 1165007 INFO
(SUITE-ComputePlanActionTest-seed#[8FA1EBE83DCC545B]-worker) [ ]
o.a.s.c.MiniSolrCloudCluster Starting cluster of 1 servers in
/home/jenkins/workspace/Lucene-Solr-7.x-Linux/solr/build/solr-core/test/J2/temp/solr.cloud.autoscaling.ComputePlanActionTest_8FA1EBE83DCC545B-001/tempDir-001
[junit4] 2> 1165007 INFO
(SUITE-ComputePlanActionTest-seed#[8FA1EBE83DCC545B]-worker) [ ]
o.a.s.c.ZkTestServer STARTING ZK TEST SERVER
[junit4] 2> 1165007 INFO (Thread-3965) [ ] o.a.s.c.ZkTestServer client
port:0.0.0.0/0.0.0.0:0
[junit4] 2> 1165007 INFO (Thread-3965) [ ] o.a.s.c.ZkTestServer
Starting server
[junit4] 2> 1165008 ERROR (Thread-3965) [ ] 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> 1165107 INFO
(SUITE-ComputePlanActionTest-seed#[8FA1EBE83DCC545B]-worker) [ ]
o.a.s.c.ZkTestServer start zk server on port:45779
[junit4] 2> 1165109 INFO (zkConnectionManagerCallback-2101-thread-1) [
] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 1165111 INFO (jetty-launcher-2098-thread-1) [ ]
o.e.j.s.Server jetty-9.4.8.v20171121, build timestamp:
2017-11-22T00:27:37+03:00, git hash: 82b8fb23f757335bb3329d540ce37a2a2615f0a8
[junit4] 2> 1165111 INFO (jetty-launcher-2098-thread-1) [ ]
o.e.j.s.session DefaultSessionIdManager workerName=node0
[junit4] 2> 1165111 INFO (jetty-launcher-2098-thread-1) [ ]
o.e.j.s.session No SessionScavenger set, using defaults
[junit4] 2> 1165111 INFO (jetty-launcher-2098-thread-1) [ ]
o.e.j.s.session Scavenging every 600000ms
[junit4] 2> 1165112 INFO (jetty-launcher-2098-thread-1) [ ]
o.e.j.s.h.ContextHandler Started
o.e.j.s.ServletContextHandler@8e550b4{/solr,null,AVAILABLE}
[junit4] 2> 1165112 INFO (jetty-launcher-2098-thread-1) [ ]
o.e.j.s.AbstractConnector Started ServerConnector@48cdcc8d{SSL,[ssl,
http/1.1]}{127.0.0.1:39655}
[junit4] 2> 1165112 INFO (jetty-launcher-2098-thread-1) [ ]
o.e.j.s.Server Started @1166714ms
[junit4] 2> 1165112 INFO (jetty-launcher-2098-thread-1) [ ]
o.a.s.c.s.e.JettySolrRunner Jetty properties: {hostContext=/solr,
hostPort=39655}
[junit4] 2> 1165113 ERROR (jetty-launcher-2098-thread-1) [ ]
o.a.s.u.StartupLoggingUtils Missing Java Option solr.log.dir. Logging may be
missing or incomplete.
[junit4] 2> 1165113 INFO (jetty-launcher-2098-thread-1) [ ]
o.a.s.s.SolrDispatchFilter ___ _ Welcome to Apache Solr? version
7.3.0
[junit4] 2> 1165113 INFO (jetty-launcher-2098-thread-1) [ ]
o.a.s.s.SolrDispatchFilter / __| ___| |_ _ Starting in cloud mode on port null
[junit4] 2> 1165113 INFO (jetty-launcher-2098-thread-1) [ ]
o.a.s.s.SolrDispatchFilter \__ \/ _ \ | '_| Install dir: null
[junit4] 2> 1165113 INFO (jetty-launcher-2098-thread-1) [ ]
o.a.s.s.SolrDispatchFilter |___/\___/_|_| Start time:
2018-01-29T21:41:10.071239Z
[junit4] 2> 1165116 INFO (zkConnectionManagerCallback-2103-thread-1) [
] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 1165116 INFO (jetty-launcher-2098-thread-1) [ ]
o.a.s.s.SolrDispatchFilter solr.xml found in ZooKeeper. Loading...
[junit4] 2> 1165121 INFO (jetty-launcher-2098-thread-1) [ ]
o.a.s.c.ZkContainer Zookeeper client=127.0.0.1:45779/solr
[junit4] 2> 1165122 INFO (zkConnectionManagerCallback-2107-thread-1) [
] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 1165123 INFO
(zkConnectionManagerCallback-2109-thread-1-processing-n:127.0.0.1:39655_solr)
[n:127.0.0.1:39655_solr ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 1165155 INFO (jetty-launcher-2098-thread-1)
[n:127.0.0.1:39655_solr ] o.a.s.c.Overseer Overseer (id=null) closing
[junit4] 2> 1165155 INFO (jetty-launcher-2098-thread-1)
[n:127.0.0.1:39655_solr ] o.a.s.c.OverseerElectionContext I am going to be
the leader 127.0.0.1:39655_solr
[junit4] 2> 1165155 INFO (jetty-launcher-2098-thread-1)
[n:127.0.0.1:39655_solr ] o.a.s.c.Overseer Overseer
(id=72059247537684483-127.0.0.1:39655_solr-n_0000000000) starting
[junit4] 2> 1165158 DEBUG
(OverseerStateUpdate-72059247537684483-127.0.0.1:39655_solr-n_0000000000)
[n:127.0.0.1:39655_solr ] o.a.s.c.Overseer Starting to work on the main queue
[junit4] 2> 1165158 DEBUG
(OverseerAutoScalingTriggerThread-72059247537684483-127.0.0.1:39655_solr-n_0000000000)
[n:127.0.0.1:39655_solr ] o.a.s.c.a.OverseerTriggerThread Adding
.autoAddReplicas trigger
[junit4] 2> 1165158 INFO (jetty-launcher-2098-thread-1)
[n:127.0.0.1:39655_solr ] o.a.s.c.ZkController Register node as live in
ZooKeeper:/live_nodes/127.0.0.1:39655_solr
[junit4] 2> 1165159 DEBUG
(OverseerAutoScalingTriggerThread-72059247537684483-127.0.0.1:39655_solr-n_0000000000)
[n:127.0.0.1:39655_solr ] o.a.s.c.a.OverseerTriggerThread Refreshing
/autoscaling.json with znode version 1
[junit4] 2> 1165159 INFO
(zkCallback-2108-thread-1-processing-n:127.0.0.1:39655_solr)
[n:127.0.0.1:39655_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from
ZooKeeper... (0) -> (1)
[junit4] 2> 1165159 DEBUG
(OverseerAutoScalingTriggerThread-72059247537684483-127.0.0.1:39655_solr-n_0000000000)
[n:127.0.0.1:39655_solr ] o.a.s.c.a.NodeLostTrigger Initial livenodes:
[127.0.0.1:39655_solr]
[junit4] 2> 1165159 DEBUG
(OverseerAutoScalingTriggerThread-72059247537684483-127.0.0.1:39655_solr-n_0000000000)
[n:127.0.0.1:39655_solr ] o.a.s.c.a.OverseerTriggerThread Current
znodeVersion 1, lastZnodeVersion -1
[junit4] 2> 1165159 DEBUG
(OverseerAutoScalingTriggerThread-72059247537684483-127.0.0.1:39655_solr-n_0000000000)
[n:127.0.0.1:39655_solr ] o.a.s.c.a.OverseerTriggerThread Processed trigger
updates upto znodeVersion 1
[junit4] 2> 1165160 DEBUG
(OverseerAutoScalingTriggerThread-72059247537684483-127.0.0.1:39655_solr-n_0000000000)
[n:127.0.0.1:39655_solr ] o.a.s.c.a.OverseerTriggerThread -- clean old
nodeAdded markers
[junit4] 2> 1165161 DEBUG
(OverseerAutoScalingTriggerThread-72059247537684483-127.0.0.1:39655_solr-n_0000000000)
[n:127.0.0.1:39655_solr ] o.a.s.c.a.OverseerTriggerThread Current
znodeVersion 1, lastZnodeVersion 1
[junit4] 2> 1165161 DEBUG (ScheduledTrigger-4220-thread-1)
[n:127.0.0.1:39655_solr ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger:
.auto_add_replicas with currently live nodes: 1
[junit4] 2> 1165187 INFO (jetty-launcher-2098-thread-1)
[n:127.0.0.1:39655_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for
'solr_39655.solr.node' (registry 'solr.node') enabled at server:
com.sun.jmx.mbeanserver.JmxMBeanServer@e817da5
[junit4] 2> 1165192 INFO (jetty-launcher-2098-thread-1)
[n:127.0.0.1:39655_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for
'solr_39655.solr.jvm' (registry 'solr.jvm') enabled at server:
com.sun.jmx.mbeanserver.JmxMBeanServer@e817da5
[junit4] 2> 1165192 INFO (jetty-launcher-2098-thread-1)
[n:127.0.0.1:39655_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for
'solr_39655.solr.jetty' (registry 'solr.jetty') enabled at server:
com.sun.jmx.mbeanserver.JmxMBeanServer@e817da5
[junit4] 2> 1165193 INFO (jetty-launcher-2098-thread-1)
[n:127.0.0.1:39655_solr ] o.a.s.c.CorePropertiesLocator Found 0 core
definitions underneath
/home/jenkins/workspace/Lucene-Solr-7.x-Linux/solr/build/solr-core/test/J2/temp/solr.cloud.autoscaling.ComputePlanActionTest_8FA1EBE83DCC545B-001/tempDir-001/node1/.
[junit4] 2> 1165201 INFO (zkConnectionManagerCallback-2113-thread-1) [
] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 1165203 INFO (zkConnectionManagerCallback-2117-thread-1) [
] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 1165204 INFO
(SUITE-ComputePlanActionTest-seed#[8FA1EBE83DCC545B]-worker) [ ]
o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (1)
[junit4] 2> 1165204 INFO
(SUITE-ComputePlanActionTest-seed#[8FA1EBE83DCC545B]-worker) [ ]
o.a.s.c.s.i.ZkClientClusterStateProvider Cluster at 127.0.0.1:45779/solr ready
[junit4] 2> 1165209 INFO
(TEST-ComputePlanActionTest.testNodeAdded-seed#[8FA1EBE83DCC545B]) [ ]
o.a.s.SolrTestCaseJ4 ###Starting testNodeAdded
[junit4] 2> 1165210 DEBUG
(zkCallback-2108-thread-1-processing-n:127.0.0.1:39655_solr)
[n:127.0.0.1:39655_solr ] o.a.s.c.a.OverseerTriggerThread Refreshing
/autoscaling.json with znode version 2
[junit4] 2> 1165210 INFO
(TEST-ComputePlanActionTest.testNodeAdded-seed#[8FA1EBE83DCC545B]) [ ]
o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (1)
[junit4] 2> 1165210 DEBUG
(OverseerAutoScalingTriggerThread-72059247537684483-127.0.0.1:39655_solr-n_0000000000)
[n:127.0.0.1:39655_solr ] o.a.s.c.a.OverseerTriggerThread Processed trigger
updates upto znodeVersion 2
[junit4] 2> 1165211 DEBUG
(OverseerAutoScalingTriggerThread-72059247537684483-127.0.0.1:39655_solr-n_0000000000)
[n:127.0.0.1:39655_solr ] o.a.s.c.a.OverseerTriggerThread -- clean old
nodeLost markers
[junit4] 2> 1165211 DEBUG
(OverseerAutoScalingTriggerThread-72059247537684483-127.0.0.1:39655_solr-n_0000000000)
[n:127.0.0.1:39655_solr ] o.a.s.c.a.OverseerTriggerThread -- clean old
nodeAdded markers
[junit4] 2> 1165212 DEBUG
(OverseerAutoScalingTriggerThread-72059247537684483-127.0.0.1:39655_solr-n_0000000000)
[n:127.0.0.1:39655_solr ] o.a.s.c.a.OverseerTriggerThread Current
znodeVersion 2, lastZnodeVersion 2
[junit4] 2> 1165225 INFO (qtp1357068221-11835) [n:127.0.0.1:39655_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> 1165225 DEBUG (qtp1357068221-11834) [n:127.0.0.1:39655_solr
] o.a.s.c.a.AutoScalingHandler Verified autoscaling configuration
[junit4] 2> 1165226 INFO (qtp1357068221-11834) [n:127.0.0.1:39655_solr
] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/autoscaling
params={wt=javabin&version=2} status=0 QTime=4
[junit4] 2> 1165226 DEBUG
(zkCallback-2108-thread-1-processing-n:127.0.0.1:39655_solr)
[n:127.0.0.1:39655_solr ] o.a.s.c.a.OverseerTriggerThread Refreshing
/autoscaling.json with znode version 3
[junit4] 2> 1165226 DEBUG
(OverseerAutoScalingTriggerThread-72059247537684483-127.0.0.1:39655_solr-n_0000000000)
[n:127.0.0.1:39655_solr ] o.a.s.c.a.OverseerTriggerThread Processed trigger
updates upto znodeVersion 3
[junit4] 2> 1165226 DEBUG
(OverseerAutoScalingTriggerThread-72059247537684483-127.0.0.1:39655_solr-n_0000000000)
[n:127.0.0.1:39655_solr ] o.a.s.c.a.OverseerTriggerThread -- clean old
nodeLost markers
[junit4] 2> 1165226 DEBUG
(OverseerAutoScalingTriggerThread-72059247537684483-127.0.0.1:39655_solr-n_0000000000)
[n:127.0.0.1:39655_solr ] o.a.s.c.a.OverseerTriggerThread -- clean old
nodeAdded markers
[junit4] 2> 1165226 DEBUG
(OverseerAutoScalingTriggerThread-72059247537684483-127.0.0.1:39655_solr-n_0000000000)
[n:127.0.0.1:39655_solr ] o.a.s.c.a.OverseerTriggerThread Current
znodeVersion 3, lastZnodeVersion 3
[junit4] 2> 1165230 INFO (qtp1357068221-11836) [n:127.0.0.1:39655_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> 1165230 DEBUG (qtp1357068221-11830) [n:127.0.0.1:39655_solr
] o.a.s.c.a.AutoScalingHandler Verified autoscaling configuration
[junit4] 2> 1165231 INFO (qtp1357068221-11830) [n:127.0.0.1:39655_solr
] o.a.s.s.HttpSolrCall [admin] webapp=null path=/cluster/autoscaling
params={wt=javabin&version=2} status=0 QTime=4
[junit4] 2> 1165231 DEBUG
(zkCallback-2108-thread-1-processing-n:127.0.0.1:39655_solr)
[n:127.0.0.1:39655_solr ] o.a.s.c.a.OverseerTriggerThread Refreshing
/autoscaling.json with znode version 4
[junit4] 2> 1165231 DEBUG
(OverseerAutoScalingTriggerThread-72059247537684483-127.0.0.1:39655_solr-n_0000000000)
[n:127.0.0.1:39655_solr ] o.a.s.c.a.OverseerTriggerThread Processed trigger
updates upto znodeVersion 4
[junit4] 2> 1165231 DEBUG
(OverseerAutoScalingTriggerThread-72059247537684483-127.0.0.1:39655_solr-n_0000000000)
[n:127.0.0.1:39655_solr ] o.a.s.c.a.OverseerTriggerThread -- clean old
nodeLost markers
[junit4] 2> 1165231 DEBUG
(OverseerAutoScalingTriggerThread-72059247537684483-127.0.0.1:39655_solr-n_0000000000)
[n:127.0.0.1:39655_solr ] o.a.s.c.a.OverseerTriggerThread -- clean old
nodeAdded markers
[junit4] 2> 1165231 DEBUG
(OverseerAutoScalingTriggerThread-72059247537684483-127.0.0.1:39655_solr-n_0000000000)
[n:127.0.0.1:39655_solr ] o.a.s.c.a.OverseerTriggerThread Current
znodeVersion 4, lastZnodeVersion 4
[junit4] 2> 1165247 INFO (qtp1357068221-11835) [n:127.0.0.1:39655_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> 1165247 DEBUG (qtp1357068221-11834) [n:127.0.0.1:39655_solr
] o.a.s.c.a.AutoScalingHandler Verified autoscaling configuration
[junit4] 2> 1165247 INFO (qtp1357068221-11834) [n:127.0.0.1:39655_solr
] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/autoscaling
params={wt=javabin&version=2} status=0 QTime=15
[junit4] 2> 1165247 DEBUG
(zkCallback-2108-thread-1-processing-n:127.0.0.1:39655_solr)
[n:127.0.0.1:39655_solr ] o.a.s.c.a.OverseerTriggerThread Refreshing
/autoscaling.json with znode version 5
[junit4] 2> 1165249 INFO (qtp1357068221-11836) [n:127.0.0.1:39655_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> 1165249 DEBUG (qtp1357068221-11830) [n:127.0.0.1:39655_solr
] o.a.s.c.a.AutoScalingHandler Verified autoscaling configuration
[junit4] 2> 1165249 INFO (qtp1357068221-11830) [n:127.0.0.1:39655_solr
] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/autoscaling
params={wt=javabin&version=2} status=0 QTime=1
[junit4] 2> 1165249 DEBUG
(zkCallback-2108-thread-1-processing-n:127.0.0.1:39655_solr)
[n:127.0.0.1:39655_solr ] o.a.s.c.a.NodeAddedTrigger Initial livenodes:
[127.0.0.1:39655_solr]
[junit4] 2> 1165249 DEBUG
(zkCallback-2108-thread-1-processing-n:127.0.0.1:39655_solr)
[n:127.0.0.1:39655_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> 1165249 DEBUG
(OverseerAutoScalingTriggerThread-72059247537684483-127.0.0.1:39655_solr-n_0000000000)
[n:127.0.0.1:39655_solr ] o.a.s.c.a.OverseerTriggerThread Processed trigger
updates upto znodeVersion 5
[junit4] 2> 1165250 INFO (qtp1357068221-11834) [n:127.0.0.1:39655_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> 1165250 DEBUG
(zkCallback-2108-thread-2-processing-n:127.0.0.1:39655_solr)
[n:127.0.0.1:39655_solr ] o.a.s.c.a.OverseerTriggerThread Refreshing
/autoscaling.json with znode version 6
[junit4] 2> 1165250 DEBUG
(zkCallback-2108-thread-2-processing-n:127.0.0.1:39655_solr)
[n:127.0.0.1:39655_solr ] o.a.s.c.a.NodeAddedTrigger Initial livenodes:
[127.0.0.1:39655_solr]
[junit4] 2> 1165250 DEBUG
(zkCallback-2108-thread-2-processing-n:127.0.0.1:39655_solr)
[n:127.0.0.1:39655_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> 1165251 INFO
(OverseerThreadFactory-4222-thread-1-processing-n:127.0.0.1:39655_solr)
[n:127.0.0.1:39655_solr ] o.a.s.c.a.c.CreateCollectionCmd Create collection
testNodeAdded
[junit4] 2> 1165251 WARN
(OverseerThreadFactory-4222-thread-1-processing-n:127.0.0.1:39655_solr)
[n:127.0.0.1:39655_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> 1165252 DEBUG
(OverseerAutoScalingTriggerThread-72059247537684483-127.0.0.1:39655_solr-n_0000000000)
[n:127.0.0.1:39655_solr ] o.a.s.c.a.OverseerTriggerThread -- clean old
nodeLost markers
[junit4] 2> 1165252 DEBUG (ScheduledTrigger-4220-thread-1)
[n:127.0.0.1:39655_solr ] o.a.s.c.a.NodeAddedTrigger Running
NodeAddedTrigger node_added_trigger
[junit4] 2> 1165252 DEBUG (ScheduledTrigger-4220-thread-1)
[n:127.0.0.1:39655_solr ] o.a.s.c.a.NodeAddedTrigger Found livenodes: 1
[junit4] 2> 1165252 DEBUG
(OverseerAutoScalingTriggerThread-72059247537684483-127.0.0.1:39655_solr-n_0000000000)
[n:127.0.0.1:39655_solr ] o.a.s.c.a.OverseerTriggerThread Current
znodeVersion 6, lastZnodeVersion 5
[junit4] 2> 1165252 DEBUG
(OverseerAutoScalingTriggerThread-72059247537684483-127.0.0.1:39655_solr-n_0000000000)
[n:127.0.0.1:39655_solr ] o.a.s.c.a.OverseerTriggerThread Processed trigger
updates upto znodeVersion 6
[junit4] 2> 1165253 INFO (qtp1357068221-11835) [n:127.0.0.1:39655_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> 1165256 DEBUG
(OverseerAutoScalingTriggerThread-72059247537684483-127.0.0.1:39655_solr-n_0000000000)
[n:127.0.0.1:39655_solr ] o.a.s.c.a.OverseerTriggerThread -- clean old
nodeLost markers
[junit4] 2> 1165257 DEBUG
(OverseerAutoScalingTriggerThread-72059247537684483-127.0.0.1:39655_solr-n_0000000000)
[n:127.0.0.1:39655_solr ] o.a.s.c.a.OverseerTriggerThread Current
znodeVersion 6, lastZnodeVersion 6
[junit4] 2> 1165260 INFO
(OverseerThreadFactory-4222-thread-1-processing-n:127.0.0.1:39655_solr)
[n:127.0.0.1:39655_solr ] o.a.s.c.s.c.a.PolicyHelper returnSession,
curr-time 25230656 sessionWrapper.createTime 25230649221005,
this.sessionWrapper.createTime 25230649221005
[junit4] 2> 1165263 DEBUG
(OverseerStateUpdate-72059247537684483-127.0.0.1:39655_solr-n_0000000000)
[n:127.0.0.1:39655_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> 1165263 DEBUG
(OverseerStateUpdate-72059247537684483-127.0.0.1:39655_solr-n_0000000000)
[n:127.0.0.1:39655_solr ] o.a.s.c.o.ClusterStateMutator building a new
cName: testNodeAdded
[junit4] 2> 1165263 DEBUG
(OverseerStateUpdate-72059247537684483-127.0.0.1:39655_solr-n_0000000000)
[n:127.0.0.1:39655_solr ] o.a.s.c.o.ZkStateWriter going to create_collection
/collections/testNodeAdded/state.json
[junit4] 2> 1165364 DEBUG
(OverseerStateUpdate-72059247537684483-127.0.0.1:39655_solr-n_0000000000)
[n:127.0.0.1:39655_solr ] o.a.s.c.Overseer processMessage: queueSize: 1,
message = {
[junit4] 2> "operation":"ADDREPLICA",
[junit4] 2> "collection":"testNodeAdded",
[junit4] 2> "shard":"shard1",
[junit4] 2> "core":"testNodeAdded_shard1_replica_n1",
[junit4] 2> "state":"down",
[junit4] 2> "base_url":"https://127.0.0.1:39655/solr";,
[junit4] 2> "type":"NRT",
[junit4] 2> "waitForFinalState":"false"} current state version: 0
[junit4] 2> 1165364 INFO
(OverseerStateUpdate-72059247537684483-127.0.0.1:39655_solr-n_0000000000)
[n:127.0.0.1:39655_solr ] o.a.s.c.o.SliceMutator createReplica() {
[junit4] 2> "operation":"ADDREPLICA",
[junit4] 2> "collection":"testNodeAdded",
[junit4] 2> "shard":"shard1",
[junit4] 2> "core":"testNodeAdded_shard1_replica_n1",
[junit4] 2> "state":"down",
[junit4] 2> "base_url":"https://127.0.0.1:39655/solr";,
[junit4] 2> "type":"NRT",
[junit4] 2> "waitForFinalState":"false"}
[junit4] 2> 1165365 DEBUG
(OverseerStateUpdate-72059247537684483-127.0.0.1:39655_solr-n_0000000000)
[n:127.0.0.1:39655_solr ] o.a.s.c.o.SliceMutator Old Slice: shard1:{
[junit4] 2> "range":"80000000-7fffffff",
[junit4] 2> "state":"active",
[junit4] 2> "replicas":{}}
[junit4] 2> 1165365 DEBUG
(OverseerStateUpdate-72059247537684483-127.0.0.1:39655_solr-n_0000000000)
[n:127.0.0.1:39655_solr ] o.a.s.c.o.SliceMutator New Slice: shard1:{
[junit4] 2> "range":"80000000-7fffffff",
[junit4] 2> "state":"active",
[junit4] 2> "replicas":{"core_node3":{
[junit4] 2> "core":"testNodeAdded_shard1_replica_n1",
[junit4] 2> "base_url":"https://127.0.0.1:39655/solr";,
[junit4] 2> "state":"down",
[junit4] 2> "node_name":null,
[junit4] 2> "type":"NRT"}}}
[junit4] 2> 1165365 DEBUG
(OverseerStateUpdate-72059247537684483-127.0.0.1:39655_solr-n_0000000000)
[n:127.0.0.1:39655_solr ] o.a.s.c.Overseer processMessage: queueSize: 2,
message = {
[junit4] 2> "operation":"ADDREPLICA",
[junit4] 2> "collection":"testNodeAdded",
[junit4] 2> "shard":"shard1",
[junit4] 2> "core":"testNodeAdded_shard1_replica_n2",
[junit4] 2> "state":"down",
[junit4] 2> "base_url":"https://127.0.0.1:39655/solr";,
[junit4] 2> "type":"NRT",
[junit4] 2> "waitForFinalState":"false"} current state version: 0
[junit4] 2> 1165365 INFO
(OverseerStateUpdate-72059247537684483-127.0.0.1:39655_solr-n_0000000000)
[n:127.0.0.1:39655_solr ] o.a.s.c.o.SliceMutator createReplica() {
[junit4] 2> "operation":"ADDREPLICA",
[junit4] 2> "collection":"testNodeAdded",
[junit4] 2> "shard":"shard1",
[junit4] 2> "core":"testNodeAdded_shard1_replica_n2",
[junit4] 2> "state":"down",
[junit4] 2> "base_url":"https://127.0.0.1:39655/solr";,
[junit4] 2> "type":"NRT",
[junit4] 2> "waitForFinalState":"false"}
[junit4] 2> 1165366 DEBUG
(OverseerStateUpdate-72059247537684483-127.0.0.1:39655_solr-n_0000000000)
[n:127.0.0.1:39655_solr ] o.a.s.c.o.SliceMutator Old Slice: shard1:{
[junit4] 2> "range":"80000000-7fffffff",
[junit4] 2> "state":"active",
[junit4] 2> "replicas":{"core_node3":{
[junit4] 2> "core":"testNodeAdded_shard1_replica_n1",
[junit4] 2> "base_url":"https://127.0.0.1:39655/solr";,
[junit4] 2> "state":"down",
[junit4] 2> "node_name":null,
[junit4] 2> "type":"NRT"}}}
[junit4] 2> 1165366 DEBUG
(OverseerStateUpdate-72059247537684483-127.0.0.1:39655_solr-n_0000000000)
[n:127.0.0.1:39655_solr ] o.a.s.c.o.SliceMutator New Slice: shard1:{
[junit4] 2> "range":"80000000-7fffffff",
[junit4] 2> "state":"active",
[junit4] 2> "replicas":{
[junit4] 2> "core_node3":{
[junit4] 2> "core":"testNodeAdded_shard1_replica_n1",
[junit4] 2> "base_url":"https://127.0.0.1:39655/solr";,
[junit4] 2> "state":"down",
[junit4] 2> "node_name":null,
[junit4] 2> "type":"NRT"},
[junit4] 2> "core_node4":{
[junit4] 2> "core":"testNodeAdded_shard1_replica_n2",
[junit4] 2> "base_url":"https://127.0.0.1:39655/solr";,
[junit4] 2> "state":"down",
[junit4] 2> "node_name":null,
[junit4] 2> "type":"NRT"}}}
[junit4] 2> 1165466 DEBUG
(OverseerStateUpdate-72059247537684483-127.0.0.1:39655_solr-n_0000000000)
[n:127.0.0.1:39655_solr ] o.a.s.c.o.ZkStateWriter going to update_collection
/collections/testNodeAdded/state.json version: 0
[junit4] 2> 1165568 INFO (qtp1357068221-11866) [n:127.0.0.1:39655_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> 1165568 INFO (qtp1357068221-11866) [n:127.0.0.1:39655_solr
] o.a.s.c.TransientSolrCoreCacheDefault Allocating transient cache for
2147483647 transient cores
[junit4] 2> 1165569 INFO (qtp1357068221-11829) [n:127.0.0.1:39655_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> 1165570 DEBUG
(OverseerStateUpdate-72059247537684483-127.0.0.1:39655_solr-n_0000000000)
[n:127.0.0.1:39655_solr ] o.a.s.c.Overseer processMessage: queueSize: 1,
message = {
[junit4] 2> "core":"testNodeAdded_shard1_replica_n2",
[junit4] 2> "core_node_name":"core_node4",
[junit4] 2> "roles":null,
[junit4] 2> "base_url":"https://127.0.0.1:39655/solr";,
[junit4] 2> "node_name":"127.0.0.1:39655_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> 1165570 DEBUG
(OverseerStateUpdate-72059247537684483-127.0.0.1:39655_solr-n_0000000000)
[n:127.0.0.1:39655_solr ] o.a.s.c.o.ReplicaMutator Update state numShards=1
message={
[junit4] 2> "core":"testNodeAdded_shard1_replica_n2",
[junit4] 2> "core_node_name":"core_node4",
[junit4] 2> "roles":null,
[junit4] 2> "base_url":"https://127.0.0.1:39655/solr";,
[junit4] 2> "node_name":"127.0.0.1:39655_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> 1165570 DEBUG
(OverseerStateUpdate-72059247537684483-127.0.0.1:39655_solr-n_0000000000)
[n:127.0.0.1:39655_solr ] o.a.s.c.o.ReplicaMutator Will update state for
replica:
core_node4:{"core":"testNodeAdded_shard1_replica_n2","base_url":"https://127.0.0.1:39655/solr","node_name":"127.0.0.1:39655_solr","state":"down","type":"NRT"}
[junit4] 2> 1165570 DEBUG
(OverseerStateUpdate-72059247537684483-127.0.0.1:39655_solr-n_0000000000)
[n:127.0.0.1:39655_solr ] o.a.s.c.o.ReplicaMutator Collection is now:
DocCollection(testNodeAdded//collections/testNodeAdded/state.json/1)={
[junit4] 2> "pullReplicas":"0",
[junit4] 2> "replicationFactor":"2",
[junit4] 2> "router":{"name":"compositeId"},
[junit4] 2> "maxShardsPerNode":"1",
[junit4] 2> "autoAddReplicas":"false",
[junit4] 2> "nrtReplicas":"2",
[junit4] 2> "tlogReplicas":"0",
[junit4] 2> "shards":{"shard1":{
[junit4] 2> "range":"80000000-7fffffff",
[junit4] 2> "state":"active",
[junit4] 2> "replicas":{
[junit4] 2> "core_node3":{
[junit4] 2> "core":"testNodeAdded_shard1_replica_n1",
[junit4] 2> "base_url":"https://127.0.0.1:39655/solr";,
[junit4] 2> "state":"down",
[junit4] 2> "node_name":null,
[junit4] 2> "type":"NRT"},
[junit4] 2> "core_node4":{
[junit4] 2> "core":"testNodeAdded_shard1_replica_n2",
[junit4] 2> "base_url":"https://127.0.0.1:39655/solr";,
[junit4] 2> "node_name":"127.0.0.1:39655_solr",
[junit4] 2> "state":"down",
[junit4] 2> "type":"NRT"}}}}}
[junit4] 2> 1165570 DEBUG
(OverseerStateUpdate-72059247537684483-127.0.0.1:39655_solr-n_0000000000)
[n:127.0.0.1:39655_solr ] o.a.s.c.Overseer processMessage: queueSize: 2,
message = {
[junit4] 2> "core":"testNodeAdded_shard1_replica_n1",
[junit4] 2> "core_node_name":"core_node3",
[junit4] 2> "roles":null,
[junit4] 2> "base_url":"https://127.0.0.1:39655/solr";,
[junit4] 2> "node_name":"127.0.0.1:39655_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> 1165570 DEBUG
(OverseerStateUpdate-72059247537684483-127.0.0.1:39655_solr-n_0000000000)
[n:127.0.0.1:39655_solr ] o.a.s.c.o.ReplicaMutator Update state numShards=1
message={
[junit4] 2> "core":"testNodeAdded_shard1_replica_n1",
[junit4] 2> "core_node_name":"core_node3",
[junit4] 2> "roles":null,
[junit4] 2> "base_url":"https://127.0.0.1:39655/solr";,
[junit4] 2> "node_name":"127.0.0.1:39655_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> 1165570 DEBUG
(OverseerStateUpdate-72059247537684483-127.0.0.1:39655_solr-n_0000000000)
[n:127.0.0.1:39655_solr ] o.a.s.c.o.ReplicaMutator Will update state for
replica:
core_node3:{"core":"testNodeAdded_shard1_replica_n1","base_url":"https://127.0.0.1:39655/solr","node_name":"127.0.0.1:39655_solr","state":"down","type":"NRT"}
[junit4] 2> 1165570 DEBUG
(OverseerStateUpdate-72059247537684483-127.0.0.1:39655_solr-n_0000000000)
[n:127.0.0.1:39655_solr ] o.a.s.c.o.ReplicaMutator Collection is now:
DocCollection(testNodeAdded//collections/testNodeAdded/state.json/1)={
[junit4] 2> "pullReplicas":"0",
[junit4] 2> "replicationFactor":"2",
[junit4] 2> "router":{"name":"compositeId"},
[junit4] 2> "maxShardsPerNode":"1",
[junit4] 2> "autoAddReplicas":"false",
[junit4] 2> "nrtReplicas":"2",
[junit4] 2> "tlogReplicas":"0",
[junit4] 2> "shards":{"shard1":{
[junit4] 2> "range":"80000000-7fffffff",
[junit4] 2> "state":"active",
[junit4] 2> "replicas":{
[junit4] 2> "core_node3":{
[junit4] 2> "core":"testNodeAdded_shard1_replica_n1",
[junit4] 2> "base_url":"https://127.0.0.1:39655/solr";,
[junit4] 2> "node_name":"127.0.0.1:39655_solr",
[junit4] 2> "state":"down",
[junit4] 2> "type":"NRT"},
[junit4] 2> "core_node4":{
[junit4] 2> "core":"testNodeAdded_shard1_replica_n2",
[junit4] 2> "base_url":"https://127.0.0.1:39655/solr";,
[junit4] 2> "node_name":"127.0.0.1:39655_solr",
[junit4] 2> "state":"down",
[junit4] 2> "type":"NRT"}}}}}
[junit4] 2> 1165671 DEBUG
(OverseerStateUpdate-72059247537684483-127.0.0.1:39655_solr-n_0000000000)
[n:127.0.0.1:39655_solr ] o.a.s.c.o.ZkStateWriter going to update_collection
/collections/testNodeAdded/state.json version: 1
[junit4] 2> 1165671 INFO
(zkCallback-2108-thread-1-processing-n:127.0.0.1:39655_solr)
[n:127.0.0.1:39655_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> 1165671 INFO
(zkCallback-2108-thread-2-processing-n:127.0.0.1:39655_solr)
[n:127.0.0.1:39655_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> 1165671 INFO
(zkCallback-2108-thread-3-processing-n:127.0.0.1:39655_solr)
[n:127.0.0.1:39655_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> 1166253 DEBUG (ScheduledTrigger-4220-thread-2)
[n:127.0.0.1:39655_solr ] o.a.s.c.a.NodeAddedTrigger Running
NodeAddedTrigger node_added_trigger
[junit4] 2> 1166253 DEBUG (ScheduledTrigger-4220-thread-2)
[n:127.0.0.1:39655_solr ] o.a.s.c.a.NodeAddedTrigger Found livenodes: 1
[junit4] 2> 1166575 INFO (qtp1357068221-11866) [n:127.0.0.1:39655_solr
c:testNodeAdded s:shard1 r:core_node4 x:testNodeAdded_shard1_replica_n2]
o.a.s.c.SolrConfig Using Lucene MatchVersion: 7.3.0
[junit4] 2> 1166576 INFO (qtp1357068221-11829) [n:127.0.0.1:39655_solr
c:testNodeAdded s:shard1 r:core_node3 x:testNodeAdded_shard1_replica_n1]
o.a.s.c.SolrConfig Using Lucene MatchVersion: 7.3.0
[junit4] 2> 1166580 INFO (qtp1357068221-11866) [n:127.0.0.1:39655_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> 1166581 INFO (qtp1357068221-11829) [n:127.0.0.1:39655_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> 1166582 INFO (qtp1357068221-11866) [n:127.0.0.1:39655_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> 1166582 INFO (qtp1357068221-11866) [n:127.0.0.1:39655_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> 1166584 INFO (qtp1357068221-11866) [n:127.0.0.1:39655_solr
c:testNodeAdded s:shard1 r:core_node4 x:testNodeAdded_shard1_replica_n2]
o.a.s.m.r.SolrJmxReporter JMX monitoring for
'solr_39655.solr.core.testNodeAdded.shard1.replica_n2' (registry
'solr.core.testNodeAdded.shard1.replica_n2') enabled at server:
com.sun.jmx.mbeanserver.JmxMBeanServer@e817da5
[junit4] 2> 1166584 INFO (qtp1357068221-11829) [n:127.0.0.1:39655_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> 1166584 INFO (qtp1357068221-11866) [n:127.0.0.1:39655_solr
c:testNodeAdded s:shard1 r:core_node4 x:testNodeAdded_shard1_replica_n2]
o.a.s.c.SolrCore solr.RecoveryStrategy.Builder
[junit4] 2> 1166584 INFO (qtp1357068221-11829) [n:127.0.0.1:39655_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> 1166584 INFO (qtp1357068221-11866) [n:127.0.0.1:39655_solr
c:testNodeAdded s:shard1 r:core_node4 x:testNodeAdded_shard1_replica_n2]
o.a.s.c.SolrCore [[testNodeAdded_shard1_replica_n2] ] Opening new SolrCore at
[/home/jenkins/workspace/Lucene-Solr-7.x-Linux/solr/build/solr-core/test/J2/temp/solr.cloud.autoscaling.ComputePlanActionTest_8FA1EBE83DCC545B-001/tempDir-001/node1/testNodeAdded_shard1_replica_n2],
dataDir=[/home/jenkins/workspace/Lucene-Solr-7.x-Linux/solr/build/solr-core/test/J2/temp/solr.cloud.autoscaling.ComputePlanActionTest_8FA1EBE83DCC545B-001/tempDir-001/node1/./testNodeAdded_shard1_replica_n2/data/]
[junit4] 2> 1166585 INFO (qtp1357068221-11829) [n:127.0.0.1:39655_solr
c:testNodeAdded s:shard1 r:core_node3 x:testNodeAdded_shard1_replica_n1]
o.a.s.m.r.SolrJmxReporter JMX monitoring for
'solr_39655.solr.core.testNodeAdded.shard1.replica_n1' (registry
'solr.core.testNodeAdded.shard1.replica_n1') enabled at server:
com.sun.jmx.mbeanserver.JmxMBeanServer@e817da5
[junit4] 2> 1166585 INFO (qtp1357068221-11829) [n:127.0.0.1:39655_solr
c:testNodeAdded s:shard1 r:core_node3 x:testNodeAdded_shard1_replica_n1]
o.a.s.c.SolrCore solr.RecoveryStrategy.Builder
[junit4] 2> 1166585 INFO (qtp1357068221-11829) [n:127.0.0.1:39655_solr
c:testNodeAdded s:shard1 r:core_node3 x:testNodeAdded_shard1_replica_n1]
o.a.s.c.SolrCore [[testNodeAdded_shard1_replica_n1] ] Opening new SolrCore at
[/home/jenkins/workspace/Lucene-Solr-7.x-Linux/solr/build/solr-core/test/J2/temp/solr.cloud.autoscaling.ComputePlanActionTest_8FA1EBE83DCC545B-001/tempDir-001/node1/testNodeAdded_shard1_replica_n1],
dataDir=[/home/jenkins/workspace/Lucene-Solr-7.x-Linux/solr/build/solr-core/test/J2/temp/solr.cloud.autoscaling.ComputePlanActionTest_8FA1EBE83DCC545B-001/tempDir-001/node1/./testNodeAdded_shard1_replica_n1/data/]
[junit4] 2> 1166638 INFO (qtp1357068221-11829) [n:127.0.0.1:39655_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> 1166638 INFO (qtp1357068221-11866) [n:127.0.0.1:39655_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> 1166638 INFO (qtp1357068221-11866) [n:127.0.0.1:39655_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> 1166638 INFO (qtp1357068221-11829) [n:127.0.0.1:39655_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> 1166639 INFO (qtp1357068221-11829) [n:127.0.0.1:39655_solr
c:testNodeAdded s:shard1 r:core_node3 x:testNodeAdded_shard1_replica_n1]
o.a.s.u.CommitTracker Hard AutoCommit: disabled
[junit4] 2> 1166639 INFO (qtp1357068221-11866) [n:127.0.0.1:39655_solr
c:testNodeAdded s:shard1 r:core_node4 x:testNodeAdded_shard1_replica_n2]
o.a.s.u.CommitTracker Hard AutoCommit: disabled
[junit4] 2> 1166639 INFO (qtp1357068221-11829) [n:127.0.0.1:39655_solr
c:testNodeAdded s:shard1 r:core_node3 x:testNodeAdded_shard1_replica_n1]
o.a.s.u.CommitTracker Soft AutoCommit: disabled
[junit4] 2> 1166639 INFO (qtp1357068221-11866) [n:127.0.0.1:39655_solr
c:testNodeAdded s:shard1 r:core_node4 x:testNodeAdded_shard1_replica_n2]
o.a.s.u.CommitTracker Soft AutoCommit: disabled
[junit4] 2> 1166640 INFO (qtp1357068221-11866) [n:127.0.0.1:39655_solr
c:testNodeAdded s:shard1 r:core_node4 x:testNodeAdded_shard1_replica_n2]
o.a.s.s.SolrIndexSearcher Opening
[Searcher@7d504acf[testNodeAdded_shard1_replica_n2] main]
[junit4] 2> 1166640 INFO (qtp1357068221-11829) [n:127.0.0.1:39655_solr
c:testNodeAdded s:shard1 r:core_node3 x:testNodeAdded_shard1_replica_n1]
o.a.s.s.SolrIndexSearcher Opening
[Searcher@29c5f629[testNodeAdded_shard1_replica_n1] main]
[junit4] 2> 1166641 INFO (qtp1357068221-11866) [n:127.0.0.1:39655_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> 1166641 INFO (qtp1357068221-11829) [n:127.0.0.1:39655_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> 1166641 INFO (qtp1357068221-11866) [n:127.0.0.1:39655_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> 1166641 INFO (qtp1357068221-11829) [n:127.0.0.1:39655_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> 1166642 INFO (qtp1357068221-11866) [n:127.0.0.1:39655_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> 1166642 INFO (qtp1357068221-11829) [n:127.0.0.1:39655_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> 1166642 INFO
(searcherExecutor-4225-thread-1-processing-n:127.0.0.1:39655_solr
x:testNodeAdded_shard1_replica_n2 s:shard1 c:testNodeAdded r:core_node4)
[n:127.0.0.1:39655_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@7d504acf[testNodeAdded_shard1_replica_n2]
main{ExitableDirectoryReader(UninvertingDirectoryReader())}
[junit4] 2> 1166642 INFO
(searcherExecutor-4226-thread-1-processing-n:127.0.0.1:39655_solr
x:testNodeAdded_shard1_replica_n1 s:shard1 c:testNodeAdded r:core_node3)
[n:127.0.0.1:39655_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@29c5f629[testNodeAdded_shard1_replica_n1]
main{ExitableDirectoryReader(UninvertingDirectoryReader())}
[junit4] 2> 1166642 INFO (qtp1357068221-11866) [n:127.0.0.1:39655_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 1590964593990041600
[junit4] 2> 1166642 INFO (qtp1357068221-11829) [n:127.0.0.1:39655_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 1590964593990041600
[junit4] 2> 1166646 INFO (qtp1357068221-11866) [n:127.0.0.1:39655_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> 1166648 INFO (qtp1357068221-11829) [n:127.0.0.1:39655_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> 1166648 INFO (qtp1357068221-11829) [n:127.0.0.1:39655_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> 1166648 INFO (qtp1357068221-11829) [n:127.0.0.1:39655_solr
c:testNodeAdded s:shard1 r:core_node3 x:testNodeAdded_shard1_replica_n1]
o.a.s.c.SyncStrategy Sync replicas to
https://127.0.0.1:39655/solr/testNodeAdded_shard1_replica_n1/
[junit4] 2> 1166648 DEBUG
(OverseerStateUpdate-72059247537684483-127.0.0.1:39655_solr-n_0000000000)
[n:127.0.0.1:39655_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> 1166648 INFO (qtp1357068221-11829) [n:127.0.0.1:39655_solr
c:testNodeAdded s:shard1 r:core_node3 x:testNodeAdded_shard1_replica_n1]
o.a.s.u.PeerSync PeerSync: core=testNodeAdded_shard1_replica_n1
url=https://127.0.0.1:39655/solr START
replicas=[https://127.0.0.1:39655/solr/testNodeAdded_shard1_replica_n2/]
nUpdates=100
[junit4] 2> 1166650 INFO (qtp1357068221-11867) [n:127.0.0.1:39655_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> 1166748 DEBUG
(OverseerStateUpdate-72059247537684483-127.0.0.1:39655_solr-n_0000000000)
[n:127.0.0.1:39655_solr ] o.a.s.c.o.ZkStateWriter going to update_collection
/collections/testNodeAdded/state.json version: 2
[junit4] 2> 1166749 INFO
(zkCallback-2108-thread-2-processing-n:127.0.0.1:39655_solr)
[n:127.0.0.1:39655_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> 1166749 INFO
(zkCallback-2108-thread-1-processing-n:127.0.0.1:39655_solr)
[n:127.0.0.1:39655_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> 1166749 INFO
(zkCallback-2108-thread-3-processing-n:127.0.0.1:39655_solr)
[n:127.0.0.1:39655_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> 1166948 INFO (qtp1357068221-11829) [n:127.0.0.1:39655_solr
c:testNodeAdded s:shard1 r:core_node3 x:testNodeAdded_shard1_replica_n1]
o.a.s.u.PeerSync PeerSync: core=testNodeAdded_shard1_replica_n1
url=https://127.0.0.1:39655/solr DONE. We have no versions. sync failed.
[junit4] 2> 1166948 INFO (qtp1357068221-11829) [n:127.0.0.1:39655_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> 1166948 INFO (qtp1357068221-11829) [n:127.0.0.1:39655_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> 1166948 INFO (qtp1357068221-11829) [n:127.0.0.1:39655_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> 1166950 INFO (qtp1357068221-11829) [n:127.0.0.1:39655_solr
c:testNodeAdded s:shard1 r:core_node3 x:testNodeAdded_shard1_replica_n1]
o.a.s.c.ShardLeaderElectionContext I am the new leader:
https://127.0.0.1:39655/solr/testNodeAdded_shard1_replica_n1/ shard1
[junit4] 2> 1166950 DEBUG
(OverseerStateUpdate-72059247537684483-127.0.0.1:39655_solr-n_0000000000)
[n:127.0.0.1:39655_solr ] o.a.s.c.Overseer processMessage: queueSize: 1,
message = {
[junit4] 2> "operation":"leader",
[junit4] 2> "shard":"shard1",
[junit4] 2> "collection":"testNodeAdded",
[junit4] 2> "base_url":"https://127.0.0.1:39655/solr";,
[junit4] 2> "core":"testNodeAdded_shard1_replica_n1",
[junit4] 2> "state":"active"} current state version: 0
[junit4] 2> 1167051 DEBUG
(OverseerStateUpdate-72059247537684483-127.0.0.1:39655_solr-n_0000000000)
[n:127.0.0.1:39655_solr ] o.a.s.c.o.ZkStateWriter going to update_collection
/collections/testNodeAdded/state.json version: 3
[junit4] 2> 1167051 INFO
(zkCallback-2108-thread-1-processing-n:127.0.0.1:39655_solr)
[n:127.0.0.1:39655_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> 1167051 INFO
(zkCallback-2108-thread-3-processing-n:127.0.0.1:39655_solr)
[n:127.0.0.1:39655_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> 1167051 INFO
(zkCallback-2108-thread-2-processing-n:127.0.0.1:39655_solr)
[n:127.0.0.1:39655_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> 1167101 INFO (qtp1357068221-11829) [n:127.0.0.1:39655_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> 1167102 DEBUG
(OverseerStateUpdate-72059247537684483-127.0.0.1:39655_solr-n_0000000000)
[n:127.0.0.1:39655_solr ] o.a.s.c.Overseer processMessage: queueSize: 1,
message = {
[junit4] 2> "core":"testNodeAdded_shard1_replica_n1",
[junit4] 2> "core_node_name":"core_node3",
[junit4] 2> "roles":null,
[junit4] 2> "base_url":"https://127.0.0.1:39655/solr";,
[junit4] 2> "node_name":"127.0.0.1:39655_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> 1167102 DEBUG
(OverseerStateUpdate-72059247537684483-127.0.0.1:39655_solr-n_0000000000)
[n:127.0.0.1:39655_solr ] o.a.s.c.o.ReplicaMutator Update state numShards=1
message={
[junit4] 2> "core":"testNodeAdded_shard1_replica_n1",
[junit4] 2> "core_node_name":"core_node3",
[junit4] 2> "roles":null,
[junit4] 2> "base_url":"https://127.0.0.1:39655/solr";,
[junit4] 2> "node_name":"127.0.0.1:39655_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> 1167102 DEBUG
(OverseerStateUpdate-72059247537684483-127.0.0.1:39655_solr-n_0000000000)
[n:127.0.0.1:39655_solr ] o.a.s.c.o.ReplicaMutator Will update state for
replica:
core_node3:{"core":"testNodeAdded_shard1_replica_n1","base_url":"https://127.0.0.1:39655/solr","node_name":"127.0.0.1:39655_solr","state":"active","type":"NRT","leader":"true"}
[junit4] 2> 1167102 DEBUG
(OverseerStateUpdate-72059247537684483-127.0.0.1:39655_solr-n_0000000000)
[n:127.0.0.1:39655_solr ] o.a.s.c.o.ReplicaMutator Collection is now:
DocCollection(testNodeAdded//collections/testNodeAdded/state.json/4)={
[junit4] 2> "pullReplicas":"0",
[junit4] 2> "replicationFactor":"2",
[junit4] 2> "router":{"name":"compositeId"},
[junit4] 2> "maxShardsPerNode":"1",
[junit4] 2> "autoAddReplicas":"false",
[junit4] 2> "nrtReplicas":"2",
[junit4] 2> "tlogReplicas":"0",
[junit4] 2> "shards":{"shard1":{
[junit4] 2> "range":"80000000-7fffffff",
[junit4] 2> "state":"active",
[junit4] 2> "replicas":{
[junit4] 2> "core_node3":{
[junit4] 2> "core":"testNodeAdded_shard1_replica_n1",
[junit4] 2> "base_url":"https://127.0.0.1:39655/solr";,
[junit4] 2> "node_name":"127.0.0.1:39655_solr",
[junit4] 2> "state":"active",
[junit4] 2> "type":"NRT",
[junit4] 2> "leader":"true"},
[junit4] 2> "core_node4":{
[junit4] 2> "core":"testNodeAdded_shard1_replica_n2",
[junit4] 2> "base_url":"https://127.0.0.1:39655/solr";,
[junit4] 2> "node_name":"127.0.0.1:39655_solr",
[junit4] 2> "state":"down",
[junit4] 2> "type":"NRT"}}}}}
[junit4] 2> 1167183 INFO (qtp1357068221-11829) [n:127.0.0.1:39655_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=1614
[junit4] 2> 1167202 DEBUG
(OverseerStateUpdate-72059247537684483-127.0.0.1:39655_solr-n_0000000000)
[n:127.0.0.1:39655_solr ] o.a.s.c.o.ZkStateWriter going to update_collection
/collections/testNodeAdded/state.json version: 4
[junit4] 2> 1167202 INFO
(zkCallback-2108-thread-2-processing-n:127.0.0.1:39655_solr)
[n:127.0.0.1:39655_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> 1167202 INFO
(zkCallback-2108-thread-3-processing-n:127.0.0.1:39655_solr)
[n:127.0.0.1:39655_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> 1167202 INFO
(zkCallback-2108-thread-1-processing-n:127.0.0.1:39655_solr)
[n:127.0.0.1:39655_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> 1167253 DEBUG (ScheduledTrigger-4220-thread-2)
[n:127.0.0.1:39655_solr ] o.a.s.c.a.NodeAddedTrigger Running
NodeAddedTrigger node_added_trigger
[junit4] 2> 1167253 DEBUG (ScheduledTrigger-4220-thread-2)
[n:127.0.0.1:39655_solr ] o.a.s.c.a.NodeAddedTrigger Found livenodes: 1
[junit4] 2> 1167648 DEBUG
(OverseerStateUpdate-72059247537684483-127.0.0.1:39655_solr-n_0000000000)
[n:127.0.0.1:39655_solr ] o.a.s.c.Overseer processMessage: queueSize: 1,
message = {
[junit4] 2> "core":"testNodeAdded_shard1_replica_n2",
[junit4] 2> "core_node_name":"core_node4",
[junit4] 2> "roles":null,
[junit4] 2> "base_url":"https://127.0.0.1:39655/solr";,
[junit4] 2> "node_name":"127.0.0.1:39655_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> 1167648 DEBUG
(OverseerStateUpdate-72059247537684483-127.0.0.1:39655_solr-n_0000000000)
[n:127.0.0.1:39655_solr ] o.a.s.c.o.ReplicaMutator Update state numShards=1
message={
[junit4] 2> "core":"testNodeAdded_shard1_replica_n2",
[junit4] 2> "core_node_name":"core_node4",
[junit4] 2> "roles":null,
[junit4] 2> "base_url":"https://127.0.0.1:39655/solr";,
[junit4] 2> "node_name":"127.0.0.1:39655_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> 1167648 DEBUG
(OverseerStateUpdate-72059247537684483-127.0.0.1:39655_solr-n_0000000000)
[n:127.0.0.1:39655_solr ] o.a.s.c.o.ReplicaMutator Will update state for
replica:
core_node4:{"core":"testNodeAdded_shard1_replica_n2","base_url":"https://127.0.0.1:39655/solr","node_name":"127.0.0.1:39655_solr","state":"active","type":"NRT"}
[junit4] 2> 1167649 DEBUG
(OverseerStateUpdate-72059247537684483-127.0.0.1:39655_solr-n_0000000000)
[n:127.0.0.1:39655_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":"https://127.0.0.1:39655/solr";,
[junit4] 2> "node_name":"127.0.0.1:39655_solr",
[junit4] 2> "state":"active",
[junit4] 2> "type":"NRT",
[junit4] 2> "leader":"true"},
[junit4] 2> "core_node4":{
[junit4] 2> "core":"testNodeAdded_shard1_replica_n2",
[junit4] 2> "base_url":"https://127.0.0.1:39655/solr";,
[junit4] 2> "node_name":"127.0.0.1:39655_solr",
[junit4] 2> "state":"active",
[junit4] 2> "type":"NRT"}}}}}
[junit4] 2> 1167654 INFO (qtp1357068221-11866) [n:127.0.0.1:39655_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=2085
[junit4] 2> 1167655 INFO (qtp1357068221-11834) [n:127.0.0.1:39655_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> 1167749 DEBUG
(OverseerStateUpdate-72059247537684483-127.0.0.1:39655_solr-n_0000000000)
[n:127.0.0.1:39655_solr ] o.a.s.c.o.ZkStateWriter going to update_collection
/collections/testNodeAdded/state.json version: 5
[junit4] 2> 1167749 INFO
(zkCallback-2108-thread-1-processing-n:127.0.0.1:39655_solr)
[n:127.0.0.1:39655_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> 1167749 INFO
(zkCallback-2108-thread-2-processing-n:127.0.0.1:39655_solr)
[n:127.0.0.1:39655_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> 1167749 INFO
(zkCallback-2108-thread-3-processing-n:127.0.0.1:39655_solr)
[n:127.0.0.1:39655_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> 1168254 DEBUG (ScheduledTrigger-4220-thread-2)
[n:127.0.0.1:39655_solr ] o.a.s.c.a.NodeAddedTrigger Running
NodeAddedTrigger node_added_trigger
[junit4] 2> 1168254 DEBUG (ScheduledTrigger-4220-thread-2)
[n:127.0.0.1:39655_solr ] o.a.s.c.a.NodeAddedTrigger Found livenodes: 1
[junit4] 2> 1168655 INFO (qtp1357068221-11834) [n:127.0.0.1:39655_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=3405
[junit4] 2> 1168659 INFO (qtp1357068221-11836) [n:127.0.0.1:39655_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> 1168660 INFO (qtp1357068221-11866) [n:127.0.0.1:39655_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> 1168660 DEBUG (qtp1357068221-11830) [n:127.0.0.1:39655_solr
] o.a.s.c.a.AutoScalingHandler Verified autoscaling configuration
[junit4] 2> 1168661 INFO (qtp1357068221-11830) [n:127.0.0.1:39655_solr
] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/autoscaling
params={wt=javabin&version=2} status=0 QTime=3
[junit4] 2> 1168661 DEBUG
(zkCallback-2108-thread-2-processing-n:127.0.0.1:39655_solr)
[n:127.0.0.1:39655_solr ] o.a.s.c.a.OverseerTriggerThread Refreshing
/autoscaling.json with znode version 7
[junit4] 2> 1168661 DEBUG
(zkCallback-2108-thread-2-processing-n:127.0.0.1:39655_solr)
[n:127.0.0.1:39655_solr ] o.a.s.c.a.NodeAddedTrigger Initial livenodes:
[127.0.0.1:39655_solr]
[junit4] 2> 1168661 DEBUG
(zkCallback-2108-thread-2-processing-n:127.0.0.1:39655_solr)
[n:127.0.0.1:39655_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> 1168661 DEBUG
(OverseerAutoScalingTriggerThread-72059247537684483-127.0.0.1:39655_solr-n_0000000000)
[n:127.0.0.1:39655_solr ] o.a.s.c.a.OverseerTriggerThread Processed trigger
updates upto znodeVersion 7
[junit4] 2> 1168662 DEBUG
(OverseerAutoScalingTriggerThread-72059247537684483-127.0.0.1:39655_solr-n_0000000000)
[n:127.0.0.1:39655_solr ] o.a.s.c.a.OverseerTriggerThread -- clean old
nodeLost markers
[junit4] 2> 1168662 DEBUG
(OverseerAutoScalingTriggerThread-72059247537684483-127.0.0.1:39655_solr-n_0000000000)
[n:127.0.0.1:39655_solr ] o.a.s.c.a.OverseerTriggerThread Current
znodeVersion 7, lastZnodeVersion 7
[junit4] 2> 1168662 INFO
(TEST-ComputePlanActionTest.testNodeAdded-seed#[8FA1EBE83DCC545B]) [ ]
o.e.j.s.Server jetty-9.4.8.v20171121, build timestamp:
2017-11-22T00:27:37+03:00, git hash: 82b8fb23f757335bb3329d540ce37a2a2615f0a8
[junit4] 2> 1168663 INFO
(TEST-ComputePlanActionTest.testNodeAdded-seed#[8FA1EBE83DCC545B]) [ ]
o.e.j.s.session DefaultSessionIdManager workerName=node0
[junit4] 2> 1168663 INFO
(TEST-ComputePlanActionTest.testNodeAdded-seed#[8FA1EBE83DCC545B]) [ ]
o.e.j.s.session No SessionScavenger set, using defaults
[junit4] 2> 1168663 INFO
(TEST-ComputePlanActionTest.testNodeAdded-seed#[8FA1EBE83DCC545B]) [ ]
o.e.j.s.session Scavenging every 600000ms
[junit4] 2> 1168663 INFO
(TEST-ComputePlanActionTest.testNodeAdded-seed#[8FA1EBE83DCC545B]) [ ]
o.e.j.s.h.ContextHandler Started
o.e.j.s.ServletContextHandler@14f9fd70{/solr,null,AVAILABLE}
[junit4] 2> 1168663 INFO
(TEST-ComputePlanActionTest.testNodeAdded-seed#[8FA1EBE83DCC545B]) [ ]
o.e.j.s.AbstractConnector Started ServerConnector@3a9b68b7{SSL,[ssl,
http/1.1]}{127.0.0.1:45745}
[junit4] 2> 1168663 INFO
(TEST-ComputePlanActionTest.testNodeAdded-seed#[8FA1EBE83DCC545B]) [ ]
o.e.j.s.Server Started @1170265ms
[junit4] 2> 1168664 INFO
(TEST-ComputePlanActionTest.testNodeAdded-seed#[8FA1EBE83DCC545B]) [ ]
o.a.s.c.s.e.JettySolrRunner Jetty properties: {hostContext=/solr,
hostPort=45745}
[junit4] 2> 1168664 ERROR
(TEST-ComputePlanActionTest.testNodeAdded-seed#[8FA1EBE83DCC545B]) [ ]
o.a.s.u.StartupLoggingUtils Missing Java Option solr.log.dir. Logging may be
missing or incomplete.
[junit4] 2> 1168664 INFO
(TEST-ComputePlanActionTest.testNodeAdded-seed#[8FA1EBE83DCC545B]) [ ]
o.a.s.s.SolrDispatchFilter ___ _ Welcome to Apache Solr? version
7.3.0
[junit4] 2> 1168664 INFO
(TEST-ComputePlanActionTest.testNodeAdded-seed#[8FA1EBE83DCC545B]) [ ]
o.a.s.s.SolrDispatchFilter / __| ___| |_ _ Starting in cloud mode on port null
[junit4] 2> 1168664 INFO
(TEST-ComputePlanActionTest.testNodeAdded-seed#[8FA1EBE83DCC545B]) [ ]
o.a.s.s.SolrDispatchFilter \__ \/ _ \ | '_| Install dir: null
[junit4] 2> 1168664 INFO
(TEST-ComputePlanActionTest.testNodeAdded-seed#[8FA1EBE83DCC545B]) [ ]
o.a.s.s.SolrDispatchFilter |___/\___/_|_| Start time:
2018-01-29T21:41:13.622550Z
[junit4] 2> 1168665 INFO (zkConnectionManagerCallback-2120-thread-1) [
] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 1168665 INFO
(TEST-ComputePlanActionTest.testNodeAdded-seed#[8FA1EBE83DCC545B]) [ ]
o.a.s.s.SolrDispatchFilter solr.xml found in ZooKeeper. Loading...
[junit4] 2> 1168671 INFO
(TEST-ComputePlanActionTest.testNodeAdded-seed#[8FA1EBE83DCC545B]) [ ]
o.a.s.c.ZkContainer Zookeeper client=127.0.0.1:45779/solr
[junit4] 2> 1168672 INFO (zkConnectionManagerCallback-2124-thread-1) [
] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 1168673 INFO
(zkConnectionManagerCallback-2126-thread-1-processing-n:127.0.0.1:45745_solr)
[n:127.0.0.1:45745_solr ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 1168675 INFO
(TEST-ComputePlanActionTest.testNodeAdded-seed#[8FA1EBE83DCC545B])
[n:127.0.0.1:45745_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from
ZooKeeper... (0) -> (1)
[junit4] 2> 1168676 INFO
(TEST-ComputePlanActionTest.testNodeAdded-seed#[8FA1EBE83DCC545B])
[n:127.0.0.1:45745_solr ] o.a.s.c.Overseer Overseer (id=null) closing
[junit4] 2> 1168677 INFO
(TEST-ComputePlanActionTest.testNodeAdded-seed#[8FA1EBE83DCC545B])
[n:127.0.0.1:45745_solr ] o.a.s.c.ZkController Register node as live in
ZooKeeper:/live_nodes/127.0.0.1:45745_solr
[junit4] 2> 1168677 DEBUG
(OverseerStateUpdate-72059247537684483-127.0.0.1:39655_solr-n_0000000000)
[n:127.0.0.1:39655_solr ] o.a.s.c.Overseer processMessage: queueSize: 1,
message = {
[junit4] 2> "operation":"downnode",
[junit4] 2> "node_name":"127.0.0.1:45745_solr"} current state version: 0
[junit4] 2> 1168677 DEBUG
(OverseerStateUpdate-72059247537684483-127.0.0.1:39655_solr-n_0000000000)
[n:127.0.0.1:39655_solr ] o.a.s.c.o.NodeMutator DownNode state invoked for
node: 127.0.0.1:45745_solr
[junit4] 2> 1168678 INFO (zkCallback-2116-thread-2) [ ]
o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (1) -> (2)
[junit4] 2> 1168678 INFO (zkCallback-2116-thread-1) [ ]
o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (1) -> (2)
[junit4] 2> 1168678 INFO
(zkCallback-2108-thread-2-processing-n:127.0.0.1:39655_solr)
[n:127.0.0.1:39655_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from
ZooKeeper... (1) -> (2)
[junit4] 2> 1168678 INFO
(zkCallback-2125-thread-1-processing-n:127.0.0.1:45745_solr)
[n:127.0.0.1:45745_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from
ZooKeeper... (1) -> (2)
[junit4] 2> 1168708 INFO
(TEST-ComputePlanActionTest.testNodeAdded-seed#[8FA1EBE83DCC545B])
[n:127.0.0.1:45745_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for
'solr_45745.solr.node' (registry 'solr.node') enabled at server:
com.sun.jmx.mbeanserver.JmxMBeanServer@e817da5
[junit4] 2> 1168714 INFO
(TEST-ComputePlanActionTest.testNodeAdded-seed#[8FA1EBE83DCC545B])
[n:127.0.0.1:45745_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for
'solr_45745.solr.jvm' (registry 'solr.jvm') enabled at server:
com.sun.jmx.mbeanserver.JmxMBeanServer@e817da5
[junit4] 2> 1168714 INFO
(TEST-ComputePlanActionTest.testNodeAdded-seed#[8FA1EBE83DCC545B])
[n:127.0.0.1:45745_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for
'solr_45745.solr.jetty' (registry 'solr.jetty') enabled at server:
com.sun.jmx.mbeanserver.JmxMBeanServer@e817da5
[junit4] 2> 1168715 INFO
(TEST-ComputePlanActionTest.testNodeAdded-seed#[8FA1EBE83DCC545B])
[n:127.0.0.1:45745_solr ] o.a.s.c.CorePropertiesLocator Found 0 core
definitions underneath
/home/jenkins/workspace/Lucene-Solr-7.x-Linux/solr/build/solr-core/test/J2/temp/solr.cloud.autoscaling.ComputePlanActionTest_8FA1EBE83DCC545B-001/tempDir-001/node2/.
[junit4] 2> 1169252 INFO
(OverseerCollectionConfigSetProcessor-72059247537684483-127.0.0.1:39655_solr-n_0000000000)
[n:127.0.0.1:39655_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> 1169254 DEBUG (ScheduledTrigger-4220-thread-2)
[n:127.0.0.1:39655_solr ] o.a.s.c.a.NodeAddedTrigger Running
NodeAddedTrigger node_added_trigger
[junit4] 2> 1169254 DEBUG (ScheduledTrigger-4220-thread-2)
[n:127.0.0.1:39655_solr ] o.a.s.c.a.NodeAddedTrigger Found livenodes: 2
[junit4] 2> 1169254 DEBUG (ScheduledTrigger-4220-thread-2)
[n:127.0.0.1:39655_solr ] o.a.s.c.a.NodeAddedTrigger Tracking new node:
127.0.0.1:45745_solr at time 25234649837248
[junit4] 2> 1170254 DEBUG (ScheduledTrigger-4220-thread-2)
[n:127.0.0.1:39655_solr ] o.a.s.c.a.NodeAddedTrigger Running
NodeAddedTrigger node_added_trigger
[junit4] 2> 1170254 DEBUG (ScheduledTrigger-4220-thread-2)
[n:127.0.0.1:39655_solr ] o.a.s.c.a.NodeAddedTrigger Found livenodes: 2
[junit4] 2> 1170255 DEBUG (ScheduledTrigger-4220-thread-2)
[n:127.0.0.1:39655_solr ] o.a.s.c.a.NodeAddedTrigger NodeAddedTrigger
node_added_trigger firing registered processor for nodes:
[127.0.0.1:45745_solr] added at times [25234649837248], now=25235650474567
[junit4] 2> 1170255 DEBUG (ScheduledTrigger-4220-thread-2)
[n:127.0.0.1:39655_solr ] o.a.s.c.a.ScheduledTriggers ++++++++ Cooldown
inactive - processing event: {
[junit4] 2> "id":"16f36656eec0Tba9evxvoyzpwykyxov6ebvm0j",
[junit4] 2> "source":"node_added_trigger",
[junit4] 2> "eventTime":25234649837248,
[junit4] 2> "eventType":"NODEADDED",
[junit4] 2> "properties":{
[junit4] 2> "eventTimes":[25234649837248],
[junit4] 2> "nodeNames":["127.0.0.1:45745_solr"]}}
[junit4] 2> 1170255 DEBUG (ScheduledTrigger-4220-thread-2)
[n:127.0.0.1:39655_solr ] o.a.s.c.a.ScheduledTriggers Pausing all triggers:
[node_added_trigger]
[junit4] 2> 1170256 INFO (ScheduledTrigger-4220-thread-2)
[n:127.0.0.1:39655_solr ] o.a.s.c.a.SystemLogListener Collection .system
does not exist, disabling logging.
[junit4] 2> 1170256 DEBUG
(AutoscalingActionExecutor-4221-thread-1-processing-n:127.0.0.1:39655_solr)
[n:127.0.0.1:39655_solr ] o.a.s.c.a.ScheduledTriggers -- processing actions
for {
[junit4] 2> "id":"16f36656eec0Tba9evxvoyzpwykyxov6ebvm0j",
[junit4] 2> "source":"node_added_trigger",
[junit4] 2> "eventTime":25234649837248,
[junit4] 2> "eventType":"NODEADDED",
[junit4] 2> "properties":{
[junit4] 2> "eventTimes":[25234649837248],
[junit4] 2> "_enqueue_time_":25235650983383,
[junit4] 2> "nodeNames":["127.0.0.1:45745_solr"]}}
[junit4] 2> 1170256 DEBUG
(AutoscalingActionExecutor-4221-thread-1-processing-n:127.0.0.1:39655_solr)
[n:127.0.0.1:39655_solr ] o.a.s.c.a.ComputePlanAction -- processing event: {
[junit4] 2> "id":"16f36656eec0Tba9evxvoyzpwykyxov6ebvm0j",
[junit4] 2> "source":"node_added_trigger",
[junit4] 2> "eventTime":25234649837248,
[junit4] 2> "eventType":"NODEADDED",
[junit4] 2> "properties":{
[junit4] 2> "eventTimes":[25234649837248],
[junit4] 2> "_enqueue_time_":25235650983383,
[junit4] 2> "nodeNames":["127.0.0.1:45745_solr"]}} with context
properties: {BEFORE_ACTION=[compute_plan]}
[junit4] 2> 1170257 INFO (qtp1357068221-11836) [n:127.0.0.1:39655_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> 1170258 INFO (qtp1357068221-11830) [n:127.0.0.1:39655_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> 1170271 INFO (qtp1922004914-11893) [n:127.0.0.1:45745_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> 1170271 INFO
(AutoscalingActionExecutor-4221-thread-1-processing-n:127.0.0.1:39655_solr)
[n:127.0.0.1:39655_solr ] o.a.s.c.a.ComputePlanAction Computed Plan:
action=MOVEREPLICA&collection=testNodeAdded&targetNode=127.0.0.1:45745_solr&inPlaceMove=true&replica=core_node3
[junit4] 2> 1170272 INFO
(AutoscalingActionExecutor-4221-thread-1-processing-n:127.0.0.1:39655_solr)
[n:127.0.0.1:39655_solr ] o.a.s.c.s.c.a.PolicyHelper returnSession,
curr-time 25235667 sessionWrapper.createTime 25235667013528,
this.sessionWrapper.createTime 25235667013528
[junit4] 2> 1170272 DEBUG
(TEST-ComputePlanActionTest.testNodeAdded-seed#[8FA1EBE83DCC545B]) [ ]
o.a.s.c.a.ComputePlanActionTest -------------_ FINAL STATE --------------
[junit4] 2> 1170272 DEBUG
(AutoscalingActionExecutor-4221-thread-1-processing-n:127.0.0.1:39655_solr)
[n:127.0.0.1:39655_solr ] o.a.s.c.a.ScheduledTriggers Resuming trigger:
node_added_trigger after 5000ms
[junit4] 2> 1170272 DEBUG
(AutoscalingActionExecutor-4221-thread-1-processing-n:127.0.0.1:39655_solr)
[n:127.0.0.1:39655_solr ] o.a.s.c.a.ScheduledTriggers -- processing took 16
ms for event id=16f36656eec0Tba9evxvoyzpwykyxov6ebvm0j
[junit4] 2> 1170273 INFO (qtp1357068221-11836) [n:127.0.0.1:39655_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> 1170274 DEBUG
(TEST-ComputePlanActionTest.testNodeAdded-seed#[8FA1EBE83DCC545B]) [ ]
o.a.s.c.a.ComputePlanActionTest * Node values: 127.0.0.1:39655_solr
[junit4] 2> {
[junit4] 2> "node":"127.0.0.1:39655_solr",
[junit4] 2> "cores":2,
[junit4] 2> "port":"39655",
[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":219.48534393310547}
[junit4] 2> 1170275 INFO (qtp1922004914-11895) [n:127.0.0.1:45745_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> 1170275 DEBUG
(TEST-ComputePlanActionTest.testNodeAdded-seed#[8FA1EBE83DCC545B]) [ ]
o.a.s.c.a.ComputePlanActionTest * Node values: 127.0.0.1:45745_solr
[junit4] 2> {
[junit4] 2> "node":"127.0.0.1:45745_solr",
[junit4] 2> "cores":0,
[junit4] 2> "port":"45745",
[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":219.48534393310547}
[junit4] 2> 1170275 DEBUG
(TEST-ComputePlanActionTest.testNodeAdded-seed#[8FA1EBE83DCC545B]) [ ]
o.a.s.c.a.ComputePlanActionTest * Live nodes: [127.0.0.1:39655_solr,
127.0.0.1:45745_solr]
[junit4] 2> 1170275 DEBUG
(TEST-ComputePlanActionTest.testNodeAdded-seed#[8FA1EBE83DCC545B]) [ ]
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":"https://127.0.0.1:39655/solr";,
[junit4] 2> "node_name":"127.0.0.1:39655_solr",
[junit4] 2> "state":"active",
[junit4] 2> "type":"NRT",
[junit4] 2> "leader":"true"},
[junit4] 2> "core_node4":{
[junit4] 2> "core":"testNodeAdded_shard1_replica_n2",
[junit4] 2> "base_url":"https://127.0.0.1:39655/solr";,
[junit4] 2> "node_name":"127.0.0.1:39655_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> 1170275 INFO
(TEST-ComputePlanActionTest.testNodeAdded-seed#[8FA1EBE83DCC545B]) [ ]
o.a.s.SolrTestCaseJ4 ###Ending testNodeAdded
[junit4] 2> 1170285 INFO
(TEST-ComputePlanActionTest.testSelectedCollections-seed#[8FA1EBE83DCC545B]) [
] o.a.s.SolrTestCaseJ4 ###Starting testSelectedCollections
[junit4] 2> 1170286 DEBUG
(zkCallback-2108-thread-2-processing-n:127.0.0.1:39655_solr)
[n:127.0.0.1:39655_solr ] o.a.s.c.a.OverseerTriggerThread Refreshing
/autoscaling.json with znode version 8
[junit4] 2> 1170286 DEBUG
(OverseerAutoScalingTriggerThread-72059247537684483-127.0.0.1:39655_solr-n_0000000000)
[n:127.0.0.1:39655_solr ] o.a.s.c.a.OverseerTriggerThread Processed trigger
updates upto znodeVersion 8
[junit4] 2> 1170286 INFO
(TEST-ComputePlanActionTest.testSelectedCollections-seed#[8FA1EBE83DCC545B]) [
] o.e.j.s.AbstractConnector Stopped ServerConnector@3a9b68b7{SSL,[ssl,
http/1.1]}{127.0.0.1:0}
[junit4] 2> 1170286 INFO
(TEST-ComputePlanActionTest.testSelectedCollections-seed#[8FA1EBE83DCC545B]) [
] o.a.s.c.CoreContainer Shutting down CoreContainer instance=1690809063
[junit4] 2> 1170286 DEBUG
(OverseerAutoScalingTriggerThread-72059247537684483-127.0.0.1:39655_solr-n_0000000000)
[n:127.0.0.1:39655_solr ] o.a.s.c.a.OverseerTriggerThread -- clean old
nodeLost markers
[junit4] 2> 1170287 INFO
(TEST-ComputePlanActionTest.testSelectedCollections-seed#[8FA1EBE83DCC545B]) [
] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.node,
tag=null
[junit4] 2> 1170287 INFO
(TEST-ComputePlanActionTest.testSelectedCollections-seed#[8FA1EBE83DCC545B]) [
] o.a.s.m.r.SolrJmxReporter Closing reporter
[org.apache.solr.metrics.reporters.SolrJmxReporter@7bb9827e: rootName =
solr_45745, domain = solr.node, service url = null, agent id = null] for
registry solr.node / com.codahale.metrics.MetricRegistry@e2d3902
[junit4] 2> 1170287 DEBUG
(OverseerAutoScalingTriggerThread-72059247537684483-127.0.0.1:39655_solr-n_0000000000)
[n:127.0.0.1:39655_solr ] o.a.s.c.a.OverseerTriggerThread -- clean old
nodeAdded markers
[junit4] 2> 1170287 DEBUG
(OverseerAutoScalingTriggerThread-72059247537684483-127.0.0.1:39655_solr-n_0000000000)
[
[...truncated too long message...]
Rule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:40)
[junit4] 2> at
com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:40)
[junit4] 2> at
com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
[junit4] 2> at
com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
[junit4] 2> at
org.apache.lucene.util.TestRuleAssertionsRequired$1.evaluate(TestRuleAssertionsRequired.java:53)
[junit4] 2> at
org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:47)
[junit4] 2> at
org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:64)
[junit4] 2> at
org.apache.lucene.util.TestRuleIgnoreTestSuites$1.evaluate(TestRuleIgnoreTestSuites.java:54)
[junit4] 2> at
com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
[junit4] 2> at
com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:368)
[junit4] 2> at java.base/java.lang.Thread.run(Thread.java:844)
[junit4] 2>
[junit4] 2> 1309945 INFO
(TEST-StatsReloadRaceTest.testParallelReloadAndStats-seed#[8FA1EBE83DCC545B]) [
] o.a.s.SolrTestCaseJ4 ###Ending testParallelReloadAndStats
[junit4] 2> NOTE: reproduce with: ant test -Dtestcase=StatsReloadRaceTest
-Dtests.method=testParallelReloadAndStats -Dtests.seed=8FA1EBE83DCC545B
-Dtests.multiplier=3 -Dtests.slow=true -Dtests.locale=en-TK
-Dtests.timezone=Asia/Hovd -Dtests.asserts=true -Dtests.file.encoding=ISO-8859-1
[junit4] FAILURE 18.2s J2 | StatsReloadRaceTest.testParallelReloadAndStats
<<<
[junit4] > Throwable #1: java.lang.AssertionError: missing 'metrics'
element in handler's output: {}
[junit4] > at
__randomizedtesting.SeedInfo.seed([8FA1EBE83DCC545B:403F8ED1B23D3C04]:0)
[junit4] > at
org.apache.solr.handler.admin.StatsReloadRaceTest.requestMetrics(StatsReloadRaceTest.java:128)
[junit4] > at
org.apache.solr.handler.admin.StatsReloadRaceTest.testParallelReloadAndStats(StatsReloadRaceTest.java:77)
[junit4] > at
java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
[junit4] > at
java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
[junit4] > at
java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
[junit4] > at
java.base/java.lang.reflect.Method.invoke(Method.java:564)
[junit4] > at java.base/java.lang.Thread.run(Thread.java:844)
[junit4] 2> 1309946 INFO
(SUITE-StatsReloadRaceTest-seed#[8FA1EBE83DCC545B]-worker) [ ]
o.a.s.SolrTestCaseJ4 ###deleteCore
[junit4] 2> 1309946 INFO
(SUITE-StatsReloadRaceTest-seed#[8FA1EBE83DCC545B]-worker) [ ]
o.a.s.c.CoreContainer Shutting down CoreContainer instance=2007043069
[junit4] 2> 1309946 INFO
(SUITE-StatsReloadRaceTest-seed#[8FA1EBE83DCC545B]-worker) [ ]
o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.node,
tag=null
[junit4] 2> 1309946 INFO
(SUITE-StatsReloadRaceTest-seed#[8FA1EBE83DCC545B]-worker) [ ]
o.a.s.m.r.SolrJmxReporter Closing reporter
[org.apache.solr.metrics.reporters.SolrJmxReporter@434d8e0e: rootName = null,
domain = solr.node, service url = null, agent id = null] for registry solr.node
/ com.codahale.metrics.MetricRegistry@775e6e70
[junit4] 2> 1309950 INFO
(SUITE-StatsReloadRaceTest-seed#[8FA1EBE83DCC545B]-worker) [ ]
o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.jvm,
tag=null
[junit4] 2> 1309950 INFO
(SUITE-StatsReloadRaceTest-seed#[8FA1EBE83DCC545B]-worker) [ ]
o.a.s.m.r.SolrJmxReporter Closing reporter
[org.apache.solr.metrics.reporters.SolrJmxReporter@7dbabf76: rootName = null,
domain = solr.jvm, service url = null, agent id = null] for registry solr.jvm /
com.codahale.metrics.MetricRegistry@767ee139
[junit4] 2> 1309953 INFO
(SUITE-StatsReloadRaceTest-seed#[8FA1EBE83DCC545B]-worker) [ ]
o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.jetty,
tag=null
[junit4] 2> 1309953 INFO
(SUITE-StatsReloadRaceTest-seed#[8FA1EBE83DCC545B]-worker) [ ]
o.a.s.m.r.SolrJmxReporter Closing reporter
[org.apache.solr.metrics.reporters.SolrJmxReporter@15bc23d1: rootName = null,
domain = solr.jetty, service url = null, agent id = null] for registry
solr.jetty / com.codahale.metrics.MetricRegistry@5b47ae8a
[junit4] 2> 1309954 INFO (coreCloseExecutor-4598-thread-1) [
x:collection1] o.a.s.c.SolrCore [collection1] CLOSING SolrCore
org.apache.solr.core.SolrCore@2ce2d2f5
[junit4] 2> 1309954 INFO (coreCloseExecutor-4598-thread-1) [
x:collection1] o.a.s.m.SolrMetricManager Closing metric reporters for
registry=solr.core.collection1, tag=753062645
[junit4] 2> 1309954 INFO (coreCloseExecutor-4598-thread-1) [
x:collection1] o.a.s.m.r.SolrJmxReporter Closing reporter
[org.apache.solr.metrics.reporters.SolrJmxReporter@2b49aa39: rootName = null,
domain = solr.core.collection1, service url = null, agent id = null] for
registry solr.core.collection1 / com.codahale.metrics.MetricRegistry@6b94e203
[junit4] 2> 1309963 ERROR (coreCloseExecutor-4598-thread-1) [
x:collection1] o.a.s.c.SolrCore org.apache.lucene.store.AlreadyClosedException:
this IndexReader is closed
[junit4] 2> at
org.apache.lucene.index.IndexReader.ensureOpen(IndexReader.java:268)
[junit4] 2> at
org.apache.lucene.index.StandardDirectoryReader.getVersion(StandardDirectoryReader.java:338)
[junit4] 2> at
org.apache.lucene.index.FilterDirectoryReader.getVersion(FilterDirectoryReader.java:119)
[junit4] 2> at
org.apache.lucene.index.FilterDirectoryReader.getVersion(FilterDirectoryReader.java:119)
[junit4] 2> at
org.apache.solr.search.SolrIndexSearcher.lambda$initializeMetrics$14(SolrIndexSearcher.java:2263)
[junit4] 2> at
org.apache.solr.metrics.SolrCoreMetricManager.lambda$close$1(SolrCoreMetricManager.java:156)
[junit4] 2> at
java.base/java.util.TreeMap.forEach(TreeMap.java:1002)
[junit4] 2> at
java.base/java.util.Collections$UnmodifiableMap.forEach(Collections.java:1506)
[junit4] 2> at
org.apache.solr.metrics.SolrCoreMetricManager.close(SolrCoreMetricManager.java:155)
[junit4] 2> at
org.apache.solr.core.SolrCore.close(SolrCore.java:1513)
[junit4] 2> at
org.apache.solr.core.SolrCores.lambda$close$0(SolrCores.java:141)
[junit4] 2> at
java.base/java.util.concurrent.FutureTask.run(FutureTask.java:264)
[junit4] 2> at
org.apache.solr.common.util.ExecutorUtil$MDCAwareThreadPoolExecutor.lambda$execute$0(ExecutorUtil.java:188)
[junit4] 2> at
java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1167)
[junit4] 2> at
java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:641)
[junit4] 2> at java.base/java.lang.Thread.run(Thread.java:844)
[junit4] 2>
[junit4] 2> NOTE: leaving temporary files on disk at:
/home/jenkins/workspace/Lucene-Solr-7.x-Linux/solr/build/solr-core/test/J2/temp/solr.handler.admin.StatsReloadRaceTest_8FA1EBE83DCC545B-001
[junit4] 2> NOTE: test params are: codec=Asserting(Lucene70):
{name_s=Lucene50(blocksize=128), multiDefault=FST50,
id=Lucene50(blocksize=128)},
docValues:{range_facet_l_dv=DocValuesFormat(name=Lucene70),
_version_=DocValuesFormat(name=Lucene70),
range_facet_i_dv=DocValuesFormat(name=Asserting),
intDvoDefault=DocValuesFormat(name=Lucene70),
timestamp=DocValuesFormat(name=Asserting)}, maxPointsInLeafNode=1751,
maxMBSortInHeap=6.37510935839959, sim=RandomSimilarity(queryNorm=true): {},
locale=en-TK, timezone=Asia/Hovd
[junit4] 2> NOTE: Linux 4.13.0-32-generic amd64/Oracle Corporation 9.0.1
(64-bit)/cpus=8,threads=1,free=184652600,total=518979584
[junit4] 2> NOTE: All tests run in this JVM: [TestCloudRecovery,
TestCorePropertiesReload, TestFiltering, DeleteReplicaTest, TestStressReorder,
TestConfigSetsAPI, TlogReplayBufferedWhileIndexingTest,
TestTolerantUpdateProcessorCloud, MinimalSchemaTest, TestNRTOpen,
TestSimpleTextCodec, TestLMJelinekMercerSimilarityFactory,
TestDistributedMissingSort, TestLFUCache, TestFilteredDocIdSet,
MergeStrategyTest, ReturnFieldsTest, DateFieldTest, TestCodecSupport,
TestManagedSchemaAPI, CacheHeaderTest, TestRandomRequestDistribution,
DistributedFacetPivotSmallTest, ResponseLogComponentTest,
LIRRollingUpdatesTest, SolrCLIZkUtilsTest, TestMacroExpander,
CdcrRequestHandlerTest, TestStandardQParsers, DistanceFunctionTest,
TestAnalyzedSuggestions, TestSubQueryTransformerDistrib,
TestDFRSimilarityFactory, AliasIntegrationTest, TestCoreContainer,
SearchHandlerTest, TestChildDocTransformer, ConvertedLegacyTest, CopyFieldTest,
OverseerCollectionConfigSetProcessorTest, TestLazyCores, SearchHandlerTest,
TestAnalyzeInfixSuggestions, RecoveryZkTest, LeaderFailureAfterFreshStartTest,
SolrMetricManagerTest, TestDownShardTolerantSearch, NoCacheHeaderTest,
TestCoreBackup, MoveReplicaHDFSTest, RulesTest, TestFaceting,
MigrateRouteKeyTest, TestCryptoKeys, TestRawTransformer,
TestLeaderElectionZkExpiry, DistributedQueryComponentOptimizationTest,
TestPolicyCloud, HighlighterMaxOffsetTest, TestSchemaManager,
TestDocBasedVersionConstraints, CircularListTest,
CoreMergeIndexesAdminHandlerTest, BasicDistributedZk2Test,
TestOverriddenPrefixQueryForCustomFieldType, TestStressInPlaceUpdates,
DirectoryFactoryTest, TestAtomicUpdateErrorCases,
LeaderElectionIntegrationTest, AutoAddReplicasIntegrationTest,
CollectionsAPISolrJTest, TestCoreDiscovery, CollectionReloadTest,
ComputePlanActionTest, DistributedFacetPivotLargeTest,
FileBasedSpellCheckerTest, ChaosMonkeyNothingIsSafeWithPullReplicasTest,
StatsReloadRaceTest]
[junit4] Completed [357/771 (2!)] on J2 in 19.46s, 1 test, 1 failure <<<
FAILURES!
[...truncated 42314 lines...]
---------------------------------------------------------------------
To unsubscribe, e-mail: dev-unsubscr...@lucene.apache.org
For additional commands, e-mail: dev-h...@lucene.apache.org
